- 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
- Get join link generated by an old Desktop client (I used 2.22)
- 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
- 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.
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'
-vvvlogging we see that the messagevg-requestis sent unencrypted and the relay's filtermail rejects it: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-requestrejected unencrypted), it reproduces on Desktop 2.59 with an indefinite hang.Steps to reproduce the problem
uvx cmsend --init ci-chatmail.testrun.orgthenuvx cmsend -vvv -t LOG --join "<join-link>"orLogs