search

cmeng-git / atalk-android

xmpp/jabber client for android
Apache License 2.0
155 stars 56 forks source link

can not send text message via XMPP account with OMEMO enabled: Attempt to invoke virtual method 'java.util.HashMap org.jivesoftware.smackx.omemo.element.OmemoBundleElement.getPreKeys()' on a null object reference #173

Closed slavoon4 closed 3 years ago

slavoon4 commented 3 years ago

can not send text message via XMPP account with OMEMO enabled: application shows a message Attempt to invoke virtual method 'java.util.HashMap org.jivesoftware.smackx.omemo.element.OmemoBundleElement.getPreKeys()' on a null object reference 2021_01_11_07 56 04 I deleted any other XMPP account from the aTalk application and added the XMPP account that had never been registered in this aTalk application before (never been added before) (slavoon23@404.city, but was registered some month before at 404.city server and I used it at other applications).

I cleared chat text message history and OMEMO keys (i suppose...). I rebooted the phone, wait until aTalk goes Online account status, receive a message from another XMPP user account (papamail@404.city via Conversations application). Converastion application shows it's all ok and text message is OMEMO encrypted. aTalk application received it and shows all ok and this inbound message is OMEMO encrypted. But when I try to send text message from aTalk to Conversations - aTalk shows error described above.

Prior to the observed problem I opened the Account settings in aTalk application and the last button with the broom (Clear) and cleared everything (XEP-0237, XEP-0115, XEP-0030, XEP-0084/XEP-0153, XEP-0384 and debug log of aTalk).

The problem continues after rebooting device (can receive text messages, but can not send). Now I will not delete this XMPP account from aTalk application and add it back (in hope to resolve the problem) due to have the ability to send further reports.

In your "i removed XMPP user account and added it again and it helped"; does this refer to the same user account as in your comment. - No, it was the same problem, but in the past with another account.

slavoon4 commented 3 years ago

I type any text and press the triangle button with airplane on it "send message". the message disappears and the button switches to the microphone icon and this error message appears

cmeng-git commented 3 years ago

Thanks for the detailed descriptions and the latest debug log. The latest debug log contains the previous event (1/11), and the repeated test on (1/12). Based on your input and the debug log, below are my comments:

Prior to the observed problem I opened the Account settings in aTalk application and the last button with the broom (Clear) and cleared everything (XEP-0237, XEP-0115, XEP-0030, XEP-0084/XEP-0153, XEP-0384 and debug log of aTalk).

These are purely actions taken on database, and pay little action to the actual aTalk normal operation. Actually these options should only be activated when one see problems on those respective areas. In most cases, user is required to exit and relaunch aTalk to ensure aTalk takes steps to re-init the database content. In particular XEP-0384, the action in fact cleans up all the contents in OMEMO tables, including its OMEMO device ID. This was the likely reason why you see the problem on 1/11. From the log, the whole prekeys table for OMEMO device id 1151002113 is no longer in the database and hence:

01-11 07:44:22.721 W/(ChatController.java:316)#sendMessage( 4448): Send instant message exception: Attempt to invoke virtual method 'java.util.HashMap org.jivesoftware.smackx.omemo.element.OmemoBundleElement.getPreKeys()' on a null object reference

On 1/12: From debug log, I see that OMEMO routine recreates a new OMEMO device ID 486745735; the new prekeys table was published onto the server and received a confirmation reply from server. By right everything should return to normal after this, and OMEMO should start using this new ID. The problem is, I see that OMEMO continues to use the old device id 1151002113, this is the reason why the problem continue to exist on the second repeated test and still received:

01-12 20:44:34.929 W/(ChatController.java:316)#sendMessage( 4684): Send instant message exception: Attempt to invoke virtual method 'java.util.HashMap org.jivesoftware.smackx.omemo.element.OmemoBundleElement.getPreKeys()' on a null object reference

Seems like the active OMEMO device ID used is out of sync with the latest published device ID, and I am not sure why this can happen. Need to get back to smack team for some advice.

Meantime, can you perform the following steps and see if thing returns to normal: a. Exit aTalk b. Go to aTalk 'App Info', select 'Storage' and 'Clear cache' c. Relaunch aTalk, and see if thing returns to normal.

Please send me the debug log again, after sending text from papamail, followed by reply text from slavoon23.; if the problem persist.

cmeng-git commented 3 years ago

From Slavoon4:

