search

gkdr / lurch

XEP-0384: OMEMO Encryption for libpurple.
GNU General Public License v3.0
289 stars 32 forks source link

Received omemo message that does not contain a key for this device #173

Open ghost opened 3 years ago

ghost commented 3 years ago

Using lurch 0.7.0 in pidgin

(22:43:38) g_log: xmlnode_to_str_helper: assertion node != NULL' failed (22:43:38) g_log: jabber_send_raw: assertiondata != NULL' failed (22:43:38) g_log: jabber_is_stanza: assertion `packet != NULL' failed (22:43:38) jabber: XML parser error for JabberStream 03398850: Domain 3, code 100, level 1: xmlns: URI eu.siacs.conversations.axolotl is not absolute (22:43:38) lurch: lurch_bundle_create_session: failed to import xml into bundle (-12000) (22:43:38) lurch: lurch_bundle_request_cb: failed to create a session (-12000)

I created a private group and verified the fingerprints. When I send a message from Pidgin to Blabber on Android, I get "Received omemo message that does not contain a key for this device" for every message

But when I send a message from blabber to pidgin, there are no such messages.

This is my first time opening up an issue so if I didn't provide enough information then please let me know.

gkdr commented 3 years ago

hi, and thanks for the report.

this has been happening recently, and so far i couldn't manage to figure out why. the screenshot and the part from the debug log show two different things: first, it seems session establishment failed because the bundle was NULL (maybe?), then the other device does not send a message because there is no session.

for the first problem, i need to return a more specific error code in a different library. for the second problem, i could try to repair the session instead of just writing an error message - other clients probably do something like that. both things are on my list, but are just workarounds or debugging help.

what you could do to help me figure out the actual problem is to paste some more from the debug log. the thing that might help me reproduce this is the naked XML, which you can find in the debug log prepended by jabber: Sending (ssl) ... or jabber: Recv (ssl) .... thanks in advance :slightly_smiling_face:

ghost commented 3 years ago 

(16:43:26) jabber: Sending (ssl) (alicebob@yourdata.forsale/1138870587571503023655194274): <message type='groupchat' id='purplebb4f909c' to='sanityofcults@conference.yourdata.forsale'><encrypted xmlns='eu.siacs.conversations.axolotl'><header sid='1693545079'><key rid='1921170956'>MwhjEiEF01py+MLQHRV8GmzAk9KphXndDPE8fR+WcCFl2f+wQBwaIQUiX57npMMwOrWm57MfbHBDuQzbGY6Y4miI2e2keIXgMyJiMwohBUtM1trS/7sV/O3X+9Mr7EN/dA/Q72nlRL3L9J1M0KY4EAEYACIwzNq1ErkWgEqOxdgKlXYu7RI4L3O+5rF/hO9mqDYDKJn+gGu652Q2CnyNBL9sG18K0jXvmDE5uLco9+TFpwYwAQ==</key><iv>TUQuyDz5F6LnqFIS</iv></header><payload>R56kjg==</payload></encrypted><encryption xmlns='urn:xmpp:eme:0' namespace='eu.siacs.conversations.axolotl' name='OMEMO'/><store xmlns='urn:xmpp:hints'/></message>
(16:43:27) jabber: Recv (ssl)(735): <message xml:lang='en' to='alicebob@yourdata.forsale/1138870587571503023655194274' from='sanityofcults@conference.yourdata.forsale/alicebob' type='groupchat' id='purplebb4f909c'><encrypted xmlns='eu.siacs.conversations.axolotl'><header sid='1693545079'><key rid='1921170956'>MwhjEiEF01py+MLQHRV8GmzAk9KphXndDPE8fR+WcCFl2f+wQBwaIQUiX57npMMwOrWm57MfbHBDuQzbGY6Y4miI2e2keIXgMyJiMwohBUtM1trS/7sV/O3X+9Mr7EN/dA/Q72nlRL3L9J1M0KY4EAEYACIwzNq1ErkWgEqOxdgKlXYu7RI4L3O+5rF/hO9mqDYDKJn+gGu652Q2CnyNBL9sG18K0jXvmDE5uLco9+TFpwYwAQ==</key><iv>TUQuyDz5F6LnqFIS</iv></header><payload>R56kjg==</payload></encrypted><encryption xmlns='urn:xmpp:eme:0' namespace='eu.siacs.conversations.axolotl' name='OMEMO'/><store xmlns='urn:xmpp:hints'/></message>```
```(16:43:27) jabber: XML parser error for JabberStream 0x5634db06bd50: Domain 3, code 100, level 1: xmlns: URI eu.siacs.conversations.axolotl is not absolute
(16:43:27) lurch: received omemo message that does not contain a key for this device, skipping
(16:43:28) util: Writing file prefs.xml to directory /home/alice/.purple
(16:43:28) util: Writing file /home/alice/.purple/prefs.xml
(16:44:06) jabber: Sending (ssl) (alicebob@yourdata.forsale/1138870587571503023655194274): <iq type='get' id='purplebb4f909d'><ping xmlns='urn:xmpp:ping'/></iq>
(16:44:06) jabber: Recv (ssl)(150): <iq xml:lang='en' to='alicebob@yourdata.forsale/1138870587571503023655194274' from='alicebob@yourdata.forsale' type='result' id='purplebb4f909d'/>
(16:45:06) jabber: Sending (ssl) (alicebob@yourdata.forsale/1138870587571503023655194274): <iq type='get' id='purplebb4f909e'><ping xmlns='urn:xmpp:ping'/></iq>
(16:45:06) jabber: Recv (ssl)(150): <iq xml:lang='en' to='alicebob@yourdata.forsale/1138870587571503023655194274' from='alicebob@yourdata.forsale' type='result' id='purplebb4f909e'/>
(16:46:06) jabber: Sending (ssl) (alicebob@yourdata.forsale/1138870587571503023655194274): <iq type='get' id='purplebb4f909f'><ping xmlns='urn:xmpp:ping'/></iq>
(16:46:06) jabber: Recv (ssl)(150): <iq xml:lang='en' to='alicebob@yourdata.forsale/1138870587571503023655194274' from='alicebob@yourdata.forsale' type='result' id='purplebb4f909f'/>
(16:47:06) jabber: Sending (ssl) (alicebob@yourdata.forsale/1138870587571503023655194274): <iq type='get' id='purplebb4f90a0'><ping xmlns='urn:xmpp:ping'/></iq>
(16:47:06) jabber: Recv (ssl)(150): <iq xml:lang='en' to='alicebob@yourdata.forsale/1138870587571503023655194274' from='alicebob@yourdata.forsale' type='result' id='purplebb4f90a0'/>
HumanG33k commented 3 years ago

I have the same issue, If it can help :  I used to use several devices (at least conversation and pidgin). In my case.

(I not check log)

gkdr commented 3 years ago

hi @katsuragi99, thanks for providing the debug full log. unfortunately it's not the same error as in the original post, were you not able to reproduce that? since it's a groupchat, i believe that the message received omemo message that does not contain a key for this device, skipping is correct, because with the signal protocol, you shouldn't encrypt something for yourself. instead, the message is just directly written to the message window when sending, and ignored when the server sends it back as a groupchat message. what is the output of typing /lurch status?

@HumanG33k could you ask your friend for the output of the /lurch status command as well?

HumanG33k commented 3 years ago

@gkdr my friend no use pidgin i do. I guess i have to wait is online to do it ?

When i try "/lurch status" in the pidgin conversation window the output is : 

Valid arguments for 'lurch' in IMs are 'show', 'remove', 'blacklist', 'uninstall', and 'help'.

In order to help :

gkdr commented 3 years ago

the command i suggested is only available in the new version. are you willing to try it with that?

hecktest commented 3 years ago

Since 0.7 (?) lurch seems to fail to advertise or retrieve new device FPs. A friend got this error after a clean reinstall of pidgin and lurch, the fingerprint produced with /lurch fp show was not known to my device when queried with /lurch fp contact. After I upgraded to 0.7 myself and we both wiped our DBs, the situation was reversed. Adding the missing device to the sqlite DB manually made it work again.

tbjorheim commented 3 years ago

Hi. I just like to add that I have the same issue. Started after I upgraded to version 0.7.

TraceyC77 commented 3 years ago

I just ran into this error on a new install of lurch via building from source on Solus. I was sending a message to my own account from the same account to test.

Here is the debug output, I've redacted the key string and my address but left everything else intact

The debug log output

```xml (11:17:33) gtkutils: gdk_pixbuf_new_from_file() returned nothing for file /usr/share/pixmaps/pidgin/emotes/small/satisfied.png: Failed to open file “/usr/share/pixmaps/pidgin/emotes/small/satisfied.png”: No such file or directory (11:17:34) util: Writing file prefs.xml to directory /home/tracey/.purple (11:17:34) util: Writing file /home/tracey/.purple/prefs.xml (11:17:38) jabber: Sending (ssl) (me@host/Home laptop): (11:17:38) jabber: Sending (ssl) (me@host/Home laptop): (11:17:38) jabber: Recv (ssl)(205): (11:17:38) jabber: Recv (ssl)(26): (11:17:38) jabber: Sending (ssl) (me@host/Home laptop): (11:17:38) jabber: Recv (ssl)(33): (11:17:38) XEP-0198: Acknowledged 48 out of 48 outbound stanzas (11:17:38) lurch: retrieved devicelist for me@host: (11:17:38) lurch: retrieved own devicelist: (11:17:38) lurch: lurch_msg_encrypt_for_addrs: trying to encrypt key for 1 devices (11:17:38) lurch: lurch_key_encrypt: encrypting key for me@host:1651996201 (11:17:38) xmlnode: XML parser error for xmlnode 0x168c510: Domain 3, code 100, level 1: xmlns: URI eu.siacs.conversations.axolotl is not absolute (11:17:38) jabber: Sending (ssl) (me@host/Home laptop):

