Error while uploading avatar

General Discussion
1

Does anyone know why I get error below while uploading an avatar?
I am using Snikket on an iOS. When I want to upload an avatar Snikket says it is unsupported, however it updates under Personal Eventing the urn:xmpp:avatar:data record though.
So, the app changes my Pub Sub Node but says Openfire does not support it.
And the app does not show the new avatar.

2022.05.13 20:17:34 DEBUG [socket_c2s-thread-2]: org.jivesoftware.openfire.spi.RoutingTableImpl - Error stanza to bare JID discarded: <message from="andre.dombrowsky@xxxxxx/Snikket.XVP3" id="d4tBrtSG" type="error" to="andre.dombrowsky@xxxxxx"><event xmlns="http://jabber.org/protocol/pubsub#event"><items node="urn:xmpp:avatar:data"><item id="56ee25d85fa5c1e9227327f67d0de18a88d62e73" node="urn:xmpp:avatar:data"><data xmlns="urn:xmpp:avatar:data">iVBORw0KGgoAAAANSUhEUgAAAWgAAAECCAYAAADTik3pAAAAAXNSR0IArs4c6QAAAHhlWElmTU0AKgAAAAgABAEaAAUAAAABAAAAPgEbAAUAAAABAAAARgEoAAMAAAABAAIAAIdpAAQAAAABAAAATgAAAAAAAACQAAAAAQAAAJAAAAABAAOgAQADAAAAAQABAACgAgAEAAAAAQAAAWigAwAEAAAAAQAAAQIAAAAAWlLpGAAAAAlwSFlzAAAWJQAAFiUBSVIk8AAAABxpRE9UAAAAAgAAAAAAAACBAAAAKAAAAIEAAACBAAAypilKaDwAADJySURBVHgB7J0JlFXVlfcFRBCcY2

<address jid="andre.dombrowsky@xxxxx/Snikket.XVP3" type="replyto"/></addresses><error type="modify"><bad-request xmlns="urn:ietf:params:xml:ns:xmpp-stanzas"></bad-request></error>
2

That’s weird. I wonder if this is Openfire failing to return an error that itself generated. Sadly, the stanzas that you provided aren’t quite complete. Can you provide the full request and response stanzas please?

3

@guus
Thx for the response Guus.
Please find the log below.
I started uploading the avatar exactly at 15:47:00 h

Additional info:
I am using openldap for user and groups. There is one group with all members configured as roster for all user.

ldap.override.avatar: true

provider.vcard.className: org.jivesoftware.openfire.ldap.LdapVCardProvider

ldap.vcard-mapping :

<![CDATA[
<vCard xmlns="vcard-temp">
  <N><GIVEN>{cn}</GIVEN></N> 
  <EMAIL><INTERNET/> <USERID>{mail}</USERID></EMAIL> 
  <FN>{displayName}</FN> 
  <NICKNAME>{uid}</NICKNAME> 
  <ADR><HOME/> <STREET>{homePostalAddress}</STREET></ADR> 
  <ADR><WORK/> <STREET>{postalAddress}</STREET> <LOCALITY>{l}</LOCALITY> <REGION{st}</REGION> <PCODE>{postalCode}</PCODE></ADR> 
  <TEL><HOME/> <VOICE/> <NUMBER>{homePhone}</NUMBER></TEL> 
  <TEL><WORK/><VOICE/> <NUMBER>{telephoneNumber}</NUMBER></TEL> 
  <TEL><WORK/> <CELL/> <NUMBER>{mobile}</NUMBER></TEL> 
  <TEL><WORK/> <PAGER/> <NUMBER>{pager}</NUMBER></TEL> 
  <TITLE>{title}</TITLE> 
  <ORG><ORGUNIT>{departmentNumber}</ORGUNIT></ORG>
</vCard>]]>

2022.05.18 15:47:00 TRACE [hz.openfire.InvocationMonitorThread]: com.hazelcast.spi.impl.operationservice.impl.InvocationMonitor - [10.0.0.102]:5701 [openfire] [3.12.5] Scanning all invocations
2022.05.18 15:47:01 TRACE [hz.openfire.InvocationMonitorThread]: com.hazelcast.spi.impl.operationservice.impl.InvocationMonitor - [10.0.0.102]:5701 [openfire] [3.12.5] Broadcasting operation control packets to: 1 members
2022.05.18 15:47:01 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslFilter - Session Server[9](SSL): Message received : HeapBuffer[pos=0 lim=30 cap=64: 17 03 03 00 19 00 00 00 00 00 00 33 DA 1F 52 54...]
2022.05.18 15:47:01 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslHandler - Session Server[9](SSL) Processing the received message
2022.05.18 15:47:01 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslFilter - Session Server[9](SSL): Processing the SSL Data 
2022.05.18 15:47:01 DEBUG [NioProcessor-2]: org.apache.mina.filter.executor.OrderedThreadPoolExecutor - Adding event MESSAGE_RECEIVED to session 9
Queue : [MESSAGE_RECEIVED, ]

2022.05.18 15:47:01 DEBUG [socket_c2s-thread-3]: org.apache.mina.core.filterchain.IoFilterEvent - Firing a MESSAGE_RECEIVED event for session 9
2022.05.18 15:47:01 DEBUG [socket_c2s-thread-3]: org.apache.mina.filter.codec.ProtocolCodecFilter - Processing a MESSAGE_RECEIVED for session 9
2022.05.18 15:47:01 DEBUG [socket_c2s-thread-3]: org.apache.mina.core.filterchain.IoFilterEvent - Event MESSAGE_RECEIVED has been fired for session 9
2022.05.18 15:47:01 TRACE [hz.openfire.InvocationMonitorThread]: com.hazelcast.spi.impl.operationservice.impl.InvocationMonitor - [10.0.0.102]:5701 [openfire] [3.12.5] Scanning all invocations
2022.05.18 15:47:02 TRACE [hz.openfire.InvocationMonitorThread]: com.hazelcast.spi.impl.operationservice.impl.InvocationMonitor - [10.0.0.102]:5701 [openfire] [3.12.5] Scanning all invocations
2022.05.18 15:47:03 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslFilter - Session Server[1135](SSL): Message received : HeapBuffer[pos=0 lim=256 cap=256: 17 03 03 40 18 06 90 C9 D6 25 7F E2 3A F4 1A FC...]
2022.05.18 15:47:03 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslHandler - Session Server[1135](SSL) Processing the received message
2022.05.18 15:47:03 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslFilter - Session Server[1135](SSL): Processing the SSL Data 
2022.05.18 15:47:03 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslFilter - Session Server[1135](SSL): Message received : HeapBuffer[pos=0 lim=512 cap=512: 42 1B 89 53 D4 F4 AE 49 E3 85 BC 36 F6 AA EE 97...]
2022.05.18 15:47:03 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslHandler - Session Server[1135](SSL) Processing the received message
2022.05.18 15:47:03 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslFilter - Session Server[1135](SSL): Processing the SSL Data 
2022.05.18 15:47:03 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslFilter - Session Server[1135](SSL): Message received : HeapBuffer[pos=0 lim=600 cap=1024: 57 74 83 76 CC B3 ED 03 EC 08 11 DF EA 84 E6 3E...]
2022.05.18 15:47:03 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslHandler - Session Server[1135](SSL) Processing the received message
2022.05.18 15:47:03 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslFilter - Session Server[1135](SSL): Processing the SSL Data 
2022.05.18 15:47:03 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslFilter - Session Server[1135](SSL): Message received : HeapBuffer[pos=0 lim=1024 cap=1024: 6E 75 F9 A8 57 C5 96 FA 26 11 26 79 95 7C D6 2A...]
2022.05.18 15:47:03 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslHandler - Session Server[1135](SSL) Processing the received message
2022.05.18 15:47:03 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslFilter - Session Server[1135](SSL): Processing the SSL Data 
2022.05.18 15:47:03 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslFilter - Session Server[1135](SSL): Message received : HeapBuffer[pos=0 lim=344 cap=2048: B9 E4 C4 57 BD 84 65 AF 2A 47 12 71 BE 18 6B 25...]
2022.05.18 15:47:03 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslHandler - Session Server[1135](SSL) Processing the received message
2022.05.18 15:47:03 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslFilter - Session Server[1135](SSL): Processing the SSL Data 
2022.05.18 15:47:03 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslFilter - Session Server[1135](SSL): Message received : HeapBuffer[pos=0 lim=1368 cap=2048: 18 E0 47 F0 0F B9 00 BC C0 92 46 84 92 72 8E 2F...]
2022.05.18 15:47:03 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslHandler - Session Server[1135](SSL) Processing the received message
2022.05.18 15:47:03 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslFilter - Session Server[1135](SSL): Processing the SSL Data 
2022.05.18 15:47:03 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslFilter - Session Server[1135](SSL): Message received : HeapBuffer[pos=0 lim=1368 cap=2048: A1 6D 3E 35 C6 82 39 21 E0 FA 61 F7 3C EA AD D1...]
2022.05.18 15:47:03 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslHandler - Session Server[1135](SSL) Processing the received message
2022.05.18 15:47:03 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslFilter - Session Server[1135](SSL): Processing the SSL Data 
2022.05.18 15:47:03 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslFilter - Session Server[1135](SSL): Message received : HeapBuffer[pos=0 lim=1368 cap=2048: 96 E6 B8 8B 56 5D A6 7D A0 F2 45 79 01 5A BE 6C...]
2022.05.18 15:47:03 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslHandler - Session Server[1135](SSL) Processing the received message
2022.05.18 15:47:03 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslFilter - Session Server[1135](SSL): Processing the SSL Data 
2022.05.18 15:47:03 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslFilter - Session Server[1135](SSL): Message received : HeapBuffer[pos=0 lim=2048 cap=2048: 45 21 A1 F8 C5 AB 7B 22 DF 6C 7F 06 56 78 4D 0C...]
2022.05.18 15:47:03 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslHandler - Session Server[1135](SSL) Processing the received message
2022.05.18 15:47:03 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslFilter - Session Server[1135](SSL): Processing the SSL Data 
2022.05.18 15:47:03 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslFilter - Session Server[1135](SSL): Message received : HeapBuffer[pos=0 lim=2056 cap=4096: AD C7 A2 B8 00 CE 5D 7E EE 10 F8 A7 DD 69 F0 55...]
2022.05.18 15:47:03 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslHandler - Session Server[1135](SSL) Processing the received message
2022.05.18 15:47:03 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslFilter - Session Server[1135](SSL): Processing the SSL Data 
2022.05.18 15:47:03 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslFilter - Session Server[1135](SSL): Message received : HeapBuffer[pos=0 lim=1368 cap=4096: D1 D2 79 3A 9A 88 89 D8 0E CA 42 EB F8 C3 6A E7...]
2022.05.18 15:47:03 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslHandler - Session Server[1135](SSL) Processing the received message
2022.05.18 15:47:03 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslFilter - Session Server[1135](SSL): Processing the SSL Data 
2022.05.18 15:47:03 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslFilter - Session Server[1135](SSL): Message received : HeapBuffer[pos=0 lim=1368 cap=4096: D9 1D 1A 8D B3 67 28 26 3A 75 C0 4D 47 62 5E 76...]
2022.05.18 15:47:03 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslHandler - Session Server[1135](SSL) Processing the received message
2022.05.18 15:47:03 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslFilter - Session Server[1135](SSL): Processing the SSL Data 
2022.05.18 15:47:03 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslFilter - Session Server[1135](SSL): Message received : HeapBuffer[pos=0 lim=2048 cap=2048: CE AB 1F A4 B8 16 A1 C3 98 18 A7 FB 7B 01 F6 78...]
2022.05.18 15:47:03 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslHandler - Session Server[1135](SSL) Processing the received message
2022.05.18 15:47:03 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslFilter - Session Server[1135](SSL): Processing the SSL Data 
2022.05.18 15:47:03 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslFilter - Session Server[1135](SSL): Message received : HeapBuffer[pos=0 lim=688 cap=4096: 7D DC 55 1F B7 03 14 3C D7 18 38 B9 EF 03 CA 84...]
2022.05.18 15:47:03 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslHandler - Session Server[1135](SSL) Processing the received message
2022.05.18 15:47:03 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslFilter - Session Server[1135](SSL): Processing the SSL Data 
2022.05.18 15:47:03 DEBUG [NioProcessor-2]: org.apache.mina.filter.executor.OrderedThreadPoolExecutor - Adding event MESSAGE_RECEIVED to session 1135
Queue : [MESSAGE_RECEIVED, ]

