Projects tigase _server tigase-muc Issues #163
Data truncation: Incorrect datetime value: '1970-01-01 00:00:00' for column '_since' at row 1 (#163)
Closed
wojciech.kapcia@tigase.net opened 3 months ago
[2024-06-13 16:46:49:814] [SEVERE  ] [              in_0-muc ] StanzaProcessor.processPacket()  : Error retrieving messages from database when processing from=sess-man@ip-172-31-22-51.us-west-2.compute.internal, to=null, serverAuthorisedStanzaFrom=Optional.empty, DATA=<iq xmlns="jabber:client" id="267e597f-…-…-…-…" type="set" to="…@muc.jabber.today" from="…@jabber.today/…"><query queryid="2c5e8f51-…-…-…-…" xmlns="urn:xmpp:mam:2"><x xmlns="jabber:x:data" type="submit"><field var="FORM_TYPE" type="hidden"><value>urn:xmpp:mam:2<value></field><field var="start"><value>1970-01-01T00:00:00Z</value></field></x><set xmlns="http://jabber.org/protocol/rsm"><max>20</max><before></set></query></iq>, SIZE=492, XMLNS=jabber:client, PRIORITY=NORMAL, PERMISSION=AUTH, TYPE=set, STABLE_ID=null
java.lang.RuntimeException: Error retrieving messages from database
	at tigase.xmpp.mam.modules.QueryModule.process(QueryModule.java:86)
	at tigase.muc.modules.MAMQueryModule.process(MAMQueryModule.java:65)
	at tigase.component.modules.StanzaProcessor.execute(StanzaProcessor.java:219)
	at tigase.component.modules.StanzaProcessor.process(StanzaProcessor.java:206)
	at tigase.component.modules.StanzaProcessor.processPacket(StanzaProcessor.java:103)
	at tigase.component.AbstractKernelBasedComponent.processPacket(AbstractKernelBasedComponent.java:81)
	at tigase.muc.MUCComponent.processPacket(MUCComponent.java:122)
	at tigase.muc.cluster.MUCComponentClustered.processPacket(SourceFile:87)
	at tigase.server.AbstractMessageReceiver$QueueListener.run(AbstractMessageReceiver.java:1398)
Caused by: tigase.db.TigaseDBException: Failed to retrieve number of messages for room …@muc.jabber.today
	at tigase.muc.history.JDBCHistoryProvider.countItems(JDBCHistoryProvider.java:457)
	at tigase.muc.history.JDBCHistoryProvider.queryItems(JDBCHistoryProvider.java:283)
	at jdk.internal.reflect.GeneratedMethodAccessor90.invoke(Unknown Source)
	at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source)
	at java.base/java.lang.reflect.Method.invoke(Unknown Source)
	at tigase.stats.StatisticsInvocationHandler.invoke(StatisticsInvocationHandler.java:91)
	at jdk.proxy2/jdk.proxy2.$Proxy59.queryItems(Unknown Source)
	at tigase.muc.history.HistoryProviderMDBean.queryItems(HistoryProviderMDBean.java:151)
	at tigase.xmpp.mam.modules.QueryModule.process(QueryModule.java:84)
	... 8 more
Caused by: com.mysql.cj.jdbc.exceptions.MysqlDataTruncation: Data truncation: Incorrect datetime value: '1970-01-01 00:00:00' for column '_since' at row 1
	at com.mysql.cj.jdbc.exceptions.SQLExceptionsMapping.translateException(SQLExceptionsMapping.java:104)
	at com.mysql.cj.jdbc.ClientPreparedStatement.executeInternal(ClientPreparedStatement.java:953)
	at com.mysql.cj.jdbc.ClientPreparedStatement.executeQuery(ClientPreparedStatement.java:1009)
	at com.mysql.cj.jdbc.CallableStatement.executeQuery(CallableStatement.java:891)
	at jdk.internal.reflect.GeneratedMethodAccessor8.invoke(Unknown Source)
	at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source)
	at java.base/java.lang.reflect.Method.invoke(Unknown Source)
	at tigase.db.jdbc.PreparedStatementInvocationHandler.invoke(PreparedStatementInvocationHandler.java:43)
	at jdk.proxy2/jdk.proxy2.$Proxy42.executeQuery(Unknown Source)
	at tigase.muc.history.JDBCHistoryProvider.countItems(JDBCHistoryProvider.java:446)
	... 16 more
