Smack Omemo deviceList error handler implementation

Followings are the observation when init omemo services on example.ru server.

  1. The logs are captured for account babai@example.ru on both the aTalk and Conversations running on Note-8.
  2. The server has a problem in supporting the following info query i.e.
    <query xmlns='http://jabber.org/protocol/disco#info' node='eu.siacs.conversations.axolotl.devicelist'></query>
  3. However it seems that conversations has provided an alternative when this is not supported by server. The omemo option is available; I did not proceed to test the omemo messaging as I have only a single test account. The customer claims it is working on Conversations.
  4. On aTalk, the omemo feature cannot be supported.

Any comment?

==== aTalk omemo implementation ====
08-30 13:48:03.375 23366-24336/org.atalk.android D/SMACK: SENT (0): <iq to='babai@example.ru' id='8WRgv-67' type='get'><query xmlns='http://jabber.org/protocol/disco#info' node='eu.siacs.conversations.axolotl.devicelist'></query></iq>
08-30 13:48:04.275 23366-24337/org.atalk.android D/SMACK: RECV (0): <iq type="error" id="8WRgv-67" from="babai@example.ru" to="babai@example.ru/atalk"><query xmlns="http://jabber.org/protocol/disco#info" node="eu.siacs.conversations.axolotl.devicelist"/><error code="404" type="cancel"><item-not-found xmlns="urn:ietf:params:xml:ns:xmpp-stanzas"/></error></iq>
08-30 13:48:04.312 23366-24534/org.atalk.android E/aTalk: [710] org.atalk.crypto.omemo.AndroidOmemoService.initializationFailed().127 OmemoManager init failed
    org.jivesoftware.smack.XMPPException$XMPPErrorException: XMPP error reply received from babai@example.ru: XMPPError: item-not-found - cancel
        at org.jivesoftware.smack.StanzaCollector.nextResultOrThrow(StanzaCollector.java:268)
        at org.jivesoftware.smack.StanzaCollector.nextResultOrThrow(StanzaCollector.java:219)
        at org.jivesoftware.smackx.pubsub.PubSubManager.getNode(PubSubManager.java:240)
        at org.jivesoftware.smackx.pubsub.PubSubManager.getLeafNode(PubSubManager.java:326)
        at org.jivesoftware.smackx.omemo.OmemoService.fetchDeviceList(OmemoService.java:611)
        at org.jivesoftware.smackx.omemo.OmemoService.refreshAndRepublishDeviceList(OmemoService.java:660)
        at org.jivesoftware.smackx.omemo.OmemoService.init(OmemoService.java:266)
        at org.jivesoftware.smackx.omemo.OmemoManager.initialize(OmemoManager.java:250)
        at org.jivesoftware.smackx.omemo.OmemoManager$2.run(OmemoManager.java:266)
        at java.lang.Thread.run(Thread.java:764)


==== Conversations omemo implementation ====
08-30 13:37:10.368 21331-21595/eu.siacs.conversations D/conversations: AxolotlService : Couldn't find <item> in bundle IQ packet: <iq type="error" xmlns="jabber:client" to="babai@example.ru/phone" from="babai@example.ru" id="ZX0nAWd1yna1sw"><pubsub xmlns="http://jabber.org/protocol/pubsub"><items node="eu.siacs.conversations.axolotl.bundles:1425536" xmlns="http://jabber.org/protocol/pubsub"/></pubsub><error type="cancel" code="404" xmlns="jabber:client"><item-not-found xmlns="urn:ietf:params:xml:ns:xmpp-stanzas"/></error></iq>
08-30 13:37:10.382 21331-21595/eu.siacs.conversations W/conversations: AxolotlService (babai@example.ru): Received invalid bundle:<iq type="error" xmlns="jabber:client" to="babai@example.ru/phone" from="babai@example.ru" id="ZX0nAWd1yna1sw"><pubsub xmlns="http://jabber.org/protocol/pubsub"><items node="eu.siacs.conversations.axolotl.bundles:1425536" xmlns="http://jabber.org/protocol/pubsub"/></pubsub><error type="cancel" code="404" xmlns="jabber:client"><item-not-found xmlns="urn:ietf:params:xml:ns:xmpp-stanzas"/></error></iq>
08-30 13:37:10.393 21331-21595/eu.siacs.conversations W/conversations: AxolotlService (babai@example.ru): Received invalid prekeys:<iq type="error" xmlns="jabber:client" to="babai@example.ru/phone" from="babai@example.ru" id="ZX0nAWd1yna1sw"><pubsub xmlns="http://jabber.org/protocol/pubsub"><items node="eu.siacs.conversations.axolotl.bundles:1425536" xmlns="http://jabber.org/protocol/pubsub"/></pubsub><error type="cancel" code="404" xmlns="jabber:client"><item-not-found xmlns="urn:ietf:params:xml:ns:xmpp-stanzas"/></error></iq>
08-30 13:37:10.398 21331-21595/eu.siacs.conversations I/conversations: AxolotlService (babai@example.ru): Could not retrieve own IdentityKeyPair
    AxolotlService : Generating axolotl IdentityKeyPair...
