search

gkdr / lurch

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

cannot send omemo encrypted messages with portable edition of pidgin ... #159

Closed ghost closed 3 years ago

ghost commented 3 years ago

Hello guys.

I use the actual portable edition of pidgin with the actual version of lurch 0.6.8 and I am not able to send encrypted any more I also tried the 0.6.9 development version and it is also not working. please note that I can receive omemo encrypted but I cannot send with omemo encryption. I used windows 7 64 bit edition.
The settings of the 0.6.9 development edition say something of a logfile, but I cannot find that logfile

UPDATES ... First I tested with Conversations ... I was not able to send encrypted to conversations, but I was able to read the omemo encrypted message sent to me with conversations. Second I tested with Gajim. Same result. I was able to read the omemo encrypted message sent to me with Gajim, but I was not able to encrypt the mesage The failure I get looks like this :

(2021-01-22 12:54:36) There was an error encrypting the message and it was not sent. You can try again, or try to find the problem by looking at the debug log.

gkdr commented 3 years ago

hi @ecxod,

thanks for reaching out! since the message does not even seem to leave the client, i suspect it's not related to the actual encryption. this could be a good thing, because then it's not some client compatibility issue :slightly_smiling_face:

you can find the debug log mentioned in the error message at Help > Debug Window in Pidgin. (i'm assuming the portable version did not remove it.) can you try to send a message with that window open and paste the error message here?

ghost commented 3 years ago

I was able to start it with the -d option and I found two places where pidgin was whining.

(15:51:02) jabber: XML parser error for JabberStream 03433308: Domain 3, code 100, level 1: xmlns: URI eu.siacs.conversations.axolotl is not absolute
(15:51:02) jabber: Recv (ssl)(4095): iszTbBPIiGLgs</preKeyPublic>

this sounds like a %PATH% issue to me ... but the PATH is ok like this :

C:\gtk\bin;
C:\Users\Christian\AppData\Roaming\.purple\;
C:\Users\Christian\pidgin-2.14.1-win32bin;

and the second one was

(15:51:02) lurch: lurch_bundle_create_session: creating a session between user1@example.com and user2@example.com from a received bundle
(15:51:02) lurch: lurch_bundle_create_session: failed to import xml into bundle (-12000)
(15:51:02) lurch: lurch_bundle_request_cb: failed to create a session (-12000)

Somebody has a hint ?

gkdr commented 3 years ago

thanks! now we're one step closer. :slightly_smiling_face: good thing you found that flag, and weird that it's not as easy as in the desktop version.

regarding your findings:

alien2003 commented 3 years ago

The issue presents in Chatty app (OS: Mobian on Pinephone)

gkdr commented 3 years ago

hi @alien2003, that's good to know, thanks. do you know if you can get to the libpurple debug log somehow?

alien2003 commented 3 years ago

@gkdr 

(11:30:10) lurch: lurch_bundle_request_cb: alien@darkn.space received bundle update from alien@darkn.space:4986
(11:30:10) lurch: lurch_bundle_create_session: creating a session between alien@darkn.space and alien@darkn.space from a received bundle
(11:30:10) lurch: lurch_bundle_create_session: bundle's device id is 4986
(11:30:10) jabber: Recv (ssl)(26): <r xmlns='urn:xmpp:sm:3'/>
(11:30:10) jabber: Sending (ssl) (alien@darkn.space/12598123798804036770218227): <a xmlns='urn:xmpp:sm:3' h='94'/>
(11:30:10) jabber: Recv (ssl)(33): <a h='39' xmlns='urn:xmpp:sm:3'/>
(11:30:10) XEP-0198: Acknowledged 39 out of 41 outbound stanzas
(11:30:11) jabber: Recv (ssl)(33): <a h='40' xmlns='urn:xmpp:sm:3'/>
(11:30:11) XEP-0198: Acknowledged 40 out of 41 outbound stanzas
(11:30:11) jabber: Recv (ssl)(33): <a h='41' xmlns='urn:xmpp:sm:3'/>
(11:30:11) XEP-0198: Acknowledged 41 out of 41 outbound stanzas
(11:30:11) jabber: Recv (ssl)(4095): <iq xml:lang='en' to='alien@darkn.space/12598123798804036770218227' from='alien@darkn.space' type='result' id='alien@darkn.space#1003739987#-1924966417'><pubsub xmlns='http://jabber.org/protocol/pubsub'><set xmlns='http://jabber.org/protocol/rsm'><count>1</count><first index='0'>2021-01-20T22:28:28.394701Z</first><last>2021-01-20T22:28:28.394701Z</last></set><items node='eu.siacs.conversations.axolotl.bundles:1003739987'><item id='64B2C5CC5CFC4'><bundle xmlns='eu.siacs.conversations.axolotl'>
   <signedPreKeyPublic signedPreKeyId='2138761424'>BWaNnK89HxhtbwU2ES7WdF7KG4iRJjNOZvwJB1LqD4dI</signedPreKeyPublic>
   <signedPreKeySignature>GTXte1ZtZiPFEIzkTM+/DsfWML/2T5dEDRVP6Ql5cqL4M8tIv/XOaVdIoFrM8lUujEco31Rigu9muhYLsKiABg==</signedPreKeySignature>
   <identityKey>BSpnNmi+88erBsC0oZPgOgnFRjMrYoUD7XyLFtY1PH0l</identityKey>
   <prekeys>
    <preKeyPublic preKeyId='1'>BeZfDf8clm8bT3ZjJ+ia+ejwdhtoqRF9LcTVjCj2uut+</preKeyPublic>
    <preKeyPublic preKeyId='2'>BUk48b6suoY08vatpQGIJ5xyWT0drcVcnvxnUlBblyhe</preKeyPublic>
    <preKeyPublic preKeyId='3'>BZL3edVAckSgty/yQceQh0ZlDFrFd1CntsEWWbwDNvsf</preKeyPublic>
    <preKeyPublic preKeyId='4'>BfuQ6totfzA5N95iDgqagV3I5lNJC+NxiX5uuoHj0TUM</preKeyPublic>
    <preKeyPublic preKeyId='5'>BfgzEIWJxJQp3sexyfiONzgywFG41El+wRDYu8tRp8kG</preKeyPublic>
    <preKeyPublic preKeyId='6'>BUCFC7HLI4MtzRVgxUy7LkAm/ZMYG9GAWj21T7pFQMQs</preKeyPublic>
    <preKeyPublic preKeyId='7'>BQ5MWdzcngFe+lrWTqDqjNnNsCP7vNlt6tDXduw+k2Qw</preKeyPublic>
    <preKeyPublic preKeyId='8'>BQhA2UMqUJR/kDmnaCZAipvEX2kdMwPMUByGlJw7hBZS</preKeyPublic>
    <preKeyPublic preKeyId='9'>BZ+arz7eZ9JXPJbNJcuHVFbQUohGKGeWOO1RcpaVbow6</preKeyPublic>
    <preKeyPublic preKeyId='10'>BY0t19daIw1mYfiuTfARfdxxgF5ntdlTLMXIxmbVlfYR</preKeyPublic>
    <preKeyPublic preKeyId='11'>BSovNslsLfZ4rDIt+vL08y/NrVulDAR6bBed65avBIhD</preKeyPublic>
    <preKeyPublic preKeyId='12'>BZ4Wu1g/3bVctXi2Pgf25MeMRA3yVDZ5aZXwa5joQXgz</preKeyPublic>
    <preKeyPublic preKeyId='13'>BVbpJYWPRRuadm+nvBmlE9SFoaSicR50rhLJm2Dzly9m</preKeyPublic>
    <preKeyPublic preKeyId='14'>BcJgdRLdQ5KjIbH2tCKhC6+x9DXLpQ4q8Ub9evcPxwdi</preKeyPublic>
    <preKeyPublic preKeyId='15'>BTQNcG8kx+ykCHa1qX+xpIKHKPxY9E5IZ7daD/ebqgBM</preKeyPublic>
    <preKeyPublic preKeyId='16'>BUKM1ppymkdH57BaXsGVONqdbH5NkrwEdXPrE9Eg9LNJ</preKeyPublic>
    <preKeyPublic preKeyId='17'>BcLakaN7M29deQ87P48+K1pQpv8pQsPajSeAtq1/awto</preKeyPublic>
    <preKeyPublic preKeyId='18'>BR58cJ+ktbNa37EEgRlSoGf+EW94vq8PfE2Ftvoq7REL</preKeyPublic>
    <preKeyPublic preKeyId='19'>BSdz92uoHEV0+R//RXJvBYnX9WTfh+45cHOhU8k7u2Q8</preKeyPublic>
    <preKeyPublic preKeyId='21'>BW7/D7tgFgErKuUjgWrAa5T9spv0WenDImS/wi/qsqM7</preKeyPublic>
    <preKeyPublic preKeyId='22'>BeL724TMEzJh0nLWfmp/vnM8YArpMSCg1IxuhPr3Pm1+</preKeyPublic>
    <preKeyPublic preKeyId='23'>Bd5cHdEdRc/krchzi2628OEnfy/eM4rzVBoZ90fODXxk</preKeyPublic>
    <preKeyPublic preKeyId='24'>BRtYSp4FgI8hglfnBZVRiPvb9CbyJJdBm/PdPjeXHkAO</preKeyPublic>
    <preKeyPublic preKeyId='25'>Bes7LiLYvFeaMdbNCUEuegC+AIOsbtX8NH6P/+rihR9U</preKeyPublic>
    <preKeyPublic preKeyId='26'>Bb7WpltJkRTkWkkrpoKW2SheMMKUiq1WU/sawBHVfXhT</preKeyPublic>
    <preKeyPublic preKeyId='27'>BVvggcUrHbnkNfvYRX8030HcAaRQatstYTSrsc4qdk4f</preKeyPublic>
    <preKeyPublic preKeyId='28'>BQoHKLIn1T8K5ClmAEyWAoRO2qdPiJvh6cYQgjkd7S0R</preKeyPublic>
    <preKeyPublic preKeyId='29'>BSTQxJ/uExzNZwAEFMRT1DyC/1qtkZsb3vMNRFsvlUUj</preKeyPublic>
    <preKeyPublic preKeyId='30'>BZwnQdJsAK9s3CUeRv5UxxDYUhEAJDG29Zl1ZxeW9g9j</preKeyPublic>
    <preKeyPublic preKeyId='31'>BUVsKeE/Wa5CtoIi2S6Jmlw1JbSpLLgqdW9DqGWHOVQG</preKeyPublic>
    <preKeyPublic preKeyId='32'>BeOvWhzW9i5IfR7XlA20g6lkD5/42BCxB2AQuEC2rl5e</preKeyPublic>
    <preKeyPublic preKeyId='33'>BW1NOSBKxQVSuPGdukZwyLjMUZ1C0oIIAT9t+4vG5OoT</preKeyPublic>
    <preKeyPublic preKeyId='34'>BUH0V8CLnmqp92go85UCpCmIs56lHcxNJJ22gPFB2rBf</preKeyPublic>
    <preKeyPublic preKeyId='35'>BegG0sp4bEBPfkJflcABCNkHt/N0Fv9f183VEiLGLpYn</preKeyPublic>
    <preKeyPublic preKeyId='36'>Bdy/m4WnU59oPu6emxOobbxiYoIBayFL++SjUiXOEMId</preKeyPublic>
    <preKeyPublic preKeyId='37'>BRmcpmkAO2
(11:30:11) jabber: XML parser error for JabberStream 0xaaaaf7bb9f10: Domain 3, code 100, level 1: xmlns: URI eu.siacs.conversations.axolotl is not absolute
(11:30:11) jabber: Recv (ssl)(4095): kdQbZGe5JpxW3TenHGKucI1m0y2D/Nlxwc</preKeyPublic>
    <preKeyPublic preKeyId='38'>Ba2TQglLnoTb+wUX18xtaqIsm0Ps0QWxRoDWp5rLHFs3</preKeyPublic>
    <preKeyPublic preKeyId='39'>BYWZd52uApGjcr20sO5iImXzq1O+pqXe0MokDaYiEPwu</preKeyPublic>
    <preKeyPublic preKeyId='40'>BdU81VaznxKLPvFoedvFojPMnPVbCEGPeCZ/A/GKi0J/</preKeyPublic>
    <preKeyPublic preKeyId='41'>BTq256f3gH7MR7tRcBSVcZHGZ1gMQ9LOu/mjNrDdhlcs</preKeyPublic>
    <preKeyPublic preKeyId='42'>BXv5Z4aUgJTc4yvQ2gCR+wk7DiiiUfr2eBoeRZJ+3WZd</preKeyPublic>
    <preKeyPublic preKeyId='43'>BWMyZlov3yhtGNK417IoLreuKom+XWVOgddgXU1ANxho</preKeyPublic>
    <preKeyPublic preKeyId='44'>BVeF5yPH0KNpe/AbRlGSNl4mgIJfOkP1e42irl0HTQgZ</preKeyPublic>
    <preKeyPublic preKeyId='45'>BX8T6P59UzPhtJv29uPGnttm7L0p1XF5T0lQYywwbhs5</preKeyPublic>
    <preKeyPublic preKeyId='46'>BaT9hDS9/Z/sX8AqsYzPxmsTvlswP2pqkNosoI8TI/lp</preKeyPublic>
    <preKeyPublic preKeyId='47'>BUIxgC95KiuZfRrsp9dU4JJz9zvlepPyaHsKbvLJH4Nf</preKeyPublic>
    <preKeyPublic preKeyId='48'>BVHW63wYjLoHJO2haab/EFZSmH0+Hz3LL4gRmfClfKpP</preKeyPublic>
    <preKeyPublic preKeyId='49'>Baqn1/3wfMKLkpR2hzZgORTyBw9g+D9glgdUpHuhhjAv</preKeyPublic>
    <preKeyPublic preKeyId='51'>BS+Jk82zBN5nVVQX5dBSHbPuXf6Ta9PQAG5IKZV6oRpB</preKeyPublic>
    <preKeyPublic preKeyId='52'>BQgrZcpsoCRaK/cLuqeBvXmAmOQKvwlaYH4oFJuiwroB</preKeyPublic>
    <preKeyPublic preKeyId='53'>BQ/OeYLjjNjvdoxID7GArvue1FwEQ5fvATv2NyeO/tIa</preKeyPublic>
    <preKeyPublic preKeyId='54'>Besm87Jr7+lxsW850VKuJboyu56FW+UZsiVETHqzstpZ</preKeyPublic>
    <preKeyPublic preKeyId='55'>BVLTUBci7C2olFoMw/V3wYgK2HJLHF832BQ9N9yI6qUr</preKeyPublic>
    <preKeyPublic preKeyId='56'>BXpAmw+TZsdTDfAtnYDSHZwFxgAM1RJn5+qyNKxy7GsQ</preKeyPublic>
    <preKeyPublic preKeyId='57'>BSgV2dyXPDVi1sbNkQzceLQzrOBFiXuqBRu68mfuSacI</preKeyPublic>
    <preKeyPublic preKeyId='58'>BSxPEV2u0D9fbIFZqAo/WAeOmDaxyrlG42fAikCuFBJU</preKeyPublic>
    <preKeyPublic preKeyId='59'>BQJ90Rk2ZpfqyOxSRZgrzwajuKX/WvjtGb6GF459rp8j</preKeyPublic>
    <preKeyPublic preKeyId='60'>BQGlX8MBIQO6pgYxs2VuexSZdpLJ7rM88D/CqTXhPLBP</preKeyPublic>
    <preKeyPublic preKeyId='61'>BYG2zZl405778GHaSmOVdZSc6uG0Y3NJsKnICVUvy25u</preKeyPublic>
    <preKeyPublic preKeyId='62'>BZniLCfxhp43K9a8/AqEZCRxIlZa4INRaZKBabqrpUY/</preKeyPublic>
    <preKeyPublic preKeyId='63'>BaYmHYa/m1M0c1E5jrI5V0OzKMoifz5+p8kgBuTu21pH</preKeyPublic>
    <preKeyPublic preKeyId='64'>BbeEFyzQIhVTvJR+cqt31pHSeN9yGytLa4EdMkgDX0kC</preKeyPublic>
    <preKeyPublic preKeyId='65'>BeKNZNuZxQkNm+IpTkKbGfiqLf/hOfCAjgS0uBJ99AYy</preKeyPublic>
    <preKeyPublic preKeyId='66'>BXOMJScEH+wmYbSDs8ML3Kc5ZWjFjN8L1/bfFUK3tuVf</preKeyPublic>
    <preKeyPublic preKeyId='67'>BaSbHGUbrlZDx2YaFIOb5SzLNcLJBgsHbODjDfOQs68y</preKeyPublic>
    <preKeyPublic preKeyId='68'>BULa/b9q8ZYsbiwQyIAOWtSbw141Clzf7j1bwpe1/GEG</preKeyPublic>
    <preKeyPublic preKeyId='69'>BVgVxS+vXMUmuxVyQjI5Y1LuPz2KVVSqqB2/lX/imS4J</preKeyPublic>
    <preKeyPublic preKeyId='70'>BYu+Jp42mrPzHGykz3MkYVk1Ltm+7hp3Zo8RxOifuyZ3</preKeyPublic>
    <preKeyPublic preKeyId='71'>BXfLFZ0EGBiMlBBSjr0cIWxl4QEV4gumNdJjirObNPUm</preKeyPublic>
    <preKeyPublic preKeyId='72'>Bbk02umA/Yo5AlBVyA/F+cNhUhaB9ztipsH/IEMMKOIQ</preKeyPublic>
    <preKeyPublic preKeyId='73'>Bae861GSlnp4lMTqMTrnWfATHWNblDvQHYak9GJUA6od</preKeyPublic>
    <preKeyPublic preKeyId='74'>BX2N76JOSz4C68UQKMTumlicR1PK2PqTbhbtryVawxhx</preKeyPublic>
    <preKeyPublic preKeyId='75'>BTdvzFbd16tB/RoIHRU3//SmKOEKGfIzs47kzFnX+h41</preKeyPublic>
    <preKeyPublic preKeyId='76'>BVoJBCAljdbnSLhIGsHVisPgpHzcYdPJwOITWoZAGFV8</preKeyPublic>
    <preKeyPublic preKeyId='77'>BQSc7dG73v9LN6KRmBAcBvixnpGXWsdejnqow7yY5gx7</preKeyPublic>
    <preKeyPublic preKeyId='78'>BQZ5YGu4GE9XiY+FVme9b7Zl1ISx0LdJVXQ0mfH7q4Yl</preKeyPublic>
    <preKeyPublic preKeyId='79'>BU/Zyl+lM1tOFFRR5KvLc3AeiLIYU+J7EbnZ7/DD+bEc</preKeyPublic>
    <preKeyPublic preKeyId='80'>Ba8cXc1V7GycTP8sf6kW0DcjO/M6M3a5xWdafHjIU7MD</preKeyPublic>
    <preKeyPublic preKeyId='81'>BfsduPgGDSsTfgsXSm6jKcuog+62MW/CrCwF+ddgRRFX</preKeyPublic>
    <preKeyPublic preKeyId='82'>BWEFM7m3eQDciOMly4YTWqMxXaIju5SqwC9i4xdBEgV9</preKeyPubli
(11:30:11) jabber: Recv (ssl)(1900): c>
    <preKeyPublic preKeyId='83'>BbkUi8br4sxG7SBUM9nZfdILYn+bcCyNfwDgYid5MGYQ</preKeyPublic>
    <preKeyPublic preKeyId='84'>BVnhzE7PuQdWPLeYd+l+T4sLi7KSL1Qd5+xy+gdBtYhE</preKeyPublic>
    <preKeyPublic preKeyId='85'>BbJ5B7UM78AJ7duBtzHkMN+UKmTC6shiXuiMrlPPQjVd</preKeyPublic>
    <preKeyPublic preKeyId='86'>BZzdhYXqjwjx7G6NPX+UkrMHQ6rniuvZVBD5yfZ+Snsy</preKeyPublic>
    <preKeyPublic preKeyId='87'>BWXq9mD+Ps0mXRVB1R72EEh51yqkUsGENiGGya5FsCUk</preKeyPublic>
    <preKeyPublic preKeyId='88'>BQsWdI2HKOsLOnRRR66VAADmubvqRDz5fjU/fbh8p+dR</preKeyPublic>
    <preKeyPublic preKeyId='89'>BawupAAlkCpqz3SRVx/aOI/+ykeYRQLEGoJx+KBw/JlC</preKeyPublic>
    <preKeyPublic preKeyId='90'>BVI7N+8Vx6cQlXm21yuzmoAvkKjerFeo2g6vZHXEJ+wC</preKeyPublic>
    <preKeyPublic preKeyId='91'>BTqEGeXknYKpo5XOSAeuiVL9QmA+iqo+ijt2T+pqevc3</preKeyPublic>
    <preKeyPublic preKeyId='92'>BfHVs+s6/DX6BE/r4vbEh7jEVR5+GP/zYUYEphzF/S4t</preKeyPublic>
    <preKeyPublic preKeyId='93'>BcN/RdAEq84gvKCl+bbY2eU8TCik71Djv5BQqpAL9MoX</preKeyPublic>
    <preKeyPublic preKeyId='94'>BaY8l6WwqWFpNiBdnN4IFVrockRmspeuGzV+kKzj7LE6</preKeyPublic>
    <preKeyPublic preKeyId='95'>BXSMX3FLFMVp2j9JyA8HS0BR6ehvhkocoKMaze5zuaE3</preKeyPublic>
    <preKeyPublic preKeyId='96'>BWiWn9xSXhZUhFUv4vqmnqusoK5PtCMFBm7qzj7+U704</preKeyPublic>
    <preKeyPublic preKeyId='97'>Be9XBN40fXnyQXso10hVCjSdMfZ++nlzBfxYuZs4Dak2</preKeyPublic>
    <preKeyPublic preKeyId='98'>BSm3wUY6uyDCUgoHebiyzCh1EHOnVdEraprHDz32kxhX</preKeyPublic>
    <preKeyPublic preKeyId='99'>BbSST3l4lFxEW8+n5kGczQAgT8/mSsoBpaEYgX1aAR17</preKeyPublic>
    <preKeyPublic preKeyId='100'>Ba0TpKJeag7/FuwrZA3E9WyP27WHGTN5cl8DsztVDo0T</preKeyPublic>
    <preKeyPublic preKeyId='101'>BW2t4E92w9zfE5Kdfu6lWWK3HI52BeH8khTCFnlDOGFa</preKeyPublic>
    <preKeyPublic preKeyId='102'>BUCxsR2jiX/Wo1J9fmIwg8Hgp+OIhy/sHr46Z9jghBRK</preKeyPublic>
   </prekeys>
  </bundle></item></items></pubsub></iq>
(11:30:11) lurch: lurch_bundle_request_cb: alien@darkn.space received bundle update from alien@darkn.space:1003739987
(11:30:11) lurch: lurch_bundle_create_session: creating a session between alien@darkn.space and alien@darkn.space from a received bundle
(11:30:11) lurch: lurch_bundle_create_session: failed to import xml into bundle (-12000)
(11:30:11) lurch: lurch_bundle_request_cb: failed to create a session (-12000)
(11:30:11) jabber: Recv (ssl)(26): <r xmlns='urn:xmpp:sm:3'/>
(11:30:11) jabber: Sending (ssl) (alien@darkn.space/12598123798804036770218227): <a xmlns='urn:xmpp:sm:3' h='95'/>
(11:30:14) util: Writing file blist.xml to directory /home/alarm/.purple
(11:30:14) util: Writing file /home/alarm/.purple/blist.xml
gkdr commented 3 years ago

@alien2003 cool, thanks. i'll plug that into a unit test and see what's going wrong.

gkdr commented 3 years ago

well, when i call omemo_bundle_import on the bundle you provided inside a unit test, it works. unfortunately the error code is returned when it thinks that any of the elements are missing, so i can't tell which one it is. from looking at it, it seems all right, too. would it be possible to run chatty through a debugger?

(i wonder if pidgin changed the way the xml is passed to functions? my code expects it to start at the <items> node. there was a similar issue recently which seemed to resolve itself after recompiling. the only other moving part might be the xml library itself.)

alien2003 commented 3 years ago

@gkdr really I'm not familiar on how to run it through debugger and it's a mobile app running on phone but if you will give me a tip where to start, I'll try

alien2003 commented 3 years ago

Fixed by itself in Chatty on Mobian. Seems like the issue is not related to this project

ghost commented 3 years ago 
* the seoncd one is the actual cause for your problems. it does look like it could be a client compatibility issue after all :( could you again try to send a message while the debug log is open and paste the raw xml of the whole bundle here? you can recognize it by the `<bundle>` element. (any data in there is public, and you can remove the JID if you would like to,)

jane@example.com(conversations) sends message to bill@example.com(pidgin)

bill@example.com sees the following message :

(2021-03-09 16:57:17) 
There was an error decrypting an OMEMO message addressed to this device. See the debug log for details.
(2021-03-09 16:57:17) jane: 
I sent you an OMEMO encrypted message but your client doesn’t seem to support that. Find more information on https://conversations.im/omemo

here is the log file :

(16:57:14) jabber: Recv (ssl)(210): <message to='bill@example.com' from='jane@example.com/Conversations.eOT6' type='chat'><composing xmlns='http://jabber.org/protocol/chatstates'/><no-store xmlns='urn:xmpp:hints'/><no-storage xmlns='urn:xmpp:hints'/></message>
(16:57:14) jabber: Recv (ssl)(26): <r xmlns='urn:xmpp:sm:3'/>
(16:57:14) jabber: Sending (ssl) (bill@example.com/cHbzUDWk): <a xmlns='urn:xmpp:sm:3' h='243'/>
(16:57:17) jabber: Recv (ssl)(207): <message to='bill@example.com' from='jane@example.com/Conversations.eOT6' type='chat'><active xmlns='http://jabber.org/protocol/chatstates'/><no-store xmlns='urn:xmpp:hints'/><no-storage xmlns='urn:xmpp:hints'/></message>
(16:57:17) jabber: Recv (ssl)(26): <r xmlns='urn:xmpp:sm:3'/>
(16:57:17) jabber: Sending (ssl) (bill@example.com/cHbzUDWk): <a xmlns='urn:xmpp:sm:3' h='244'/>
(16:57:17) jabber: Recv (ssl)(2022): <message id='d5f29289-27a4-487f-9f94-76b0351abcb2' to='bill@example.com' from='jane@example.com/Conversations.eOT6' type='chat'><body>I sent you an OMEMO encrypted message but your client doesnÆt seem to support that. Find more information on https://conversations.im/omemo</body><encrypted xmlns='eu.siacs.conversations.axolotl'><header sid='356060139'><key rid='1308660079'>MwohBQc8vGVzCFkcwdguxJwBkJEor4zI0WRzWrTerCvZ2ltvEJkBGKcBIjByO/0nN4P/F0R2hAoy1dlunL3xCojUhlHIyPeAs4bMXCJbjt+OCIQS2gcmXad610TQdvJvwwmT9w==</key><key rid='1952162570'>MwohBbRsCANigYbcMZdMgMxjxkv03fabmzvcM7miAoCNKBA4EAAYACIwYaXkapiqpCSv8uOT10WmICgHVrC2LfwCw0b3tJfvJdvXLN2JrL128D+uFNVh0+A+YxU/v6g+gQQ=</key><key rid='348397656'>MwohBYVuSt+qdqLB/4AyDpH2P8aZZr2jtLhjHY1D4UmopJwuEAAYAiIwDD/ccZA8fPYSEhtlpsFzfDEeLl99z2jvIcQrxprwIczg/tFr0+pwnarsIDRa6ID65YF18UeDmms=</key><key rid='295908456'>MwohBe2UH4uqpRD6NAZMw5f2hLVJaNeWE6hZG4tQNeRVuNdUEFsYACIwCdwlJgYrfQqN7K4V2emOXsmUFrNjd4R8/HRcdbulWG7KGZQzkNg5khGXvJaiS4+wvuDVh97Regs=</key><key rid='420020322' prekey='true'>MwggEiEFE20SLnCKqcSLMlRR11KD9qtO3kWB5N+4EfYkoe3JEwkaIQWoKzc+vgWEYzanqYOT4ffGbqPRxlDv0U2Y1jwnswycUSJjMwohBZt5JP26+L+t4ik48gzruPMnAPcumnFj1IskBtxwj/9REIcEGAAiMC3H98Ydh73EOnusPIWIcYOqRldxg5EHz78p8O/HByN3Hg3Sv99P7jUE8p2wGWHHyQTXhxefcmGtKOuX5KkBMAA=</key><key rid='922871145'>MwohBXiptQknt8rvd/fqxNZpjbawy244Uni1PEfI1GnK+3xWEE0YASIwvw+/md+p9UWxiupiVtjx+fsPO1/kRGOH2k5FaXfOG6DoTbP2FYgzAwTR3IkmBeKOkIW5pqtaz3Q=</key><key rid='1242692755'>MwohBWsEQspFPITC7AiqqmObJhM+VqUtRhvC3NUj/W8vwzMpEAAYEiIwz/tZwE4vLf8eN1eq5CJdAsoagEKd2MyNMCGSogR6/onQrYZN1uxVkJO81mtSCdBvUy7auvkY4Nw=</key><iv>6qImkC9wx0dpo9Tz</iv></header><payload>DOF8rg==</payload></encrypted><request xmlns='urn:xmpp:receipts'/><markable xmlns='urn:xmpp:chat-markers:0'/><origin-id id='d5f29289-27a4-487f-9f94-76b0351abcb2' xmlns='urn:xmpp:sid:0'/><store xmlns='urn:xmpp:hints'/><encryption name='OMEMO' namespace='eu.siacs.conversations.axolotl' xmlns='urn:xmpp:eme:0'/><stanza-id id='VJ0YF2EwA0SEKsQa' xmlns='urn:xmpp:sid:0' by='bill@example.com'/></message>
(16:57:17) jabber: XML parser error for JabberStream 09900730: Domain 3, code 100, level 1: xmlns: URI eu.siacs.conversations.axolotl is not absolute
(16:57:17) lurch: lurch_message_decrypt: failed to prekey msg (-1003)
(16:57:17) jabber: Binding conversation to jane@example.com/Conversations.eOT6
(16:57:18) sound: Playing C:\Program Files (x86)\Pidgin\sounds\purple\receive.wav

then bill writes back to jane

(17:11:52) jabber: Recv (ssl)(26): <r xmlns='urn:xmpp:sm:3'/>
(17:11:52) jabber: Sending (ssl) (bill@example.com/cHbzUDWk): <a xmlns='urn:xmpp:sm:3' h='265'/>
(17:12:10) jabber: Sending (ssl) (bill@example.com/cHbzUDWk): <message type='chat' id='purple6bcd2819' to='jane@example.com/Conversations.eOT6'><composing xmlns='http://jabber.org/protocol/chatstates'/></message>
(17:12:10) jabber: Sending (ssl) (bill@example.com/cHbzUDWk): <r xmlns='urn:xmpp:sm:3'/>
(17:12:11) jabber: Recv (ssl)(33): <a xmlns='urn:xmpp:sm:3' h='52'/>
(17:12:11) XEP-0198: Acknowledged 52 out of 52 outbound stanzas
(17:12:18) jabber: Sending (ssl) (bill@example.com/cHbzUDWk): <message type='chat' id='purple6bcd281a' to='jane@example.com/Conversations.eOT6'><paused xmlns='http://jabber.org/protocol/chatstates'/></message>
(17:12:18) jabber: Sending (ssl) (bill@example.com/cHbzUDWk): <r xmlns='urn:xmpp:sm:3'/>
(17:12:18) conversation: typed...
(17:12:18) jabber: Recv (ssl)(33): <a xmlns='urn:xmpp:sm:3' h='53'/>
(17:12:18) XEP-0198: Acknowledged 53 out of 53 outbound stanzas
(17:12:19) lurch: retrieved devicelist for jane@example.com:<publish node="eu.siacs.conversations.axolotl.devicelist"><item><list xmlns="eu.siacs.conversations.axolotl"><device id="356060139" /><device id="1242692755" /></list></item></publish>
(17:12:19) lurch: retrieved own devicelist:<publish node="eu.siacs.conversations.axolotl.devicelist"><item><list xmlns="eu.siacs.conversations.axolotl"><device id="295908456" /><deviceid="348397656" /><device id="420020322" /><device id="922871145" /><device id="1308660079" /><device id="1952162570" /></list></item></publish>
(17:12:19) lurch: lurch_msg_encrypt_for_addrs: trying to encrypt key for 7 devices
(17:12:19) lurch: lurch_key_encrypt: encrypting key for jane@example.com:1242692755
(17:12:19) lurch: lurch_key_encrypt: encrypting key for jane@example.com:356060139
(17:12:19) lurch: lurch_key_encrypt: encrypting key for bill@example.com:1952162570
(17:12:19) lurch: lurch_key_encrypt: encrypting key for bill@example.com:1308660079
(17:12:19) lurch: lurch_key_encrypt: encrypting key for bill@example.com:922871145
(17:12:19) lurch: lurch_key_encrypt: encrypting key for bill@example.com:348397656
(17:12:19) lurch: lurch_key_encrypt: encrypting key for bill@example.com:295908456
(17:12:19) xmlnode: XML parser error for xmlnode 09B26E38: Domain 3, code 100, level 1: xmlns: URI eu.siacs.conversations.axolotl is not absolute
(17:12:19) jabber: Sending (ssl) (bill@example.com/cHbzUDWk): <message type='chat' id='purple6bcd281b' to='jane@example.com/Conversations.eOT6'><active xmlns='http://jabber.org/protocol/chatstates'/><encrypted xmlns='eu.siacs.conversations.axolotl'><header sid='420020322'><key rid='295908456'>MwjflO8HEiEFPA7adqUqcsJU026Mi/arFhWxq9cWAAYE8jaH82As8WcaIQWoahQfaP9cWgLZE0T6uB3JvVV4yphk9axXfYH7aWykXSJiMwohBVZvazJow98qGikKakTnw/ACv5X8MfZOMAGssb9GwJAZEAoYACIwYon8dkBIMm2dtIqf3f0Dsg71ewKfL4QJ5d5Y0w4YlEPdXNaZBqh3f6nSLb6J7FiOIWwrGOsErAoo4oCkyAEw9G8=</key><key rid='348397656'>Mwi6x8gCEiEFK1QeSTyRe5G0oV4eCh3lSxlNGnRHoLOOj7d60MmXEy4aIQWoahQfaP9cWgLZE0T6uB3JvVV4yphk9axXfYH7aWykXSJiMwohBVaPaVooZtgEfDnhOrp41h2AluQqV5mNUP3ll6KANrYvEAoYACIwFlTVeTlzFTQlvmdNTvKX9PoM3o0km5o6VOsaccgEJx6L0mmSiTXoJiNLuoUCvGGR4M4j9CQt6KUo4oCkyAEwtqgB</key><key rid='922871145'>MwjLuLEGEiEFbQYjt8akUXu/pQmJ/DoRDHxa7RULT4H+Qp4DKwQJvw8aIQWoahQfaP9cWgLZE0T6uB3JvVV4yphk9axXfYH7aWykXSJiMwohBTbs6q/BnIrElGmboNRrWVKjg4cpxQtSs2MKPcvDaac8EAoYACIwZq3nc/Zq/Wko2rvtWKs2cWNDpTlv3ss781b1gQZC7TFKy2GQIBI1clTXSyD8I/OuqKThhp/mpC8o4oCkyAEw+dsD</key><key rid='1308660079'>MwgtEiEFCBfi93WQ7qZeqU/4vLlsWXKpZ0PJKVW7pRpc+cZoTSQaIQWoahQfaP9cWgLZE0T6uB3JvVV4yphk9axXfYH7aWykXSJiMwohBU99j3uWOZDenKKluPmJjFQRnjdOgW71fwxy+I604n0zEAoYACIwJFytYWogw5DjUnwrkgZgFbVPisOmBjMutOfZue/qPqkEgcwcIwXo716NijQ2yUPxN7ECVj913iUo4oCkyAEwAQ==</key><key rid='1952162570'>MwohBbc9/itAA0BhqAFHxwG/e0RTvD0tcZPOQYO2bPIY1lZyEAoYACIwHLGYea9VIEY61X+sWHe2T9WdvVzPW7vQj4WFxWc4KJUlqGZEn7YJGyUpH4/6L61Xb0ZMOD0ccl0=</key><key rid='356060139'>MwgVEiEFg+tPi+wzrE9Z+XWuzxMJOTzusXeXgfeoMjTIKRX44AYaIQWoahQfaP9cWgLZE0T6uB3JvVV4yphk9axXfYH7aWykXSJiMwohBahG0ahyO/OiALC5XwdSjH8M2F/gM19x5j92Fusd6M5REAoYACIwh29T83xHd/bV/lHmsUjGHu3LGW0Pg2KgvC5PSTC/XkVbncXFx0fGns4pOCwEzL3nEJJK3ZYlHC4o4oCkyAEwAQ==</key><key rid='1242692755'>Mwjzq/0DEiEFAfVatHBRXp6sK5cLMr2kVXcPWGn9AGS0oh2HkyMDWAMaIQWoahQfaP9cWgLZE0T6uB3JvVV4yphk9axXfYH7aWykXSJiMwohBVej4Y8FIPBDjzALYG4Ofl23YdXC5zPMgSp6INK1Bhg+EAoYACIwAtQxhAY5oi2VBOrUsexXTV9LSkM7xBiAfm7wWOC7WT1aSA2zL90YtrljZancueHBRL0TEPxkq/Ao4oCkyAEwjdwC</key><iv>D52GHZ9e8/oniaxF+OD6fA==</iv></header><payload>sVyQbQ==</payload></encrypted><encryption xmlns='urn:xmpp:eme:0' namespace='eu.siacs.conversations.axolotl' name='OMEMO'/><store xmlns='urn:xmpp:hints'/></message>
(17:12:19) jabber: Sending (ssl) (bill@example.com/cHbzUDWk): <r xmlns='urn:xmpp:sm:3'/>
(17:12:19) sound: Playing C:\Program Files (x86)\Pidgin\sounds\purple\send.wav
(17:12:19) jabber: Sending (ssl) (bill@example.com/cHbzUDWk): <message type='chat' id='purple6bcd281c' to='jane@example.com/Conversations.eOT6'><active xmlns='http://jabber.org/protocol/chatstates'/></message>
(17:12:19) jabber: Sending (ssl) (bill@example.com/cHbzUDWk): <r xmlns='urn:xmpp:sm:3'/>
(17:12:19) jabber: Recv (ssl)(66): <a xmlns='urn:xmpp:sm:3' h='54'/><a xmlns='urn:xmpp:sm:3' h='55'/>
(17:12:19) XEP-0198: Acknowledged 54 out of 55 outbound stanzas

* what xmpp server and version are you running?

prosody 0.11.2

ghost commented 3 years ago

possible this helps more

(17:49:21) util: Writing file prefs.xml to directory C:\Users\Christian\AppData\Roaming\.purple
(17:49:21) util: Writing file C:\Users\Christian\AppData\Roaming\.purple\prefs.xml
(17:49:27) jabber: Sending (ssl) (bill@example.com/xDCzXWu8): <iq type='get' id='purple8a846abd'><ping xmlns='urn:xmpp:ping'/></iq>
(17:49:27) jabber: Sending (ssl) (bill@example.com/xDCzXWu8): <r xmlns='urn:xmpp:sm:3'/>
(17:49:27) jabber: Recv (ssl)(63): <iq id='purple8a846abd' to='bill@example.com/xDCzXWu8' type='result'/>
(17:49:27) jabber: Recv (ssl)(26): <r xmlns='urn:xmpp:sm:3'/>
(17:49:27) jabber: Sending (ssl) (bill@example.com/xDCzXWu8): <a xmlns='urn:xmpp:sm:3' h='247'/>
(17:49:27) jabber: Recv (ssl)(33): <a xmlns='urn:xmpp:sm:3' h='41'/>
(17:49:27) XEP-0198: Acknowledged 41 out of 41 outbound stanzas
(17:49:35) jabber: Recv (ssl)(289): <message id='3a56b406-8c4b-49bc-9232-21efa25b1411' to='bill@example.com' from='jane@example.com/gajim.X99Z1ERZ' type='chat'><origin-id id='3a56b406-8c4b-49bc-9232-21efa25b1411' xmlns='urn:xmpp:sid:0' /><composing xmlns='http://jabber.org/protocol/chatstates'/><no-store xmlns='urn:xmpp:hints'/></message>
(17:49:35) lurch: [AXC INFO] axc_init: initializing axolotl client
(17:49:35) lurch: [AXC DEBUG] axc_init: created and set axolotl context
(17:49:35) lurch: [AXC DEBUG] axc_init: set axolotl crypto provider
(17:49:35) lurch: [AXC DEBUG] axc_init: created store context
(17:49:35) lurch: [AXC DEBUG] axc_init: set store context
(17:49:35) lurch: [AXC INFO] axc_init: done initializing axc
(17:49:35) jabber: Recv (ssl)(26): <r xmlns='urn:xmpp:sm:3'/>
(17:49:35) jabber: Sending (ssl) (bill@example.com/xDCzXWu8): <a xmlns='urn:xmpp:sm:3' h='248'/>
(17:49:36) jabber: Recv (ssl)(1566): <message id='2afb07fe-ac79-4209-a8ee-a6895e2fd605' to='bill@example.com' from='jane@example.com/gajim.X99Z1ERZ' type='chat'><request xmlns='urn:xmpp:receipts'/><active xmlns='http://jabber.org/protocol/chatstates'/><markable xmlns='urn:xmpp:chat-markers:0'/><origin-id id='2afb07fe-ac79-4209-a8ee-a6895e2fd605' xmlns='urn:xmpp:sid:0'/><encrypted xmlns='eu.siacs.conversations.axolotl'><header sid='1242692755'><key rid='356060139'>MwohBfbv/HXiiiBEyjBcOlZRMEYyyvkC7TVfkPjwl+i25ZkQEAIYGyIwZYcgSvrCy8VK9AVOViTFEU1QNPTnRt+BqPij59yBrk2DvSaND6giQxgMUHW+lecSwEpT+2bi8J8=</key><key rid='295908456'>MwohBb2/Tuejwhlh5jMeaKs8BYUV62bs+vLsLMFI50MemBtWEP4BGAAiMLxMQJaMCpipT/V4QOpcHUaf0mAOXw5fBTCy+Zvvp2N9TEjmf2j2y/6P+4Ynv5zBemlW/pZzxBpZ</key><key rid='1952162570'>MwohBQEwt4xPRpzGNHc9YXnavmfMnFMDc3/ipB+QXMVlAOVHEAIYACIwv4WuF54MAqal8OY/B564lzw9drPdtFYN/rPxZkFMo9vsZJqbrweXTBPyV0LJzVTkw+k0zpbeIeA=</key><key rid='922871145'>MwohBV73/HG43wZO9EcUJ6nBO0q1TQ9OLqgEMDgvtUSbQJRqEO4BGAAiMAW4u2Vj5ovJfF3teyjMVAm9YP+db5T72FPPYz5seiJh+ogI0UbgqztWMqvei166YqMjEDtvONyq</key><key rid='348397656'>MwohBf0BLkeA7I42w9YSHC05R1CXcp3gzVqnr1WL0gDps/wiEA4YDyIwpQ1S8R4LB044VdPT3e+nKPy+aRVrsPeP+2AxiDYU+T0M5x5WDFuan9I3937MXElDKmqB2fM6fC0=</key><iv>qBavW4bn4rib3Btp</iv></header><payload>6lKj</payload></encrypted><encryption name='OMEMO' namespace='eu.siacs.conversations.axolotl' xmlns='urn:xmpp:eme:0'/><body>You received a message encrypted with OMEMO but your client doesn&apos;t support OMEMO.</body><store xmlns='urn:xmpp:hints'/><stanza-id id='UphkQ5YLOtdPimKM' xmlns='urn:xmpp:sid:0' by='bill@example.com'/></message>
(17:49:36) jabber: XML parser error for JabberStream 0816A7B0: Domain 3, code 100, level 1: xmlns: URI eu.siacs.conversations.axolotl is not absolute
(17:49:36) lurch: [AXC INFO] axc_init: initializing axolotl client
(17:49:36) lurch: [AXC DEBUG] axc_init: created and set axolotl context
(17:49:36) lurch: [AXC DEBUG] axc_init: set axolotl crypto provider
(17:49:36) lurch: [AXC DEBUG] axc_init: created store context
(17:49:36) lurch: [AXC DEBUG] axc_init: set store context
(17:49:36) lurch: [AXC INFO] axc_init: done initializing axc
(17:49:36) lurch: received omemo message that does not contain a key for this device, skipping
(17:49:37) sound: Playing C:\Program Files (x86)\Pidgin\sounds\purple\receive.wav
(17:49:37) lurch: [AXC INFO] axc_init: initializing axolotl client
(17:49:37) lurch: [AXC DEBUG] axc_init: created and set axolotl context
(17:49:37) lurch: [AXC DEBUG] axc_init: set axolotl crypto provider
(17:49:37) lurch: [AXC DEBUG] axc_init: created store context
(17:49:37) lurch: [AXC DEBUG] axc_init: set store context
(17:49:37) lurch: [AXC INFO] axc_init: done initializing axc
(17:49:37) jabber: Recv (ssl)(26): <r xmlns='urn:xmpp:sm:3'/>
(17:49:37) jabber: Sending (ssl) (bill@example.com/xDCzXWu8): <a xmlns='urn:xmpp:sm:3' h='249'/>
gkdr commented 3 years ago

@ecxod Thanks for providing the debug log. I don't see the error message related to sending you posted initially in there; instead, now receiving seems to be a problem.

The error code -1003 you see at first in the debug log is from deep down in the library. As far as I can see, the key referenced in the message can in fact not be found in the DB. This could again be anything. Corrupt DB, bug in my code, bug in Conversations, bug in the server sending out old data.

This seems to have fixed itself. I think you turned on the additional logging in the plugin options? This would have helped with the first error message, unfortunately not with this second one. That's because now it's not on DB level, but protocol level. And I plugged the exact message into a unit test and cannot reproduce it. I really don't know how this could be happening - maybe some encoding issue? Is it possible for you to update the XMPP server you are using?

ghost commented 3 years ago

Thank you for fixing lurch. The so called "offline" version did the job. The portable version is not working. God bless you :-)