2022.05.18 15:47:03 DEBUG [socket_c2s-thread-5]: org.apache.mina.core.filterchain.IoFilterEvent - Firing a MESSAGE_RECEIVED event for session 1135
2022.05.18 15:47:03 DEBUG [socket_c2s-thread-5]: org.apache.mina.filter.codec.ProtocolCodecFilter - Processing a MESSAGE_RECEIVED for session 1135
2022.05.18 15:47:03 DEBUG [socket_c2s-thread-5]: org.apache.mina.core.filterchain.IoFilterEvent - Event MESSAGE_RECEIVED has been fired for session 1135
2022.05.18 15:47:03 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslFilter - Session Server[1135](SSL): Message received : HeapBuffer[pos=0 lim=1368 cap=4096: 40 18 06 90 C9 D6 25 7F E2 3B D6 7A 67 5C 2C 22...]
2022.05.18 15:47:03 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslHandler - Session Server[1135](SSL) Processing the received message
2022.05.18 15:47:03 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslFilter - Session Server[1135](SSL): Processing the SSL Data 
2022.05.18 15:47:03 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslFilter - Session Server[1135](SSL): Message received : HeapBuffer[pos=0 lim=1368 cap=2048: 41 6B 31 E8 27 8E E5 78 33 B6 E1 71 AF 97 A2 29...]
2022.05.18 15:47:03 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslHandler - Session Server[1135](SSL) Processing the received message
2022.05.18 15:47:03 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslFilter - Session Server[1135](SSL): Processing the SSL Data 
2022.05.18 15:47:03 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslFilter - Session Server[1135](SSL): Message received : HeapBuffer[pos=0 lim=1368 cap=2048: A2 A0 C6 4B AB 03 C6 C0 BD B5 D7 66 2C 41 52 94...]
2022.05.18 15:47:03 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslHandler - Session Server[1135](SSL) Processing the received message
2022.05.18 15:47:03 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslFilter - Session Server[1135](SSL): Processing the SSL Data 
2022.05.18 15:47:03 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslFilter - Session Server[1135](SSL): Message received : HeapBuffer[pos=0 lim=2048 cap=2048: 13 89 9E E7 CB D3 6A 2B D5 44 F5 6F 25 A2 1F 09...]
2022.05.18 15:47:03 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslHandler - Session Server[1135](SSL) Processing the received message
2022.05.18 15:47:03 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslFilter - Session Server[1135](SSL): Processing the SSL Data 
2022.05.18 15:47:03 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslFilter - Session Server[1135](SSL): Message received : HeapBuffer[pos=0 lim=688 cap=4096: 05 6A 75 4C 12 8E 1B C9 45 61 9F 18 6A 62 08 A0...]
2022.05.18 15:47:03 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslHandler - Session Server[1135](SSL) Processing the received message
2022.05.18 15:47:03 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslFilter - Session Server[1135](SSL): Processing the SSL Data 
2022.05.18 15:47:03 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslFilter - Session Server[1135](SSL): Message received : HeapBuffer[pos=0 lim=1368 cap=4096: E7 AC 87 0F 50 3F C1 42 A0 05 9F 57 8D DC FD AF...]
2022.05.18 15:47:03 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslHandler - Session Server[1135](SSL) Processing the received message
2022.05.18 15:47:03 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslFilter - Session Server[1135](SSL): Processing the SSL Data 
2022.05.18 15:47:03 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslFilter - Session Server[1135](SSL): Message received : HeapBuffer[pos=0 lim=1368 cap=2048: 5E 90 B6 E1 01 0A B1 75 40 36 D6 70 7C 3C 63 57...]
2022.05.18 15:47:03 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslHandler - Session Server[1135](SSL) Processing the received message
2022.05.18 15:47:03 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslFilter - Session Server[1135](SSL): Processing the SSL Data 
2022.05.18 15:47:03 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslFilter - Session Server[1135](SSL): Message received : HeapBuffer[pos=0 lim=1368 cap=2048: 12 DD 27 97 30 C4 BD 99 7C EC 8B 88 D8 8E 10 70...]
2022.05.18 15:47:03 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslHandler - Session Server[1135](SSL) Processing the received message
2022.05.18 15:47:03 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslFilter - Session Server[1135](SSL): Processing the SSL Data 
2022.05.18 15:47:03 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslFilter - Session Server[1135](SSL): Message received : HeapBuffer[pos=0 lim=1368 cap=2048: D1 3C 63 77 88 24 EF ED 58 FF 4F 81 E5 C8 9F 49...]
2022.05.18 15:47:03 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslHandler - Session Server[1135](SSL) Processing the received message
2022.05.18 15:47:03 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslFilter - Session Server[1135](SSL): Processing the SSL Data 
2022.05.18 15:47:03 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslFilter - Session Server[1135](SSL): Message received : HeapBuffer[pos=0 lim=1368 cap=2048: FC 34 AA F9 16 E5 19 12 F5 B5 7F 09 8D D9 7F 66...]
2022.05.18 15:47:03 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslHandler - Session Server[1135](SSL) Processing the received message
2022.05.18 15:47:03 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslFilter - Session Server[1135](SSL): Processing the SSL Data 
2022.05.18 15:47:03 TRACE [hz.openfire.InvocationMonitorThread]: com.hazelcast.spi.impl.operationservice.impl.InvocationMonitor - [10.0.0.102]:5701 [openfire] [3.12.5] Scanning all invocations
2022.05.18 15:47:03 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslFilter - Session Server[1135](SSL): Message received : HeapBuffer[pos=0 lim=1368 cap=2048: E0 66 6B 27 08 F5 A8 55 D5 BB 66 59 38 35 AF CB...]
2022.05.18 15:47:03 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslHandler - Session Server[1135](SSL) Processing the received message
2022.05.18 15:47:03 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslFilter - Session Server[1135](SSL): Processing the SSL Data 
2022.05.18 15:47:03 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslFilter - Session Server[1135](SSL): Message received : HeapBuffer[pos=0 lim=1368 cap=2048: 3B B4 40 BB 5E 7B 48 D7 3D 02 0E AB B5 6B ED 79...]
2022.05.18 15:47:03 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslHandler - Session Server[1135](SSL) Processing the received message
2022.05.18 15:47:03 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslFilter - Session Server[1135](SSL): Processing the SSL Data 
2022.05.18 15:47:03 DEBUG [NioProcessor-2]: org.apache.mina.filter.executor.OrderedThreadPoolExecutor - Adding event MESSAGE_RECEIVED to session 1135
Queue : [MESSAGE_RECEIVED, ]

