Data truncation: Incorrect datetime value: '1970-01-01 00:00:00' for column '

wojciech.kapcia@tigase.net opened 6 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 6 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 6 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 6 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 6 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 6 months ago

Workaround for MySQL TIMESTAMP limitations #163

Andrzej Wójcik (Tigase) committed 6 months ago

94eca7f9

Andrzej Wójcik (Tigase) changed state to 'In Progress' 6 months ago

Previous Value	Current Value
Open	In Progress

Andrzej Wójcik (Tigase) changed state to 'In QA' 6 months ago

Previous Value	Current Value
In Progress	In QA

Andrzej Wójcik (Tigase) commented 6 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' 6 months ago

Previous Value	Current Value
In QA	Closed

wojciech.kapcia@tigase.net commented 6 months ago

Looks good.

wojciech.kapcia@tigase.net added to iteration "tigase-server-8.5.0" 6 months ago

wojciech.kapcia@tigase.net removed from iteration "Candidate for next minor release" 6 months ago

wojciech.kapcia@tigase.net changed fields 6 months ago

Name	Previous Value	Current Value
Version	empty	tigase-server-8.5.0

Type	Bug
Priority	If you are bored
Assignee	Andrzej Wójcik (Tigase)
Version	tigase-server-8.5.0
Sprints	n/a
Customer	n/a