Skip to content

Joining groups via link from old clients (2.22) hangs on recent versions (2.57+) #8608

Description

@j4n
  • Operating System: Linux
  • Core Version: 2.57.0, bug reproduces with deltachat-rpc-server 2.59; does not reproduce with core 2.56.0
  • Client Version: cmsend 0.5.0, Desktop 2.22 / 2.59

Expected behavior

Joining a group via a link created by Desktop 2.22 should complete the secure-join handshake and add the device to the group.

Actual behavior

The join hangs indefinitely. With cmsends' -vvv logging we see that the message vg-request is sent unencrypted and the relay's filtermail rejects it:

Permanent(Response { code: Code { severity: PermanentNegativeCompletion, category: Connections, detail: Three }, message: ["Encryption Needed: Invalid Unencrypted Mail"] })

Core then retries every 30s and never gets further, so the join hangs indefinitely.

This looks like a regression introduced somewhere between core 2.56.0 (join succeeds) and 2.57.0 (join hangs, vg-request rejected unencrypted), it reproduces on Desktop 2.59 with an indefinite hang.

Steps to reproduce the problem

  1. Get join link generated by an old Desktop client (I used 2.22)
  2. Either:
  • uvx cmsend --init ci-chatmail.testrun.org then uvx cmsend -vvv -t LOG --join "<join-link>" or
  • Try to join with a recent Desktop client
  1. Observe the hang

Logs