2022.05.18 15:47:03 DEBUG [socket_c2s-thread-2]: org.apache.mina.core.filterchain.IoFilterEvent - Firing a MESSAGE_RECEIVED event for session 1135
2022.05.18 15:47:03 DEBUG [socket_c2s-thread-2]: org.apache.mina.filter.codec.ProtocolCodecFilter - Processing a MESSAGE_RECEIVED for session 1135
2022.05.18 15:47:03 DEBUG [socket_c2s-thread-2]: org.apache.mina.core.filterchain.IoFilterEvent - Event MESSAGE_RECEIVED has been fired for session 1135
2022.05.18 15:47:03 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslFilter - Session Server[1135](SSL): Message received : HeapBuffer[pos=0 lim=1368 cap=2048: 90 C9 D6 25 7F E2 3C 27 1D 53 38 89 C0 5C CF B2...]
2022.05.18 15:47:03 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslHandler - Session Server[1135](SSL) Processing the received message
2022.05.18 15:47:03 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslFilter - Session Server[1135](SSL): Processing the SSL Data 
2022.05.18 15:47:03 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslFilter - Session Server[1135](SSL): Message received : HeapBuffer[pos=0 lim=1368 cap=2048: E3 42 C9 54 6A 80 45 E7 49 7C 4C 46 E0 C0 22 16...]
2022.05.18 15:47:03 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslHandler - Session Server[1135](SSL) Processing the received message
2022.05.18 15:47:03 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslFilter - Session Server[1135](SSL): Processing the SSL Data 
2022.05.18 15:47:03 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslFilter - Session Server[1135](SSL): Message received : HeapBuffer[pos=0 lim=1368 cap=2048: 97 3A 71 E9 5B 95 97 71 55 4D 25 79 9D BB 49 EB...]
2022.05.18 15:47:03 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslHandler - Session Server[1135](SSL) Processing the received message
2022.05.18 15:47:03 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslFilter - Session Server[1135](SSL): Processing the SSL Data 
2022.05.18 15:47:04 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslFilter - Session Server[1135](SSL): Message received : HeapBuffer[pos=0 lim=1368 cap=2048: C6 66 A1 95 62 D3 78 56 5F 45 18 D4 05 20 9F 48...]
2022.05.18 15:47:04 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslHandler - Session Server[1135](SSL) Processing the received message
2022.05.18 15:47:04 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslFilter - Session Server[1135](SSL): Processing the SSL Data 
2022.05.18 15:47:04 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslFilter - Session Server[1135](SSL): Message received : HeapBuffer[pos=0 lim=1368 cap=2048: 8D A6 2A F1 B3 44 71 E3 35 69 11 E1 D1 D6 13 F1...]
2022.05.18 15:47:04 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslHandler - Session Server[1135](SSL) Processing the received message
2022.05.18 15:47:04 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslFilter - Session Server[1135](SSL): Processing the SSL Data 
2022.05.18 15:47:04 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslFilter - Session Server[1135](SSL): Message received : HeapBuffer[pos=0 lim=1368 cap=2048: DC 9A 9A F0 0E B7 6A 73 A5 22 C7 4C 04 02 15 0D...]
2022.05.18 15:47:04 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslHandler - Session Server[1135](SSL) Processing the received message
2022.05.18 15:47:04 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslFilter - Session Server[1135](SSL): Processing the SSL Data 
2022.05.18 15:47:04 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslFilter - Session Server[1135](SSL): Message received : HeapBuffer[pos=0 lim=1368 cap=2048: 58 EF DA EF 8F FE 27 56 98 D5 47 39 3E 97 27 4A...]
2022.05.18 15:47:04 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslHandler - Session Server[1135](SSL) Processing the received message
2022.05.18 15:47:04 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslFilter - Session Server[1135](SSL): Processing the SSL Data 
2022.05.18 15:47:04 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslFilter - Session Server[1135](SSL): Message received : HeapBuffer[pos=0 lim=1368 cap=2048: E3 7D B7 21 56 1B 85 50 A3 E3 D5 BE 61 76 17 2D...]
2022.05.18 15:47:04 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslHandler - Session Server[1135](SSL) Processing the received message
2022.05.18 15:47:04 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslFilter - Session Server[1135](SSL): Processing the SSL Data 
2022.05.18 15:47:04 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslFilter - Session Server[1135](SSL): Message received : HeapBuffer[pos=0 lim=1368 cap=2048: 21 32 01 82 10 4D 60 52 09 27 97 D6 6B 30 6A C0...]
2022.05.18 15:47:04 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslHandler - Session Server[1135](SSL) Processing the received message
2022.05.18 15:47:04 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslFilter - Session Server[1135](SSL): Processing the SSL Data 
2022.05.18 15:47:04 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslFilter - Session Server[1135](SSL): Message received : HeapBuffer[pos=0 lim=1368 cap=2048: F4 D0 FB 53 B5 F3 F3 92 0E E3 D1 B2 D8 59 C6 69...]
2022.05.18 15:47:04 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslHandler - Session Server[1135](SSL) Processing the received message
2022.05.18 15:47:04 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslFilter - Session Server[1135](SSL): Processing the SSL Data 
2022.05.18 15:47:04 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslFilter - Session Server[1135](SSL): Message received : HeapBuffer[pos=0 lim=1368 cap=2048: 7C B8 6C 06 66 4E CF B0 5A 67 F4 54 01 98 30 21...]
2022.05.18 15:47:04 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslHandler - Session Server[1135](SSL) Processing the received message
2022.05.18 15:47:04 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslFilter - Session Server[1135](SSL): Processing the SSL Data 
2022.05.18 15:47:04 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslFilter - Session Server[1135](SSL): Message received : HeapBuffer[pos=0 lim=1368 cap=2048: 5B FF B2 47 63 C1 55 12 26 59 AF DE 43 A6 EA BA...]
2022.05.18 15:47:04 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslHandler - Session Server[1135](SSL) Processing the received message
2022.05.18 15:47:04 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslFilter - Session Server[1135](SSL): Processing the SSL Data 
2022.05.18 15:47:04 DEBUG [NioProcessor-2]: org.apache.mina.filter.executor.OrderedThreadPoolExecutor - Adding event MESSAGE_RECEIVED to session 1135
Queue : [MESSAGE_RECEIVED, ]

2022.05.18 15:47:04 DEBUG [socket_c2s-thread-4]: org.apache.mina.core.filterchain.IoFilterEvent - Firing a MESSAGE_RECEIVED event for session 1135
2022.05.18 15:47:04 DEBUG [socket_c2s-thread-4]: org.apache.mina.filter.codec.ProtocolCodecFilter - Processing a MESSAGE_RECEIVED for session 1135
2022.05.18 15:47:04 DEBUG [socket_c2s-thread-4]: org.apache.mina.core.filterchain.IoFilterEvent - Event MESSAGE_RECEIVED has been fired for session 1135
2022.05.18 15:47:04 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslFilter - Session Server[1135](SSL): Message received : HeapBuffer[pos=0 lim=2048 cap=2048: 25 7F E2 3D 20 82 2E C1 CF B7 7C 48 19 5D F9 76...]
2022.05.18 15:47:04 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslHandler - Session Server[1135](SSL) Processing the received message
2022.05.18 15:47:04 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslFilter - Session Server[1135](SSL): Processing the SSL Data 
2022.05.18 15:47:04 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslFilter - Session Server[1135](SSL): Message received : HeapBuffer[pos=0 lim=688 cap=4096: 56 5C 86 C8 14 FA F8 3F DD DC 71 D8 33 85 54 2B...]
2022.05.18 15:47:04 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslHandler - Session Server[1135](SSL) Processing the received message
2022.05.18 15:47:04 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslFilter - Session Server[1135](SSL): Processing the SSL Data 
2022.05.18 15:47:04 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslFilter - Session Server[1135](SSL): Message received : HeapBuffer[pos=0 lim=1368 cap=4096: EE B3 36 97 12 6B 4E A3 41 7F 1B 2E 16 FF 52 2D...]
2022.05.18 15:47:04 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslHandler - Session Server[1135](SSL) Processing the received message
2022.05.18 15:47:04 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslFilter - Session Server[1135](SSL): Processing the SSL Data 
2022.05.18 15:47:04 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslFilter - Session Server[1135](SSL): Message received : HeapBuffer[pos=0 lim=1368 cap=2048: 53 59 97 5E CB 4B A2 5B F3 EF AF DB D4 14 B2 68...]
2022.05.18 15:47:04 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslHandler - Session Server[1135](SSL) Processing the received message
2022.05.18 15:47:04 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslFilter - Session Server[1135](SSL): Processing the SSL Data 
2022.05.18 15:47:04 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslFilter - Session Server[1135](SSL): Message received : HeapBuffer[pos=0 lim=1368 cap=2048: 35 49 33 50 F8 40 13 7E F5 F8 61 92 07 F2 AF 86...]
2022.05.18 15:47:04 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslHandler - Session Server[1135](SSL) Processing the received message
2022.05.18 15:47:04 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslFilter - Session Server[1135](SSL): Processing the SSL Data 
2022.05.18 15:47:04 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslFilter - Session Server[1135](SSL): Message received : HeapBuffer[pos=0 lim=1368 cap=2048: 48 89 68 BE F9 57 B8 6D 1F 82 42 3A BE D0 E5 5D...]
2022.05.18 15:47:04 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslHandler - Session Server[1135](SSL) Processing the received message
2022.05.18 15:47:04 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslFilter - Session Server[1135](SSL): Processing the SSL Data 
2022.05.18 15:47:04 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslFilter - Session Server[1135](SSL): Message received : HeapBuffer[pos=0 lim=1368 cap=2048: 45 4E FD D6 3A 7B 2F 69 45 3B F4 3E FF 92 8D 95...]
2022.05.18 15:47:04 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslHandler - Session Server[1135](SSL) Processing the received message
2022.05.18 15:47:04 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslFilter - Session Server[1135](SSL): Processing the SSL Data 
2022.05.18 15:47:04 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslFilter - Session Server[1135](SSL): Message received : HeapBuffer[pos=0 lim=1368 cap=2048: 60 1A A9 FC 6B 25 26 02 4B 7A 94 07 86 7D 8C 76...]
2022.05.18 15:47:04 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslHandler - Session Server[1135](SSL) Processing the received message
2022.05.18 15:47:04 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslFilter - Session Server[1135](SSL): Processing the SSL Data 
2022.05.18 15:47:04 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslFilter - Session Server[1135](SSL): Message received : HeapBuffer[pos=0 lim=1368 cap=2048: 63 8C 7A 79 15 04 B6 15 CD 41 96 93 16 66 5B E0...]
2022.05.18 15:47:04 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslHandler - Session Server[1135](SSL) Processing the received message
2022.05.18 15:47:04 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslFilter - Session Server[1135](SSL): Processing the SSL Data 
2022.05.18 15:47:04 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslFilter - Session Server[1135](SSL): Message received : HeapBuffer[pos=0 lim=2048 cap=2048: F4 13 96 BD DB 8D 6D C1 8D 03 BF 43 F7 B4 DA D1...]
2022.05.18 15:47:04 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslHandler - Session Server[1135](SSL) Processing the received message
2022.05.18 15:47:04 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslFilter - Session Server[1135](SSL): Processing the SSL Data 
2022.05.18 15:47:04 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslFilter - Session Server[1135](SSL): Message received : HeapBuffer[pos=0 lim=688 cap=4096: D1 27 84 53 27 6B EF D8 DE C1 7E 3B FB EA 22 71...]
2022.05.18 15:47:04 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslHandler - Session Server[1135](SSL) Processing the received message
2022.05.18 15:47:04 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslFilter - Session Server[1135](SSL): Processing the SSL Data 
2022.05.18 15:47:04 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslFilter - Session Server[1135](SSL): Message received : HeapBuffer[pos=0 lim=1368 cap=4096: 18 FA 0B 07 C0 DA B2 CD AE AB 80 8B 7F 44 62 5F...]
2022.05.18 15:47:04 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslHandler - Session Server[1135](SSL) Processing the received message
2022.05.18 15:47:04 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslFilter - Session Server[1135](SSL): Processing the SSL Data 
2022.05.18 15:47:04 DEBUG [NioProcessor-2]: org.apache.mina.filter.executor.OrderedThreadPoolExecutor - Adding event MESSAGE_RECEIVED to session 1135
Queue : [MESSAGE_RECEIVED, ]

