1 Reply Latest reply on Aug 26, 2017 12:25 AM by cmeng

    Smack Omemo Identities Regenerate failed on slow android device due to reply timeout

    cmeng

      Below is the captured log for Samsung S3 when for aTalk when user triggers the omemoDevice identities regenerate option. It looks like the regenerate of the 100 identity keys takes a long time for a slow device like S3. Smack Omemo throws reply timeout even before the prekeys are published to the server.

      Because of the reply timeout exception, the device omemo database may be left in an inconsistent, not working state.

      May be omemo should only check for reply after the preKeys bundle has been published to the server. This itself already taken more than 6 seconds.

       

      By the way, I see there is not action taken by Omemo when an corrupted keyPairs is encountered. Is manually regenerate the omemoDevice identities by the user, the correct approach to rectify the problem? Any better alternative like keyPairs repairing or delete the corrupted keyPairs etc?

       

      ============ aTalk log for omemo identities regeneration process ===========

      08-22 09:32:25.430 E/αTalk: [10] org.jivesoftware.smackx.omemo.OmemoManager.run() connectionListener.authenticated() failed to initialize OmemoManager: Invalid IdentityKeyPair for omemoDevice: swan@atalk.org:949870470; com.google.protobuf.InvalidProtocolBufferException: Protocol message contained an invalid tag (zero).

      08-22 09:33:42.155 I/αTalk: [1] org.jivesoftware.smackx.omemo.OmemoStore.isAvailableDeviceId() Check if id 1048500688 is available...

      08-22 09:33:42.625 I/αTalk: [1] org.jivesoftware.smackx.omemo.OmemoStore.regenerate() Regenerating with deviceId 1048500688...

      08-22 09:33:42.805 I/αTalk: [1] org.atalk.crypto.omemo.SQLiteOmemoStore.storeOmemoIdentityKeyPair().490 Store omemo identityKeyPair for :swan@atalk.org:1048500688

      08-22 09:34:10.140 W/System.err: org.jivesoftware.smack.SmackException$NoResponseException: No response received within reply timeout. Timeout was 10000ms (~10s). Waited for response using: IQReplyFilter: iqAndIdFilter (AndFilter: (OrFilter: (IQTypeFilter: type=error, IQTypeFilter: type=result), StanzaIdFilter: id=REV4j-122)), : fromFilter (OrFilter: (FromMatchesFilter (full): swan@atalk.org, FromMatchesFilter (full): null)).

      08-22 09:34:10.150 W/System.err:     at org.jivesoftware.smack.StanzaCollector.nextResultOrThrow(StanzaCollector.java:2 53)

      08-22 09:34:10.155 W/System.err:     at org.jivesoftware.smack.StanzaCollector.nextResultOrThrow(StanzaCollector.java:2 08)

      08-22 09:34:10.160 W/System.err:     at org.jivesoftware.smackx.pubsub.LeafNode.send(LeafNode.java:350)

      08-22 09:34:10.160 W/System.err:     at org.jivesoftware.smackx.pubsub.LeafNode.send(LeafNode.java:325)

      08-22 09:34:10.165 W/System.err:     at org.jivesoftware.smackx.pubsub.PubSubManager.tryToPublishAndPossibleAutoCreate( PubSubManager.java:394)

      08-22 09:34:10.170 W/System.err:     at org.jivesoftware.smackx.omemo.OmemoService.publishBundle(OmemoService.java:301)

      08-22 09:34:10.170 W/System.err:     at org.jivesoftware.smackx.omemo.OmemoManager.regenerate(OmemoManager.java:408)

      08-22 09:34:10.175 W/System.err:     at org.atalk.crypto.omemo.OmemoRegenerateDialog$2.onClick(OmemoRegenerateDialog.ja va:103)

      08-22 09:34:10.175 W/System.err:     at com.android.internal.app.AlertController$ButtonHandler.handleMessage(AlertContr oller.java:167)

      08-22 09:34:10.180 W/System.err:     at android.os.Handler.dispatchMessage(Handler.java:99)

      08-22 09:34:10.185 W/System.err:     at android.os.Looper.loop(Looper.java:137)

      08-22 09:34:10.185 W/System.err:     at android.app.ActivityThread.main(ActivityThread.java:4507)

      08-22 09:34:10.190 W/System.err:     at java.lang.reflect.Method.invokeNative(Native Method)

      08-22 09:34:10.190 W/System.err:     at java.lang.reflect.Method.invoke(Method.java:511)

      08-22 09:34:10.195 W/System.err:     at com.android.internal.os.ZygoteInit$MethodAndArgsCaller.run(ZygoteInit.java:790)

      08-22 09:34:10.195 W/System.err:     at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:557)

      08-22 09:34:10.200 W/System.err:     at dalvik.system.NativeStart.main(Native Method)

      08-22 09:35:57.745 D/SMACK: SENT (0): <iq to='swan@atalk.org' id='REV4j-122' type='set'><pubsub xmlns='http://jabber.org/protocol/pubsub'><publish node='eu.siacs.conversations.axolotl.bundles:1048500688'><item><bundle xmlns='eu.siacs.conversations.axolotl'><signedPreKeyPublic signedPreKeyId='1'>BfPxdS23oVEfhhzpWX2+NUGOb/1eK5EFahSA1SBjWcQs</signedPreKeyPu blic><signedPreKeySignature>liXX/jyK4zuFebHqlzsQzf8GQM9HkFPMcpaxMp+JWUs3MQ5rq5Q1 lJYdg7o6JkDarOSUt4Es+HnudQzF0WbKDA==</signedPreKeySignature><identityKey>BRfiyZY 5m3R0CqkH3LGf/IBZIuqwkXoGMa4dT73jVMwk</identityKey><prekeys><preKeyPublic preKeyId='1'>BcNqCCZx1UYohPcRhd/LN5yN8v5xhJdyin9kXgptkiR6</preKeyPublic><preKey Public

      ....

      preKeyId='37'>BZm8g4pvVOzsw/6uw512HOOxDszrSXRa0oQuQEtEjj5L</preKeyPublic><preKey Public preKeyId='42'>Bd3RHkVIvOfkHgrdBNXIBumqb87EuHwFlF7Wr/qR6I9l</preKeyPublic><preKe yPublic preKeyId='43'>BVw/7biP1O/oFtiAxjTPh

      08-22 09:35:57.745 D/SMACK: SENT (0): </pubsub></iq>

      08-22 09:36:02.990 D/SMACK: SENT (0): <iq to='atalk.org' id='REV4j-123' type='get'><query xmlns='http://jabber.org/protocol/disco#items'></query></iq>

      08-22 09:36:03.905 D/SMACK: RECV (0): <iq xml:lang='en' to='swan@atalk.org/atalk' from='swan@atalk.org' type='result' id='REV4j-122'><pubsub xmlns='http://jabber.org/protocol/pubsub'><publish node='eu.siacs.conversations.axolotl.bundles:1048500688'><item id='5DF594BA215'/></publish></pubsub></iq>

        • Re: Smack Omemo Identities Regenerate failed on slow android device due to reply timeout
          cmeng

          If I fixed the Note 3 issue as reported in the link below by disabling the ART runtime ahead-of-time (AOT) by setting

          android:vmSafeMode="true" in AndroidManifest.xml

          https://issuetracker.google.com/issues/64425255

          See below link for more info on ART:

          Disable Android ART ahead-of-time compilation to optimize debug deployment | Android By Code

           

          Smakc-4.2.1-beta2-SNAPSHOT will always throws "No response received within reply timeout" exception. It was found that without the ART, the fetching/generation of the prekeys in aTalk took almost 3 minutes even on Note3 to send and is after the response timeout exception has been thrown.

          I hope the smack team will look into how to synchronize the sending and checking for the stanza response so that it is independent of device speed. Otherwise aTalk will have reliability issue on a slow devices e.g. Samsung S3.

           

          =============== aTalk log cat with ART disabled ==============

          08-26 14:36:30.098 E/αTalk: [14] org.jivesoftware.smackx.omemo.OmemoManager.run() connectionListener.authenticated() failed to initialize OmemoManager: No response received within reply timeout. Timeout was 10000ms (~10s). Waited for response using: IQReplyFilter: iqAndIdFilter (AndFilter: (OrFilter: (IQTypeFilter: type=error, IQTypeFilter: type=result), StanzaIdFilter: id=02A88-200)), : fromFilter (OrFilter: (FromMatchesFilter (full): leopard@icrypto.com, FromMatchesFilter (full): null)).

          08-26 14:36:32.298 E/αTalk: [15] org.jivesoftware.smackx.omemo.OmemoManager.run() connectionListener.authenticated() failed to initialize OmemoManager: No response received within reply timeout. Timeout was 10000ms (~10s). Waited for response using: IQReplyFilter: iqAndIdFilter (AndFilter: (OrFilter: (IQTypeFilter: type=error, IQTypeFilter: type=result), StanzaIdFilter: id=02A88-217)), : fromFilter (OrFilter: (FromMatchesFilter (full): leopard@atalk.org, FromMatchesFilter (full): null)).

           

          08-26 14:39:27.688 D/SMACK: SENT (0): <iq to='leopard@icrypto.com' id='02A88-200' type='set'><pubsub xmlns='http://jabber.org/protocol/pubsub'><publish node='eu.siacs.conversations.axolotl.bundles:1383749680'><item><bundle xmlns='eu.siacs.conversations.axolotl'><signedPreKeyPublic signedPreKeyId='1'>BeotKh1bUk3+6f8FxuJ0IzGwkj7E5CLro6O6pdyrG+h3</signedPreKeyPu blic><signedPreKeySignature>I/PCBeqrcHd/7WScciUxAXwoRTfADpk5xYJUTus7jSS+my2T7KuW NHDDmN1ujA60czstmEDb498uwqFjQ74rAQ==</signedPreKeySignature><identityKey>BcFVClj HcY/epo03OMQjEc2ZO0aJjOiDzV8v/fe9CH9q</identityKey><prekeys><preKeyPublic preKeyId='37'>BZC/QpkbsUC6um+f+Z5Rba+1zngMNm/xz+MfstPoTrdW</preKeyPublic><preKe yPublic

          ....

          preKeyId='58'>BU2/IKyn4HzVYGlZ53a47t+mKbrtY9SRrfRxSEqwwvpA</preKeyPublic><preKey Public preKeyId='46'>BXuvjperyt9bNT/SN/UjuNsHn0K74kB7PKlXqOlkLpl/</preKeyPublic><preKe yPublic preKeyId='14'>BdI/tCZUZ

          08-26 14:39:27.698 D/SMACK: SENT (0): </pubsub></iq>

           

          08-26 14:39:30.508 D/SMACK: SENT (1): <iq to='leopard@atalk.org' id='02A88-217' type='set'><pubsub xmlns='http://jabber.org/protocol/pubsub'><publish node='eu.siacs.conversations.axolotl.bundles:1011347036'><item><bundle xmlns='eu.siacs.conversations.axolotl'><signedPreKeyPublic signedPreKeyId='1'>BcdRaXODwwV2iX21saahdi5EXYx2zHnKL9ToLHwQPExS</signedPreKeyPu blic><signedPreKeySignature>9InTdCLINuWZFTQpidfrcoCthzXG0UEBWG6KC+0pLXUlclSKZo6C OLUCgZT26lfv7Xw5PUW+WkJwC7F2avykAA==</signedPreKeySignature><identityKey>BbZGG4d UIqGR4GkiE2QDSwoa2JnFyiTowje+tIlOkAZ5</identityKey><prekeys><preKeyPublic preKeyId='103'>BbW/KsLDl9IoAu9mmojckoRpRXBIRc+APhilqE+Ua193</preKeyPublic><preK eyPublic

          .....

          preKeyId='58'>BU3EwWiMLqLZ9KmANhmmT3esbgXlpjWgWHwSZAy99eRX</preKeyPublic><preKey Public preKeyId='46'>BeXzeIe5mr3a0Dbz+wsSYpnHPt0zB9CdlzM6g2TpVuUH</preKeyPublic><preKe yPublic preKeyId='14'>BX2+cFhupE

          08-26 14:39:30.508 D/SMACK: SENT (1): </pubsub></iq>

          08-26 14:39:32.058 D/SMACK: RECV (0): <iq xml:lang='en' to='leopard@icrypto.com/atalk' from='leopard@icrypto.com' type='result' id='02A88-200'><pubsub xmlns='http://jabber.org/protocol/pubsub'><publish node='eu.siacs.conversations.axolotl.bundles:1383749680'><item id='5DFB2196664E4'/></publish></pubsub></iq>

          08-26 14:39:34.938 D/SMACK: RECV (1): <iq xml:lang='en' to='leopard@atalk.org/atalk' from='leopard@atalk.org' type='result' id='02A88-217'><pubsub xmlns='http://jabber.org/protocol/pubsub'><publish node='eu.siacs.conversations.axolotl.bundles:1011347036'><item id='5DFB219935F93'/></publish></pubsub></iq>