Andrzej Wójcik (Tigase) commented 3 months ago

I'm not sure what we can do here. We already tried to resolve this issue and if incoming data value transformed to MySQL database server timezone results in value lower that 1970-01-01 this error is triggered. As Tigase XMPP Server is not aware of MySQL server timezone, this is hard to protect against.

The only solution I could suggest would be (for MySQL) just assume that everything below arbitrary selected date value will be replaced with ie. 1970-01-02T00:00:00 just to get rid of this issue.

Andrzej Wójcik (Tigase) commented 3 months ago

Maybe the "final" solution would be to get rid of TIMESTAMP type and replace it with DATETIME? There is one more reason to do so - TIMESTAMP is only valid for dates in range 1970-01-01 to 2038-01-19 03:14:04.499999, in the next 14 years it will not be usable (unless the MySQL implementation will change).

wojciech.kapcia@tigase.net commented 3 months ago

I'm not sure what we can do here. We already tried to resolve this issue and if incoming data value transformed to MySQL database server timezone results in value lower that 1970-01-01 this error is triggered. As Tigase XMPP Server is not aware of MySQL server timezone, this is hard to protect against.

Shouldn't we be using UTC? Thus making timezones irrelevant here? Unless we don't enforce timezones correctly (on MySQL server nor on the connection level)?

Maybe the "final" solution would be to get rid of TIMESTAMP type and replace it with DATETIME? There is one more reason to do so - TIMESTAMP is only valid for dates in range 1970-01-01 to 2038-01-19 03:14:04.499999, in the next 14 years it will not be usable (unless the MySQL implementation will change).

IMHO using DATETIME seems the most reasonable here, though it's twice the size...

Andrzej Wójcik (Tigase) commented 3 months ago

Shouldn't we be using UTC? Thus making timezones irrelevant here? Unless we don't enforce timezones correctly (on MySQL server nor on the connection level)?

We specify timestamp with server time and JDBC driver passes that to MySQL but it converts data to its own value matching MySQL server time zone AFAIR.

IMHO using DATETIME seems the most reasonable here, though it's twice the size...

We have some protections for MySQL in MAM, but it also fails and I'm not sure why...

if (data_repo.getDatabaseType() == DataRepository.dbTypes.mysql && crit.getStart().getTime() <= 0) {
    stmt.setObject(i++, null);
} else {
    data_repo.setTimestamp(stmt, i++, convertToTimestamp(crit.getStart()));
}
Referenced from commit 3 months ago
Andrzej Wójcik (Tigase) changed state to 'In Progress' 3 months ago
Previous Value Current Value
Open
In Progress
Andrzej Wójcik (Tigase) changed state to 'In QA' 3 months ago
Previous Value Current Value
In Progress
In QA
Andrzej Wójcik (Tigase) commented 3 months ago

I've applied the same fix as in MAM as it should fix most of the errors. Maybe not all, but it should be good enough for now before (if) we migrate to DATETIME field type.

wojciech.kapcia@tigase.net changed state to 'Closed' 3 months ago
Previous Value Current Value
In QA
Closed
wojciech.kapcia@tigase.net commented 3 months ago

Looks good.

wojciech.kapcia@tigase.net added to iteration "tigase-server-8.5.0" 3 months ago
wojciech.kapcia@tigase.net removed from iteration "Candidate for next minor release" 3 months ago
wojciech.kapcia@tigase.net changed fields 3 months ago
Name Previous Value Current Value
Version
empty
tigase-server-8.5.0
issue 1 of 1
Type
Bug
Priority
If you are bored
Assignee
Version
tigase-server-8.5.0
Sprints
n/a
Customer
n/a
Iterations
Issue Votes (0)
Watchers (3)
Reference
tigase/_server/tigase-muc#163
Please wait...
Page is in error, reload to recover