2022.05.18 15:47:04 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslFilter - Session Server[1135](SSL): Message received : HeapBuffer[pos=0 lim=1368 cap=2048: 3E 2E E9 72 BD 8C 69 F3 FF D9 A1 E7 8D 85 DF 36...]
2022.05.18 15:47:04 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslHandler - Session Server[1135](SSL) Processing the received message
2022.05.18 15:47:04 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslFilter - Session Server[1135](SSL): Processing the SSL Data 
2022.05.18 15:47:04 DEBUG [socket_c2s-thread-6]: org.apache.mina.core.filterchain.IoFilterEvent - Firing a MESSAGE_RECEIVED event for session 1135
2022.05.18 15:47:04 DEBUG [socket_c2s-thread-6]: org.apache.mina.filter.codec.ProtocolCodecFilter - Processing a MESSAGE_RECEIVED for session 1135
2022.05.18 15:47:04 DEBUG [socket_c2s-thread-6]: org.apache.mina.core.filterchain.IoFilterEvent - Event MESSAGE_RECEIVED has been fired for session 1135
2022.05.18 15:47:04 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslFilter - Session Server[1135](SSL): Message received : HeapBuffer[pos=0 lim=2048 cap=2048: 60 60 9D CA B3 34 E8 B1 19 A2 06 46 45 7F 27 28...]
2022.05.18 15:47:04 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslHandler - Session Server[1135](SSL) Processing the received message
2022.05.18 15:47:04 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslFilter - Session Server[1135](SSL): Processing the SSL Data 
2022.05.18 15:47:04 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslFilter - Session Server[1135](SSL): Message received : HeapBuffer[pos=0 lim=2056 cap=4096: 3D CD 0B 2C 6C 70 C1 FB 1C F8 9D B9 C1 AF 2B 73...]
2022.05.18 15:47:04 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslHandler - Session Server[1135](SSL) Processing the received message
2022.05.18 15:47:04 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslFilter - Session Server[1135](SSL): Processing the SSL Data 
2022.05.18 15:47:04 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslFilter - Session Server[1135](SSL): Message received : HeapBuffer[pos=0 lim=2736 cap=4096: 9D 5F 40 3E 1B D1 B6 5D 96 74 8A 9F A8 20 4A 1A...]
2022.05.18 15:47:04 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslHandler - Session Server[1135](SSL) Processing the received message
2022.05.18 15:47:04 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslFilter - Session Server[1135](SSL): Processing the SSL Data 
2022.05.18 15:47:04 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslFilter - Session Server[1135](SSL): Message received : HeapBuffer[pos=0 lim=1368 cap=4096: 15 E6 78 FA 0B 9F 25 B5 BA 29 96 7F F7 EA 50 84...]
2022.05.18 15:47:04 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslHandler - Session Server[1135](SSL) Processing the received message
2022.05.18 15:47:04 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslFilter - Session Server[1135](SSL): Processing the SSL Data 
2022.05.18 15:47:04 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslFilter - Session Server[1135](SSL): Message received : HeapBuffer[pos=0 lim=1368 cap=4096: A7 A8 87 4A 19 F4 BD 68 6B 41 E2 F8 6D A3 23 80...]
2022.05.18 15:47:04 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslHandler - Session Server[1135](SSL) Processing the received message
2022.05.18 15:47:04 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslFilter - Session Server[1135](SSL): Processing the SSL Data 
2022.05.18 15:47:04 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslFilter - Session Server[1135](SSL): Message received : HeapBuffer[pos=0 lim=1368 cap=2048: FA 76 F2 6D 76 76 08 C6 10 04 5C 7F 99 34 09 45...]
2022.05.18 15:47:04 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslHandler - Session Server[1135](SSL) Processing the received message
2022.05.18 15:47:04 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslFilter - Session Server[1135](SSL): Processing the SSL Data 
2022.05.18 15:47:04 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslFilter - Session Server[1135](SSL): Message received : HeapBuffer[pos=0 lim=2048 cap=2048: C1 05 81 5B 94 8F 1C 11 EE 47 CE EA 8F E7 1E 4E...]
2022.05.18 15:47:04 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslHandler - Session Server[1135](SSL) Processing the received message
2022.05.18 15:47:04 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslFilter - Session Server[1135](SSL): Processing the SSL Data 
2022.05.18 15:47:04 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslFilter - Session Server[1135](SSL): Message received : HeapBuffer[pos=0 lim=626 cap=4096: 11 5A CD 12 91 E4 C2 53 53 C9 C2 52 D3 C6 46 49...]
2022.05.18 15:47:04 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslHandler - Session Server[1135](SSL) Processing the received message
2022.05.18 15:47:04 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslFilter - Session Server[1135](SSL): Processing the SSL Data 
2022.05.18 15:47:04 DEBUG [NioProcessor-2]: org.apache.mina.filter.executor.OrderedThreadPoolExecutor - Adding event MESSAGE_RECEIVED to session 1135
Queue : [MESSAGE_RECEIVED, ]

2022.05.18 15:47:04 DEBUG [socket_c2s-thread-3]: org.apache.mina.core.filterchain.IoFilterEvent - Firing a MESSAGE_RECEIVED event for session 1135
2022.05.18 15:47:04 DEBUG [socket_c2s-thread-3]: org.apache.mina.filter.codec.ProtocolCodecFilter - Processing a MESSAGE_RECEIVED for session 1135
2022.05.18 15:47:04 DEBUG [socket_c2s-thread-3]: org.apache.mina.core.filterchain.IoFilterEvent - Event MESSAGE_RECEIVED has been fired for session 1135
2022.05.18 15:47:04 DEBUG [TaskEngine-pool-369]: org.apache.mina.filter.ssl.SslFilter - Session Server[1135](SSL): Writing Message : WriteRequest: HeapBuffer[pos=0 lim=128 cap=4096: 3C 69 71 20 74 79 70 65 3D 22 72 65 73 75 6C 74...]
2022.05.18 15:47:04 TRACE [TaskEngine-pool-369]: class org.jivesoftware.openfire.streammanagement.StreamManager[80.187.120.23] - Added stanza of type 'iq' to collection of unacknowledged stanzas (x=20). Collection size is now 3.
2022.05.18 15:47:04 DEBUG [NioProcessor-2]: org.apache.mina.filter.executor.OrderedThreadPoolExecutor - Adding event MESSAGE_SENT to session 1135
Queue : [MESSAGE_SENT, ]