08-30 13:37:10.443 21331-21595/eu.siacs.conversations I/conversations: AxolotlService (babai@example.ru): Adding own IdentityKey org.whispersystems.libsignal.IdentityKey@8ec995c9 to PEP.
08-30 13:37:10.449 21331-21595/eu.siacs.conversations I/conversations: AxolotlService (babai@example.ru): Adding new signedPreKey with ID 1 to PEP.
08-30 13:37:13.095 21331-21595/eu.siacs.conversations I/conversations: AxolotlService (babai@example.ru): Adding 100 new preKeys to PEP.
08-30 13:37:13.113 21331-21595/eu.siacs.conversations D/conversations: AxolotlService (babai@example.ru): : Bundle 1425536 in PEP not current. Publishing...

Hm, I wonder why I never got that exception during my testing. I will see if I can fix that soon.

I created SMACK-830 for this.

1 Like

#268 should fix this.

Thanks for the patch.
I just included your fixed in aTalk running on smack 4.4.0-alpha2 (local built). Followings are my observations:

  1. The omemo deviceList fetch does not trigger exception anymore
  2. OmemoManager#contactSupportsOmemo(bareJid) always return false. Because of this aTalk omemo option is being disabled in chat encryption choice selection.
  3. When an omemo message is received from Conversations, aTalk is able to decrypt the message and display it correctly.
  4. Upon receiving an omemo message, aTalk will also auto enable and enter into omemo session.
  5. However whenever aTalk is trying to send an omemo message, it triggers a prompt requesting user to authenticate the buddy, but the identity key is missing in the prompt for user selection. Apparently there is no identity key stored in the database and getFingerprintAndMaybeBuildSession() also failed. See attached snapshot. The aTalk log is also attached below.

============ aTalk log ============
09-03 04:58:06.805 10499-10499/org.atalk.android W/aTalk: [2] org.atalk.crypto.omemo.SQLiteOmemoStore.loadOmemoIdentityKey().433 OMEMO IdentityKey is missing for: babai@babai.ru:1425536
09-03 04:58:06.807 10499-10647/org.atalk.android D/SMACK: SENT (0): <iq to='babai@babai.ru' id='BNcHO-274' type='get'><query xmlns='http://jabber.org/protocol/disco#info' node='eu.siacs.conversations.axolotl.bundles:1425536'></query></iq>
09-03 04:58:07.015 10499-10648/org.atalk.android D/SMACK: RECV (0): <r xmlns='urn:xmpp:sm:3' />
09-03 04:58:07.016 10499-10647/org.atalk.android D/SMACK: SENT (0): <a xmlns='urn:xmpp:sm:3' h='112'/>
09-03 04:58:07.529 10499-10648/org.atalk.android D/SMACK: RECV (0): <iq type="error" id="BNcHO-274" from="babai@babai.ru" to="test@babai.ru/atalk"><query xmlns="http://jabber.org/protocol/disco#info" node="eu.siacs.conversations.axolotl.bundles:1425536"/><error code="404" type="cancel"><item-not-found xmlns="urn:ietf:params:xml:ns:xmpp-stanzas"/></error></iq>
09-03 04:58:07.531 10499-10499/org.atalk.android W/System.err: org.jivesoftware.smackx.omemo.exceptions.CannotEstablishOmemoSessionException
09-03 04:58:07.532 10499-10499/org.atalk.android W/System.err:     at org.jivesoftware.smackx.omemo.OmemoService.buildFreshSessionWithDevice(OmemoService.java:775)
        at org.jivesoftware.smackx.omemo.OmemoStore.getFingerprintAndMaybeBuildSession(OmemoStore.java:616)
        at org.jivesoftware.smackx.omemo.OmemoManager.getFingerprint(OmemoManager.java:607)
        at org.atalk.crypto.omemo.OmemoAuthenticateDialog.getBuddyFingerPrints(OmemoAuthenticateDialog.java:124)
        at org.atalk.crypto.omemo.OmemoAuthenticateDialog.onCreate(OmemoAuthenticateDialog.java:92)
        at android.app.Activity.performCreate(Activity.java:7183)
        at android.app.Instrumentation.callActivityOnCreate(Instrumentation.java:1220)
        at android.app.ActivityThread.performLaunchActivity(ActivityThread.java:2910)
        at android.app.ActivityThread.handleLaunchActivity(ActivityThread.java:3032)
        at android.app.ActivityThread.-wrap11(Unknown Source:0)
        at android.app.ActivityThread$H.handleMessage(ActivityThread.java:1696)
        at android.os.Handler.dispatchMessage(Handler.java:105)
        at android.os.Looper.loop(Looper.java:164)
        at android.app.ActivityThread.main(ActivityThread.java:6940)
        at java.lang.reflect.Method.invoke(Native Method)
        at com.android.internal.os.Zygote$MethodAndArgsCaller.run(Zygote.java:327)
        at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:1374)
  1. So aTalk is still unable to send any omemo message. There is no problem in receiving omemo messages from Conversations.

