The problem occurs with the following test environment and test procedure for multi-session.
-
Initial setup
a. Note-3: leopard@atalk.org/atalk (online)
b. Note-2: swordfish@atalk.org/atalk2 (online)
c. Note-8: swordfish@atalk.org/atalk (not-launch and offline) -
Start omemo messaging between 1a and 1b. Omemo messages exchanges between a and b work normally as expected.
-
Start aTalk on 1c device. Upon authentication and sent. Note-8 receives the pubsub#event for swordfish@atalk.org/atalk2 from the server. In response, Note-8 publishes its deviceList to server.
-
Upon receiving new pubsub from Note-8 by ejabberd server, it immediately sends an updated pubsub#event to Note-2.
-
When Note-2 receives the new pubsub#event, it performs a similar reciprocal task likes Note-8
-
This causes an endless loop to start between Note-8 and Note-2 and publishing and receiving pubsub#event to and from ejabberd server.
-
The endless stops only when either one of swordfish clients is logoff.
Initially thought it was ejabberd problem so I reported to ejabberd. But after careful analyzing the stanza exchanges, I think it is caused by smack-omemo
==== Debug log for aTalk (Note-8) engages in an endless loop in pubsub exchanges =======
01-26 13:03:26.249 D/SMACK: RECV (0): <presence xml:lang='en' to='swordfish@atalk.org/atalk' from='swordfish@atalk.org/atalk2' id='BO807-10450'><x xmlns='vcard-temp:x:update'><photo>2644872feed4850eb50d8562f17e2bc84932164c</photo></x><c xmlns='http://jabber.org/protocol/caps' hash='sha-1' node='http://android.atalk.org' ver='qlaf8fmwUojcVNOO07fSQc7Ko9Y='/><priority>30</priority><status/></presence>
01-26 13:03:35.156 D/SMACK: RECV (0): <message to='swordfish@atalk.org/atalk' from='swordfish@atalk.org' type='headline'><event xmlns='http://jabber.org/protocol/pubsub#event'><items node='eu.siacs.conversations.axolotl.devicelist'><item id='5ECE63A79EF62'><list xmlns='eu.siacs.conversations.axolotl'><device id='13537229'/></list></item></items></event><addresses xmlns='http://jabber.org/protocol/address'><address jid='swordfish@atalk.org/atalk2' type='replyto'/></addresses></message>
01-26 13:03:35.182 I/aTalk: [23359] org.atalk.persistance.DatabaseBackend.storeCachedDeviceList().1327 Identities table updated for activeDevice: swordfish@atalk.org:13537229
01-26 13:03:35.186 I/aTalk: [23359] org.atalk.persistance.DatabaseBackend.storeCachedDeviceList().1352 Identities table updated for inactiveDevice: swordfish@atalk.org:2144464921
01-26 13:03:35.199 I/aTalk: [23359] org.atalk.persistance.DatabaseBackend.storeCachedDeviceList().1327 Identities table updated for activeDevice: swordfish@atalk.org:2144464921
01-26 13:03:35.204 I/aTalk: [23359] org.atalk.persistance.DatabaseBackend.storeCachedDeviceList().1352 Identities table updated for inactiveDevice: swordfish@atalk.org:13537229
01-26 13:03:35.210 D/SMACK: SENT (0): <iq to='swordfish@atalk.org' id='uiZON-126' type='set'><pubsub xmlns='http://jabber.org/protocol/pubsub'><publish node='eu.siacs.conversations.axolotl.devicelist'><item><list xmlns='eu.siacs.conversations.axolotl'><device id='2144464921'/></list></item></publish></pubsub></iq>
01-26 13:03:35.327 D/SMACK: RECV (0): <iq xml:lang='en' to='swordfish@atalk.org/atalk' from='swordfish@atalk.org' type='result' id='uiZON-126'><pubsub xmlns='http://jabber.org/protocol/pubsub'><publish node='eu.siacs.conversations.axolotl.devicelist'><item id='5ECE63A7D97D4'/></publish></pubsub></iq>
01-26 13:03:35.384 D/SMACK: RECV (0): <presence xml:lang='en' to='swordfish@atalk.org/atalk' from='swordfish@atalk.org/atalk2' id='BO807-10474'><x xmlns='vcard-temp:x:update'><photo>2644872feed4850eb50d8562f17e2bc84932164c</photo></x><c xmlns='http://jabber.org/protocol/caps' hash='sha-1' node='http://android.atalk.org' ver='qlaf8fmwUojcVNOO07fSQc7Ko9Y='/><priority>30</priority><status/></presence>
01-26 13:03:35.388 D/SMACK: RECV (0): <message to='swordfish@atalk.org/atalk' from='swordfish@atalk.org' type='headline'><event xmlns='http://jabber.org/protocol/pubsub#event'><items node='eu.siacs.conversations.axolotl.devicelist'><item id='5ECE63A7D97D4'><list xmlns='eu.siacs.conversations.axolotl'><device id='2144464921'/></list></item></items></event><addresses xmlns='http://jabber.org/protocol/address'><address jid='swordfish@atalk.org/atalk' type='replyto'/></addresses></message>
01-26 13:03:35.402 I/aTalk: [23359] org.atalk.persistance.DatabaseBackend.storeCachedDeviceList().1327 Identities table updated for activeDevice: swordfish@atalk.org:2144464921
01-26 13:03:35.409 I/aTalk: [23359] org.atalk.persistance.DatabaseBackend.storeCachedDeviceList().1352 Identities table updated for inactiveDevice: swordfish@atalk.org:13537229
01-26 13:03:35.423 I/aTalk: [23359] org.atalk.persistance.DatabaseBackend.storeCachedDeviceList().1327 Identities table updated for activeDevice: swordfish@atalk.org:2144464921
01-26 13:03:35.428 I/aTalk: [23359] org.atalk.persistance.DatabaseBackend.storeCachedDeviceList().1352 Identities table updated for inactiveDevice: swordfish@atalk.org:13537229
01-26 13:03:35.771 D/SMACK: RECV (0): <message to='swordfish@atalk.org/atalk' from='swordfish@atalk.org' type='headline'><event xmlns='http://jabber.org/protocol/pubsub#event'><items node='eu.siacs.conversations.axolotl.devicelist'><item id='5ECE63A845A8A'><list xmlns='eu.siacs.conversations.axolotl'><device id='13537229'/></list></item></items></event><addresses xmlns='http://jabber.org/protocol/address'><address jid='swordfish@atalk.org/atalk2' type='replyto'/></addresses></message>
01-26 13:03:35.799 I/aTalk: [23359] org.atalk.persistance.DatabaseBackend.storeCachedDeviceList().1327 Identities table updated for activeDevice: swordfish@atalk.org:13537229
01-26 13:03:35.807 I/aTalk: [23359] org.atalk.persistance.DatabaseBackend.storeCachedDeviceList().1352 Identities table updated for inactiveDevice: swordfish@atalk.org:2144464921
01-26 13:03:35.827 I/aTalk: [23359] org.atalk.persistance.DatabaseBackend.storeCachedDeviceList().1327 Identities table updated for activeDevice: swordfish@atalk.org:2144464921
01-26 13:03:35.834 I/aTalk: [23359] org.atalk.persistance.DatabaseBackend.storeCachedDeviceList().1352 Identities table updated for inactiveDevice: swordfish@atalk.org:13537229
01-26 13:03:35.844 D/SMACK: SENT (0): <iq to='swordfish@atalk.org' id='uiZON-131' type='set'><pubsub xmlns='http://jabber.org/protocol/pubsub'><publish node='eu.siacs.conversations.axolotl.devicelist'><item><list xmlns='eu.siacs.conversations.axolotl'><device id='2144464921'/></list></item></publish></pubsub></iq>
01-26 13:03:35.957 D/SMACK: RECV (0): <iq xml:lang='en' to='swordfish@atalk.org/atalk' from='swordfish@atalk.org' type='result' id='uiZON-131'><pubsub xmlns='http://jabber.org/protocol/pubsub'><publish node='eu.siacs.conversations.axolotl.devicelist'><item id='5ECE63A8805F2'/></publish></pubsub></iq>
01-26 13:03:35.964 D/SMACK: RECV (0): <message to='swordfish@atalk.org/atalk' from='swordfish@atalk.org' type='headline'><event xmlns='http://jabber.org/protocol/pubsub#event'><items node='eu.siacs.conversations.axolotl.devicelist'><item id='5ECE63A8805F2'><list xmlns='eu.siacs.conversations.axolotl'><device id='2144464921'/></list></item></items></event><addresses xmlns='http://jabber.org/protocol/address'><address jid='swordfish@atalk.org/atalk' type='replyto'/></addresses></message>
01-26 13:03:35.988 I/aTalk: [23359] org.atalk.persistance.DatabaseBackend.storeCachedDeviceList().1327 Identities table updated for activeDevice: swordfish@atalk.org:2144464921
01-26 13:03:35.993 I/aTalk: [23359] org.atalk.persistance.DatabaseBackend.storeCachedDeviceList().1352 Identities table updated for inactiveDevice: swordfish@atalk.org:13537229
01-26 13:03:36.004 I/aTalk: [23359] org.atalk.persistance.DatabaseBackend.storeCachedDeviceList().1327 Identities table updated for activeDevice: swordfish@atalk.org:2144464921
01-26 13:03:36.009 I/aTalk: [23359] org.atalk.persistance.DatabaseBackend.storeCachedDeviceList().1352 Identities table updated for inactiveDevice: swordfish@atalk.org:13537229
01-26 13:03:36.136 D/SMACK: RECV (0): <message to='swordfish@atalk.org/atalk' from='swordfish@atalk.org' type='headline'><event xmlns='http://jabber.org/protocol/pubsub#event'><items node='eu.siacs.conversations.axolotl.devicelist'><item id='5ECE63A8AAD1E'><list xmlns='eu.siacs.conversations.axolotl'><device id='13537229'/></list></item></items></event><addresses xmlns='http://jabber.org/protocol/address'><address jid='swordfish@atalk.org/atalk2' type='replyto'/></addresses></message>
01-26 13:03:36.163 I/aTalk: [23359] org.atalk.persistance.DatabaseBackend.storeCachedDeviceList().1327 Identities table updated for activeDevice: swordfish@atalk.org:13537229
01-26 13:03:36.171 I/aTalk: [23359] org.atalk.persistance.DatabaseBackend.storeCachedDeviceList().1352 Identities table updated for inactiveDevice: swordfish@atalk.org:2144464921
01-26 13:03:36.192 I/aTalk: [23359] org.atalk.persistance.DatabaseBackend.storeCachedDeviceList().1327 Identities table updated for activeDevice: swordfish@atalk.org:2144464921
01-26 13:03:36.199 I/aTalk: [23359] org.atalk.persistance.DatabaseBackend.storeCachedDeviceList().1352 Identities table updated for inactiveDevice: swordfish@atalk.org:13537229
01-26 13:03:36.206 D/SMACK: SENT (0): <iq to='swordfish@atalk.org' id='uiZON-135' type='set'><pubsub xmlns='http://jabber.org/protocol/pubsub'><publish node='eu.siacs.conversations.axolotl.devicelist'><item><list xmlns='eu.siacs.conversations.axolotl'><device id='2144464921'/></list></item></publish></pubsub></iq>
01-26 13:03:36.335 D/SMACK: RECV (0): <iq xml:lang='en' to='swordfish@atalk.org/atalk' from='swordfish@atalk.org' type='result' id='uiZON-135'><pubsub xmlns='http://jabber.org/protocol/pubsub'><publish node='eu.siacs.conversations.axolotl.devicelist'><item id='5ECE63A8D93DC'/></publish></pubsub></iq>
01-26 13:03:36.343 D/SMACK: RECV (0): <message to='swordfish@atalk.org/atalk' from='swordfish@atalk.org' type='headline'><event xmlns='http://jabber.org/protocol/pubsub#event'><items node='eu.siacs.conversations.axolotl.devicelist'><item id='5ECE63A8D93DC'><list xmlns='eu.siacs.conversations.axolotl'><device id='2144464921'/></list></item></items></event><addresses xmlns='http://jabber.org/protocol/address'><address jid='swordfish@atalk.org/atalk' type='replyto'/></addresses></message>
01-26 13:03:36.368 I/aTalk: [23359] org.atalk.persistance.DatabaseBackend.storeCachedDeviceList().1327 Identities table updated for activeDevice: swordfish@atalk.org:2144464921
01-26 13:03:36.376 I/aTalk: [23359] org.atalk.persistance.DatabaseBackend.storeCachedDeviceList().1352 Identities table updated for inactiveDevice: swordfish@atalk.org:13537229
01-26 13:03:36.397 I/aTalk: [23359] org.atalk.persistance.DatabaseBackend.storeCachedDeviceList().1327 Identities table updated for activeDevice: swordfish@atalk.org:2144464921
01-26 13:03:36.404 I/aTalk: [23359] org.atalk.persistance.DatabaseBackend.storeCachedDeviceList().1352 Identities table updated for inactiveDevice: swordfish@atalk.org:13537229
01-26 13:03:36.547 D/SMACK: RECV (0): <message to='swordfish@atalk.org/atalk' from='swordfish@atalk.org' type='headline'><event xmlns='http://jabber.org/protocol/pubsub#event'><items node='eu.siacs.conversations.axolotl.devicelist'><item id='5ECE63A917F4D'><list xmlns='eu.siacs.conversations.axolotl'><device id='13537229'/></list></item></items></event><addresses xmlns='http://jabber.org/protocol/address'><address jid='swordfish@atalk.org/atalk2' type='replyto'/></addresses></message>
01-26 13:03:36.573 I/aTalk: [23359] org.atalk.persistance.DatabaseBackend.storeCachedDeviceList().1327 Identities table updated for activeDevice: swordfish@atalk.org:13537229
01-26 13:03:36.580 I/aTalk: [23359] org.atalk.persistance.DatabaseBackend.storeCachedDeviceList().1352 Identities table updated for inactiveDevice: swordfish@atalk.org:2144464921
01-26 13:03:36.591 I/aTalk: [23359] org.atalk.persistance.DatabaseBackend.storeCachedDeviceList().1327 Identities table updated for activeDevice: swordfish@atalk.org:2144464921
01-26 13:03:36.596 I/aTalk: [23359] org.atalk.persistance.DatabaseBackend.storeCachedDeviceList().1352 Identities table updated for inactiveDevice: swordfish@atalk.org:13537229
01-26 13:03:36.601 D/SMACK: SENT (0): <iq to='swordfish@atalk.org' id='uiZON-139' type='set'><pubsub xmlns='http://jabber.org/protocol/pubsub'><publish node='eu.siacs.conversations.axolotl.devicelist'><item><list xmlns='eu.siacs.conversations.axolotl'><device id='2144464921'/></list></item></publish></pubsub></iq>
01-26 13:03:36.759 D/SMACK: RECV (0): <iq xml:lang='en' to='swordfish@atalk.org/atalk' from='swordfish@atalk.org' type='result' id='uiZON-139'><pubsub xmlns='http://jabber.org/protocol/pubsub'><publish node='eu.siacs.conversations.axolotl.devicelist'><item id='5ECE63A9446E2'/></publish></pubsub></iq>
01-26 13:03:36.767 D/SMACK: RECV (0): <message to='swordfish@atalk.org/atalk' from='swordfish@atalk.org' type='headline'><event xmlns='http://jabber.org/protocol/pubsub#event'><items node='eu.siacs.conversations.axolotl.devicelist'><item id='5ECE63A9446E2'><list xmlns='eu.siacs.conversations.axolotl'><device id='2144464921'/></list></item></items></event><addresses xmlns='http://jabber.org/protocol/address'><address jid='swordfish@atalk.org/atalk' type='replyto'/></addresses></message>
01-26 13:03:36.788 I/aTalk: [23359] org.atalk.persistance.DatabaseBackend.storeCachedDeviceList().1327 Identities table updated for activeDevice: swordfish@atalk.org:2144464921
01-26 13:03:36.793 I/aTalk: [23359] org.atalk.persistance.DatabaseBackend.storeCachedDeviceList().1352 Identities table updated for inactiveDevice: swordfish@atalk.org:13537229
01-26 13:03:36.804 I/aTalk: [23359] org.atalk.persistance.DatabaseBackend.storeCachedDeviceList().1327 Identities table updated for activeDevice: swordfish@atalk.org:2144464921
01-26 13:03:36.808 I/aTalk: [23359] org.atalk.persistance.DatabaseBackend.storeCachedDeviceList().1352 Identities table updated for inactiveDevice: swordfish@atalk.org:13537229
01-26 13:03:36.932 D/SMACK: RECV (0): <message to='swordfish@atalk.org/atalk' from='swordfish@atalk.org' type='headline'><event xmlns='http://jabber.org/protocol/pubsub#event'><items node='eu.siacs.conversations.axolotl.devicelist'><item id='5ECE63A976BA7'><list xmlns='eu.siacs.conversations.axolotl'><device id='13537229'/></list></item></items></event><addresses xmlns='http://jabber.org/protocol/address'><address jid='swordfish@atalk.org/atalk2' type='replyto'/></addresses></message>
01-26 13:03:36.959 I/aTalk: [23359] org.atalk.persistance.DatabaseBackend.storeCachedDeviceList().1327 Identities table updated for activeDevice: swordfish@atalk.org:13537229
01-26 13:03:36.964 I/aTalk: [23359] org.atalk.persistance.DatabaseBackend.storeCachedDeviceList().1352 Identities table updated for inactiveDevice: swordfish@atalk.org:2144464921
01-26 13:03:36.975 I/aTalk: [23359] org.atalk.persistance.DatabaseBackend.storeCachedDeviceList().1327 Identities table updated for activeDevice: swordfish@atalk.org:2144464921
01-26 13:03:36.980 I/aTalk: [23359] org.atalk.persistance.DatabaseBackend.storeCachedDeviceList().1352 Identities table updated for inactiveDevice: swordfish@atalk.org:13537229
01-26 13:03:36.986 D/SMACK: SENT (0): <iq to='swordfish@atalk.org' id='uiZON-143' type='set'><pubsub xmlns='http://jabber.org/protocol/pubsub'><publish node='eu.siacs.conversations.axolotl.devicelist'><item><list xmlns='eu.siacs.conversations.axolotl'><device id='2144464921'/></list></item></publish></pubsub></iq>
01-26 13:03:37.103 D/SMACK: RECV (0): <iq xml:lang='en' to='swordfish@atalk.org/atalk' from='swordfish@atalk.org' type='result' id='uiZON-143'><pubsub xmlns='http://jabber.org/protocol/pubsub'><publish node='eu.siacs.conversations.axolotl.devicelist'><item id='5ECE63A9A28B4'/></publish></pubsub></iq>
01-26 13:03:37.110 D/SMACK: RECV (0): <message to='swordfish@atalk.org/atalk' from='swordfish@atalk.org' type='headline'><event xmlns='http://jabber.org/protocol/pubsub#event'><items node='eu.siacs.conversations.axolotl.devicelist'><item id='5ECE63A9A28B4'><list xmlns='eu.siacs.conversations.axolotl'><device id='2144464921'/></list></item></items></event><addresses xmlns='http://jabber.org/protocol/address'><address jid='swordfish@atalk.org/atalk' type='replyto'/></addresses></message>
01-26 13:03:37.135 I/aTalk: [23359] org.atalk.persistance.DatabaseBackend.storeCachedDeviceList().1327 Identities table updated for activeDevice: swordfish@atalk.org:2144464921
01-26 13:03:37.143 I/aTalk: [23359] org.atalk.persistance.DatabaseBackend.storeCachedDeviceList().1352 Identities table updated for inactiveDevice: swordfish@atalk.org:13537229
01-26 13:03:37.154 I/aTalk: [23359] org.atalk.persistance.DatabaseBackend.storeCachedDeviceList().1327 Identities table updated for activeDevice: swordfish@atalk.org:2144464921
01-26 13:03:37.159 I/aTalk: [23359] org.atalk.persistance.DatabaseBackend.storeCachedDeviceList().1352 Identities table updated for inactiveDevice: swordfish@atalk.org:13537229
01-26 13:03:37.300 D/SMACK: RECV (0): <message to='swordfish@atalk.org/atalk' from='swordfish@atalk.org' type='headline'><event xmlns='http://jabber.org/protocol/pubsub#event'><items node='eu.siacs.conversations.axolotl.devicelist'><item id='5ECE63A9CF266'><list xmlns='eu.siacs.conversations.axolotl'><device id='13537229'/></list></item></items></event><addresses xmlns='http://jabber.org/protocol/address'><address jid='swordfish@atalk.org/atalk2' type='replyto'/></addresses></message>