2022.05.18 15:47:04 DEBUG [socket_c2s-thread-5]: org.apache.mina.core.filterchain.IoFilterEvent - Firing a MESSAGE_SENT event for session 1135
2022.05.18 15:47:04 DEBUG [socket_c2s-thread-5]: org.apache.mina.core.filterchain.IoFilterEvent - Event MESSAGE_SENT has been fired for session 1135
2022.05.18 15:47:04 TRACE [TaskEngine-pool-369]: org.jivesoftware.openfire.pubsub.DefaultPubSubPersistenceProvider - Creating published item: UniqueIdentifier{serviceId='bob.hopper@XXXXX.net', nodeId='urn:xmpp:avatar:data', itemId='6f8157f54c24b515a6703aa309afb7ae0a77b0b5'} (write to database)
2022.05.18 15:47:04 TRACE [hz.openfire.partition-operation.thread-1]: com.hazelcast.concurrent.lock.operations.LockOperation - [10.0.0.102]:5701 [openfire] [3.12.5] Acquired lock Routing User Sessions for [10.0.0.102]:5701 - a69837b6-e497-449b-98fc-617cbb378efe, thread ID: 6165
2022.05.18 15:47:04 TRACE [hz.openfire.partition-operation.thread-1]: com.hazelcast.concurrent.lock.operations.UnlockOperation - [10.0.0.102]:5701 [openfire] [3.12.5] Released lock Routing User Sessions
2022.05.18 15:47:04 TRACE [TaskEngine-pool-369]: org.jivesoftware.openfire.pep.PEPService - Recipient 'bob.hopper@XXXXX.net/Snikket.sNjN' is an intended recipient of service 'bob.hopper@XXXXX.net' sending a notification for node 'urn:xmpp:avatar:data': <message><event xmlns="http://jabber.org/protocol/pubsub#event"><items node="urn:xmpp:avatar:data"><item id="6f8157f54c24b515a6703aa309afb7ae0a77b0b5"><data xmlns="urn:xmpp:avatar:data">iVBORw0KGgoAAAANSUhEUgAAAJkAAACZCAYAAAA8XJi6AAAAAX...............................................................</data></item></items></event></message>
2022.05.18 15:47:04 TRACE [TaskEngine-pool-369]: org.jivesoftware.openfire.pep.PEPService - Recipient 'bob.hopper@XXXXX.net/Snikket.sNjN' is a local user using a full JID. Notifications will be sent only if there's an active session (which there is)
2022.05.18 15:47:04 TRACE [TaskEngine-pool-369]: org.jivesoftware.openfire.pep.PEPService - Recipient 'bob.hopper@XXXXX.net/Snikket.sNjN' has these delivery address(es): bob.hopper@XXXXX.net/Snikket.sNjN
2022.05.18 15:47:04 TRACE [TaskEngine-pool-369]: org.jivesoftware.openfire.pep.PEPService - Recipient 'bob.hopper@XXXXX.net/Snikket.sNjN': Not sending notification to address 'bob.hopper@XXXXX.net/Snikket.sNjN' that does not have CAPS urn:xmpp:avatar:data+notify
2022.05.18 15:47:04 TRACE [TaskEngine-pool-369]: org.jivesoftware.openfire.pep.PEPService - Recipient 'bob.hopper@XXXXX.net/Snikket.sNjN': Done processing notification for service 'bob.hopper@XXXXX.net' on node 'urn:xmpp:avatar:data'
2022.05.18 15:47:04 TRACE [hz.openfire.InvocationMonitorThread]: com.hazelcast.spi.impl.operationservice.impl.InvocationMonitor - [10.0.0.102]:5701 [openfire] [3.12.5] Scanning all invocations
2022.05.18 15:47:05 TRACE [hz.openfire.InvocationMonitorThread]: com.hazelcast.spi.impl.operationservice.impl.InvocationMonitor - [10.0.0.102]:5701 [openfire] [3.12.5] Scanning all invocations
2022.05.18 15:47:06 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslFilter - Session Server[9](SSL): Message received : HeapBuffer[pos=0 lim=30 cap=64: 17 03 03 00 19 00 00 00 00 00 00 33 DB 66 B7 6A...]
2022.05.18 15:47:06 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslHandler - Session Server[9](SSL) Processing the received message
2022.05.18 15:47:06 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslFilter - Session Server[9](SSL): Processing the SSL Data 
2022.05.18 15:47:06 DEBUG [NioProcessor-2]: org.apache.mina.filter.executor.OrderedThreadPoolExecutor - Adding event MESSAGE_RECEIVED to session 9
Queue : [MESSAGE_RECEIVED, ]

2022.05.18 15:47:06 DEBUG [socket_c2s-thread-2]: org.apache.mina.core.filterchain.IoFilterEvent - Firing a MESSAGE_RECEIVED event for session 9
2022.05.18 15:47:06 DEBUG [socket_c2s-thread-2]: org.apache.mina.filter.codec.ProtocolCodecFilter - Processing a MESSAGE_RECEIVED for session 9
2022.05.18 15:47:06 DEBUG [socket_c2s-thread-2]: org.apache.mina.core.filterchain.IoFilterEvent - Event MESSAGE_RECEIVED has been fired for session 9
2022.05.18 15:47:06 TRACE [hz.openfire.InvocationMonitorThread]: com.hazelcast.spi.impl.operationservice.impl.InvocationMonitor - [10.0.0.102]:5701 [openfire] [3.12.5] Scanning all invocations

THX
Andre

4

Sadly, this doesn’t include the stanzas (like the ones that you sent earlier). Can you please include XML logs?

One thing that does stand out is that the user that is uploading the avatar (bob.hopper) does not get a notification of that upload on it’s Snikket device. Openfire does not send that notification, because it has determined that the client has not indicated that it wants to receive such notifications:

Not sending notification to address 'bob.hopper@XXXXX.net/Snikket.sNjN' that does not have CAPS urn:xmpp:avatar:data+notify

Maybe that confuses the client?

Snikket-IOS is based on Siskin 6. Can you try to use Siskin, to see if the problem is also present with that client?

5

That’s all weird,
so first I have tried to upload with siskin. Same result but the error message is different.
Siskin: ERROR user avatar publication failed. Reason: not acceptable
Snikket: Profile picture upload failed. Unable to publish your picture at this time. Unsupported.

I have exported the logs again, also the xml log.
Please find below the logs.

2022.05.19 19:44:01 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslHandler - Session Server[787](SSL) Processing the received message
2022.05.19 19:44:01 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslFilter - Session Server[787](SSL): Processing the SSL Data 
2022.05.19 19:44:01 DEBUG [NioProcessor-2]: org.apache.mina.filter.executor.OrderedThreadPoolExecutor - Adding event MESSAGE_RECEIVED to session 787
Queue : [MESSAGE_RECEIVED, ]

2022.05.19 19:44:01 DEBUG [socket_c2s-thread-2]: org.apache.mina.core.filterchain.IoFilterEvent - Firing a MESSAGE_RECEIVED event for session 787
2022.05.19 19:44:01 DEBUG [socket_c2s-thread-2]: org.apache.mina.filter.codec.ProtocolCodecFilter - Processing a MESSAGE_RECEIVED for session 787
2022.05.19 19:44:01 DEBUG [socket_c2s-thread-2]: org.apache.mina.core.filterchain.IoFilterEvent - Event MESSAGE_RECEIVED has been fired for session 787
2022.05.19 19:44:01 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslFilter - Session Server[787](SSL): Message received : HeapBuffer[pos=0 lim=1368 cap=2048: E4 23 36 DD 79 C1 B1 AE 9C 68 A6 28 03 48 EE 79...]
2022.05.19 19:44:01 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslHandler - Session Server[787](SSL) Processing the received message
2022.05.19 19:44:01 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslFilter - Session Server[787](SSL): Processing the SSL Data 
2022.05.19 19:44:01 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslFilter - Session Server[787](SSL): Message received : HeapBuffer[pos=0 lim=1368 cap=2048: 24 DE AD DB D4 F0 0A 90 38 35 76 99 97 35 E9 B7...]
2022.05.19 19:44:01 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslHandler - Session Server[787](SSL) Processing the received message
2022.05.19 19:44:01 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslFilter - Session Server[787](SSL): Processing the SSL Data 
2022.05.19 19:44:01 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslFilter - Session Server[787](SSL): Message received : HeapBuffer[pos=0 lim=1368 cap=2048: AB 50 EA 6A F0 0C 95 62 0C 66 E3 A8 19 3E A0 3B...]
2022.05.19 19:44:01 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslHandler - Session Server[787](SSL) Processing the received message
2022.05.19 19:44:01 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslFilter - Session Server[787](SSL): Processing the SSL Data 
2022.05.19 19:44:01 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslFilter - Session Server[787](SSL): Message received : HeapBuffer[pos=0 lim=1368 cap=2048: F5 F4 73 E7 C6 45 F5 28 74 1A CB D6 78 A0 95 C4...]
2022.05.19 19:44:01 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslHandler - Session Server[787](SSL) Processing the received message
2022.05.19 19:44:01 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslFilter - Session Server[787](SSL): Processing the SSL Data 
2022.05.19 19:44:01 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslFilter - Session Server[787](SSL): Message received : HeapBuffer[pos=0 lim=1368 cap=2048: E6 59 BB 02 F7 A2 5A BD B1 25 0C B7 2E 9C 2C 9C...]
2022.05.19 19:44:01 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslHandler - Session Server[787](SSL) Processing the received message
2022.05.19 19:44:01 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslFilter - Session Server[787](SSL): Processing the SSL Data 
2022.05.19 19:44:01 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslFilter - Session Server[787](SSL): Message received : HeapBuffer[pos=0 lim=1368 cap=2048: AE C5 35 C3 98 B9 51 F3 92 0F C5 47 90 BD 64 7C...]
2022.05.19 19:44:01 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslHandler - Session Server[787](SSL) Processing the received message
2022.05.19 19:44:01 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslFilter - Session Server[787](SSL): Processing the SSL Data 
2022.05.19 19:44:01 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslFilter - Session Server[787](SSL): Message received : HeapBuffer[pos=0 lim=1368 cap=2048: B9 95 A8 76 58 9B 3F B8 7C 7B E8 59 BB F1 8E 4F...]
2022.05.19 19:44:01 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslHandler - Session Server[787](SSL) Processing the received message
2022.05.19 19:44:01 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslFilter - Session Server[787](SSL): Processing the SSL Data 
2022.05.19 19:44:01 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslFilter - Session Server[787](SSL): Message received : HeapBuffer[pos=0 lim=1368 cap=2048: FC 29 B0 AE 83 98 BE 5D FE D7 A3 07 6B F7 A8 08...]
2022.05.19 19:44:01 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslHandler - Session Server[787](SSL) Processing the received message
2022.05.19 19:44:01 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslFilter - Session Server[787](SSL): Processing the SSL Data 
2022.05.19 19:44:01 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslFilter - Session Server[787](SSL): Message received : HeapBuffer[pos=0 lim=1368 cap=2048: E2 EA EE 26 F7 F9 9A 28 C1 1A EC DA 7E 2B 2B D3...]
2022.05.19 19:44:01 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslHandler - Session Server[787](SSL) Processing the received message
2022.05.19 19:44:01 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslFilter - Session Server[787](SSL): Processing the SSL Data 
2022.05.19 19:44:01 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslFilter - Session Server[787](SSL): Message received : HeapBuffer[pos=0 lim=1368 cap=2048: C0 47 77 F2 4A C9 7A F3 59 2A 47 A0 50 54 76 DB...]
2022.05.19 19:44:01 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslHandler - Session Server[787](SSL) Processing the received message
2022.05.19 19:44:01 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslFilter - Session Server[787](SSL): Processing the SSL Data 
2022.05.19 19:44:01 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslFilter - Session Server[787](SSL): Message received : HeapBuffer[pos=0 lim=1368 cap=2048: 87 8B 8D 4A 02 50 00 E4 97 15 D4 D9 27 BE 4F 39...]
2022.05.19 19:44:01 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslHandler - Session Server[787](SSL) Processing the received message
2022.05.19 19:44:01 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslFilter - Session Server[787](SSL): Processing the SSL Data 
2022.05.19 19:44:01 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslFilter - Session Server[787](SSL): Message received : HeapBuffer[pos=0 lim=1368 cap=2048: DF 84 A6 0A 71 31 89 77 65 20 2C 6B C9 5C 1F 54...]
2022.05.19 19:44:01 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslHandler - Session Server[787](SSL) Processing the received message
2022.05.19 19:44:01 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslFilter - Session Server[787](SSL): Processing the SSL Data 
2022.05.19 19:44:01 DEBUG [NioProcessor-2]: org.apache.mina.filter.executor.OrderedThreadPoolExecutor - Adding event MESSAGE_RECEIVED to session 787
Queue : [MESSAGE_RECEIVED, ]