At this point I believe that there is probably another problem in aTalk which causes the behaviour you’re observing.

Before I received your reply, I restarted my home server/xmpp server a couple of times trying to get blueman working. Not sure if this has changed the below new observation.

I rechecked again this morning with your new input, below is my new observation:

  1. Upon received an omemo message from Conversations, aTalk auto enters into omemo session with Conversation.
  2. Surprisingly aTalk is now able to send and receive omemo messages with conversation.
  3. This time, I checked and confirmed that the aTalk SQL table now has a new complete/correct buddy identity row entry in the table for omemo message communications

=========
I rewind to the previous aTalk error log, and found that the babai@babai.ru:1425536 identity row entry is still there, but will all other column fields including the identityKey with null values. I then trace the event based on the above error log and has the following conclusion:

  1. In OmemoStore#getFingerprintAndMaybeBuildSession()#loadOmemoIdentityKey(), aTalk did response correctly with identityKey == null.
  2. The problem actually failed in PubSubManager when it executed the getLeafNode() i.e.
    OmemoService#fetchBundle#pm.getLeafNode(contactsDevice.getBundleNodeName());
  3. Believe It throws one of the exception, either NotALeafNodeException or NotAPubSubNodeException
    from the xmpp server.
  4. This leads to CannotEstablishOmemoSessionException as shown in the log.
  5. May be my unintentionally restart the xmpp server has actually clear the server problem.

===========

OmemoManager#contactSupportsOmemo(bareJid) always return false. Because of this aTalk omemo option is being disabled in chat encryption choice selection.

However the above problem still remain and aTalk cannot init a omemo chat session with the buddy; The contactSupportsOmemo uses OmemoManager#getOmemoService().refreshDeviceList(), hence
it always receive reply with “item-not-found”. Any suggestion?

09-05 11:18:47.537 17296-17406/org.atalk.android D/SMACK: SENT (0): <iq to='babai@babai.ru' id='krE9O-520' type='get'><query xmlns='http://jabber.org/protocol/disco#info' node='eu.siacs.conversations.axolotl.devicelist'></query></iq>
09-05 11:18:48.656 17296-17407/org.atalk.android D/SMACK: RECV (0): <iq type="error" id="krE9O-520" from="babai@babai.ru" to="test@babai.ru/atalk"><query xmlns="http://jabber.org/protocol/disco#info" node="eu.siacs.conversations.axolotl.devicelist"/><error code="404" type="cancel"><item-not-found xmlns="urn:ietf:params:xml:ns:xmpp-stanzas"/></error></iq>

Thats not supposed to happen and sounds like a server bug to me. What server are you running?

Customer is having an old OpenFire v4.1.6 installed on their server.

Actually your patch provided earlier is also for the same error. All the tests carried out in this discussion are actually based on this server.

As a fallback, can we check for buddy identityKey, if presence, then assume buddy does support omemo messaging.

Conversations works ok with this server.
Just found that Conversations always enable omemo option even the contact does not support omemo messaging.

Thats true, but also a little inconvenient in my opinion.

If I remember correctly, Openfire had some issues with PubSub.
I’d suggest you open a bug report for openfire with the stanza logs that cause the item-not-found error.

Customer has just upgraded their openFire service to the latest release 4.2.3 yesterday. This problem has been resolved in v4.2.3. However I am seeing another major problem in openfire 4.2.3.

FYI:
Openfire v4.2.3 throws out of order sm ack and closes the stream unexpectedly

Glad to hear that the OMEMO issue has been resolved :slight_smile:

Edit: For now you might want to disable SM in Openfire