Skip to content

Contact receives unintentional and undecryptable OTR #611

Closed
Closed
Contact receives unintentional and undecryptable OTR#611

Description

@joostrijneveld
joostrijneveld
opened on Nov 25, 2016

I'm trying out the beta to communicate with a Conversations.im user using OMEMO. However, every now and again, he reports receiving a blurb of OTR ciphertext. Notably, these messages do not show up in ChatSecure on my side.

Last night we sent several messages back and forth, and sometime later he received such an OTR blurb. This morning, I mindlessly opened and closed the app without sending any messages, and he again reported receiving messages. The receiving timestamps on these messages were again sometime later (but at a time I'm certain I did not interact with the app, as I was physically away from my phone), making me think it was related.

On my prosody server, I see the following logs (the timestamps on the messages were 07:50 and 8:34). Note that [email protected] is the account I'm using with ChatSecure, and 92.51.148.190 is the conversations.im server where my friend has an account.

Nov 25 07:49:58 s2sinfce300	info	incoming s2s connection conversations.im->joostrijneveld.nl complete
Nov 25 07:50:00 c2sbcab10	info	Client connected
Nov 25 07:50:01 c2sbcab10	info	Authenticated as [email protected]
Nov 25 07:50:01 s2sout13456e0	info	Beginning new connection attempt to conversations.im ([92.51.148.190]:5269)
Nov 25 07:50:01 s2sout13456e0	info	outgoing s2s connection joostrijneveld.nl->conversations.im complete
Nov 25 07:50:02 c2sbcab10	warn	The client says it handled 1 new stanzas, but we only sent 0 :)
Nov 25 07:50:29 c2sbcab10	info	Client disconnected: closed
Nov 25 08:34:54 joostrijneveld.nl:saslauth	info	Accepting SASL EXTERNAL identity from conversations.im
Nov 25 08:34:54 s2sine5f2e0	info	incoming s2s connection conversations.im->joostrijneveld.nl complete
Nov 25 08:34:56 c2sfb8230	info	Client connected
Nov 25 08:34:56 c2sfb8230	info	Authenticated as [email protected]
Nov 25 08:34:57 s2sout10f28f0	info	Beginning new connection attempt to conversations.im ([92.51.148.190]:5269)
Nov 25 08:34:57 s2sout10f28f0	info	outgoing s2s connection joostrijneveld.nl->conversations.im complete
Nov 25 08:35:03 c2sfb8230	warn	The client says it handled 1 new stanzas, but we only sent 0 :)
Nov 25 08:35:24 c2sfb8230	info	Client disconnected: closed

The logs seems to indicate that it's actually the conversations.im server initiating the connection.. However, my friend is only seeing these messages coming from me, and not from other people using Conversations or Gajim.

My next debugging step is to create an account at a third party server (i.e. duckduckgo's or conversations') to see if that's part of the reason.