2022.05.19 19:44:01 DEBUG [socket_c2s-thread-3]: org.apache.mina.core.filterchain.IoFilterEvent - Firing a MESSAGE_RECEIVED event for session 787
2022.05.19 19:44:01 DEBUG [socket_c2s-thread-3]: org.apache.mina.filter.codec.ProtocolCodecFilter - Processing a MESSAGE_RECEIVED for session 787
2022.05.19 19:44:01 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslFilter - Session Server[787](SSL): Message received : HeapBuffer[pos=0 lim=1368 cap=2048: DE 75 FC 49 B0 31 29 57 CA 81 E0 53 F0 32 91 47...]
2022.05.19 19:44:01 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslHandler - Session Server[787](SSL) Processing the received message
2022.05.19 19:44:01 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslFilter - Session Server[787](SSL): Processing the SSL Data 
2022.05.19 19:44:01 DEBUG [socket_c2s-thread-3]: org.apache.mina.core.filterchain.IoFilterEvent - Event MESSAGE_RECEIVED has been fired for session 787
2022.05.19 19:44:01 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslFilter - Session Server[787](SSL): Message received : HeapBuffer[pos=0 lim=1368 cap=2048: 8C 20 E1 B6 E4 40 D6 A4 28 DF 64 83 C0 2A 1D 9F...]
2022.05.19 19:44:01 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslHandler - Session Server[787](SSL) Processing the received message
2022.05.19 19:44:01 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslFilter - Session Server[787](SSL): Processing the SSL Data 
2022.05.19 19:44:01 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslFilter - Session Server[787](SSL): Message received : HeapBuffer[pos=0 lim=1368 cap=2048: 71 64 AC C4 D8 09 5F 4A 38 6C 2F 1B DE A4 82 37...]
2022.05.19 19:44:01 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslHandler - Session Server[787](SSL) Processing the received message
2022.05.19 19:44:01 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslFilter - Session Server[787](SSL): Processing the SSL Data 
2022.05.19 19:44:01 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslFilter - Session Server[787](SSL): Message received : HeapBuffer[pos=0 lim=1368 cap=2048: B1 44 E0 5C BF E1 B2 9F 70 59 C2 69 05 CD 1D B6...]
2022.05.19 19:44:01 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslHandler - Session Server[787](SSL) Processing the received message
2022.05.19 19:44:01 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslFilter - Session Server[787](SSL): Processing the SSL Data 
2022.05.19 19:44:01 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslFilter - Session Server[787](SSL): Message received : HeapBuffer[pos=0 lim=1368 cap=2048: DE C2 9A A3 09 C1 C1 69 EE 52 5E 10 E8 20 59 24...]
2022.05.19 19:44:01 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslHandler - Session Server[787](SSL) Processing the received message
2022.05.19 19:44:01 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslFilter - Session Server[787](SSL): Processing the SSL Data 
2022.05.19 19:44:01 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslFilter - Session Server[787](SSL): Message received : HeapBuffer[pos=0 lim=1368 cap=2048: 5C 44 1F AC B5 8A 60 1A 82 AA 18 19 A7 BE 0B 84...]
2022.05.19 19:44:01 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslHandler - Session Server[787](SSL) Processing the received message
2022.05.19 19:44:01 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslFilter - Session Server[787](SSL): Processing the SSL Data 
2022.05.19 19:44:01 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslFilter - Session Server[787](SSL): Message received : HeapBuffer[pos=0 lim=1368 cap=2048: 55 A1 77 3A 85 E5 BC 49 B3 36 F2 FF 05 01 D5 3C...]
2022.05.19 19:44:01 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslHandler - Session Server[787](SSL) Processing the received message
2022.05.19 19:44:01 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslFilter - Session Server[787](SSL): Processing the SSL Data 
2022.05.19 19:44:01 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslFilter - Session Server[787](SSL): Message received : HeapBuffer[pos=0 lim=1368 cap=2048: F8 C6 6B 2A 6A A3 2E 47 D0 31 D2 2B 35 E3 98 EA...]
2022.05.19 19:44:01 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslHandler - Session Server[787](SSL) Processing the received message
2022.05.19 19:44:01 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslFilter - Session Server[787](SSL): Processing the SSL Data 
2022.05.19 19:44:01 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslFilter - Session Server[787](SSL): Message received : HeapBuffer[pos=0 lim=1368 cap=2048: 09 3B D9 5B A3 A7 FD C1 EE 3F D5 E2 7A 84 4B 42...]
2022.05.19 19:44:01 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslHandler - Session Server[787](SSL) Processing the received message
2022.05.19 19:44:01 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslFilter - Session Server[787](SSL): Processing the SSL Data 
2022.05.19 19:44:01 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslFilter - Session Server[787](SSL): Message received : HeapBuffer[pos=0 lim=802 cap=2048: AF 35 40 6C 61 AC C2 29 06 1E DC 3F 91 A5 73 AA...]
2022.05.19 19:44:01 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslHandler - Session Server[787](SSL) Processing the received message
2022.05.19 19:44:01 DEBUG [NioProcessor-2]: org.apache.mina.filter.ssl.SslFilter - Session Server[787](SSL): Processing the SSL Data 
2022.05.19 19:44:01 DEBUG [NioProcessor-2]: org.apache.mina.filter.executor.OrderedThreadPoolExecutor - Adding event MESSAGE_RECEIVED to session 787
Queue : [MESSAGE_RECEIVED, ]

2022.05.19 19:44:01 DEBUG [socket_c2s-thread-5]: org.apache.mina.core.filterchain.IoFilterEvent - Firing a MESSAGE_RECEIVED event for session 787
2022.05.19 19:44:01 DEBUG [socket_c2s-thread-5]: org.apache.mina.filter.codec.ProtocolCodecFilter - Processing a MESSAGE_RECEIVED for session 787
2022.05.19 19:44:01 DEBUG [socket_c2s-thread-5]: org.apache.mina.core.filterchain.IoFilterEvent - Event MESSAGE_RECEIVED has been fired for session 787
2022.05.19 19:44:01 DEBUG [TaskEngine-pool-188]: org.apache.mina.filter.ssl.SslFilter - Session Server[787](SSL): Writing Message : WriteRequest: HeapBuffer[pos=0 lim=140 cap=4096: 3C 69 71 20 74 79 70 65 3D 22 72 65 73 75 6C 74...]
2022.05.19 19:44:01 TRACE [TaskEngine-pool-188]: class org.jivesoftware.openfire.streammanagement.StreamManager[IP.IP.IP.IP] - Added stanza of type 'iq' to collection of unacknowledged stanzas (x=48). Collection size is now 5.
2022.05.19 19:44:01 DEBUG [TaskEngine-pool-188]: class org.jivesoftware.openfire.streammanagement.StreamManager[IP.IP.IP.IP] - Requesting acknowledgement from peer, as we have 5 or more unacknowledged stanzas.
2022.05.19 19:44:01 DEBUG [TaskEngine-pool-188]: org.apache.mina.filter.ssl.SslFilter - Session Server[787](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...]
2022.05.19 19:44:01 DEBUG [NioProcessor-2]: org.apache.mina.filter.executor.OrderedThreadPoolExecutor - Adding event MESSAGE_SENT to session 787
Queue : [MESSAGE_SENT, ]