I did this (exit aTalk, in Android settings - applications - cleared the aTalk's cache). The problem persist. The Conversations still able to send texts (from account papamail) to aTalk (to account slavoon23), but the first time (today) Conversations shows 'error while receiving OMEMO key' message while i try to send text from Conversations to aTalk the first time after I cleared cache of aTalk. But later Conversations does not show this message, aTalk still can receive texts and can not send. Both applications shows all messages are encrypted.

cmeng-git commented 3 years ago

I have relayed the info to smack team for advice: https://discourse.igniterealtime.org/t/smack-omemo-4-4-0-encounters-null-object-reference-while-sending-an-omemo-message/89496

Can you perform an "Regenerate OMEMO identities" to see it help. Please send me the debug log.

cmeng-git commented 3 years ago

Kindly perform an "Regenerate OMEMO identities" to see it helps; please refer to smack bug report for reason.

If "Regenerate OMEMO identities" does not work, the last resort is to remove the user account, and then add it back again.

slavoon4 commented 3 years ago

after Regenerate OMEMO identities (at aTalk) - Conversations shows it took keys blindly from user slavoon23, after this Conversations able to send OMEMO encrypted messages to slavoon23 (Conversations shows that messages are encrypted, aTalk shows messages are encrypted), but now aTalk able to send unencrypted messages to papamail account (and he receives them). Then I try to turn on the OMEMO encryption in aTalk - it shows: OMEMO session setup failed! Null values! (i can not show here the exactly phrase because I translated it from russian aTalk interface). I need to proceed to remove the user account, and then add it back again?  

Sent: Tuesday, January 19, 2021 at 5:46 AM From: "Eng ChongMeng" notifications@github.com To: "cmeng-git/atalk-android" atalk-android@noreply.github.com Cc: "slavoon4" papamail@mail.com, "Author" author@noreply.github.com Subject: Re: [cmeng-git/atalk-android] can not send text message via XMPP account with OMEMO enabled: Attempt to invoke virtual method 'java.util.HashMap org.jivesoftware.smackx.omemo.element.OmemoBundleElement.getPreKeys()' on a null object reference (#173)

 

Kindly perform an "Regenerate OMEMO identities" to see it helps; please refer to smack bug report for reason.

If "Regenerate OMEMO identities" does not work, the last resort is to remove the user account, and then add it back again.

— You are receiving this because you authored the thread. Reply to this email directly, view it on GitHub, or unsubscribe.

cmeng-git commented 3 years ago

Your observed behavior are correct after you performed ""Regenerate OMEMO iddentities"; except the last error message i.e. OMEMO session setup failed! Null values! This is the cause that you are unable to send any omemo messages.

I have reviewed all your debug log info, below is my finding: From the log, I can see that your have four omemo device Ids being created since 01/12:

01-12 20:44:31.506 D/SMACK   ( 4684): RECV (3): 
01-12 20:44:31.506 D/SMACK   ( 4684):       <item id='64A42ED2444BF'>
01-12 20:44:31.506 D/SMACK   ( 4684):         <list xmlns='eu.siacs.conversations.axolotl'>
01-12 20:44:31.506 D/SMACK   ( 4684):           <device id='1151002113'/>
01-12 20:44:31.506 D/SMACK   ( 4684):           <device id='486745735'/>
01-12 20:44:31.506 D/SMACK   ( 4684):           <device id='909412898'/>
01-12 20:44:31.506 D/SMACK   ( 4684):           <device id='935698264'/>
01-12 20:44:31.506 D/SMACK   ( 4684):         </list>
01-12 20:44:31.506 D/SMACK   ( 4684):       </item>
01-12 20:44:31.506 D/SMACK   ( 4684):     </items>
01-12 20:44:31.506 D/SMACK   ( 4684):   </pubsub>
01-12 20:44:31.506 D/SMACK   ( 4684): </iq>

From the latest log, II cannot find any log info indicates that you performed "Regenerate OMEMO iddentities" since 01/12. When was the last time you did the "Regenerate OMEMO iddentities", before sending the last debug log?

The reason I asked is that all the latest debug log on 01/18 and 01/19, seems that the same set of Id's are still causing your observed problem. When you select the "OMEMO" encryption option, aTalk proceeds to verify all its intended recipients (including its own cc devices) to ensure all have the proper identityKeys present for encryption; however your debug log shown this is not so for: a. slavoon23@404.city:935698264 b. slavoon23@404.city:1151002113 c. papamail@404.city:1743131651

Not sure if papamail@404.city:1743131651 is also the old deviceId, cannot find any log info to confirm this.

If you have performed the regenerate, can you try to do the "Purge unsued identities" to see it returns to normal operation. See below for bug report to smack team.

Smack Omemo causes system crashes when buddy prekeys is empty or corrupted

2021-01-19 08:53:17.895 WARNING: [18] org.jivesoftware.smackx.omemo.OmemoService.buildMissingSessionsWithDevices() slavoon23@404.city:486745735 cannot establish session with slavoon23@404.city:935698264 because their bundle could not be fetched.
org.jivesoftware.smackx.omemo.exceptions.CannotEstablishOmemoSessionException
    at org.jivesoftware.smackx.omemo.OmemoService.buildFreshSessionWithDevice(OmemoService.java:793)
    at org.jivesoftware.smackx.omemo.OmemoService.buildMissingSessionsWithDevices(OmemoService.java:834)
    at org.jivesoftware.smackx.omemo.OmemoService.encrypt(OmemoService.java:358)
    at org.jivesoftware.smackx.omemo.OmemoService.createOmemoMessage(OmemoService.java:542)
    at org.jivesoftware.smackx.omemo.OmemoManager.encrypt(OmemoManager.java:340)
    at org.jivesoftware.smackx.omemo.OmemoManager.encrypt(OmemoManager.java:313)
    at org.atalk.crypto.CryptoFragment.doHandleOmemoPressed(CryptoFragment.java:342)
    at org.atalk.crypto.CryptoFragment.onOptionsItemSelected(CryptoFragment.java:236)
    at androidx.fragment.app.Fragment.performOptionsItemSelected(Fragment.java:3109)
    at androidx.fragment.app.FragmentManager.dispatchOptionsItemSelected(FragmentManager.java:3210)
    at androidx.fragment.app.FragmentController.dispatchOptionsItemSelected(FragmentController.java:416)
    at androidx.fragment.app.FragmentActivity.onMenuItemSelected(FragmentActivity.java:346)
    at com.android.internal.policy.PhoneWindow.onMenuItemSelected(PhoneWindow.java:1182)
    at com.android.internal.view.menu.MenuBuilder.dispatchMenuItemSelected(MenuBuilder.java:766)
    at com.android.internal.view.menu.SubMenuBuilder.dispatchMenuItemSelected(SubMenuBuilder.java:82)
    at com.android.internal.view.menu.MenuItemImpl.invoke(MenuItemImpl.java:152)
    at com.android.internal.view.menu.MenuBuilder.performItemAction(MenuBuilder.java:909)
    at com.android.internal.view.menu.MenuBuilder.performItemAction(MenuBuilder.java:899)
    at com.android.internal.view.menu.MenuPopupHelper.onItemClick(MenuPopupHelper.java:205)
    at android.widget.AdapterView.performItemClick(AdapterView.java:315)
    at android.widget.AbsListView.performItemClick(AbsListView.java:1193)
    at android.widget.AbsListView$PerformClick.run(AbsListView.java:3231)
    at android.widget.AbsListView$3.run(AbsListView.java:4207)
    at android.os.Handler.handleCallback(Handler.java:815)
    at android.os.Handler.dispatchMessage(Handler.java:104)
    at android.os.Looper.loop(Looper.java:207)
    at android.app.ActivityThread.main(ActivityThread.java:5728)
    at java.lang.reflect.Method.invoke(Native Method)
    at com.android.internal.os.ZygoteInit$MethodAndArgsCaller.run(ZygoteInit.java:789)
    at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:679)

2021-01-19 08:53:18.158 WARNING: [18] org.jivesoftware.smackx.omemo.OmemoService.buildMissingSessionsWithDevices() slavoon23@404.city:486745735 cannot establish session with slavoon23@404.city:1151002113 because their bundle could not be fetched.
.....

2021-01-19 08:54:18.750 WARNING: [20] org.jivesoftware.smackx.omemo.OmemoService.onOmemoMessageStanzaReceived() No raw session found for contact papamail@404.city:1743131651. 
org.jivesoftware.smackx.omemo.exceptions.NoRawSessionException: org.whispersystems.libsignal.InvalidMessageException: No valid sessions.
    at org.jivesoftware.smackx.omemo.signal.SignalOmemoRatchet.doubleRatchetDecrypt(SignalOmemoRatchet.java:128)
    at org.jivesoftware.smackx.omemo.OmemoRatchet.retrieveMessageKeyAndAuthTag(OmemoRatchet.java:107)
    at org.jivesoftware.smackx.omemo.OmemoService.decryptMessage(OmemoService.java:457)
    at org.jivesoftware.smackx.omemo.OmemoService.onOmemoMessageStanzaReceived(OmemoService.java:1192)
    at org.jivesoftware.smackx.omemo.OmemoManager$3.run(OmemoManager.java:959)
    at java.lang.Thread.run(Thread.java:818)
Caused by: org.whispersystems.libsignal.InvalidMessageException: No valid sessions.
    at org.whispersystems.libsignal.SessionCipher.decrypt(SessionCipher.java:290)
    at org.whispersystems.libsignal.SessionCipher.decrypt(SessionCipher.java:243)
    at org.whispersystems.libsignal.SessionCipher.decrypt(SessionCipher.java:211)
    at org.jivesoftware.smackx.omemo.signal.SignalOmemoRatchet.doubleRatchetDecrypt(SignalOmemoRatchet.java:122)
    ... 5 more
Caused by: org.whispersystems.libsignal.InvalidMessageException: Bad Mac!
    at org.whispersystems.libsignal.protocol.SignalMessage.verifyMac(SignalMessage.java:119)
    at org.whispersystems.libsignal.SessionCipher.decrypt(SessionCipher.java:313)
    at org.whispersystems.libsignal.SessionCipher.decrypt(SessionCipher.java:268)
    ... 8 more
2021-01-19 08:54:18.754 WARNING: [20] org.jivesoftware.smackx.omemo.OmemoService.repairBrokenSessionWithPreKeyMessage() Attempt to repair the session by sending a fresh preKey message to papamail@404.city:1743131651
2021-01-19 08:54:19.279 WARNING: [18] org.jivesoftware.smackx.omemo.OmemoService.buildMissingSessionsWithDevices() slavoon23@404.city:486745735 cannot establish session with slavoon23@404.city:935698264 because their bundle could not be fetched.
org.jivesoftware.smackx.omemo.exceptions.CannotEstablishOmemoSessionException
    at org.jivesoftware.smackx.omemo.OmemoService.buildFreshSessionWithDevice(OmemoService.java:793)
    at org.jivesoftware.smackx.omemo.OmemoService.buildMissingSessionsWithDevices(OmemoService.java:834)
    at org.jivesoftware.smackx.omemo.OmemoService.encrypt(OmemoService.java:358)
    at org.jivesoftware.smackx.omemo.OmemoService.createOmemoMessage(OmemoService.java:542)
    at org.jivesoftware.smackx.omemo.OmemoManager.encrypt(OmemoManager.java:340)
    at org.jivesoftware.smackx.omemo.OmemoManager.encrypt(OmemoManager.java:313)
    at org.atalk.crypto.CryptoFragment.doHandleOmemoPressed(CryptoFragment.java:342)
    at org.atalk.crypto.CryptoFragment.onOptionsItemSelected(CryptoFragment.java:236)
    at org.atalk.crypto.CryptoFragment.lambda$setChatType$5$CryptoFragment(CryptoFragment.java:1127)
    at org.atalk.crypto.-$$Lambda$CryptoFragment$h_37WEKFquvm0dXpp4cIDvQ21cE.run(lambda)
    at org.atalk.service.osgi.OSGiFragment.runOnUiThread(OSGiFragment.java:74)
    at org.atalk.crypto.CryptoFragment.setChatType(CryptoFragment.java:1120)
    at org.atalk.android.gui.chat.ChatFragment$ChatListAdapter.lambda$addMessageImpl$0$ChatFragment$ChatListAdapter(ChatFragment.java:999)
    at org.atalk.android.gui.chat.-$$Lambda$ChatFragment$ChatListAdapter$2IqTF6N9gHrBsrL25CAaE9So9BU.run(lambda)
    at android.os.Handler.handleCallback(Handler.java:815)
    at android.os.Handler.dispatchMessage(Handler.java:104)
    at android.os.Looper.loop(Looper.java:207)
    at android.app.ActivityThread.main(ActivityThread.java:5728)
    at java.lang.reflect.Method.invoke(Native Method)
    at com.android.internal.os.ZygoteInit$MethodAndArgsCaller.run(ZygoteInit.java:789)
    at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:679)