Activity

  1. ronnicek commented on Nov 28, 2016

    @ronnicek
    ronnicek
    on Nov 28, 2016

    Hi,

    I have the same problem with my server (both accounts are on same server).

    Actually, I cannot choose OMEMO (it's activated in Gajim, but in ChatSecure I see it gray) with this account anymore - chatsecure still poiting to OTR and sending this blobs everytime like:

    [12:10:52] ‎chatsecureiOS: **Unencrypted** ?OTR:AAIDAAAAAAEAAAABAAAAwIQK/W+/y/CZ/mA+O3AAgDvJsfUpEwq6TIQ2TdzFFgqs4xijncHWnyRq7MuBrJS7U8upBMDTzUno3gb/xDphVEeZXdfii4sniufjExe9aweweSwfduRH3CdZynV1L/vITMVPjOFzgNdcInxu+/foXbzyVA+eKL8ya+IPE/UcE7hOflD+zkYT/FEq4nc1p0+zqJlmhKn8SgNSJDc09RcrHrPSCrj0uf9bsz9DaH0AQNaqDsRkv8+z+pwDWqa8ihQengAAAAAAAAABAAAAfDvAdWMLsdVkkksxFiEPrP/jS4XCY6uEGPNcAbMQfogS8AtB914IUFxjXvczXkozgLXaa/r5Vn1noceoPu6Eyu8nB491k9rt9XwBQ2Q5s3Uh9Lz5kVSDurCXwSSeH2/5BnVtn5t0SZEge8SJmgXQIKxLrJP+79TQYiOc2YwmJR8EdOTzzZJ+kY1CAoFNplGmYQAAAAA=.

    I will try to set prosody to debug mode and get some logs, but dont know if I will have time to today to debug it.

  2. chrisballinger commented on Nov 28, 2016

    @chrisballinger
    chrisballinger
    on Nov 28, 2016
    Member

    @ronnicek Are you running the 4.0 (49) beta?

  3. ronnicek commented on Nov 28, 2016

    @ronnicek
    ronnicek
    on Nov 28, 2016

    @chrisballinger yes, I am using that :)

  4. ronnicek commented on Nov 29, 2016

    @ronnicek
    ronnicek
    on Nov 29, 2016

    hello, hello..

    so I did a bit digging into it..

    When I have connected client from Chatsecure iOS client only and then I connect my desktop client, I always get these messages:

    [17:36:54] ‎chatsecureios‎: Unencrypted
    ‎[17:36:55] ‎chatsecureios‎: Unencrypted
    ‎[17:36:56] ‎chatsecureios‎: Unencrypted
    ‎[17:36:56] ‎chatsecureios‎: Unencrypted ?OTR:AAIDAAAAAAEAAAABAAAAwL80quoSUbrpIKc6JnOtnI7So7sbH+G76wSxV8Qx42nmW4UsJ6eCBIPyE8qRbQ+vDMoW4uajjgTxjwaayJZaKHs/UPR/C71nQcha0UQF7SHIjt2MS+Uq8rrqwTZvFQxXm7XtElBU88TxRezXbZtjr5yX30DBgh/zvbUCHZj+x/jqz1hF92HnnmnpxrNvmiKV5nEWlRJQyYGVWl+bbzMm0OrRVfOPbwaVPlpDNYH6PzF2uoTVxq/4Dhd8GCnB+Bh+BwAAAAAAAAABAAAAfKs+U/FISHktwgrk7bV0OnM+zx0Cu08mklpoA4JNa4wJ2S/zjKIiAFEkcEihWk0at239qUdisAIqtboEfN5l+adFPMMuEEatzJM+110MW+DOPbY+MGDhe5+lqvepoGuKePd94Let6/3S84jhSm44Uyjh+KCi8Y/y6xKCr/lXd2l5DeNLToT2fk3uJ5WkZTk7agAAAAA=.v

    And here is a log from server (debug mode):

    prosody_1 | c2s7f688c720220 debug #queue = 2
    prosody_1 | c2s7f688c720220 debug Queuing (in a moment)
    prosody_1 | c2s7f688cb9d7c0 debug Received[c2s]:
    prosody_1 | domain.net:smacks debug Received ack request, acking for 30
    prosody_1 | c2s7f688cb9d7c0 debug Handled 31 incoming stanzas
    prosody_1 | c2s7f688cb9d7c0 debug Received[c2s]:
    prosody_1 | c2s7f688cb9d7c0 debug #queue = 50
    prosody_1 | c2s7f688cb9d7c0 debug Received[c2s]:
    prosody_1 | domain.net:smacks debug Received ack request, acking for 31
    prosody_1 | c2s7f688cb9d7c0 debug Received[c2s]:
    prosody_1 | domain.net:smacks debug Received ack request, acking for 31
    prosody_1 | c2s7f688cb9d7c0 debug Handled 32 incoming stanzas
    prosody_1 | c2s7f688cb9d7c0 debug Received[c2s]:
    prosody_1 | datamanager debug Assuming empty archive2_prefs storage ('cannot open /var/lib/prosody/domain%2enet/archive2_prefs/jindrich%2eskacel.dat: No such file or directory') for user: [email protected]
    prosody_1 | domain.net:mam debug ronnicek's rule for [email protected] is nil
    prosody_1 | domain.net:mam debug ronnicek's default rule is true
    prosody_1 | c2s7f688cb9d7c0 debug Archiving stanza:
    prosody_1 | datamanager debug Assuming empty archive2_prefs storage ('cannot open /var/lib/prosody/domain%2enet/archive2_prefs/chatsecureios.dat: No such file or directory') for user: [email protected]
    prosody_1 | domain.net:mam debug chatsecureios's rule for [email protected] is nil
    prosody_1 | domain.net:mam debug chatsecureios's default rule is true
    prosody_1 | domain.net:mam debug Archiving stanza:
    prosody_1 | c2s7f688c720220 debug #queue = 3
    prosody_1 | c2s7f688cb9d7c0 debug Received[c2s]:
    prosody_1 | domain.net:smacks debug Received ack request, acking for 32
    prosody_1 | c2s7f688cb9d7c0 debug Handled 33 incoming stanzas
    prosody_1 | c2s7f688cb9d7c0 debug Received[c2s]:
    prosody_1 | c2s7f688cb9d7c0 debug #queue = 51
    prosody_1 | c2s7f688cb9d7c0 debug Received[c2s]:
    prosody_1 | domain.net:smacks debug Received ack request, acking for 33
    prosody_1 | c2s7f688cb9d7c0 debug Handled 34 incoming stanzas
    prosody_1 | c2s7f688cb9d7c0 debug Received[c2s]:
    prosody_1 | c2s7f688cb9d7c0 debug #queue = 52
    prosody_1 | c2s7f688c720220 debug Sending (after send)
    prosody_1 | c2s7f688c720220 debug Received[c2s]:
    prosody_1 | c2s7f688c720220 debug #queue = 0
    prosody_1 | c2s7f688cb9d7c0 debug Received[c2s]:
    prosody_1 | c2s7f688cb9d7c0 debug #queue = 6
    prosody_1 | c2s7f688cb9d7c0 debug Received[c2s]:
    prosody_1 | domain.net:smacks debug Received ack request, acking for 34
    prosody_1 | c2s7f688cb9d7c0 debug Handled 35 incoming stanzas
    prosody_1 | c2s7f688cb9d7c0 debug Received[c2s]:
    prosody_1 | datamanager debug Assuming empty archive2_prefs storage ('cannot open /var/lib/prosody/domain%2enet/archive2_prefs/jindrich%2eskacel.dat: No such file or directory') for user: [email protected]
    prosody_1 | domain.net:mam debug ronnicek's rule for [email protected] is nil
    prosody_1 | domain.net:mam debug ronnicek's default rule is true
    prosody_1 | c2s7f688cb9d7c0 debug Archiving stanza:
    prosody_1 | datamanager debug Assuming empty archive2_prefs storage ('cannot open /var/lib/prosody/domain%2enet/archive2_prefs/chatsecureios.dat: No such file or directory') for user: [email protected]
    prosody_1 | domain.net:mam debug chatsecureios's rule for [email protected] is nil
    prosody_1 | domain.net:mam debug chatsecureios's default rule is true
    prosody_1 | domain.net:mam debug Archiving stanza:
    prosody_1 | c2s7f688c720220 debug #queue = 1
    prosody_1 | c2s7f688c720220 debug Queuing (in a moment)
    prosody_1 | c2s7f688cb9d7c0 debug Received[c2s]:
    prosody_1 | domain.net:smacks debug Received ack request, acking for 35
    prosody_1 | c2s7f688cb9d7c0 debug Handled 36 incoming stanzas
    prosody_1 | c2s7f688cb9d7c0 debug Received[c2s]:
    prosody_1 | datamanager debug Assuming empty archive2_prefs storage ('cannot open /var/lib/prosody/domain%2enet/archive2_prefs/jindrich%2eskacel.dat: No such file or directory') for user: [email protected]
    prosody_1 | domain.net:mam debug ronnicek's rule for [email protected] is nil
    prosody_1 | domain.net:mam debug ronnicek's default rule is true
    prosody_1 | c2s7f688cb9d7c0 debug Archiving stanza:
    prosody_1 | datamanager debug Assuming empty archive2_prefs storage ('cannot open /var/lib/prosody/domain%2enet/archive2_prefs/chatsecureios.dat: No such file or directory') for user: [email protected]
    prosody_1 | domain.net:mam debug chatsecureios's rule for [email protected] is nil
    prosody_1 | domain.net:mam debug chatsecureios's default rule is true
    prosody_1 | domain.net:mam debug Archiving stanza:
    prosody_1 | c2s7f688c720220 debug #queue = 2
    prosody_1 | c2s7f688cb9d7c0 debug Handled 37 incoming stanzas
    prosody_1 | c2s7f688cb9d7c0 debug Received[c2s]:
    prosody_1 | c2s7f688cb9d7c0 debug #queue = 7
    prosody_1 | c2s7f688cb9d7c0 debug Queuing (in a moment)
    prosody_1 | c2s7f688c720220 debug Sending (after send)
    prosody_1 | c2s7f688cb9d7c0 debug Sending (after send)
    prosody_1 | c2s7f688c720220 debug Received[c2s]:
    prosody_1 | c2s7f688c720220 debug #queue = 0
    prosody_1 | c2s7f688cb9d7c0 debug Received[c2s]:
    prosody_1 | c2s7f688cb9d7c0 debug #queue = 0
    prosody_1 | c2s7f688cb9d7c0 debug Handled 38 incoming stanzas
    prosody_1 | c2s7f688cb9d7c0 debug Received[c2s]:
    prosody_1 | stanzarouter debug Routing to remote...
    prosody_1 | s2sout7f688c8e32c0 debug going to send stanza to gmail.com from domain.net
    prosody_1 | s2sout7f688c8e32c0 debug sending:
    prosody_1 | s2sout7f688c8e32c0 debug stanza sent over s2sout
    prosody_1 | s2sin7f688c9e9200 debug Received[s2sin]:
    prosody_1 | c2s7f688cb9d7c0 debug #queue = 1
    prosody_1 | c2s7f688cb9d7c0 debug Queuing (in a moment)
    prosody_1 | c2s7f688cb9d7c0 debug Sending (after send)
    prosody_1 | c2s7f688cb9d7c0 debug Received[c2s]:
    prosody_1 | c2s7f688cb9d7c0 debug #queue = 0
    prosody_1 | c2s7f688c720220 debug Handled 16 incoming stanzas
    prosody_1 | c2s7f688c720220 debug Received[c2s]:
    prosody_1 | datamanager debug Assuming empty archive2_prefs storage ('cannot open /var/lib/prosody/domain%2enet/archive2_prefs/chatsecureios.dat: No such file or directory') for user: [email protected]
    prosody_1 | domain.net:mam debug chatsecureios's rule for [email protected] is nil
    prosody_1 | domain.net:mam debug chatsecureios's default rule is true
    prosody_1 | c2s7f688c720220 debug Archiving stanza:
    prosody_1 | datamanager debug Assuming empty archive2_prefs storage ('cannot open /var/lib/prosody/domain%2enet/archive2_prefs/jindrich%2eskacel.dat: No such file or directory') for user: [email protected]
    prosody_1 | domain.net:mam debug ronnicek's rule for [email protected] is nil
    prosody_1 | domain.net:mam debug ronnicek's default rule is true
    prosody_1 | domain.net:mam debug Archiving stanza:
    prosody_1 | c2s7f688cb9d7c0 debug #queue = 1
    prosody_1 | c2s7f688cb9d7c0 debug Queuing (in a moment)
    prosody_1 | c2s7f688cb9d7c0 debug Sending (after send)
    prosody_1 | c2s7f688cb9d7c0 debug Received[c2s]:
    prosody_1 | c2s7f688cb9d7c0 debug #queue = 0

    I am really bad in reading these logs.. so I have no idea what is there and what is going on :-(. I also will send bugreport from TestFlight right away so you can have also logs from client.

    // J

  5. chrisballinger commented on Nov 29, 2016

    @chrisballinger
    chrisballinger
    on Nov 29, 2016
    Member

    We automatically try to establish new OTR sessions via ?OTRv23? which might be causing this behavior. It's needed so the OTR session can be refreshed in case the session is stale. We also create an OTR session at the same time as OMEMO so the existing OTRDATA file transfer stuff works between ChatSecure/Zom.

  6. ronnicek commented on Nov 29, 2016

    @ronnicek
    ronnicek
    on Nov 29, 2016

    Hmm. but I have OTR plugin installed also on Desktop, so why I get these Unencrypted + ?OTR:AAIDAAAAAAEAAAAB?

  7. chrisballinger commented on Nov 29, 2016

    @chrisballinger
    chrisballinger
    on Nov 29, 2016
    Member

    Anything prefixed with ?OTR should be considered encrypted by a properly function OTR plugin. If there's an encryption error that's a separate issue, but we try to hide those and just renegotiate the session.

  8. joostrijneveld commented on Nov 30, 2016

    @joostrijneveld
    joostrijneveld
    on Nov 30, 2016
    Author

    It appears that attempting to disable OTR for a contact I want to use OMEMO with (via the 'Show Advanced Encryption Settings') did not have any effect, though.. Shouldn't that prevent ?OTRv23? messages? (although now I'm doubting whether I tested this correctly)

  9. ronnicek commented on Dec 2, 2016

    @ronnicek
    ronnicek
    on Dec 2, 2016

    This is still happening in latest beta.

  10. chrisballinger commented on Dec 5, 2016

    @chrisballinger
    chrisballinger
    on Dec 5, 2016
    Member

    There is no way to fully disable OTR in the beta because we wanted to maintain backwards compatibility with OTRDATA media messaging and OTR-based Knock token exchange. Selecting OMEMO also establishes a parallel OTR session because we assume that any client that can do OMEMO can also do OTR.

    Whenever an OTR session is established we send Knock tokens (using a special OTR TLV) to the other contact regardless of whether or not they understand it, because a properly functioning client should silently filter those messages.

  11. joostrijneveld commented on Dec 6, 2016

    @joostrijneveld
    joostrijneveld
    on Dec 6, 2016
    Author

    Do you plan to make those knock tokens optional in the future (at the cost of disabling OTR functionality)? It seems they would have far-reaching privacy implications that one would not want to depend on the other party's client for.

  12. chrisballinger commented on Dec 6, 2016

    @chrisballinger
    chrisballinger
    on Dec 6, 2016
    Member

    There's always some tradeoff between modern usability expectations and ultimate idealistic privacy. When going through the onboarding for the first time, skip the "Enable Push" dialog and no push tokens will ever be created or sent. If you've already enabled it, you can disable it by turning off Background App Refresh for ChatSecure in the iOS System Settings.

    Knock token exchange is already disabled for Tor accounts.

  13. ronnicek commented on Dec 6, 2016

    @ronnicek
    ronnicek
    on Dec 6, 2016

    If I can vote, I would like to see some settings like OTR only and OMEMO only :)

  14. chrisballinger commented on Dec 6, 2016

    @chrisballinger
    chrisballinger
    on Dec 6, 2016
    Member

    @ronnicek Once we agree on a way to send arbitrary inline data blobs over OMEMO, we can phase out the OMEMO + OTR, and make it just one or the other. We will consider adding more configuration options in 4.1, but we really just need to get 4.0 out the door.

    I'd like to blame Gajim, Pidgin, and Conversations for leaking this OTR ciphertext because it should never be exposed to the user. ;)

  15. chrisballinger
    added a commit that references this issue on Dec 7, 2016

    Add Plaintext Only and OMEMO Only options. Fix OTR storage hints. #621 …

    3c9f46c

  16. chrisballinger commented on Dec 7, 2016

    @chrisballinger
    chrisballinger
    on Dec 7, 2016
    Member

    Fixed in 3c9f46c

  17. chrisballinger
    closed this as completedon Dec 7, 2016

  18. joostrijneveld commented on Dec 10, 2016

    @joostrijneveld
    joostrijneveld
    on Dec 10, 2016
    Author

    @chrisballinger While I see your point of blaming the other side of the story for not implementing, I find the fact that these messages are sent in the first place a bit of a weird quirk of OTR.. Especially since they appear to reflect behaviour / app usage. Glad to see you've resolved it - it seems to work!

    I'm not sure if it was my bad for having it set to OTR, or if it was set to OTR because of this update, but the 'Advanced Encryption Settings' was set to OTR for me now. I'm thinking that it was probably set to OMEMO, and because an extra option got inserted (i.e. Plaintext Opportunistic OTR) that effectively moved the selection one up (since it's an enum after all). Doesn't seem like much you could do about it, but I figured I'd document the behaviour here. In any case: switching it to 'OMEMO' fixed a "could not find any trusted devices" error.

  19. chrisballinger commented on Dec 10, 2016

    @chrisballinger
    chrisballinger
    on Dec 10, 2016
    Member

    @joostrijneveld Oh yeah, I changed the enum and forgot to mention in the release notes that it might change your manual override if you've installed a previous beta version.

    In any case: switching it to 'OMEMO' fixed a "could not find any trusted devices" error.

    That's really weird and most likely just a coincidence.. I think.

  20. ronnicek commented on Dec 10, 2016

    @ronnicek
    ronnicek
    on Dec 10, 2016

    great! :) I will do some more testing tomorrow and let you know..

    what I found so far is that I was not able to initial OMEMO session from ChatSecure. When I wrote from Gajim -> ChatSecure then ChatSecure have OMEMO available (till then it was unavalaible)

  21. chrisballinger commented on Dec 10, 2016

    @chrisballinger
    chrisballinger
    on Dec 10, 2016
    Member

    @ronnicek Hmmm that's not good. We we might still have a bug there. Either Gajim isn't publishing its devices in a way that we can understand, or we have a bug processing them. Device list updates should be "automatically" handled by PEP, but I've found that PEP can be buggy and unreliable.

    Would you mind testing some or all of the following scenarios? Fresh JIDs should be used for both sides.

    • Does starting a fresh OMEMO conversation from Conversations to Gajim work?

    • Does starting a fresh OMEMO conversation from ChatSecure to Conversations work?

    • Does starting a fresh OMEMO conversation from ChatSecure to ChatSecure work?

    Thanks!

  22. ronnicek commented on Dec 12, 2016

    @ronnicek
    ronnicek
    on Dec 12, 2016

    So.. my testing (sorry for delay, I didn't make it yesterday).

    I dont have second device with ChatSecure, so I was not able to test third scenario..

    First scenario:

    • Created new account on server, set it up in Conversations
    • Created new account on server, set it up in Gajim
    • Add Gajim buddy from Conversations
    • Try to send OMEMO (i found bug, that Gajim has to be restarted to get OMEMO working - so I will report that)
    • It works after restart of Gajim

    Second scenario:

    • Created new account on server, set it up in Conversations
    • Created new account on server, set it up in ChatSecure
    • Add Conversations buddy from ChatSecure
    • OMEMO works just right away

    Funny is, that I added Gajim buddy on Conversations (second account) and I am not able to start OMEMO conversations from Conversations. After reconnect account on Conversations OMEMO starts working.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Metadata

Metadata

Assignees

No one assigned

    Labels

    No labels
    No labels

    Type

    No type

    Projects

    No projects

      Milestone

      No milestone

      Relationships

      None yet

      Development

      No branches or pull requests

      Issue actions