2022.05.19 19:44:01 DEBUG [NioProcessor-2]: org.apache.mina.filter.executor.OrderedThreadPoolExecutor - Adding event MESSAGE_SENT to session 787
Queue : [MESSAGE_SENT, , MESSAGE_SENT, ]

2022.05.19 19:44:01 DEBUG [socket_c2s-thread-4]: org.apache.mina.core.filterchain.IoFilterEvent - Firing a MESSAGE_SENT event for session 787
2022.05.19 19:44:01 DEBUG [socket_c2s-thread-4]: org.apache.mina.core.filterchain.IoFilterEvent - Event MESSAGE_SENT has been fired for session 787
2022.05.19 19:44:01 DEBUG [socket_c2s-thread-4]: org.apache.mina.core.filterchain.IoFilterEvent - Firing a MESSAGE_SENT event for session 787
2022.05.19 19:44:01 DEBUG [socket_c2s-thread-4]: org.apache.mina.core.filterchain.IoFilterEvent - Event MESSAGE_SENT has been fired for session 787
2022.05.19 19:44:01 TRACE [TaskEngine-pool-188]: org.jivesoftware.openfire.pubsub.DefaultPubSubPersistenceProvider - Creating published item: UniqueIdentifier{serviceId='andre.dombrowsky@XXXXX.net', nodeId='urn:xmpp:avatar:data', itemId='87dead374ddbf18aaf3386d76b84ab09db6e752b'} (write to database)
2022.05.19 19:44:01 TRACE [TaskEngine-pool-188]: org.jivesoftware.openfire.pep.PEPService - Recipient 'andre.dombrowsky@XXXXX.net/Snikket.C5Ty' is an intended recipient of service 'andre.dombrowsky@XXXXX.net' sending a notification for node 'urn:xmpp:avatar:data': <message><event xmlns="http://jabber.org/protocol/pubsub#event"><items node="urn:xmpp:avatar:data"><item id="87dead374ddbf18aaf3386d76b84ab09db6e752b"><data xmlns="urn:xmpp:avatar:data">DATA........</data></item></items></event></message>
2022.05.19 19:44:01 TRACE [TaskEngine-pool-188]: org.jivesoftware.openfire.pep.PEPService - Recipient 'andre.dombrowsky@XXXXX.net/Snikket.C5Ty' is a local user using a full JID. Notifications will be sent only if there's an active session (which there is)
2022.05.19 19:44:01 TRACE [TaskEngine-pool-188]: org.jivesoftware.openfire.pep.PEPService - Recipient 'andre.dombrowsky@XXXXX.net/Snikket.C5Ty' has these delivery address(es): andre.dombrowsky@XXXXX.net/Snikket.C5Ty
2022.05.19 19:44:01 TRACE [TaskEngine-pool-188]: org.jivesoftware.openfire.pep.PEPService - Recipient 'andre.dombrowsky@XXXXX.net/Snikket.C5Ty': Not sending notification to address 'andre.dombrowsky@XXXXX.net/Snikket.C5Ty' that does not have CAPS urn:xmpp:avatar:data+notify
2022.05.19 19:44:01 TRACE [TaskEngine-pool-188]: org.jivesoftware.openfire.pep.PEPService - Recipient 'andre.dombrowsky@XXXXX.net/Snikket.C5Ty': Done processing notification for service 'andre.dombrowsky@XXXXX.net' on node 'urn:xmpp:avatar:data'
2022.05.19 19:44:01 TRACE [TaskEngine-pool-188]: org.jivesoftware.openfire.pep.PEPService - Recipient 'all@broadcast.XXXXX.net' is an intended recipient of service 'andre.dombrowsky@XXXXX.net' sending a notification for node 'andre.dombrowsky@XXXXX.net': <message><event xmlns="http://jabber.org/protocol/pubsub#event"><items node="urn:xmpp:avatar:data"><item id="87dead374ddbf18aaf3386d76b84ab09db6e752b" node="urn:xmpp:avatar:data"><data xmlns="urn:xmpp:avatar:data">DATA.....</data></item></items></event></message>
2022.05.19 19:44:01 TRACE [TaskEngine-pool-188]: org.jivesoftware.openfire.pep.PEPService - Recipient 'all@broadcast.XXXXX.net' is a remote user. Notifications will be sent to to the address as-is.
2022.05.19 19:44:01 TRACE [TaskEngine-pool-188]: org.jivesoftware.openfire.pep.PEPService - Recipient 'all@broadcast.XXXXX.net' has these delivery address(es): all@broadcast.XXXXX.net
2022.05.19 19:44:01 TRACE [TaskEngine-pool-188]: org.jivesoftware.openfire.pep.PEPService - Recipient 'all@broadcast.XXXXX.net': Sending notification to recipient address: 'all@broadcast.XXXXX.net'
2022.05.19 19:44:01 TRACE [hz.openfire.partition-operation.thread-1]: com.hazelcast.concurrent.lock.operations.LockOperation - [10.0.0.102]:5701 [openfire] [3.12.5] Acquired lock Routing User Sessions for [10.0.0.102]:5701 - 52775b8d-84dd-4b93-bea3-1d6afe97c9e1, thread ID: 3480
2022.05.19 19:44:01 TRACE [hz.openfire.partition-operation.thread-1]: com.hazelcast.concurrent.lock.operations.UnlockOperation - [10.0.0.102]:5701 [openfire] [3.12.5] Released lock Routing User Sessions
2022.05.19 19:44:01 DEBUG [TaskEngine-pool-188]: org.apache.mina.filter.ssl.SslFilter - Session Server[780](SSL): Writing Message : WriteRequest: HeapBuffer[pos=0 lim=78829 cap=131072: 3C 6D 65 73 73 61 67 65 20 74 6F 3D 22 62 6F 62...]
2022.05.19 19:44:01 TRACE [TaskEngine-pool-188]: class org.jivesoftware.openfire.streammanagement.StreamManager[IP.IP.IP.IP] - Added stanza of type 'message' to collection of unacknowledged stanzas (x=31). Collection size is now 2.
2022.05.19 19:44:01 DEBUG [NioProcessor-1]: org.apache.mina.filter.executor.OrderedThreadPoolExecutor - Adding event MESSAGE_SENT to session 780
Queue : [MESSAGE_SENT, ]

2022.05.19 19:44:01 DEBUG [socket_c2s-thread-2]: org.apache.mina.core.filterchain.IoFilterEvent - Firing a MESSAGE_SENT event for session 780
2022.05.19 19:44:01 DEBUG [socket_c2s-thread-2]: org.apache.mina.core.filterchain.IoFilterEvent - Event MESSAGE_SENT has been fired for session 780
2022.05.19 19:44:01 DEBUG [TaskEngine-pool-188]: org.apache.mina.filter.ssl.SslFilter - Session Server[787](SSL): Writing Message : WriteRequest: HeapBuffer[pos=0 lim=78835 cap=131072: 3C 6D 65 73 73 61 67 65 20 74 6F 3D 22 61 6E 64...]
2022.05.19 19:44:01 TRACE [TaskEngine-pool-188]: class org.jivesoftware.openfire.streammanagement.StreamManager[IP.IP.IP.IP] - Added stanza of type 'message' to collection of unacknowledged stanzas (x=49). Collection size is now 6.
2022.05.19 19:44:01 TRACE [hz.openfire.partition-operation.thread-1]: com.hazelcast.concurrent.lock.operations.LockOperation - [10.0.0.102]:5701 [openfire] [3.12.5] Acquired lock Routing User Sessions for [10.0.0.102]:5701 - 52775b8d-84dd-4b93-bea3-1d6afe97c9e1, thread ID: 3480
2022.05.19 19:44:01 DEBUG [NioProcessor-2]: org.apache.mina.filter.executor.OrderedThreadPoolExecutor - Adding event MESSAGE_SENT to session 787
Queue : [MESSAGE_SENT, ]

2022.05.19 19:44:01 DEBUG [socket_c2s-thread-3]: org.apache.mina.core.filterchain.IoFilterEvent - Firing a MESSAGE_SENT event for session 787
2022.05.19 19:44:01 DEBUG [socket_c2s-thread-3]: org.apache.mina.core.filterchain.IoFilterEvent - Event MESSAGE_SENT has been fired for session 787
2022.05.19 19:44:01 TRACE [hz.openfire.partition-operation.thread-1]: com.hazelcast.concurrent.lock.operations.UnlockOperation - [10.0.0.102]:5701 [openfire] [3.12.5] Released lock Routing User Sessions
2022.05.19 19:44:01 DEBUG [TaskEngine-pool-188]: org.jivesoftware.openfire.spi.RoutingTableImpl - Unable to route packet. No session is available so store offline. <message to="tristan.radike@XXXXX.net" from="andre.dombrowsky@XXXXX.net" id="pjDKgx0i"><event xmlns="http://jabber.org/protocol/pubsub#event"><items node="urn:xmpp:avatar:data"><item id="87dead374ddbf18aaf3386d76b84ab09db6e752b" node="urn:xmpp:avatar:data"><data xmlns="urn:xmpp:avatar:data">DATA......</data></item></items></event><addresses xmlns="http://jabber.org/protocol/address"><address type="replyto" jid="andre.dombrowsky@XXXXX.net/Snikket.C5Ty"/></addresses></message>
2022.05.19 19:44:01 TRACE [TaskEngine-pool-188]: org.jivesoftware.openfire.MessageRouter - Delegating to offline message strategy.
2022.05.19 19:44:01 DEBUG [TaskEngine-pool-188]: org.jivesoftware.openfire.spi.RoutingTableImpl - Unable to route packet. No session is available so store offline. <message to="jochen.hartmann@XXXXX.net" from="andre.dombrowsky@XXXXX.net" id="pjDKgx0i"><event xmlns="http://jabber.org/protocol/pubsub#event"><items node="urn:xmpp:avatar:data"><item id="87dead374ddbf18aaf3386d76b84ab09db6e752b" node="urn:xmpp:avatar:data"><data xmlns="urn:xmpp:avatar:data">