xxxxxx
8Rg= (11:17:38) jabber: Sending (ssl) (me@host/Home laptop): (11:17:38) jabber: Sending (ssl) (me@host/Home laptop): (11:17:38) jabber: Sending (ssl) (me@host/Home laptop): (11:17:38) gtkutils: gdk_pixbuf_new_from_file() returned nothing for file /usr/share/pixmaps/pidgin/emotes/small/satisfied.png: Failed to open file “/usr/share/pixmaps/pidgin/emotes/small/satisfied.png”: No such file or directory (11:17:38) jabber: Recv (ssl)(741):
xxxxxx
8Rg= (11:17:38) jabber: XML parser error for JabberStream 0x78e800: Domain 3, code 100, level 1: xmlns: URI eu.siacs.conversations.axolotl is not absolute (11:17:38) lurch: received omemo message that does not contain a key for this device, skipping (11:17:38) jabber: Recv (ssl)(26): (11:17:38) jabber: Sending (ssl) (me@host/Home laptop): (11:17:38) jabber: Recv (ssl)(33): (11:17:38) XEP-0198: Acknowledged 49 out of 50 outbound stanzas (11:17:38) jabber: Recv (ssl)(202): (11:17:38) jabber: Recv (ssl)(33): (11:17:38) XEP-0198: Acknowledged 50 out of 50 outbound stanzas (11:17:38) jabber: Recv (ssl)(26): (11:17:38) jabber: Sending (ssl) (me@host/Home laptop): ```

gkdr commented 3 years ago

@hecktest @tbjorheim if you remove your current device's ID from the devicelist, does the situation persist?

@TraceyC77 thanks for the detailed debug log. so once again, even though the message contains does contain a key for the device ID (<key rid='1651996201'>), it is simply not found?

tbjorheim commented 3 years ago

Hi again. I tried to remove the ID using command "/lurch id remove". But seems to be the same issue. Also tried to disable using "/lurch disable" and then "/lurch enable" again. But still the same.

I like to add that in my case, this is an issue in a group chat. And it seems like the other members get the message even if I get this error. And as mention in the other comment, it was working as it should, with the same group chat, before upgrading to 0.7.

gkdr commented 2 years ago

Thanks for trying. I'm sorry, for now I'm out of ideas. I will try adding more logging and see what comes up.

ghost commented 2 years ago

A friend and I are running into a similar issue. Whenever we send a message with lurch for OMEMO, the receiving end can't decrypt it, getting the "This message was encrypted with OMEMO and could not be decrypted." message. It looks like it's not publishing properly. When I check the fingerprints under Gajim, it shows lurch's fingerprint as inactive.

I'm running Chatty/Chats 0.7.0-rc0 with Lurch 0.7.0-1 on mobian bookworm on my Pinephone. My friend is running Pidgin 2.14.1 with the same version of Lurch. The server we're using is running Prosody 0.12.1. Here's logs from my end:

12:54:00.7260 chatty-folks[ 3405]: DEBUG: Loading eds 12:54:01.1891 chatty-application[ 3405]: INFO: chatty 0.7.0.rc0, git version: 0.7.0.rc0 12:54:01.2225 chatty-folks[ 3405]: DEBUG: Loading eds, get source registry succeeded 12:54:01.2337 chatty-folks[ 3405]: DEBUG: Loading eds source: Collected addresses 12:54:01.2366 chatty-folks[ 3405]: DEBUG: Loading eds source: Collected addresses 12:54:01.2370 chatty-folks[ 3405]: DEBUG: Loading eds source: Contacts 12:54:01.2375 chatty-folks[ 3405]: DEBUG: Loading eds source: Contacts 12:54:01.2376 chatty-folks[ 3405]: DEBUG: Loading eds source: Global address book 12:54:01.2379 chatty-folks[ 3405]: DEBUG: Loading eds source: Global address book 12:54:01.2381 chatty-folks[ 3405]: DEBUG: Loading eds source: Personal 12:54:01.2382 chatty-folks[ 3405]: DEBUG: Loading eds source: Shared Contacts: CosmoB & QuinnS 12:54:01.2436 chatty-purple[ 3405]: INFO: Loading purple, auto login: 1 12:54:01.2441 chatty-purple[ 3405]: DEBUG: chatty_purple_enable():2078: Enabling purple 12:54:03.0643 chatty-xeps[ 3405]: DEBUG: xmpp receipt feature added 12:54:03.0658 chatty-purple[ 3405]: DEBUG: plugin: ModemManager SMS, Unloading succeeded 12:54:03.0663 chatty-purple[ 3405]: DEBUG: Loaded purple plugins: prpl-bonjour:2.14.10 prpl-gg:2.14.10 prpl-novell:2.14.10 prpl-irc:2.14.10 ssl-nss:2.14.10 core-perl:2.14.10 prpl-simple:2.14.10 core-ssl:2.14.10 prpl-meanwhile:2.14.10 prpl-jabber:2.14.10 xep-http-file-upload:0.1.0 prpl-zephyr:2.14.10 core-riba-lurch:0.7.0 12:54:03.0668 chatty-purple[ 3405]: DEBUG: Added account: u#######3@j#######g-q###r.n#t 12:54:03.0670 chatty-purple[ 3405]: DEBUG: Added account: q#####4@j#######g-q###r.n#t 12:54:03.0672 chatty-purple[ 3405]: DEBUG: Added account: q#####4@k################s.c##b 12:54:03.0673 chatty-purple[ 3405]: DEBUG: Added account: q########h@m#####x.o#g 12:54:03.0674 chatty-purple[ 3405]: DEBUG: Added account: q########h@t############r.b######s 12:54:03.0808 chatty-purple[ 3405]: DEBUG: libpurple initialized. Running version 2.14.10. 12:54:03.9974 chatty-application[ 3405]: INFO: New main window created 12:54:04.1096 chatty-purple[ 3405]: DEBUG: Added chat: c####b@j#######g-q###r.n#t 12:54:04.1133 chatty-purple[ 3405]: DEBUG: Added chat: c#########t@j#######g-q###r.n#t 12:54:04.1157 chatty-purple[ 3405]: DEBUG: Added chat: +1#########3,+1#########5,+1#########3@c######m.c#m 12:54:04.1177 chatty-purple[ 3405]: DEBUG: Added chat: u########4@j#######g-q###r.n#t 12:54:04.1201 chatty-purple[ 3405]: DEBUG: Added chat: n########m@j####r.h#t-c####i.n#t 12:54:04.1220 chatty-purple[ 3405]: DEBUG: Added chat: +1#########9,+1#########5,+1#########6,+1#########4@c######m.c#m 12:54:04.1253 chatty-purple[ 3405]: DEBUG: Added chat: +1#########8@c######m.c#m 12:54:04.1275 chatty-purple[ 3405]: DEBUG: Added chat: u#######3@j#######g-q###r.n#t 12:54:04.1298 chatty-purple[ 3405]: DEBUG: Added chat: q########h@m#####x.o#g 12:54:04.1335 chatty-purple[ 3405]: DEBUG: Added chat: +1#########7@c######m.c#m 12:54:04.1350 chatty-purple[ 3405]: DEBUG: Added chat: +1#########9@c######m.c#m 12:54:04.1366 chatty-purple[ 3405]: DEBUG: Added chat: +1#########1@c######m.c#m 12:54:04.1697 chatty-folks[ 3405]: DEBUG: Loading eds, getting ebook client 'Collected addresses' succeeded 12:54:04.2023 chatty-folks[ 3405]: DEBUG: Loading eds, getting ebook client 'Contacts' succeeded 12:55:17.3261 chatty-window[ 3405]: INFO: Opening item of type: ChattyPpChat, name: Q###n S#######h 12:55:17.3266 chatty-purple[ 3405]: DEBUG: conversation: q########h@m#####x.o#g 12:55:17.3269 chatty-window[ 3405]: INFO: opening chat, type: ChattyPpChat, chat-name: q########h@m#####x.o#g 12:55:23.8942 chatty-xeps[ 3405]: DEBUG: Send ackn request for node_id: purple82efe1e0 12:55:23.8946 chatty-xeps[ 3405]: DEBUG: attached key: purple82efe1e0, table size 1

12:55:23.8948 chatty-xeps-0313[ 3405]: DEBUG: Set origin-id f54d1173-26bb-4ce7-812d-bceb2d226a74 for outgoing message 12:55:24.2052 chatty-purple[ 3405]: DEBUG: Posting message id:f54d1173-26bb-4ce7-812d-bceb2d226a74 flags:1 type:1 from: q########h@m#####x.o#g 12:55:24.7492 chatty-xeps[ 3405]: DEBUG: Received ackn for node_id: f54d1173-26bb-4ce7-812d-bceb2d226a74 12:55:24.7506 chatty-xeps-0313[ 3405]: DEBUG: Received forward id pMkFkrNw6GMMMTC4hksWk2kr from q########h@m#####x.o#g/d##o.c######6 12:55:24.7531 chatty-xeps-0313[ 3405]: DEBUG: Stealing parser for MAM, ID pMkFkrNw6GMMMTC4hksWk2kr user: q########h@m#####x.o#g/d##o.c######6 12:55:24.7542 chatty-xeps-0313[ 3405]: DEBUG: Received resubmission b98b9273-6824-416a-899d-cc9cd76b4e45 q########h@m#####x.o#g/d##o.c######6 u#######3@j#######g-q###r.n#t/F##########M 12:55:27.7101 chatty-xeps-0313[ 3405]: DEBUG: Received forward id 2hbgBaY_gAxQjMN2LknfoZf2 from q########h@m#####x.o#g/g###m.N######W 12:55:27.7123 chatty-xeps-0313[ 3405]: DEBUG: Stealing parser for MAM, ID 2hbgBaY_gAxQjMN2LknfoZf2 user: q########h@m#####x.o#g/g###m.N######W 12:55:27.7136 chatty-xeps-0313[ 3405]: DEBUG: Received resubmission 382ed679-e652-49a5-ace8-637363a51e25 q########h@m#####x.o#g/g###m.N######W u#######3@j#######g-q###r.n#t 12:55:32.2666 chatty-xeps-0313[ 3405]: DEBUG: Stealing parser for MAM, ID (null) user: q########h@m#####x.o#g/g###m.N######W 12:55:32.2678 chatty-xeps-0313[ 3405]: DEBUG: Received resubmission f10e127e-8927-4fd8-9078-a7a55ea683c1 q########h@m#####x.o#g/g###m.N######W u#######3@j#######g-q###r.n#t 12:55:34.5842 chatty-purple[ 3405]: DEBUG: Posting message id:(null) flags:512 type:1 from: q########h@m#####x.o#g 12:55:34.7416 chatty-xeps-0313[ 3405]: DEBUG: Received forward id tsGwmqB81S58XfvPsP4R3DRL from q########h@m#####x.o#g/g###m.N######W 12:55:34.7448 chatty-xeps-0313[ 3405]: DEBUG: Stealing parser for MAM, ID tsGwmqB81S58XfvPsP4R3DRL user: q########h@m#####x.o#g/g###m.N######W 12:55:34.7458 chatty-xeps-0313[ 3405]: DEBUG: Received resubmission 17cab8ed-f834-411e-bc6f-8349e2af5662 q########h@m#####x.o#g/g###m.N######W u#######3@j#######g-q###r.n#t 12:55:34.7521 chatty-xeps-0313[ 3405]: DEBUG: Receiving msg on 0x557a3280c0 from qstambaugh@mailbox.org/gajim.N43PY8XW with flags 2 12:55:34.7533 chatty-xeps-0313[ 3405]: DEBUG: Received message on qstambaugh@mailbox.org/gajim.N43PY8XW of type 1 with flags 2 12:55:34.7536 chatty-purple[ 3405]: DEBUG: Posting message id:tsGwmqB81S58XfvPsP4R3DRL flags:66 type:1 from: q########h@m#####x.o#g

I didn't really see any error messages directly referencing lurch, I just kept the parts from first connecting and what came up when sending/receiving test messages. Friend's log:

1d85e974_lurch.txt

EDIT: Added friend's logs and Pidgin version

ghost commented 2 years ago

I did a bit of testing. It works fine with whatever setup mailbox.org has for their XMPP server, but it doesn't publish its key to the keyring on my prosody server. When updating to Prosody 0.12, I switched over to its native bookmarks support. Is it possible that had something to do with it? Gajim and Dino don't have any issues with it

ghost commented 1 year ago

Most reliable way to reproduce the issue is:

1: Sign into an account, on Pidgin or Chatty running lurch, on a server running Prosody 0.12.1 or Ejabberd 22.10

2: Sign into the same account on Gajim and then use its OMEMO plugin to clear the devices keys for the account

Lurch won't publish the key again (tried disabling and enabling the account, restarted Pidgin/Chatty, etc.) so other devices won't know to encrypt for it. The only way I currently know of to work around it is: Delete the account from Pidgin/Chatty and re-add it OR run an older version of Ejabberd/Prosody

norayr commented 1 year ago

i think i have the same issue. prosody 0.12.4

norayr commented 11 months ago

i have the feeling that it works between pidgin and conversations, but not between pidgin and dino.

conversations does see the my fingerprint, but dino does not.

norayr commented 11 months ago

Lurch won't publish the key again (tried disabling and enabling the account, restarted Pidgin/Chatty, etc.) so other devices won't know to encrypt for it. The only way I currently know of to work around it is: Delete the account from Pidgin/Chatty and re-add it OR run an older version of Ejabberd/Prosody

i removed my account and added it again in pidgin. didn't help. still he same. some clients see the fingerprint of my device (conversations) and some clients (dino) don't.

ghost commented 11 months ago

On Wed, 2023-12-27 at 07:34 -0800, Norayr Chilingarian wrote:

Lurch won't publish the key again (tried disabling and enabling the account, restarted Pidgin/Chatty, etc.) so other devices won't know to encrypt for it. The only way I currently know of to work around it is: Delete the account from Pidgin/Chatty and re-add it OR run an older version of Ejabberd/Prosody i removed my account and added it again in pidgin. didn't help. still he same. some clients see the fingerprint of my device (conversations) and some clients (dino) don't. — Reply to this email directly, view it on GitHub, or unsubscribe. You are receiving this because you commented.Message ID: @.***> I've stopped testing and tinkering with lurch at this point. I've started using Dino on my pinephone, dropping Chatty, and I don't use anything else libpurple related. From what I remember, there was an update to the pep standard that newer server software uses and lurch needs to be updated to work with it. My memory isn't the greatest, though, and it's been a while since I looked into it. Good luck!

norayr commented 10 months ago

so as i said, i am using it, it can talk to conversations, but not to dino. dino does'n't see the key.

but it is interesting, that conversations also seems to loose the key? because when someone writes me from conversations, i get that 'I sent you an OMEMO encrypted message but your client doesn’t seem to support that. Find more information on https://conversations.im/omemo' but when i answer from pidgin, then suddenly end to end encryption starts working again.

gkdr commented 7 months ago

@qstambaugh Thanks for the steps to reproduce this. I'll try it.