$ uvx cmsend --init ci-chatmail.testrun.org
# creating profile on ci-chatmail.testrun.org
$ uvx cmsend -vvv -t LOG --join "https://i.delta.chat/#F5519REDACT&a=vx3redact%40ci%2Dchatmail.testrun.org&g=join%2Dtest&x=vI_h03redact&i=yuJredact-bo6YYCUvDl8dx&s=M2fpredact"
# using accounts_dir at: /home/ja/.config/cmsend
profile Profile<s0poxq0zu@ci-chatmail.testrun.org> is active
INFO 00000.7ms: src/scheduler.rs:72: starting IO
INFO 00000.9ms: src/scheduler.rs:354: Starting inbox loop.
INFO 00000.9ms: src/scheduler.rs:561: Starting SMTP loop.
INFO 00001.0ms: src/scheduler.rs:374: Transport 1: Preparing new IMAP session for inbox.
INFO 00001.0ms: src/imap.rs:304: Connecting to IMAP server.
got event: {'kind': 'ConnectivityChanged'}
INFO 00001.1ms: src/scheduler.rs:721: scheduler is running
got event: {'kind': 'ConnectivityChanged'}
INFO 00001.1ms: src/location.rs:731: Location loop is waiting for 24h 0m 0s or interrupt
INFO 00001.2ms: src/contact.rs:2152: Recently seen loop waiting for 24h 0m 0s or interrupt
INFO 00001.2ms: src/ephemeral.rs:610: Ephemeral loop waiting for deletion in 24h 0m 0s or interrupt
INFO 00001.2ms: src/smtp.rs:538: Selected rows from SMTP queue: [].
INFO 00001.3ms: src/imap.rs:319: IMAP trying to connect to ci-chatmail.testrun.org:993:tls.
INFO 00001.3ms: src/net/dns.rs:140: No memory-cached DNS resolution for ci-chatmail.testrun.org available, waiting for the resolver.
INFO 00001.4ms: src/scheduler.rs:601: SMTP fake idle started.
got event: {'kind': 'ConnectivityChanged'}
INFO 00001.4ms: src/scheduler.rs:629: SMTP has no messages to retry, waiting for interrupt.
INFO 00001.5ms: src/key.rs:482: Generating keypair.
INFO 00001.5ms: src/net/dns.rs:180: Resolved ci-chatmail.testrun.org into 2a01:4f8:c013:13c3::1.
INFO 00001.5ms: src/net/dns.rs:180: Resolved ci-chatmail.testrun.org into 49.12.217.82.
INFO 00001.6ms: src/imap/client.rs:134: Attempting IMAP connection to ci-chatmail.testrun.org ([2a01:4f8:c013:13c3::1]:993).
got event: {'kind': 'AccountsItemChanged'}
INFO 00001.6ms: src/key.rs:488: Keypair generated in 0s.
INFO 00001.7ms: src/key.rs:133: Converting secret key to public key.
INFO 00001.7ms: src/contact.rs:1096: Added contact id=10 fpr=F5519REDACT addr=vx3redact@ci-chatmail.testrun.org.
INFO 00001.7ms: src/securejoin.rs:247: Requesting secure-join ...
got event: {'chat_id': 12, 'kind': 'MsgsChanged', 'msg_id': 12}
got event: {'kind': 'ChatlistChanged'}
got event: {'chat_id': 12, 'kind': 'ChatlistItemChanged'}
got event: {'chat_id': 0, 'kind': 'MsgsChanged', 'msg_id': 0}
got event: {'kind': 'ChatlistChanged'}
got event: {'chat_id': 12, 'kind': 'ChatlistItemChanged'}
got event: {'contact_id': None, 'kind': 'ContactsChanged'}
INFO 00002.0ms: src/ephemeral.rs:610: Ephemeral loop waiting for deletion in 24h 0m 0s or interrupt
INFO 00002.0ms: src/mimefactory.rs:1853: Sending secure-join message "vg-request".
INFO 00002.2ms: src/chat.rs:2921: Message Msg#13 will be sent in one shot (no pre- and post-message). Size: 1.43 KiB.
INFO 00002.4ms: src/scheduler.rs:633: SMTP fake idle interrupted.
INFO 00002.5ms: src/smtp.rs:538: Selected rows from SMTP queue: [1].
got event: {'kind': 'ConnectivityChanged'}
got event: {'chat_id': 13, 'kind': 'MsgsChanged', 'msg_id': 14}
got event: {'kind': 'ChatlistChanged'}
got event: {'chat_id': 13, 'kind': 'ChatlistItemChanged'}
INFO 00002.6ms: src/chat.rs:320: Created group/broadcast 'join-test' grpid=vI_h03redact as Chat#13, blocked=Not.
INFO 00002.7ms: src/smtp.rs:130: SMTP trying to connect to ci-chatmail.testrun.org:465:tls.
INFO 00002.7ms: src/net/dns.rs:134: Using memory-cached DNS resolution for ci-chatmail.testrun.org.
INFO 00002.7ms: src/net/dns.rs:180: Resolved ci-chatmail.testrun.org into 2a01:4f8:c013:13c3::1.
got event: {'chat_id': 13, 'kind': 'MsgsChanged', 'msg_id': 15}
got event: {'kind': 'ChatlistChanged'}
got event: {'chat_id': 13, 'kind': 'ChatlistItemChanged'}
INFO 00002.9ms: src/net/dns.rs:180: Resolved ci-chatmail.testrun.org into 49.12.217.82.
INFO 00002.9ms: src/smtp/connect.rs:87: Attempting SMTP connection to ci-chatmail.testrun.org ([2a01:4f8:c013:13c3::1]:465).
INFO 00078.9ms: src/imap.rs:344: Logging into IMAP server with LOGIN.
got event: {'kind': 'ImapConnected', 'msg': 'IMAP-LOGIN as s0poxq0zu@ci-chatmail.testrun.org'}
got event: {'kind': 'ConnectivityChanged'}
INFO 00161.9ms: src/imap.rs:404: Successfully logged into IMAP server.
INFO 00161.9ms: src/scheduler.rs:387: Transport 1: Prepared new IMAP session for inbox.
INFO 00162.0ms: src/quota.rs:88: Transport 1: Updating quota.
INFO 00195.8ms: src/quota.rs:106: Transport 1: Updated quota.
got event: {'kind': 'ConnectivityChanged'}
INFO 00196.2ms: src/imap.rs:1347: Server supports metadata, retrieving server comment and admin contact.
got event: {'kind': 'SmtpConnected', 'msg': 'SMTP-LOGIN as s0poxq0zu@ci-chatmail.testrun.org ok'}
INFO 00250.5ms: src/smtp.rs:386: Try number 1 to send message Msg#13 (entry 1) over SMTP.
got event: {'kind': 'ConnectivityChanged'}
INFO 00269.2ms: src/imap/select_folder.rs:78: Transport 1: Selected folder "INBOX".
INFO 00269.5ms: src/imap.rs:529: Transport 1: No new emails in folder "INBOX".
got event: {'kind': 'ConnectivityChanged'}
got event: {'kind': 'ImapInboxIdle'}
INFO 00303.4ms: src/imap/idle.rs:73: Transport 1: IDLE entering wait-on-remote state in folder "INBOX".
INFO 00392.6ms: src/smtp.rs:206: SMTP failed to send: Permanent(Response { code: Code { severity: PermanentNegativeCompletion, category: Connections, detail: Three }, message: ["Encryption Needed: Invalid Unencrypted Mail"] }).
INFO 00392.8ms: src/smtp.rs:239: Permanent error, message sending failed.
INFO 00392.8ms: src/smtp.rs:282: Failed to send message over SMTP, disconnecting.
INFO 00393.1ms: src/message.rs:1985: Msg#13 failed: Permanent SMTP error: permanent: Encryption Needed: Invalid Unencrypted Mail
Message failed: Secure-Join: vg-request
got event: {'chat_id': 12, 'kind': 'ChatlistItemChanged'}
got event: {'chat_id': 12, 'kind': 'MsgsChanged', 'msg_id': 16}
got event: {'kind': 'ChatlistChanged'}
got event: {'chat_id': 12, 'kind': 'ChatlistItemChanged'}
INFO 00397.5ms: src/scheduler.rs:579: send_smtp_messages failed: Failed to send message: Permanent SMTP error: permanent: Encryption Needed: Invalid Unencrypted Mail.
INFO 00397.6ms: src/scheduler.rs:601: SMTP fake idle started.
got event: {'kind': 'ConnectivityChanged'}
INFO 00397.6ms: src/scheduler.rs:613: SMTP has messages to retry, planning to retry 30 seconds later.
INFO 30395.5ms: src/scheduler.rs:633: SMTP fake idle interrupted.
INFO 30396.1ms: src/smtp.rs:538: Selected rows from SMTP queue: [].
INFO 30396.1ms: src/scheduler.rs:601: SMTP fake idle started.
got event: {'kind': 'ConnectivityChanged'}
INFO 30396.2ms: src/scheduler.rs:629: SMTP has no messages to retry, waiting for interrupt.

Metadata

Metadata

Assignees

Labels

bugSomething is not working

Type

No type

Projects

No projects

Milestone

No milestone

Relationships

None yet

Development

No branches or pull requests

Issue actions