2022.05.19 20:01:15 DEBUG [socket_c2s-thread-5]: org.jivesoftware.openfire.spi.RoutingTableImpl - Error stanza to bare JID discarded: <message id="ctNCprR1" to="andre.dombrowsky@XXXXX.net" type="error" from="andre.dombrowsky@XXXXX.net/Snikket.C5Ty"><event xmlns="http://jabber.org/protocol/pubsub#event"><items node="urn:xmpp:avatar:data"><item node="urn:xmpp:avatar:data" id="187bb43632ad93199ec01ecefb81682d7a9ea81d"><data xmlns="urn:xmpp:avatar:data">DATA.......</data></item></items></event><addresses xmlns="http://jabber.org/protocol/address"><address jid="andre.dombrowsky@XXXXX.net/Snikket.C5Ty" type="replyto"/></addresses><error type="modify"><bad-request xmlns="urn:ietf:params:xml:ns:xmpp-stanzas"></bad-request></error></message>

xml

2022-05-19 20:05:15,600 INFO  [DebuggerPlugin] - 2022-05-19T18:05:15.600Z - C2S /IP.IP.IP.IP:57388 - RECV - (  801504205): <iq id='D032B631-C0F2-43CE-ABE9-E030FB29967B' type='set'><pubsub xmlns='http://jabber.org/protocol/pubsub'><publish node='urn:xmpp:avatar:data'><item id='65735f158b14777ffcf8d24274131fa3d3200f6c'><data xmlns='urn:xmpp:avatar:data'>DATA................</data></item></publish></pubsub></iq>
2022-05-19 20:05:15,603 INFO  [DebuggerPlugin] - INT /IP.IP.IP.IP:????? - RECV - ( 7v8q32543v): <iq id="D032B631-C0F2-43CE-ABE9-E030FB29967B" type="set" from="andre.dombrowsky@XXXXX.net/Snikket.C5Ty" to="andre.dombrowsky@XXXXX.net"><pubsub xmlns="http://jabber.org/protocol/pubsub"><publish node="urn:xmpp:avatar:data"><item id="65735f158b14777ffcf8d24274131fa3d3200f6c"><data xmlns="urn:xmpp:avatar:data">DATA.......</data></item></publish></pubsub></iq>
2022-05-19 20:05:15,604 INFO  [DebuggerPlugin] - 2022-05-19T18:05:15.604Z - C2S /IP.IP.IP.IP:57388 - RECV - (  801504205): <r xmlns='urn:xmpp:sm:3'/>
2022-05-19 20:05:15,604 INFO  [DebuggerPlugin] - 2022-05-19T18:05:15.604Z - C2S /IP.IP.IP.IP:57388 - SENT - (  801504205): <a xmlns='urn:xmpp:sm:3' h='60' />
2022-05-19 20:05:15,605 INFO  [DebuggerPlugin] - INT /IP.IP.IP.IP:????? - SENT - ( 7v8q32543v): <iq type="result" id="D032B631-C0F2-43CE-ABE9-E030FB29967B" from="andre.dombrowsky@XXXXX.net" to="andre.dombrowsky@XXXXX.net/Snikket.C5Ty"/>
2022-05-19 20:05:15,606 INFO  [DebuggerPlugin] - 2022-05-19T18:05:15.606Z - C2S /IP.IP.IP.IP:57388 - SENT - (  801504205): <iq type="result" id="D032B631-C0F2-43CE-ABE9-E030FB29967B" from="andre.dombrowsky@XXXXX.net" to="andre.dombrowsky@XXXXX.net/Snikket.C5Ty"/>
2022-05-19 20:05:15,623 INFO  [DebuggerPlugin] - INT /IP.IP.IP.IP:????? - SENT - ( 12tfotxghh): <message to="bob.hopper@XXXXX.net" from="andre.dombrowsky@XXXXX.net" id="9c9vpkHr"><event xmlns="http://jabber.org/protocol/pubsub#event"><items node="urn:xmpp:avatar:data"><item id="65735f158b14777ffcf8d24274131fa3d3200f6c" node="urn:xmpp:avatar:data"><data xmlns="urn:xmpp:avatar:data">DATA.........</data></item></items></event><addresses xmlns="http://jabber.org/protocol/address"><address type="replyto" jid="andre.dombrowsky@XXXXX.net/Snikket.C5Ty"/></addresses></message>
2022-05-19 20:05:15,626 INFO  [DebuggerPlugin] - 2022-05-19T18:05:15.626Z - C2S /IP.IP.IP.IP:51093 - SENT - ( 1099642764): <message to="bob.hopper@XXXXX.net" from="andre.dombrowsky@XXXXX.net" id="9c9vpkHr"><event xmlns="http://jabber.org/protocol/pubsub#event"><items node="urn:xmpp:avatar:data"><item id="65735f158b14777ffcf8d24274131fa3d3200f6c" node="urn:xmpp:avatar:data"><data xmlns="urn:xmpp:avatar:data">DATA......</data></item></items></event><addresses xmlns="http://jabber.org/protocol/address"><address type="replyto" jid="andre.dombrowsky@XXXXX.net/Snikket.C5Ty"/></addresses></message>
2022-05-19 20:05:15,627 INFO  [DebuggerPlugin] - INT /IP.IP.IP.IP:????? - SENT - ( 7v8q32543v): <message to="andre.dombrowsky@XXXXX.net" from="andre.dombrowsky@XXXXX.net" id="9c9vpkHr"><event xmlns="http://jabber.org/protocol/pubsub#event"><items node="urn:xmpp:avatar:data"><item id="65735f158b14777ffcf8d24274131fa3d3200f6c" node="urn:xmpp:avatar:data"><data xmlns="urn:xmpp:avatar:data">DATA......</data></item></items></event><addresses xmlns="http://jabber.org/protocol/address"><address type="replyto" jid="andre.dombrowsky@XXXXX.net/Snikket.C5Ty"/></addresses></message>
2022-05-19 20:05:15,631 INFO  [DebuggerPlugin] - 2022-05-19T18:05:15.631Z - C2S /IP.IP.IP.IP:57388 - SENT - (  801504205): <message to="andre.dombrowsky@XXXXX.net" from="andre.dombrowsky@XXXXX.net" id="9c9vpkHr"><event xmlns="http://jabber.org/protocol/pubsub#event"><items node="urn:xmpp:avatar:data"><item id="65735f158b14777ffcf8d24274131fa3d3200f6c" node="urn:xmpp:avatar:data"><data xmlns="urn:xmpp:avatar:data">DATA......</data></item></items></event><addresses xmlns="http://jabber.org/protocol/address"><address type="replyto" jid="andre.dombrowsky@XXXXX.net/Snikket.C5Ty"/></addresses></message>
2022-05-19 20:05:15,771 INFO  [DebuggerPlugin] - 2022-05-19T18:05:15.770Z - C2S /IP.IP.IP.IP:15940 - SENT - ( 1405064113): <message to="miguel.borrero@XXXXX.net" from="andre.dombrowsky@XXXXX.net" id="9c9vpkHr"><event xmlns="http://jabber.org/protocol/pubsub#event"><items node="urn:xmpp:avatar:data"><item id="65735f158b14777ffcf8d24274131fa3d3200f6c" node="urn:xmpp:avatar:data"><data xmlns="urn:xmpp:avatar:data">DATA......</data></item></items></event><addresses xmlns="http://jabber.org/protocol/address"><address type="replyto" jid="andre.dombrowsky@XXXXX.net/Snikket.C5Ty"/></addresses></message>

For the time beeing i found a workaround . I am using the ladp vcard. But the users coming exclusively from outside,thus they don’t have ldap access directly… obviously.
So, I have developed a php module for my website what is connnected with the ldap. This module makes users able to upload their avatars through this website to the ldap server. Not comfortable but works. So in german we say. Von hinten durch die Brust ins Auge. Which means, From behind through the chest into the eye.
Only thing is, that all users have to update the contact of who updated it’s avatar within client manualy.

Best regards,
Andre

6

I have been in contact with developers of the client. One of them was able to reproduce the issue with Openfire.

It appears that the client attempts to reconfigure the pubsub node, before it attempts to publish the vcard. Openfire returns an error, which it probably should not do. I have created a new issue to track this problem: [OF-2438] - Ignite Realtime Jira

Separately, the client developers have indicated that they’re going to investigate if it’s possible to handle such a scenario (not being able to reconfigure the node) more gracefully. In the long run, that might introduce some backwards compatibility with older versions of Openfire.

7

Thank you Guus. I appreciate your efforts.
Andre

8

Hi, I’m a Siskin IM developer.

We have added workarounds for Openfire-specific issues. ie. the PEP avatar publication issue and connectivity issue related to the usage of TLS 1.3.

New beta builds (Siskin IM available on TestFlight and Beagle IM downloadable from GitHub) with those fixes are available right now and most likely new versions will be released next week to the AppStore.

2 Likes
9

@hantu85 Thank you!

10

Any news on this? There was no update since you had replied. Issue is still present.

11

Could you clarify what actually is not working for you? and on which version of the app?

I’ve added workarounds for Openfire bugs to Siskin IM and those changes are part of the 7.3 version. I’ve just double checked and it is all working for me now (using Siskin IM and Openfire).