2020.11.27 15:26:38 DEBUG [socket_c2s-thread-2]: org.apache.mina.core.filterchain.IoFilterEvent - Firing a MESSAGE_RECEIVED event for session 3 2020.11.27 15:26:38 DEBUG [socket_c2s-thread-2]: org.apache.mina.filter.codec.ProtocolCodecFilter - Processing a MESSAGE_RECEIVED for session 3 2020.11.27 15:26:38 DEBUG [socket_c2s-thread-2]: com.reucon.openfire.plugin.archive.xep0313.IQQueryHandler - Archive requested is: muc1@conference.xmpp.localhost.example 2020.11.27 15:26:38 DEBUG [socket_c2s-thread-2]: com.reucon.openfire.plugin.archive.xep0313.IQQueryHandler - Found 0 unsupported field names. 2020.11.27 15:26:38 DEBUG [socket_c2s-thread-2]: com.reucon.openfire.plugin.archive.xep0313.IQQueryHandler - Archive 'muc1@conference.xmpp.localhost.example' does not relate to a local user. 2020.11.27 15:26:38 DEBUG [socket_c2s-thread-2]: com.reucon.openfire.plugin.archive.xep0313.IQQueryHandler - Archive 'muc1@conference.xmpp.localhost.example' relates to a recognized MUC room on this domain. 2020.11.27 15:26:38 DEBUG [socket_c2s-thread-2]: org.apache.mina.core.filterchain.IoFilterEvent - Event MESSAGE_RECEIVED has been fired for session 3 2020.11.27 15:26:38 DEBUG [message-archive-handler-2]: com.reucon.openfire.plugin.archive.xep0313.IQQueryHandler - Retrieving messages from archive... 2020.11.27 15:26:38 DEBUG [message-archive-handler-2]: org.jivesoftware.openfire.archive.Archiver - The timestamp that's requested (2020-11-27T15:26:38.666Z) is not in the future. All data must have already been received. There's no data queued or being worked on. Therefor, all data must have already been written. 2020.11.27 15:26:38 DEBUG [message-archive-handler-2]: org.jivesoftware.openfire.archive.Archiver - The timestamp that's requested (2020-11-27T15:26:38.666Z) is not in the future. All data must have already been received. There's no data queued or being worked on. Therefor, all data must have already been written. 2020.11.27 15:26:38 DEBUG [message-archive-handler-2]: org.jivesoftware.openfire.archive.Archiver - The timestamp that's requested (2020-11-27T15:26:38.666Z) is not in the future. All data must have already been received. There's no data queued or being worked on. Therefor, all data must have already been written. 2020.11.27 15:26:38 DEBUG [message-archive-handler-2]: org.jivesoftware.openfire.archive.Archiver - The timestamp that's requested (2020-11-27T15:26:38.666Z) is not in the future. All data must have already been received. There's no data queued or being worked on. Therefor, all data must have already been written. 2020.11.27 15:26:38 DEBUG [message-archive-handler-2]: org.jivesoftware.openfire.plugin.util.cache.ClusteredCacheFactory - Executing MultiTask: org.jivesoftware.openfire.archive.cluster.GetConversationsWriteETATask 2020.11.27 15:26:38 DEBUG [message-archive-handler-2]: com.reucon.openfire.plugin.archive.xep0313.IQQueryHandler - All data that has been requested has been written to the database. Proceed to process request. 2020.11.27 15:26:38 DEBUG [message-archive-handler-2]: org.jivesoftware.openfire.plugin.MonitoringPlugin - Getting PersistenceManager for muc1@conference.xmpp.localhost.example 2020.11.27 15:26:38 DEBUG [message-archive-handler-2]: org.jivesoftware.openfire.plugin.MonitoringPlugin - Using MucPersistenceManager 2020.11.27 15:26:38 DEBUG [message-archive-handler-2]: com.reucon.openfire.plugin.archive.impl.MucMamPersistenceManager - Finding messages of owner 'muc1@conference.xmpp.localhost.example' with start date 'null', end date '2020-11-27T15:26:38.717+0000' with 'null', query: 'null' and resultset 'XmppResultSet{after=null, before=null, index=null, max=50, first=null, firstIndex=null, last=null, count=null, complete=false}', useStableId 'true'. 2020.11.27 15:26:38 DEBUG [message-archive-handler-2]: com.reucon.openfire.plugin.archive.impl.MucMamPersistenceManager - Request for message archive of room 'muc1@conference.xmpp.localhost.example' did not specify a start date. Using EPOCH. 2020.11.27 15:26:38 DEBUG [message-archive-handler-2]: com.reucon.openfire.plugin.archive.impl.MucMamPersistenceManager - Request for message archive of room 'muc1@conference.xmpp.localhost.example' resulted in the following query data: PaginatedMucMessageQuery{startDate=Thu Jan 01 00:00:00 UTC 1970, endDate=Fri Nov 27 15:26:38 UTC 2020, room=org.jivesoftware.openfire.muc.spi.LocalMUCRoom@32a6bfe2, with='null'} 2020.11.27 15:26:38 DEBUG [message-archive-handler-2]: com.reucon.openfire.plugin.archive.impl.MucMamPersistenceManager - Request for message archive of room 'muc1@conference.xmpp.localhost.example' found a total of 3 applicable messages. Of these, 3 were actually retrieved from the database. 2020.11.27 15:26:38 DEBUG [message-archive-handler-2]: com.reucon.openfire.plugin.archive.impl.MucMamPersistenceManager - Found results for 'next page': false (based on after: null before: 1 isPagingBackwards: true) 2020.11.27 15:26:38 DEBUG [message-archive-handler-2]: com.reucon.openfire.plugin.archive.xep0313.IQQueryHandler - MAM: found: 3 items 2020.11.27 15:26:38 DEBUG [message-archive-handler-2]: com.reucon.openfire.plugin.archive.xep0313.IQQueryHandler - Retrieved 3 messages from archive. 2020.11.27 15:26:38 DEBUG [message-archive-handler-2]: com.reucon.openfire.plugin.archive.xep0313.IQQueryHandler - About to send message: ArchivedMessage[id=1,stableId=null,time=Thu Nov 12 15:00:16 UTC 2020,direction=from,stanza=] 2020.11.27 15:26:38 DEBUG [message-archive-handler-2]: com.reucon.openfire.plugin.archive.xep0313.IQQueryHandler - stanzaText: 2020.11.27 15:26:38 DEBUG [message-archive-handler-2]: com.reucon.openfire.plugin.archive.xep0313.IQQueryHandler - stanzaText length: 145 2020.11.27 15:26:38 DEBUG [message-archive-handler-2]: com.reucon.openfire.plugin.archive.xep0313.IQQueryHandler - isMuc: true 2020.11.27 15:26:38 DEBUG [message-archive-handler-2]: com.reucon.openfire.plugin.archive.xep0313.IQQueryHandler - queryRequest.getArchive(): muc1@conference.xmpp.localhost.example 2020.11.27 15:26:38 DEBUG [message-archive-handler-2]: com.reucon.openfire.plugin.archive.xep0313.IQQueryHandler - From set: muc1@conference.xmpp.localhost.example 2020.11.27 15:26:38 DEBUG [message-archive-handler-2]: org.apache.mina.filter.ssl.SslFilter - Session Server[3](SSL): Writing Message : WriteRequest: HeapBuffer[pos=0 lim=414 cap=4096: 3C 6D 65 73 73 61 67 65 20 74 6F 3D 22 75 73 65...] 2020.11.27 15:26:38 DEBUG [NioProcessor-4]: org.apache.mina.filter.executor.OrderedThreadPoolExecutor - Adding event MESSAGE_SENT to session 3 Queue : [MESSAGE_SENT, ] 2020.11.27 15:26:38 DEBUG [message-archive-handler-2]: com.reucon.openfire.plugin.archive.xep0313.IQQueryHandler - About to send message: ArchivedMessage[id=51,stableId=83b84db1-f5f0-4240-ac6e-77d22dabba30,time=Fri Nov 27 15:25:00 UTC 2020,direction=from,stanza=Ahoy from 1
] 2020.11.27 15:26:38 DEBUG [message-archive-handler-2]: com.reucon.openfire.plugin.archive.xep0313.IQQueryHandler - stanzaText: Ahoy from 1
2020.11.27 15:26:38 DEBUG [message-archive-handler-2]: com.reucon.openfire.plugin.archive.xep0313.IQQueryHandler - stanzaText length: 498 2020.11.27 15:26:38 DEBUG [socket_c2s-thread-3]: org.apache.mina.core.filterchain.IoFilterEvent - Firing a MESSAGE_SENT event for session 3 2020.11.27 15:26:38 DEBUG [message-archive-handler-2]: com.reucon.openfire.plugin.archive.xep0313.IQQueryHandler - isMuc: true 2020.11.27 15:26:38 DEBUG [socket_c2s-thread-3]: org.apache.mina.core.filterchain.IoFilterEvent - Event MESSAGE_SENT has been fired for session 3 2020.11.27 15:26:38 DEBUG [message-archive-handler-2]: com.reucon.openfire.plugin.archive.xep0313.IQQueryHandler - queryRequest.getArchive(): muc1@conference.xmpp.localhost.example 2020.11.27 15:26:38 DEBUG [message-archive-handler-2]: com.reucon.openfire.plugin.archive.xep0313.IQQueryHandler - From set: muc1@conference.xmpp.localhost.example 2020.11.27 15:26:38 DEBUG [message-archive-handler-2]: org.apache.mina.filter.ssl.SslFilter - Session Server[3](SSL): Writing Message : WriteRequest: HeapBuffer[pos=0 lim=782 cap=4096: 3C 6D 65 73 73 61 67 65 20 74 6F 3D 22 75 73 65...] 2020.11.27 15:26:38 DEBUG [NioProcessor-4]: org.apache.mina.filter.executor.OrderedThreadPoolExecutor - Adding event MESSAGE_SENT to session 3 Queue : [MESSAGE_SENT, ] 2020.11.27 15:26:38 DEBUG [message-archive-handler-2]: com.reucon.openfire.plugin.archive.xep0313.IQQueryHandler - About to send message: ArchivedMessage[id=101,stableId=5b1cf13c-b2ad-4122-a5bf-aac1a3e42294,time=Fri Nov 27 15:25:17 UTC 2020,direction=from,stanza=Ahoy yourself from 2
] 2020.11.27 15:26:38 DEBUG [message-archive-handler-2]: com.reucon.openfire.plugin.archive.xep0313.IQQueryHandler - stanzaText: Ahoy yourself from 2
2020.11.27 15:26:38 DEBUG [message-archive-handler-2]: com.reucon.openfire.plugin.archive.xep0313.IQQueryHandler - stanzaText length: 503 2020.11.27 15:26:38 DEBUG [message-archive-handler-2]: com.reucon.openfire.plugin.archive.xep0313.IQQueryHandler - isMuc: true 2020.11.27 15:26:38 DEBUG [socket_c2s-thread-2]: org.apache.mina.core.filterchain.IoFilterEvent - Firing a MESSAGE_SENT event for session 3 2020.11.27 15:26:38 DEBUG [socket_c2s-thread-2]: org.apache.mina.core.filterchain.IoFilterEvent - Event MESSAGE_SENT has been fired for session 3 2020.11.27 15:26:38 DEBUG [message-archive-handler-2]: com.reucon.openfire.plugin.archive.xep0313.IQQueryHandler - queryRequest.getArchive(): muc1@conference.xmpp.localhost.example 2020.11.27 15:26:38 DEBUG [message-archive-handler-2]: com.reucon.openfire.plugin.archive.xep0313.IQQueryHandler - From set: muc1@conference.xmpp.localhost.example 2020.11.27 15:26:38 DEBUG [message-archive-handler-2]: org.apache.mina.filter.ssl.SslFilter - Session Server[3](SSL): Writing Message : WriteRequest: HeapBuffer[pos=0 lim=792 cap=4096: 3C 6D 65 73 73 61 67 65 20 74 6F 3D 22 75 73 65...] 2020.11.27 15:26:38 DEBUG [message-archive-handler-2]: class org.jivesoftware.openfire.streammanagement.StreamManager[172.60.0.99] - Requesting acknowledgement from peer, as we have 5 or more unacknowledged stanzas. 2020.11.27 15:26:38 DEBUG [NioProcessor-4]: org.apache.mina.filter.executor.OrderedThreadPoolExecutor - Adding event MESSAGE_SENT to session 3 Queue : [MESSAGE_SENT, ] 2020.11.27 15:26:38 DEBUG [socket_c2s-thread-3]: org.apache.mina.core.filterchain.IoFilterEvent - Firing a MESSAGE_SENT event for session 3 2020.11.27 15:26:38 DEBUG [socket_c2s-thread-3]: org.apache.mina.core.filterchain.IoFilterEvent - Event MESSAGE_SENT has been fired for session 3 2020.11.27 15:26:38 DEBUG [message-archive-handler-2]: org.apache.mina.filter.ssl.SslFilter - Session Server[3](SSL): Writing Message : WriteRequest: HeapBuffer[pos=0 lim=27 cap=32: 3C 72 20 78 6D 6C 6E 73 3D 27 75 72 6E 3A 78 6D...] 2020.11.27 15:26:38 DEBUG [NioProcessor-4]: org.apache.mina.filter.executor.OrderedThreadPoolExecutor - Adding event MESSAGE_SENT to session 3 Queue : [MESSAGE_SENT, ] 2020.11.27 15:26:38 DEBUG [socket_c2s-thread-2]: org.apache.mina.core.filterchain.IoFilterEvent - Firing a MESSAGE_SENT event for session 3 2020.11.27 15:26:38 DEBUG [socket_c2s-thread-2]: org.apache.mina.core.filterchain.IoFilterEvent - Event MESSAGE_SENT has been fired for session 3 2020.11.27 15:26:38 DEBUG [message-archive-handler-2]: org.apache.mina.filter.ssl.SslFilter - Session Server[3](SSL): Writing Message : WriteRequest: HeapBuffer[pos=0 lim=342 cap=4096: 3C 69 71 20 74 79 70 65 3D 22 72 65 73 75 6C 74...] 2020.11.27 15:26:38 DEBUG [message-archive-handler-2]: com.reucon.openfire.plugin.archive.xep0313.IQQueryHandler - Done with request. The request took PT0.107S to complete, of which PT0S was spend waiting on data to be written to the database. 2020.11.27 15:26:38 DEBUG [NioProcessor-4]: org.apache.mina.filter.executor.OrderedThreadPoolExecutor - Adding event MESSAGE_SENT to session 3 Queue : [MESSAGE_SENT, ] 2020.11.27 15:26:38 DEBUG [socket_c2s-thread-3]: org.apache.mina.core.filterchain.IoFilterEvent - Firing a MESSAGE_SENT event for session 3 2020.11.27 15:26:38 DEBUG [socket_c2s-thread-3]: org.apache.mina.core.filterchain.IoFilterEvent - Event MESSAGE_SENT has been fired for session 3 2020.11.27 15:26:38 DEBUG [NioProcessor-4]: org.apache.mina.filter.ssl.SslFilter - Session Server[3](SSL): Message received : HeapBuffer[pos=0 lim=62 cap=512: 17 03 03 00 39 00 00 00 00 00 00 00 20 28 15 82...] 2020.11.27 15:26:38 DEBUG [NioProcessor-4]: org.apache.mina.filter.ssl.SslHandler - Session Server[3](SSL) Processing the received message 2020.11.27 15:26:38 DEBUG [NioProcessor-4]: org.apache.mina.filter.ssl.SslFilter - Session Server[3](SSL): Processing the SSL Data 2020.11.27 15:26:38 DEBUG [NioProcessor-4]: org.apache.mina.filter.executor.OrderedThreadPoolExecutor - Adding event MESSAGE_RECEIVED to session 3 Queue : [MESSAGE_RECEIVED, ] 2020.11.27 15:26:38 DEBUG [socket_c2s-thread-2]: org.apache.mina.core.filterchain.IoFilterEvent - Firing a MESSAGE_RECEIVED event for session 3 2020.11.27 15:26:38 DEBUG [socket_c2s-thread-2]: org.apache.mina.filter.codec.ProtocolCodecFilter - Processing a MESSAGE_RECEIVED for session 3 2020.11.27 15:26:38 DEBUG [socket_c2s-thread-2]: class org.jivesoftware.openfire.streammanagement.StreamManager[172.60.0.99] - Received acknowledgement from client: h=40 2020.11.27 15:26:38 DEBUG [socket_c2s-thread-2]: org.apache.mina.core.filterchain.IoFilterEvent - Event MESSAGE_RECEIVED has been fired for session 3 2020.11.27 15:26:38 DEBUG [NioProcessor-4]: org.apache.mina.filter.ssl.SslFilter - Session Server[3](SSL): Message received : HeapBuffer[pos=0 lim=62 cap=256: 17 03 03 00 39 00 00 00 00 00 00 00 21 47 C1 65...] 2020.11.27 15:26:38 DEBUG [NioProcessor-4]: org.apache.mina.filter.ssl.SslHandler - Session Server[3](SSL) Processing the received message 2020.11.27 15:26:38 DEBUG [NioProcessor-4]: org.apache.mina.filter.ssl.SslFilter - Session Server[3](SSL): Processing the SSL Data 2020.11.27 15:26:38 DEBUG [NioProcessor-4]: org.apache.mina.filter.executor.OrderedThreadPoolExecutor - Adding event MESSAGE_RECEIVED to session 3 Queue : [MESSAGE_RECEIVED, ] 2020.11.27 15:26:38 DEBUG [socket_c2s-thread-3]: org.apache.mina.core.filterchain.IoFilterEvent - Firing a MESSAGE_RECEIVED event for session 3 2020.11.27 15:26:38 DEBUG [socket_c2s-thread-3]: org.apache.mina.filter.codec.ProtocolCodecFilter - Processing a MESSAGE_RECEIVED for session 3 2020.11.27 15:26:38 DEBUG [socket_c2s-thread-3]: class org.jivesoftware.openfire.streammanagement.StreamManager[172.60.0.99] - Received acknowledgement from client: h=45 2020.11.27 15:26:38 DEBUG [socket_c2s-thread-3]: org.apache.mina.core.filterchain.IoFilterEvent - Event MESSAGE_RECEIVED has been fired for session 3 2020.11.27 15:26:39 DEBUG [hz.openfire.priority-generic-operation.thread-0]: com.hazelcast.internal.cluster.impl.ClusterHeartbeatManager - [172.60.0.20]:5701 [openfire] [3.12.5] Received heartbeat from Member [172.60.0.10]:5701 - 6245d46b-6b15-4962-894e-97b1939a64ae (now: 2020-11-27 15:26:39.000, timestamp: 2020-11-27 15:26:39.001) 2020.11.27 15:26:39 DEBUG [hz.openfire.priority-generic-operation.thread-0]: com.hazelcast.internal.cluster.ClusterService - [172.60.0.20]:5701 [openfire] [3.12.5] Setting cluster time diff to -1ms. 2020.11.27 15:26:40 DEBUG [pool-monitoring4]: org.jivesoftware.openfire.plugin.util.cache.ClusteredCacheFactory - Executing asynchronous DistributedTask: org.jivesoftware.openfire.archive.cluster.SendConversationEventsTask 2020.11.27 15:26:43 DEBUG [NioProcessor-4]: org.apache.mina.filter.ssl.SslFilter - Session Server[3](SSL): Message received : HeapBuffer[pos=0 lim=256 cap=256: 17 03 03 01 F2 00 00 00 00 00 00 00 22 08 F7 54...] 2020.11.27 15:26:43 DEBUG [NioProcessor-4]: org.apache.mina.filter.ssl.SslHandler - Session Server[3](SSL) Processing the received message 2020.11.27 15:26:43 DEBUG [NioProcessor-4]: org.apache.mina.filter.ssl.SslFilter - Session Server[3](SSL): Processing the SSL Data 2020.11.27 15:26:43 DEBUG [NioProcessor-4]: org.apache.mina.filter.ssl.SslFilter - Session Server[3](SSL): Message received : HeapBuffer[pos=0 lim=247 cap=512: 37 3A E3 AE 74 0D 5D 7C 8D 09 EA 02 E2 E3 0F E6...] 2020.11.27 15:26:43 DEBUG [NioProcessor-4]: org.apache.mina.filter.ssl.SslHandler - Session Server[3](SSL) Processing the received message 2020.11.27 15:26:43 DEBUG [NioProcessor-4]: org.apache.mina.filter.ssl.SslFilter - Session Server[3](SSL): Processing the SSL Data 2020.11.27 15:26:43 DEBUG [NioProcessor-4]: org.apache.mina.filter.executor.OrderedThreadPoolExecutor - Adding event MESSAGE_RECEIVED to session 3 Queue : [MESSAGE_RECEIVED, ] 2020.11.27 15:26:43 DEBUG [socket_c2s-thread-2]: org.apache.mina.core.filterchain.IoFilterEvent - Firing a MESSAGE_RECEIVED event for session 3 2020.11.27 15:26:43 DEBUG [socket_c2s-thread-2]: org.apache.mina.filter.codec.ProtocolCodecFilter - Processing a MESSAGE_RECEIVED for session 3 2020.11.27 15:26:43 DEBUG [socket_c2s-thread-2]: com.reucon.openfire.plugin.archive.xep0313.IQQueryHandler - Archive requested is: user3@xmpp.localhost.example 2020.11.27 15:26:43 DEBUG [socket_c2s-thread-2]: com.reucon.openfire.plugin.archive.xep0313.IQQueryHandler - Found 0 unsupported field names. 2020.11.27 15:26:43 DEBUG [socket_c2s-thread-2]: com.reucon.openfire.plugin.archive.xep0313.IQQueryHandler - Archive 'user3@xmpp.localhost.example' relates to a user account on this domain. 2020.11.27 15:26:43 DEBUG [socket_c2s-thread-2]: org.apache.mina.core.filterchain.IoFilterEvent - Event MESSAGE_RECEIVED has been fired for session 3 2020.11.27 15:26:43 DEBUG [message-archive-handler-2]: com.reucon.openfire.plugin.archive.xep0313.IQQueryHandler - Retrieving messages from archive... 2020.11.27 15:26:43 DEBUG [message-archive-handler-2]: org.jivesoftware.openfire.archive.Archiver - The timestamp that's requested (2020-11-27T15:26:43.093Z) is not in the future. All data must have already been received. There's no data queued or being worked on. Therefor, all data must have already been written. 2020.11.27 15:26:43 DEBUG [message-archive-handler-2]: org.jivesoftware.openfire.archive.Archiver - The timestamp that's requested (2020-11-27T15:26:43.093Z) is not in the future. All data must have already been received. There's no data queued or being worked on. Therefor, all data must have already been written. 2020.11.27 15:26:43 DEBUG [message-archive-handler-2]: org.jivesoftware.openfire.archive.Archiver - The timestamp that's requested (2020-11-27T15:26:43.093Z) is not in the future. All data must have already been received. There's no data queued or being worked on. Therefor, all data must have already been written. 2020.11.27 15:26:43 DEBUG [message-archive-handler-2]: org.jivesoftware.openfire.archive.Archiver - The timestamp that's requested (2020-11-27T15:26:43.093Z) is not in the future. All data must have already been received. There's no data queued or being worked on. Therefor, all data must have already been written. 2020.11.27 15:26:43 DEBUG [message-archive-handler-2]: org.jivesoftware.openfire.plugin.util.cache.ClusteredCacheFactory - Executing MultiTask: org.jivesoftware.openfire.archive.cluster.GetConversationsWriteETATask 2020.11.27 15:26:43 DEBUG [message-archive-handler-2]: com.reucon.openfire.plugin.archive.xep0313.IQQueryHandler - All data that has been requested has been written to the database. Proceed to process request. 2020.11.27 15:26:43 DEBUG [message-archive-handler-2]: org.jivesoftware.openfire.plugin.MonitoringPlugin - Getting PersistenceManager for user3@xmpp.localhost.example 2020.11.27 15:26:43 DEBUG [message-archive-handler-2]: com.reucon.openfire.plugin.archive.impl.JdbcPersistenceManager - Finding messages of owner 'user3@xmpp.localhost.example' with start date 'null', end date '2020-11-27T15:26:29.598+0000' with 'user2@xmpp.localhost.example' and resultset 'XmppResultSet{after=null, before=null, index=null, max=50, first=null, firstIndex=null, last=null, count=null, complete=false}', useStableId 'true'. 2020.11.27 15:26:43 DEBUG [message-archive-handler-2]: com.reucon.openfire.plugin.archive.impl.JdbcPersistenceManager - Request for message archive of user 'user3@xmpp.localhost.example' did not specify a start date. Using EPOCH. 2020.11.27 15:26:43 DEBUG [message-archive-handler-2]: com.reucon.openfire.plugin.archive.impl.JdbcPersistenceManager - Request for message archive of user 'user3@xmpp.localhost.example' resulted in the following query data: PaginatedMessageQuery{startDate=Thu Jan 01 00:00:00 UTC 1970, endDate=Fri Nov 27 15:26:29 UTC 2020, owner=user3@xmpp.localhost.example, with='user2@xmpp.localhost.example'} 2020.11.27 15:26:43 DEBUG [message-archive-handler-2]: com.reucon.openfire.plugin.archive.impl.PaginatedMessageDatabaseQuery - getPage query: SELECT fromJID, fromJIDResource, toJID, toJIDResource, sentDate, body, stanza, messageID, bareJID FROM (SELECT DISTINCT ofMessageArchive.fromJID, ofMessageArchive.fromJIDResource, ofMessageArchive.toJID, ofMessageArchive.toJIDResource, ofMessageArchive.sentDate, ofMessageArchive.body, ofMessageArchive.stanza, ofMessageArchive.messageID, ofConParticipant.bareJID FROM ofMessageArchive INNER JOIN ofConParticipant ON ofMessageArchive.conversationID = ofConParticipant.conversationID WHERE (ofMessageArchive.stanza IS NOT NULL OR ofMessageArchive.body IS NOT NULL) AND ofMessageArchive.messageID IS NOT NULL AND ofMessageArchive.sentDate >= ? AND ofMessageArchive.sentDate <= ? AND ofConParticipant.bareJID = ? AND ( ofMessageArchive.toJID = ? OR ofMessageArchive.fromJID = ? ) ORDER BY ofMessageArchive.sentDate DESC LIMIT 50 ) AS part ORDER BY sentDate 2020.11.27 15:26:43 DEBUG [message-archive-handler-2]: com.reucon.openfire.plugin.archive.impl.JdbcPersistenceManager - Request for message archive of owner 'user3@xmpp.localhost.example' found a total of 1 applicable messages. Of these, 1 were actually retrieved from the database. 2020.11.27 15:26:43 DEBUG [message-archive-handler-2]: com.reucon.openfire.plugin.archive.impl.PaginatedMessageDatabaseQuery - getPage query: SELECT fromJID, fromJIDResource, toJID, toJIDResource, sentDate, body, stanza, messageID, bareJID FROM (SELECT DISTINCT ofMessageArchive.fromJID, ofMessageArchive.fromJIDResource, ofMessageArchive.toJID, ofMessageArchive.toJIDResource, ofMessageArchive.sentDate, ofMessageArchive.body, ofMessageArchive.stanza, ofMessageArchive.messageID, ofConParticipant.bareJID FROM ofMessageArchive INNER JOIN ofConParticipant ON ofMessageArchive.conversationID = ofConParticipant.conversationID WHERE (ofMessageArchive.stanza IS NOT NULL OR ofMessageArchive.body IS NOT NULL) AND ofMessageArchive.messageID IS NOT NULL AND ofMessageArchive.sentDate >= ? AND ofMessageArchive.sentDate <= ? AND ofConParticipant.bareJID = ? AND ( ofMessageArchive.toJID = ? OR ofMessageArchive.fromJID = ? ) AND ofMessageArchive.messageID < ? ORDER BY ofMessageArchive.sentDate DESC LIMIT 1 ) AS part ORDER BY sentDate 2020.11.27 15:26:43 DEBUG [message-archive-handler-2]: com.reucon.openfire.plugin.archive.impl.JdbcPersistenceManager - Found results for 'next page': false (based on after: null before: 2 isPagingBackwards: true) 2020.11.27 15:26:43 DEBUG [message-archive-handler-2]: com.reucon.openfire.plugin.archive.xep0313.IQQueryHandler - MAM: found: 1 items 2020.11.27 15:26:43 DEBUG [message-archive-handler-2]: com.reucon.openfire.plugin.archive.xep0313.IQQueryHandler - Retrieved 1 messages from archive. 2020.11.27 15:26:43 DEBUG [message-archive-handler-2]: com.reucon.openfire.plugin.archive.xep0313.IQQueryHandler - About to send message: ArchivedMessage[id=2,stableId=null,time=Fri Nov 27 15:25:17 UTC 2020,direction=to,stanza= Ahoy yourself from 2 ] 2020.11.27 15:26:43 DEBUG [message-archive-handler-2]: com.reucon.openfire.plugin.archive.xep0313.IQQueryHandler - stanzaText: Ahoy yourself from 2 2020.11.27 15:26:43 DEBUG [message-archive-handler-2]: com.reucon.openfire.plugin.archive.xep0313.IQQueryHandler - stanzaText length: 151 2020.11.27 15:26:43 DEBUG [message-archive-handler-2]: com.reucon.openfire.plugin.archive.xep0313.IQQueryHandler - isMuc: false 2020.11.27 15:26:43 DEBUG [message-archive-handler-2]: com.reucon.openfire.plugin.archive.xep0313.IQQueryHandler - queryRequest.getArchive(): user3@xmpp.localhost.example 2020.11.27 15:26:43 DEBUG [message-archive-handler-2]: org.apache.mina.filter.ssl.SslFilter - Session Server[3](SSL): Writing Message : WriteRequest: HeapBuffer[pos=0 lim=426 cap=4096: 3C 6D 65 73 73 61 67 65 20 74 6F 3D 22 75 73 65...] 2020.11.27 15:26:43 DEBUG [NioProcessor-4]: org.apache.mina.filter.executor.OrderedThreadPoolExecutor - Adding event MESSAGE_SENT to session 3 Queue : [MESSAGE_SENT, ] 2020.11.27 15:26:43 DEBUG [socket_c2s-thread-3]: org.apache.mina.core.filterchain.IoFilterEvent - Firing a MESSAGE_SENT event for session 3 2020.11.27 15:26:43 DEBUG [socket_c2s-thread-3]: org.apache.mina.core.filterchain.IoFilterEvent - Event MESSAGE_SENT has been fired for session 3 2020.11.27 15:26:43 DEBUG [message-archive-handler-2]: org.apache.mina.filter.ssl.SslFilter - Session Server[3](SSL): Writing Message : WriteRequest: HeapBuffer[pos=0 lim=297 cap=4096: 3C 69 71 20 74 79 70 65 3D 22 72 65 73 75 6C 74...] 2020.11.27 15:26:43 DEBUG [message-archive-handler-2]: com.reucon.openfire.plugin.archive.xep0313.IQQueryHandler - Done with request. The request took PT0.034S to complete, of which PT0S was spend waiting on data to be written to the database. 2020.11.27 15:26:43 DEBUG [NioProcessor-4]: org.apache.mina.filter.executor.OrderedThreadPoolExecutor - Adding event MESSAGE_SENT to session 3 Queue : [MESSAGE_SENT, ] 2020.11.27 15:26:43 DEBUG [socket_c2s-thread-2]: org.apache.mina.core.filterchain.IoFilterEvent - Firing a MESSAGE_SENT event for session 3 2020.11.27 15:26:43 DEBUG [socket_c2s-thread-2]: org.apache.mina.core.filterchain.IoFilterEvent - Event MESSAGE_SENT has been fired for session 3 2020.11.27 15:26:44 DEBUG [hz.openfire.priority-generic-operation.thread-0]: com.hazelcast.internal.cluster.impl.ClusterHeartbeatManager - [172.60.0.20]:5701 [openfire] [3.12.5] Received heartbeat from Member [172.60.0.10]:5701 - 6245d46b-6b15-4962-894e-97b1939a64ae (now: 2020-11-27 15:26:44.000, timestamp: 2020-11-27 15:26:44.001) 2020.11.27 15:26:44 DEBUG [hz.openfire.priority-generic-operation.thread-0]: com.hazelcast.internal.cluster.ClusterService - [172.60.0.20]:5701 [openfire] [3.12.5] Setting cluster time diff to -1ms. 2020.11.27 15:26:46 DEBUG [NioProcessor-4]: org.apache.mina.filter.ssl.SslFilter - Session Server[3](SSL): Message received : HeapBuffer[pos=0 lim=503 cap=512: 17 03 03 01 F2 00 00 00 00 00 00 00 23 43 5E EA...] 2020.11.27 15:26:46 DEBUG [NioProcessor-4]: org.apache.mina.filter.ssl.SslHandler - Session Server[3](SSL) Processing the received message 2020.11.27 15:26:46 DEBUG [NioProcessor-4]: org.apache.mina.filter.ssl.SslFilter - Session Server[3](SSL): Processing the SSL Data 2020.11.27 15:26:46 DEBUG [NioProcessor-4]: org.apache.mina.filter.executor.OrderedThreadPoolExecutor - Adding event MESSAGE_RECEIVED to session 3 Queue : [MESSAGE_RECEIVED, ] 2020.11.27 15:26:46 DEBUG [socket_c2s-thread-3]: org.apache.mina.core.filterchain.IoFilterEvent - Firing a MESSAGE_RECEIVED event for session 3 2020.11.27 15:26:46 DEBUG [socket_c2s-thread-3]: org.apache.mina.filter.codec.ProtocolCodecFilter - Processing a MESSAGE_RECEIVED for session 3 2020.11.27 15:26:46 DEBUG [socket_c2s-thread-3]: com.reucon.openfire.plugin.archive.xep0313.IQQueryHandler - Archive requested is: user3@xmpp.localhost.example 2020.11.27 15:26:46 DEBUG [socket_c2s-thread-3]: com.reucon.openfire.plugin.archive.xep0313.IQQueryHandler - Found 0 unsupported field names. 2020.11.27 15:26:46 DEBUG [socket_c2s-thread-3]: com.reucon.openfire.plugin.archive.xep0313.IQQueryHandler - Archive 'user3@xmpp.localhost.example' relates to a user account on this domain. 2020.11.27 15:26:46 DEBUG [socket_c2s-thread-3]: org.apache.mina.core.filterchain.IoFilterEvent - Event MESSAGE_RECEIVED has been fired for session 3 2020.11.27 15:26:46 DEBUG [message-archive-handler-2]: com.reucon.openfire.plugin.archive.xep0313.IQQueryHandler - Retrieving messages from archive... 2020.11.27 15:26:46 DEBUG [message-archive-handler-2]: org.jivesoftware.openfire.archive.Archiver - The timestamp that's requested (2020-11-27T15:26:46.932Z) is not in the future. All data must have already been received. There's no data queued or being worked on. Therefor, all data must have already been written. 2020.11.27 15:26:46 DEBUG [message-archive-handler-2]: org.jivesoftware.openfire.archive.Archiver - The timestamp that's requested (2020-11-27T15:26:46.932Z) is not in the future. All data must have already been received. There's no data queued or being worked on. Therefor, all data must have already been written. 2020.11.27 15:26:46 DEBUG [message-archive-handler-2]: org.jivesoftware.openfire.archive.Archiver - The timestamp that's requested (2020-11-27T15:26:46.932Z) is not in the future. All data must have already been received. There's no data queued or being worked on. Therefor, all data must have already been written. 2020.11.27 15:26:46 DEBUG [message-archive-handler-2]: org.jivesoftware.openfire.archive.Archiver - The timestamp that's requested (2020-11-27T15:26:46.932Z) is not in the future. All data must have already been received. There's no data queued or being worked on. Therefor, all data must have already been written. 2020.11.27 15:26:46 DEBUG [message-archive-handler-2]: org.jivesoftware.openfire.plugin.util.cache.ClusteredCacheFactory - Executing MultiTask: org.jivesoftware.openfire.archive.cluster.GetConversationsWriteETATask 2020.11.27 15:26:46 DEBUG [message-archive-handler-2]: com.reucon.openfire.plugin.archive.xep0313.IQQueryHandler - All data that has been requested has been written to the database. Proceed to process request. 2020.11.27 15:26:46 DEBUG [message-archive-handler-2]: org.jivesoftware.openfire.plugin.MonitoringPlugin - Getting PersistenceManager for user3@xmpp.localhost.example 2020.11.27 15:26:46 DEBUG [message-archive-handler-2]: com.reucon.openfire.plugin.archive.impl.JdbcPersistenceManager - Finding messages of owner 'user3@xmpp.localhost.example' with start date 'null', end date '2020-11-27T15:26:29.598+0000' with 'user1@xmpp.localhost.example' and resultset 'XmppResultSet{after=null, before=null, index=null, max=50, first=null, firstIndex=null, last=null, count=null, complete=false}', useStableId 'true'. 2020.11.27 15:26:46 DEBUG [message-archive-handler-2]: com.reucon.openfire.plugin.archive.impl.JdbcPersistenceManager - Request for message archive of user 'user3@xmpp.localhost.example' did not specify a start date. Using EPOCH. 2020.11.27 15:26:46 DEBUG [message-archive-handler-2]: com.reucon.openfire.plugin.archive.impl.JdbcPersistenceManager - Request for message archive of user 'user3@xmpp.localhost.example' resulted in the following query data: PaginatedMessageQuery{startDate=Thu Jan 01 00:00:00 UTC 1970, endDate=Fri Nov 27 15:26:29 UTC 2020, owner=user3@xmpp.localhost.example, with='user1@xmpp.localhost.example'} 2020.11.27 15:26:46 DEBUG [message-archive-handler-2]: com.reucon.openfire.plugin.archive.impl.PaginatedMessageDatabaseQuery - getPage query: SELECT fromJID, fromJIDResource, toJID, toJIDResource, sentDate, body, stanza, messageID, bareJID FROM (SELECT DISTINCT ofMessageArchive.fromJID, ofMessageArchive.fromJIDResource, ofMessageArchive.toJID, ofMessageArchive.toJIDResource, ofMessageArchive.sentDate, ofMessageArchive.body, ofMessageArchive.stanza, ofMessageArchive.messageID, ofConParticipant.bareJID FROM ofMessageArchive INNER JOIN ofConParticipant ON ofMessageArchive.conversationID = ofConParticipant.conversationID WHERE (ofMessageArchive.stanza IS NOT NULL OR ofMessageArchive.body IS NOT NULL) AND ofMessageArchive.messageID IS NOT NULL AND ofMessageArchive.sentDate >= ? AND ofMessageArchive.sentDate <= ? AND ofConParticipant.bareJID = ? AND ( ofMessageArchive.toJID = ? OR ofMessageArchive.fromJID = ? ) ORDER BY ofMessageArchive.sentDate DESC LIMIT 50 ) AS part ORDER BY sentDate 2020.11.27 15:26:46 DEBUG [message-archive-handler-2]: com.reucon.openfire.plugin.archive.impl.JdbcPersistenceManager - Request for message archive of owner 'user3@xmpp.localhost.example' found a total of 1 applicable messages. Of these, 1 were actually retrieved from the database. 2020.11.27 15:26:46 DEBUG [message-archive-handler-2]: com.reucon.openfire.plugin.archive.impl.PaginatedMessageDatabaseQuery - getPage query: SELECT fromJID, fromJIDResource, toJID, toJIDResource, sentDate, body, stanza, messageID, bareJID FROM (SELECT DISTINCT ofMessageArchive.fromJID, ofMessageArchive.fromJIDResource, ofMessageArchive.toJID, ofMessageArchive.toJIDResource, ofMessageArchive.sentDate, ofMessageArchive.body, ofMessageArchive.stanza, ofMessageArchive.messageID, ofConParticipant.bareJID FROM ofMessageArchive INNER JOIN ofConParticipant ON ofMessageArchive.conversationID = ofConParticipant.conversationID WHERE (ofMessageArchive.stanza IS NOT NULL OR ofMessageArchive.body IS NOT NULL) AND ofMessageArchive.messageID IS NOT NULL AND ofMessageArchive.sentDate >= ? AND ofMessageArchive.sentDate <= ? AND ofConParticipant.bareJID = ? AND ( ofMessageArchive.toJID = ? OR ofMessageArchive.fromJID = ? ) AND ofMessageArchive.messageID < ? ORDER BY ofMessageArchive.sentDate DESC LIMIT 1 ) AS part ORDER BY sentDate 2020.11.27 15:26:46 DEBUG [message-archive-handler-2]: com.reucon.openfire.plugin.archive.impl.JdbcPersistenceManager - Found results for 'next page': false (based on after: null before: 1 isPagingBackwards: true) 2020.11.27 15:26:46 DEBUG [message-archive-handler-2]: com.reucon.openfire.plugin.archive.xep0313.IQQueryHandler - MAM: found: 1 items 2020.11.27 15:26:46 DEBUG [message-archive-handler-2]: com.reucon.openfire.plugin.archive.xep0313.IQQueryHandler - Retrieved 1 messages from archive. 2020.11.27 15:26:46 DEBUG [message-archive-handler-2]: com.reucon.openfire.plugin.archive.xep0313.IQQueryHandler - About to send message: ArchivedMessage[id=1,stableId=null,time=Fri Nov 27 15:25:00 UTC 2020,direction=to,stanza=Ahoy from 1
] 2020.11.27 15:26:46 DEBUG [message-archive-handler-2]: com.reucon.openfire.plugin.archive.xep0313.IQQueryHandler - stanzaText: Ahoy from 1
2020.11.27 15:26:46 DEBUG [message-archive-handler-2]: com.reucon.openfire.plugin.archive.xep0313.IQQueryHandler - stanzaText length: 492 2020.11.27 15:26:46 DEBUG [message-archive-handler-2]: com.reucon.openfire.plugin.archive.xep0313.IQQueryHandler - isMuc: false 2020.11.27 15:26:46 DEBUG [message-archive-handler-2]: com.reucon.openfire.plugin.archive.xep0313.IQQueryHandler - queryRequest.getArchive(): user3@xmpp.localhost.example 2020.11.27 15:26:46 DEBUG [message-archive-handler-2]: org.apache.mina.filter.ssl.SslFilter - Session Server[3](SSL): Writing Message : WriteRequest: HeapBuffer[pos=0 lim=779 cap=4096: 3C 6D 65 73 73 61 67 65 20 74 6F 3D 22 75 73 65...] 2020.11.27 15:26:46 DEBUG [NioProcessor-4]: org.apache.mina.filter.executor.OrderedThreadPoolExecutor - Adding event MESSAGE_SENT to session 3