One other thing I observed is that your network seems to have reliability problem. The following occurred 13 time on 1/18 - 1/19 i.e. 2021-01-18 20:42:59.493 to 2021-01-19 08:44:13.422 or between 1/18 10:42pm to next morning 1/19 08:44am. An unreliable network may also lead to Omemo database corruption.

Did you set your phone to disable all network during this period? What is your aTalk network ping setting?

2021-01-18 20:42:59.493 WARNING: [2] org.jivesoftware.smack.AbstractXMPPConnection.callConnectionClosedOnErrorListener() Connection XMPPTCPConnection[slavoon23@404.city/atalk] (0) closed with error
javax.net.ssl.SSLException: Read error: ssl=0x7f8f3ebf00: I/O error during system call, Connection timed out
    at com.android.org.conscrypt.NativeCrypto.SSL_read(Native Method)
....
2021-01-19 07:13:29.380 WARNING: [15] org.jivesoftware.smack.AbstractXMPPConnection.callConnectionClosedOnErrorListener() Connection XMPPTCPConnection[slavoon23@404.city/atalk] (1) closed with error
javax.net.ssl.SSLException: Read error: ssl=0x7f78570f00: I/O error during system call, Connection timed out

2021-01-19 08:44:13.422 INFO: [16] org.jivesoftware.smack.AbstractXMPPConnection.waitForClosingStreamTagFromServer() Exception while waiting for closing stream element from the server XMPPTCPConnection[slavoon23@404.city/atalk] (1)
org.jivesoftware.smack.SmackException$NoResponseException: No response received within reply timeout. Timeout was 5000ms (~5s). While waiting for closing stream tag from the server [XMPPTCPConnection[slavoon23@404.city/atalk] (1)]
    at org.jivesoftware.smack.AbstractXMPPConnection.waitForConditionOrConnectionException(AbstractXMPPConnection.java:732)
    at org.jivesoftware.smack.AbstractXMPPConnection.waitForConditionOrThrowConnectionException(AbstractXMPPConnection.java:737)
    at org.jivesoftware.smack.AbstractXMPPConnection.waitForClosingStreamTagFromServer(AbstractXMPPConnection.java:1024)
    at org.jivesoftware.smack.tcp.XMPPTCPConnection.shutdown(XMPPTCPConnection.java:512)
    at org.jivesoftware.smack.tcp.XMPPTCPConnection.shutdown(XMPPTCPConnection.java:492)
    at org.jivesoftware.smack.AbstractXMPPConnection.disconnect(AbstractXMPPConnection.java:972)
    at net.java.sip.communicator.impl.protocol.jabber.ProtocolProviderServiceJabberImpl.disconnectAndCleanConnection(ProtocolProviderServiceJabberImpl.java:1576)
    at net.java.sip.communicator.impl.protocol.jabber.ProtocolProviderServiceJabberImpl.unregisterInternal(ProtocolProviderServiceJabberImpl.java:1646)
    at net.java.sip.communicator.impl.protocol.jabber.ProtocolProviderServiceJabberImpl.unregister(ProtocolProviderServiceJabberImpl.java:1619)
    at net.java.sip.communicator.util.account.LoginManager$UnregisterProvider.run(LoginManager.java:345)
