RuntimeException: Error retrieving messages from database (Incorrect datetime value: '1969-12-31 23:59:59.999' for column '_from' ) (#78)
wojciech.kapcia@tigase.net opened 2 years ago
[2023-02-27 00:16:31:729] [SEVERE  ] [  in_3-message-archive ] StanzaProcessor.processPacket()  : Error retrieving messages from database when processing from=sess-man@ip-172-31-38-91.us-west-2.compute.internal, to=message-archive@ip-172-31-38-91.us-west-2.compute.internal, serverAuthorisedStanzaFrom=Optional.empty, DATA=<iq id="6N969-46" type="set" xmlns="jabber:client" from="…@sure.im/atalk"><query queryid="WQP2-4IYS-QDI8-C" xmlns="urn:xmpp:mam:2"><x type="submit" xmlns="jabber:x:data"><field var="FORM_TYPE"><value>urn:xmpp:mam:2</value></field><field var="with"><value>…@….im</value></field><field var="start"><value>1969-12-31T23:59:59.999+00:00</value></field></x><set xmlns="http://jabber.org/protocol/rsm"><max>50</max></set></query></iq>, SIZE=444, 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.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.server.AbstractMessageReceiver$QueueListener.run(AbstractMessageReceiver.java:1398)
Caused by: tigase.db.TigaseDBException: Cound not retrieve items
	at tigase.archive.db.JDBCMessageArchiveRepository.queryItems(JDBCMessageArchiveRepository.java:212)
	at tigase.archive.db.JDBCMessageArchiveRepository.queryItems(JDBCMessageArchiveRepository.java:53)
	at jdk.internal.reflect.GeneratedMethodAccessor72.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:75)
	at jdk.proxy2/jdk.proxy2.$Proxy54.queryItems(Unknown Source)
	at tigase.archive.db.MessageArchiveRepositoryPool.queryItems(MessageArchiveRepositoryPool.java:97)
	at tigase.archive.db.MessageArchiveRepositoryPool.queryItems(MessageArchiveRepositoryPool.java:45)
	at tigase.xmpp.mam.modules.QueryModule.process(QueryModule.java:84)
	... 5 more
Caused by: com.mysql.cj.jdbc.exceptions.MysqlDataTruncation: Data truncation: Incorrect datetime value: '1969-12-31 23:59:59.999' for column '_from' 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:38)
	at jdk.proxy2/jdk.proxy2.$Proxy35.executeQuery(Unknown Source)
	at tigase.archive.db.JDBCMessageArchiveRepository.getItemsCount(JDBCMessageArchiveRepository.java:618)
	at tigase.archive.db.JDBCMessageArchiveRepository.queryItems(JDBCMessageArchiveRepository.java:197)
	... 14 more

IMHO a proper IQ error should be returned to user.

Andrzej Wójcik (Tigase) commented 2 years ago

@wojtek Should we apply the same fix https://projects.tigase.net/issue/muc-130?

wojciech.kapcia@tigase.net commented 2 years ago

Yes

Andrzej Wójcik (Tigase) commented 2 years ago

I've fixed this issue but it is getting annoying as we already had "almost" the same issue with MySQL #issue #67 but with a difference of 1ms. I've modified previous fix to hopefully fix this, however, I'm not sure why this 1ms offset appeared nor what caused it.

Andrzej Wójcik (Tigase) commented 2 years ago

Fix in separate branch issue #78

wojciech.kapcia@tigase.net commented 2 years ago

Looks ok, can be merged (could you make a PR in the future as well?). I merged it.

As for the issue - it was sent by the client, so I would say it's a client "bug" of sorts (the timestamp itself is not inherently wrong, but it seems they were aiming at 1970…).

Andrzej Wójcik (Tigase) commented 2 years ago

I'll prepare PRs in the future.

issue 1 of 1
Type
Bug
Priority
Normal
Assignee
Version
Candidate for next minor release
Issue Votes (0)
Watchers (0)
Reference
tigase/_server/tigase-message-archiving#78
Please wait...
Page is in error, reload to recover