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

Data truncation: Incorrect datetime value: '1970-01-01 00:00:00' for column '_since' at row 1 (#163)

Wojciech Kapcia (Tigase) opened 11 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

Activities

Andrzej Wójcik (Tigase) commented 11 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 11 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) commented 11 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 11 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())); }
Andrzej Wójcik (Tigase) changed state to 'In Progress' 11 months ago
Previous Value Current Value
Open

In Progress
Andrzej Wójcik (Tigase) changed state to 'In QA' 11 months ago
Previous Value Current Value
In Progress

In QA
Andrzej Wójcik (Tigase) commented 11 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) changed state to 'Closed' 11 months ago
Previous Value Current Value
In QA

Closed
Wojciech Kapcia (Tigase) commented 11 months ago

Looks good.
Wojciech Kapcia (Tigase) added to iteration "tigase-server-8.5.0" 11 months ago
Wojciech Kapcia (Tigase) removed from iteration "Candidate for next minor release" 11 months ago
Wojciech Kapcia (Tigase) changed fields 11 months ago
Name Previous Value Current Value
Version
empty
tigase-server-8.5.0
Login to comment

Previous Value	Current Value
Open	In Progress

Previous Value	Current Value
In Progress	In QA

Previous Value	Current Value
In QA	Closed

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

Iterations

tigase-server-8.5.0 Open

Issue Votes (0)

Watchers (3)

Reference

tigase/_server/tigase-muc#163