slavoon4 commented 3 years ago

When was the last time you did the "Regenerate OMEMO iddentities", before sending the last debug log?

I performed Regenerate immediately before sending the last debug log

If you have performed the regenerate, can you try to do the "Purge unsued identities" to see it returns to normal operation.

now I performed Purge unused identities - and received: Could not find inactive OMEMO device for: slavoon23@404.city after that all ok: I able not to switch to OMEMO encryption in user chat and able to sent encrypted messages to Conversations (both applications show all messages encrypted). Also Conversations able to send messages to aTalk (both applications show all messages encrypted).

An unreliable network may also lead to Omemo database corruption. Did you set your phone to disable all network during this period?

It looks like my smartphone has unstable WiFi connection when I lay down it, and has normal WiFi connection when smartphone in hand in vertical position (or WiFi internet provider has bad connection to 404.city server). I try to use only mobile cellular internet several days to eliminate this problem.

What is your aTalk network ping setting?

120 seconds, Optimization Ping Internet (when connecting to mobile network): enabled. Priority: 30. Keep alive: enabled. DTMF: Auto: RTP or Inband now I am sending log to you again for some reasons (from another e-mail address)

cmeng-git commented 3 years ago

Could not find inactive OMEMO device for: slavoon23@404.city

This is because the local omemo database is not insync with the server published bundle data. The "Purge unused identities" option also removes all omemo devices (active or inactive) that are having null identity. Smack omemo manager will recreate them if need to.

Look like your earlier omemo encryption are likely due to either of the above two. The reason for having either of them is not clear at this point, need to continue monitor them.

Current implementation requires user to redo the step if this occurs.With your new input, I have modified the function so it will ignore this and continue with the rest of inactive devices cleanup.

cmeng-git commented 3 years ago

aTalk v1.5.0 release has made further improvements (see below) to handle omemo data exceptions. Will close this thread. Please raise a new bug report if thing still happen.