teams-bot init always fails the first time #14

New Issue

Closed

opened 2023-12-15 20:00:00 +00:00 by missytake · 3 comments

missytake commented

2023-12-15 20:00:00 +00:00

Owner

Expected Behavior

During teams-bot init, when I scan the QR code, it performs a normal secure-join.

Actual Behavior

When I run teams-bot init the first time, the secure-join protocol just doesn't complete. The vg-request message is moved into the DeltaChat folder and stays there.
When I run teams-bot init a second time and try again with a newly generated QR code (and chat group), it suddenly works.

Steps to Reproduce

Add a new teams-bot to bomba like this: 5f86566f41
Generate a new passphrase with pass generate -n delta/testrun.org/$addr (can also be nine.testrun.org for example, but testrun.org needs to be in the pass path atm because of teamsbot-deploy.py)
With activated venv, run pyinfra servers/bomba/inventory.py servers/bomba/teamsbot-deploy.py
Login to bomba, and the user account
run export $(cat ~/.env | xargs) && ~/.local/lib/teams-bot.venv/bin/teams-bot init -v
scan the QR code from the command line
after seeing that the securejoin doesn't complete, press ctrl^C
run export $(cat ~/.env | xargs) && ~/.local/lib/teams-bot.venv/bin/teams-bot init -v again
watch securejoin complete successfully

## Expected Behavior - During `teams-bot init`, when I scan the QR code, it performs a normal secure-join. ## Actual Behavior - When I run `teams-bot init` the first time, the secure-join protocol just doesn't complete. The `vg-request` message is moved into the DeltaChat folder and stays there. - When I run `teams-bot init` a second time and try again with a newly generated QR code (and chat group), it suddenly works. ## Steps to Reproduce - Add a new teams-bot to bomba like this: https://github.com/deltachat/sysadmin-pyinfra/commit/5f86566f412b595c9046e47ee67c5b2bed1ed14b - Generate a new passphrase with `pass generate -n delta/testrun.org/$addr` (can also be nine.testrun.org for example, but `testrun.org` needs to be in the pass path atm because of `teamsbot-deploy.py`) - With activated `venv`, run `pyinfra servers/bomba/inventory.py servers/bomba/teamsbot-deploy.py` - Login to bomba, and the user account - run `export $(cat ~/.env | xargs) && ~/.local/lib/teams-bot.venv/bin/teams-bot init -v` - scan the QR code from the command line - after seeing that the securejoin doesn't complete, press ctrl^C - run `export $(cat ~/.env | xargs) && ~/.local/lib/teams-bot.venv/bin/teams-bot init -v` again - watch securejoin complete successfully

missytake commented

2023-12-15 20:08:11 +00:00

Poster

Owner

log output (first run):

ac1dvsjns_c1.testrun.org@bomba:~$ export $(cat ~/.env | xargs) && ~/.local/lib/teams-bot.venv/bin/teams-bot init -v
INFO:the delta chat database path is /home/ac1dvsjns_c1.testrun.org/.config/teams_bot/ac1dvsjns@c1.testrun.org/delta.sqlite
0.00 [events] INFO src/sql/migrations.rs:798: Created new database; [migration] v68-v105
0.00 [events] INFO src/sql.rs:292: Opened database "/home/ac1dvsjns_c1.testrun.org/.config/teams_bot/ac1dvsjns@c1.testrun.org/delta.sqlite".
0.00 [events] INFO src/configure.rs:110: Configure ...
0.00 [events] DC_EVENT_CONFIGURE_PROGRESS data1=1 data2=None
0.00 [events] DC_EVENT_CONFIGURE_PROGRESS data1=200 data2=None
0.00 [events] INFO src/configure.rs:229: checking internal provider-info for offline autoconfig
0.00 [events] INFO src/configure.rs:244: offline autoconfig found
0.00 [events] DC_EVENT_CONFIGURE_PROGRESS data1=500 data2=None
0.00 [events] DC_EVENT_CONFIGURE_PROGRESS data1=550 data2=None
0.00 [events] DC_EVENT_CONFIGURE_PROGRESS data1=600 data2=None
0.00 [events] INFO src/configure.rs:593: Trying: imap: ac1dvsjns@c1.testrun.org@c1.testrun.org:993 security=Ssl certificate_checks=strict oauth2=false socks5_config=None
0.00 [events] INFO src/configure.rs:645: Trying: smtp: ac1dvsjns@c1.testrun.org@c1.testrun.org:465 security=Ssl certificate_checks=strict oauth2=false socks5_config=None
0.00 [events] DC_EVENT_CONNECTIVITY_CHANGED data1=0 data2=0
0.00 [events] INFO src/imap.rs:321: Connecting to IMAP server
0.03 [events] INFO src/net.rs:71: Resolved c1.testrun.org:465 into [2a01:4f9:c010:c59c::1]:465.
0.03 [events] INFO src/net.rs:71: Resolved c1.testrun.org:465 into 95.216.150.74:465.
0.03 [events] INFO src/net.rs:71: Resolved c1.testrun.org:993 into [2a01:4f9:c010:c59c::1]:993.
0.03 [events] INFO src/net.rs:71: Resolved c1.testrun.org:993 into 95.216.150.74:993.
0.08 [events] INFO src/imap.rs:391: Logging into IMAP server with LOGIN
0.15 [events] DC_EVENT_IMAP_CONNECTED data1=0 data2=IMAP-LOGIN as ac1dvsjns@c1.testrun.org
0.15 [events] DC_EVENT_CONNECTIVITY_CHANGED data1=0 data2=0
0.15 [events] INFO src/imap.rs:408: Successfully logged into IMAP server
0.15 [events] INFO src/configure.rs:617: success: imap: ac1dvsjns@c1.testrun.org@c1.testrun.org:993 security=Ssl certificate_checks=strict oauth2=false socks5_config=None
0.15 [events] DC_EVENT_CONFIGURE_PROGRESS data1=850 data2=None
0.23 [events] DC_EVENT_SMTP_CONNECTED data1=0 data2=SMTP-LOGIN as ac1dvsjns@c1.testrun.org ok
0.23 [events] INFO src/configure.rs:657: success: smtp: ac1dvsjns@c1.testrun.org@c1.testrun.org:465 security=Ssl certificate_checks=strict oauth2=false socks5_config=None
0.23 [events] DC_EVENT_CONFIGURE_PROGRESS data1=900 data2=None
0.23 [events] INFO src/imap.rs:1744: Scanning folder: Name { owner: ResponseData { raw: 4096, response: MailboxData(List { name_attributes: [Extension("\\HasNoChildren")], delimiter: Some("."), name: "INBOX" }) }, dependent: InnerName { attributes: [Extension("\\HasNoChildren")], delimiter: Some("."), name: "INBOX" } }
0.23 [events] INFO src/imap.rs:1768: Using "." as folder-delimiter.
0.23 [events] INFO src/imap.rs:1700: Looking for MVBOX-folder "DeltaChat"...
0.23 [events] INFO src/imap.rs:1700: Looking for MVBOX-folder "INBOX.DeltaChat"...
0.25 [events] INFO src/imap.rs:1716: MVBOX-folder DeltaChat created.
0.25 [events] INFO src/imap.rs:1780: Setting MVBOX FOLDER TO DeltaChat
0.25 [events] INFO src/imap.rs:1793: FINISHED configuring IMAP-folders.
0.26 [events] INFO src/imap.rs:700: uid/validity change folder INBOX: new 1/1702670667 previous 0/0.
0.26 [events] DC_EVENT_CONFIGURE_PROGRESS data1=910 data2=None
0.26 [events] DC_EVENT_CONFIGURE_PROGRESS data1=920 data2=None
0.26 [events] INFO src/key.rs:213: Generating keypair with type Default
0.27 [events] INFO src/key.rs:219: Keypair generated in 0s.
0.27 [events] INFO src/configure.rs:482: key generation completed
0.27 [events] DC_EVENT_CONFIGURE_PROGRESS data1=940 data2=None
0.27 [events] INFO src/configure.rs:135: apply config_defaults mvbox_move=0
0.27 [events] DC_EVENT_CONFIGURE_PROGRESS data1=1000 data2=None
0.27 [events] INFO src/scheduler.rs:66: starting IO
0.27 [events] INFO src/scheduler.rs:366: starting inbox loop
0.27 [events] DC_EVENT_CONNECTIVITY_CHANGED data1=0 data2=0
0.27 [events] INFO src/imap.rs:321: Connecting to IMAP server
0.27 [events] INFO src/scheduler.rs:693: starting smtp loop
0.27 [events] INFO src/scheduler.rs:858: scheduler is running
0.27 [events] INFO src/contact.rs:1736: Recently seen loop waiting for 24h 0m 0s or interrupt
0.27 [events] INFO src/net.rs:71: Resolved c1.testrun.org:993 into [2a01:4f9:c010:c59c::1]:993.
0.27 [events] INFO src/smtp.rs:652: Selected rows from SMTP queue: [].
0.27 [events] INFO src/net.rs:71: Resolved c1.testrun.org:993 into 95.216.150.74:993.
0.27 [events] INFO src/smtp.rs:757: Sending MDNs
0.27 [events] INFO src/scheduler.rs:728: smtp fake idle - started
0.27 [events] DC_EVENT_CONNECTIVITY_CHANGED data1=0 data2=0
0.27 [events] INFO src/scheduler.rs:756: smtp has no messages to retry, waiting for interrupt
0.27 [events] INFO src/ephemeral.rs:567: Ephemeral loop waiting for deletion in 24h 0m 0s or interrupt
0.27 [events] INFO src/location.rs:676: Location loop is waiting for 24h 0m 0s or interrupt
0.27 [events] DC_EVENT_MSGS_CHANGED data1=0 data2=0
0.27 [events] DC_EVENT_CHAT_MODIFIED data1=10 data2=0
0.27 [events] INFO src/chat.rs:1269: Set gossiped_timestamp for chat Chat#10 to 0.
0.27 [events] DC_EVENT_MSGS_CHANGED data1=10 data2=10
0.27 [events] INFO src/sync.rs:136: group 'xrMTcqfHBMf' not yet promoted, do not sync tokens yet.

Please scan this qr code with Delta Chat to join the verified crew group:


0.27 [events] INFO src/securejoin.rs:126: Generated QR code: OPENPGP4FPR:14ACB65317C4F6602D62A63327089749B82CFE73#a=ac1dvsjns%40c1.testrun.org&g=Team%3A%20ac1dvsjns%40c1%2Etestrun%2Eorg&x=xrMTcqfHBMf&i=wDWp2BW75Q5&s=3gCViY6zTU0
█████████████████████████████████████████████████████████
█████████████████████████████████████████████████████████
████ ▄▄▄▄▄ █▄ ▀███ ▀▀ ▀█▄▀▀▀▄▀█▀▀█▄ ███▀█ ▀▀ █ ▄▄▄▄▄ ████
████ █   █ █▀▄▄█▄▀▀██▄▄█▄ █ ▄▀█▄▄ ▄█▀▄  █ █ ▄█ █   █ ████
████ █▄▄▄█ █    █ █▄█ ▄  ▄ ▄▄▄  ▀▀ ▄███▀▀▀▀███ █▄▄▄█ ████
████▄▄▄▄▄▄▄█ ▀ █ █ █ █ █▄▀ █▄█ ▀ █ █▄█ ▀ ▀ █ █▄▄▄▄▄▄▄████
████▄▀█▀ █▄ ▄▄█▀ ▀ ▄ ▄█  ▀  ▄ ▄▄▀▀▀ ██▄▄ █▄▀▀▄ ▄  ██▄████
████ █▀█▄█▄ ▀▀▀▄█ █▀▄▀▄  ▄▀   ▀▀▀▄▀▄▄▄██▄▀▀▄  ▀█  ▄ █████
████▄█▀▀▀▄▄███▀   ███ ▀  ▀█ ▀▄▄▄██▄ ▀▀█▀ █ ▀▄██▀ █  ▀████
████ █  ▄▀▄▀ ███ █ ▀▀█▄▀▄▄█▀ ▀▄ ▄▄▄▄ ▄▀▀ ▀▀▄██ ▄  █▄█████
████▄▄███▀▄▄  ▀▄ █▀██ █ ███▀█ ▄▄▀██ █▀▄▄█▀ ▀██▄ ▄▀█▄▄████
████ █ ▄ ▄▄▄██   ▀▄ ▀ ▄ ▄▀▀███ ▀▄▄ ▄▀   ▄▀▄█▄▄█▄█▀ ▄▄████
████▄▀ ▀▀ ▄▀█▀▄ ▄▀▀▄▄▄█ █▀  █▄ █ █▄ ▀█ ██▀▀▀▀█▀█▄ ███████
█████▄▀▄ ▄▄▄ ▄▀█▀██▀▄▄█▀█  ▄▄▄ ▀█▄▀█ ▄▀▀█ ▀  ▄▄▄ ▀█ █████
████▀██  █▄█ ▀▄▄█▀█ ▄█  ▄▄ █▄█  ▄██▀▄ ▀█▄▄▀█ █▄█ ▀▄██████
████ █   ▄▄  █▄▄▄ ▄█▄▄▀▀▀█ ▄▄▄ ▀▀▄  ▄▄ ▀█▀  ▄  ▄▄▄▀▀█████
██████ ▄█▄▄▀█▀█   █▀▄ ▀ █▀▄█▀▀▀▄█▀▀▄▀█▄█ █▄▄▀█▀▄▄▀▀▄ ████
█████▄█  █▄▄█▀▀▄ ▀ ▄█▄ █ █▀█▀▀█ █▄▄█▀ █ ▄▀█▀▄▀█▀▀▄ ▀▀████
████ █▄▀██▄▄  █ ▄▄▄█ █   ▄ ██▀ ▀ ▀▄▀█▀██▀▀█ ▀▄▀ ▀█ █▀████
████▄▄▀▀██▄ ▀█▄▄▀█▄▄ ▀▄  ▄▀ ▀▄▄▀  █▄█ ▄  ▀ █▄▄▄▀▀▀▀▀▀████
████▀▀█ █▄▄██▀ ▄ █▄ ▀█▄ █▄▀▀█▀▄▄▀▄ ▀▄▄██▀█▀▀▀▄█▄▀ ▀▄█████
█████ ▀▀█▄▄▄ ▀▄▀▀ █ ▄█▄ ▀▄▄▄▀▄█▀▀█▀▄▀▄█▀█ ██▄▀▄▀▀  ▀▀████
████▄▄▄███▄█▀███ █▀▀█▄▀█▀▄ ▄▄▄  ▄ ▄ ▀█ ██ ▄▀ ▄▄▄ ▀▄▄ ████
████ ▄▄▄▄▄ █▄█▀▄ ▀▀▄█ ██▄  █▄█ █ ▄▀▄▄▄ ▀█▀ ▄ █▄█  ▀▀▀████
████ █   █ █▄ █▄▀ ▀ ▄   ▄█ ▄▄ ▄█████▀█▀ ▀▄▀▄  ▄ ▄▀▀ ▀████
████ █▄▄▄█ ██▄▄ ▀ ▄▄ ███ ▀ ▄ ▀ ▀▄▄▀█▀ █ ▀▀ ▄▀ ▀ █ ▀ ▀████
████▄▄▄▄▄▄▄█▄▄█████▄▄▄█▄▄▄▄▄▄▄▄▄██████▄▄█▄██▄█▄███▄█▄████
█████████████████████████████████████████████████████████
▀▀▀▀▀▀▀▀▀▀▀▀▀▀▀▀▀▀▀▀▀▀▀▀▀▀▀▀▀▀▀▀▀▀▀▀▀▀▀▀▀▀▀▀▀▀▀▀▀▀▀▀▀▀▀▀▀

Alternatively, copy-paste this invite to your Delta Chat desktop client: OPENPGP4FPR:14ACB65317C4F6602D62A63327089749B82CFE73#a=ac1dvsjns%40c1.testrun.org&g=Team%3A%20ac1dvsjns%40c1%2Etestrun%2Eorg&x=xrMTcqfHBMf&i=wDWp2BW75Q5&s=3gCViY6zTU0

Waiting until you join the chat
0.29 [events] INFO src/imap.rs:391: Logging into IMAP server with LOGIN
0.32 [events] DC_EVENT_IMAP_CONNECTED data1=0 data2=IMAP-LOGIN as ac1dvsjns@c1.testrun.org
0.32 [events] DC_EVENT_CONNECTIVITY_CHANGED data1=0 data2=0
0.32 [events] INFO src/imap.rs:408: Successfully logged into IMAP server
0.32 [events] DC_EVENT_CONNECTIVITY_CHANGED data1=0 data2=0
0.32 [events] INFO src/sql.rs:806: Start housekeeping...
0.32 [events] INFO src/sql.rs:852: 0 files in use.
0.32 [events] INFO src/sql.rs:787: Housekeeping done.
0.33 [events] INFO src/imap.rs:733: No new emails in folder "INBOX".
0.33 [events] INFO src/imap/scan_folders.rs:27: Starting full folder scan
0.33 [events] INFO src/imap.rs:911: 0 mails read from "INBOX".
0.33 [events] DC_EVENT_CONNECTIVITY_CHANGED data1=0 data2=0
0.33 [events] DC_EVENT_IMAP_INBOX_IDLE data1=0 data2=None
0.33 [events] INFO src/scheduler.rs:629: IMAP session supports IDLE, using it.
0.33 [events] INFO src/imap/idle.rs:54: INBOX: Idle entering wait-on-remote state
25.69 [events] INFO src/imap/idle.rs:66: INBOX: Idle has NewData ResponseData { raw: 4096, response: MailboxData(Exists(1)) }
25.70 [events] INFO src/imap.rs:911: 1 mails read from "INBOX".
25.71 [events] DC_EVENT_IMAP_MESSAGE_MOVED data1=0 data2=IMAP messages 1 moved to DeltaChat
25.71 [events] DC_EVENT_CONNECTIVITY_CHANGED data1=0 data2=0
25.71 [events] DC_EVENT_IMAP_INBOX_IDLE data1=0 data2=None
25.71 [events] INFO src/scheduler.rs:629: IMAP session supports IDLE, using it.
25.71 [events] INFO src/imap.rs:1833: got unsolicited response Other(ResponseData { raw: 4096, response: Data { status: Ok, code: Some(CopyUid(1702670666, [Uid(1)], [Uid(1)])), information: Some("Moved UIDs.") } })
25.71 [events] INFO src/imap/idle.rs:54: INBOX: Idle entering wait-on-remote state

Arrived mails at this point:

root@c1:~# cat /home/vmail/mail/c1.testrun.org/ac1dvsjns@c1.testrun.org/.DeltaChat/new/*
Return-Path: <nami@nine.testrun.org>
Delivered-To: ac1dvsjns@c1.testrun.org
Received: from c1.testrun.org
	by c1 with LMTP
	id shs1LWOxfGXE/xUATIUtfQ
	(envelope-from <nami@nine.testrun.org>)
	for <ac1dvsjns@c1.testrun.org>; Fri, 15 Dec 2023 20:04:51 +0000
Authentication-Results: c1.testrun.org;
	dkim=pass (2048-bit key; unprotected) header.d=nine.testrun.org header.i=@nine.testrun.org header.a=rsa-sha256 header.s=dkim header.b=goTfwa/G;
	dkim-atps=neutral
Received: from nine.testrun.org (nine.testrun.org [116.202.233.236])
	by c1.testrun.org (Postfix) with ESMTPS id 7B60D1F5B7
	for <ac1dvsjns@c1.testrun.org>; Fri, 15 Dec 2023 20:04:51 +0000 (UTC)
DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/simple; d=nine.testrun.org;
	s=dkim; t=1702670690;
	bh=LHBeJzy74mGEu33xoiSXZEUjY5UlacVGVji5z9K5BW8=;
	h=Subject:From:To:Date:References:From;
	b=goTfwa/GPm50Srt1Kp3mC0dxToR46GdQMdR4fnpJtbYFcUvCO7kNuX/kfJ+QpUC10
	 yRorV0imaNIgHDfw88xySkRtG3DFTGhzE1MFCaFUaFFLv3ywmzK6DK3y2PNXSzz0t6
	 ZRrtCo/zRYk4wiCOY4+K25VxwBwd5wqUDxqe6dqRH8PmhC5Y6mTwx/GWb21XsEg+0q
	 weCUzwhIU6c+8m+kN9hoEHocKmAJ3H6Z+QChHVvgXiIm4L2H8geGiaypFTRltfRuKd
	 kmvHFyy8FhyRbNcoPctLeMjwZAkHQFSNUs1evJogr4yCUQH6hAzqJbXs6s7bg/L64K
	 wMKoNbjnHXZrg==
Received: from [127.0.0.1] (localhost.localdomain [127.0.0.1])
	by nine.testrun.org (Postfix) with ESMTP id EB9C917C0937;
	Fri, 15 Dec 2023 21:04:50 +0100 (CET)
Received: from [127.0.0.1] (46.183.103.17.relaix.net [46.183.103.17])
	by nine.testrun.org (Postfix) with UTF8SMTPSA;
	Fri, 15 Dec 2023 21:04:50 +0100 (CET)
Subject: Message from Nami
Secure-Join: vg-request
Secure-Join-Invitenumber: wDWp2BW75Q5
Secure-Join-Fingerprint: F78A02546E5360608A450EBBC732676C53D60629
Secure-Join-Group: xrMTcqfHBMf
Chat-User-Avatar: 0
From: Nami <nami@nine.testrun.org>
To: <ac1dvsjns@c1.testrun.org>
Date: Fri, 15 Dec 2023 20:04:51 +0000
Message-ID: <Mr.28HVp8rUC4a.yeIiagzZixY@nine.testrun.org>
References: <Mr.28HVp8rUC4a.yeIiagzZixY@nine.testrun.org>
Chat-Version: 1.0
Autocrypt: addr=nami@nine.testrun.org; prefer-encrypt=mutual;
	keydata=xjMEZS7N+xYJKwYBBAHaRw8BAQdADetj2PiV7JXDa3TwMW+rannKREJlokrfz3zFoZnxVv
	3NFzxuYW1pQG5pbmUudGVzdHJ1bi5vcmc+wosEEBYIADMCGQEFAmUuzfsCGwMECwkIBwYVCAkKCwID
	FgIBFiEE94oCVG5TYGCKRQ67xzJnbFPWBikACgkQxzJnbFPWBikKiwD/ejO7DqEoH6PIUq8aaoNCGJ
	Yks8k0FVqogzKNMtQRWL0BAJNEORlikNoFjMuh/T3l7Ysohe+pfbqnhkL+H03qAS0IzjgEZS7N+xIK
	KwYBBAGXVQEFAQEHQD6Y8j/KXRoVqRnGpNyI3zNodqlCUBQW0aRK5oYWQ68PAwEIB8J4BBgWCAAgBQ
	JlLs37AhsMFiEE94oCVG5TYGCKRQ67xzJnbFPWBikACgkQxzJnbFPWBimEIgEAjPEyf7CCQurxBmFj
	gZIsozUfMwNvqJP7qnaUHAVMDIIA/jr0lwsXq9/D1niBCsZjdlw/mdATWORKnjWNe4mE8AwC
MIME-Version: 1.0
Content-Type: text/plain; charset=utf-8; format=flowed; delsp=no

Secure-Join: vg-request

After that, nothing happens.

log output (first run): ``` ac1dvsjns_c1.testrun.org@bomba:~$ export $(cat ~/.env | xargs) && ~/.local/lib/teams-bot.venv/bin/teams-bot init -v INFO:the delta chat database path is /home/ac1dvsjns_c1.testrun.org/.config/teams_bot/ac1dvsjns@c1.testrun.org/delta.sqlite 0.00 [events] INFO src/sql/migrations.rs:798: Created new database; [migration] v68-v105 0.00 [events] INFO src/sql.rs:292: Opened database "/home/ac1dvsjns_c1.testrun.org/.config/teams_bot/ac1dvsjns@c1.testrun.org/delta.sqlite". 0.00 [events] INFO src/configure.rs:110: Configure ... 0.00 [events] DC_EVENT_CONFIGURE_PROGRESS data1=1 data2=None 0.00 [events] DC_EVENT_CONFIGURE_PROGRESS data1=200 data2=None 0.00 [events] INFO src/configure.rs:229: checking internal provider-info for offline autoconfig 0.00 [events] INFO src/configure.rs:244: offline autoconfig found 0.00 [events] DC_EVENT_CONFIGURE_PROGRESS data1=500 data2=None 0.00 [events] DC_EVENT_CONFIGURE_PROGRESS data1=550 data2=None 0.00 [events] DC_EVENT_CONFIGURE_PROGRESS data1=600 data2=None 0.00 [events] INFO src/configure.rs:593: Trying: imap: ac1dvsjns@c1.testrun.org@c1.testrun.org:993 security=Ssl certificate_checks=strict oauth2=false socks5_config=None 0.00 [events] INFO src/configure.rs:645: Trying: smtp: ac1dvsjns@c1.testrun.org@c1.testrun.org:465 security=Ssl certificate_checks=strict oauth2=false socks5_config=None 0.00 [events] DC_EVENT_CONNECTIVITY_CHANGED data1=0 data2=0 0.00 [events] INFO src/imap.rs:321: Connecting to IMAP server 0.03 [events] INFO src/net.rs:71: Resolved c1.testrun.org:465 into [2a01:4f9:c010:c59c::1]:465. 0.03 [events] INFO src/net.rs:71: Resolved c1.testrun.org:465 into 95.216.150.74:465. 0.03 [events] INFO src/net.rs:71: Resolved c1.testrun.org:993 into [2a01:4f9:c010:c59c::1]:993. 0.03 [events] INFO src/net.rs:71: Resolved c1.testrun.org:993 into 95.216.150.74:993. 0.08 [events] INFO src/imap.rs:391: Logging into IMAP server with LOGIN 0.15 [events] DC_EVENT_IMAP_CONNECTED data1=0 data2=IMAP-LOGIN as ac1dvsjns@c1.testrun.org 0.15 [events] DC_EVENT_CONNECTIVITY_CHANGED data1=0 data2=0 0.15 [events] INFO src/imap.rs:408: Successfully logged into IMAP server 0.15 [events] INFO src/configure.rs:617: success: imap: ac1dvsjns@c1.testrun.org@c1.testrun.org:993 security=Ssl certificate_checks=strict oauth2=false socks5_config=None 0.15 [events] DC_EVENT_CONFIGURE_PROGRESS data1=850 data2=None 0.23 [events] DC_EVENT_SMTP_CONNECTED data1=0 data2=SMTP-LOGIN as ac1dvsjns@c1.testrun.org ok 0.23 [events] INFO src/configure.rs:657: success: smtp: ac1dvsjns@c1.testrun.org@c1.testrun.org:465 security=Ssl certificate_checks=strict oauth2=false socks5_config=None 0.23 [events] DC_EVENT_CONFIGURE_PROGRESS data1=900 data2=None 0.23 [events] INFO src/imap.rs:1744: Scanning folder: Name { owner: ResponseData { raw: 4096, response: MailboxData(List { name_attributes: [Extension("\\HasNoChildren")], delimiter: Some("."), name: "INBOX" }) }, dependent: InnerName { attributes: [Extension("\\HasNoChildren")], delimiter: Some("."), name: "INBOX" } } 0.23 [events] INFO src/imap.rs:1768: Using "." as folder-delimiter. 0.23 [events] INFO src/imap.rs:1700: Looking for MVBOX-folder "DeltaChat"... 0.23 [events] INFO src/imap.rs:1700: Looking for MVBOX-folder "INBOX.DeltaChat"... 0.25 [events] INFO src/imap.rs:1716: MVBOX-folder DeltaChat created. 0.25 [events] INFO src/imap.rs:1780: Setting MVBOX FOLDER TO DeltaChat 0.25 [events] INFO src/imap.rs:1793: FINISHED configuring IMAP-folders. 0.26 [events] INFO src/imap.rs:700: uid/validity change folder INBOX: new 1/1702670667 previous 0/0. 0.26 [events] DC_EVENT_CONFIGURE_PROGRESS data1=910 data2=None 0.26 [events] DC_EVENT_CONFIGURE_PROGRESS data1=920 data2=None 0.26 [events] INFO src/key.rs:213: Generating keypair with type Default 0.27 [events] INFO src/key.rs:219: Keypair generated in 0s. 0.27 [events] INFO src/configure.rs:482: key generation completed 0.27 [events] DC_EVENT_CONFIGURE_PROGRESS data1=940 data2=None 0.27 [events] INFO src/configure.rs:135: apply config_defaults mvbox_move=0 0.27 [events] DC_EVENT_CONFIGURE_PROGRESS data1=1000 data2=None 0.27 [events] INFO src/scheduler.rs:66: starting IO 0.27 [events] INFO src/scheduler.rs:366: starting inbox loop 0.27 [events] DC_EVENT_CONNECTIVITY_CHANGED data1=0 data2=0 0.27 [events] INFO src/imap.rs:321: Connecting to IMAP server 0.27 [events] INFO src/scheduler.rs:693: starting smtp loop 0.27 [events] INFO src/scheduler.rs:858: scheduler is running 0.27 [events] INFO src/contact.rs:1736: Recently seen loop waiting for 24h 0m 0s or interrupt 0.27 [events] INFO src/net.rs:71: Resolved c1.testrun.org:993 into [2a01:4f9:c010:c59c::1]:993. 0.27 [events] INFO src/smtp.rs:652: Selected rows from SMTP queue: []. 0.27 [events] INFO src/net.rs:71: Resolved c1.testrun.org:993 into 95.216.150.74:993. 0.27 [events] INFO src/smtp.rs:757: Sending MDNs 0.27 [events] INFO src/scheduler.rs:728: smtp fake idle - started 0.27 [events] DC_EVENT_CONNECTIVITY_CHANGED data1=0 data2=0 0.27 [events] INFO src/scheduler.rs:756: smtp has no messages to retry, waiting for interrupt 0.27 [events] INFO src/ephemeral.rs:567: Ephemeral loop waiting for deletion in 24h 0m 0s or interrupt 0.27 [events] INFO src/location.rs:676: Location loop is waiting for 24h 0m 0s or interrupt 0.27 [events] DC_EVENT_MSGS_CHANGED data1=0 data2=0 0.27 [events] DC_EVENT_CHAT_MODIFIED data1=10 data2=0 0.27 [events] INFO src/chat.rs:1269: Set gossiped_timestamp for chat Chat#10 to 0. 0.27 [events] DC_EVENT_MSGS_CHANGED data1=10 data2=10 0.27 [events] INFO src/sync.rs:136: group 'xrMTcqfHBMf' not yet promoted, do not sync tokens yet. Please scan this qr code with Delta Chat to join the verified crew group: 0.27 [events] INFO src/securejoin.rs:126: Generated QR code: OPENPGP4FPR:14ACB65317C4F6602D62A63327089749B82CFE73#a=ac1dvsjns%40c1.testrun.org&g=Team%3A%20ac1dvsjns%40c1%2Etestrun%2Eorg&x=xrMTcqfHBMf&i=wDWp2BW75Q5&s=3gCViY6zTU0 █████████████████████████████████████████████████████████ █████████████████████████████████████████████████████████ ████ ▄▄▄▄▄ █▄ ▀███ ▀▀ ▀█▄▀▀▀▄▀█▀▀█▄ ███▀█ ▀▀ █ ▄▄▄▄▄ ████ ████ █ █ █▀▄▄█▄▀▀██▄▄█▄ █ ▄▀█▄▄ ▄█▀▄ █ █ ▄█ █ █ ████ ████ █▄▄▄█ █ █ █▄█ ▄ ▄ ▄▄▄ ▀▀ ▄███▀▀▀▀███ █▄▄▄█ ████ ████▄▄▄▄▄▄▄█ ▀ █ █ █ █ █▄▀ █▄█ ▀ █ █▄█ ▀ ▀ █ █▄▄▄▄▄▄▄████ ████▄▀█▀ █▄ ▄▄█▀ ▀ ▄ ▄█ ▀ ▄ ▄▄▀▀▀ ██▄▄ █▄▀▀▄ ▄ ██▄████ ████ █▀█▄█▄ ▀▀▀▄█ █▀▄▀▄ ▄▀ ▀▀▀▄▀▄▄▄██▄▀▀▄ ▀█ ▄ █████ ████▄█▀▀▀▄▄███▀ ███ ▀ ▀█ ▀▄▄▄██▄ ▀▀█▀ █ ▀▄██▀ █ ▀████ ████ █ ▄▀▄▀ ███ █ ▀▀█▄▀▄▄█▀ ▀▄ ▄▄▄▄ ▄▀▀ ▀▀▄██ ▄ █▄█████ ████▄▄███▀▄▄ ▀▄ █▀██ █ ███▀█ ▄▄▀██ █▀▄▄█▀ ▀██▄ ▄▀█▄▄████ ████ █ ▄ ▄▄▄██ ▀▄ ▀ ▄ ▄▀▀███ ▀▄▄ ▄▀ ▄▀▄█▄▄█▄█▀ ▄▄████ ████▄▀ ▀▀ ▄▀█▀▄ ▄▀▀▄▄▄█ █▀ █▄ █ █▄ ▀█ ██▀▀▀▀█▀█▄ ███████ █████▄▀▄ ▄▄▄ ▄▀█▀██▀▄▄█▀█ ▄▄▄ ▀█▄▀█ ▄▀▀█ ▀ ▄▄▄ ▀█ █████ ████▀██ █▄█ ▀▄▄█▀█ ▄█ ▄▄ █▄█ ▄██▀▄ ▀█▄▄▀█ █▄█ ▀▄██████ ████ █ ▄▄ █▄▄▄ ▄█▄▄▀▀▀█ ▄▄▄ ▀▀▄ ▄▄ ▀█▀ ▄ ▄▄▄▀▀█████ ██████ ▄█▄▄▀█▀█ █▀▄ ▀ █▀▄█▀▀▀▄█▀▀▄▀█▄█ █▄▄▀█▀▄▄▀▀▄ ████ █████▄█ █▄▄█▀▀▄ ▀ ▄█▄ █ █▀█▀▀█ █▄▄█▀ █ ▄▀█▀▄▀█▀▀▄ ▀▀████ ████ █▄▀██▄▄ █ ▄▄▄█ █ ▄ ██▀ ▀ ▀▄▀█▀██▀▀█ ▀▄▀ ▀█ █▀████ ████▄▄▀▀██▄ ▀█▄▄▀█▄▄ ▀▄ ▄▀ ▀▄▄▀ █▄█ ▄ ▀ █▄▄▄▀▀▀▀▀▀████ ████▀▀█ █▄▄██▀ ▄ █▄ ▀█▄ █▄▀▀█▀▄▄▀▄ ▀▄▄██▀█▀▀▀▄█▄▀ ▀▄█████ █████ ▀▀█▄▄▄ ▀▄▀▀ █ ▄█▄ ▀▄▄▄▀▄█▀▀█▀▄▀▄█▀█ ██▄▀▄▀▀ ▀▀████ ████▄▄▄███▄█▀███ █▀▀█▄▀█▀▄ ▄▄▄ ▄ ▄ ▀█ ██ ▄▀ ▄▄▄ ▀▄▄ ████ ████ ▄▄▄▄▄ █▄█▀▄ ▀▀▄█ ██▄ █▄█ █ ▄▀▄▄▄ ▀█▀ ▄ █▄█ ▀▀▀████ ████ █ █ █▄ █▄▀ ▀ ▄ ▄█ ▄▄ ▄█████▀█▀ ▀▄▀▄ ▄ ▄▀▀ ▀████ ████ █▄▄▄█ ██▄▄ ▀ ▄▄ ███ ▀ ▄ ▀ ▀▄▄▀█▀ █ ▀▀ ▄▀ ▀ █ ▀ ▀████ ████▄▄▄▄▄▄▄█▄▄█████▄▄▄█▄▄▄▄▄▄▄▄▄██████▄▄█▄██▄█▄███▄█▄████ █████████████████████████████████████████████████████████ ▀▀▀▀▀▀▀▀▀▀▀▀▀▀▀▀▀▀▀▀▀▀▀▀▀▀▀▀▀▀▀▀▀▀▀▀▀▀▀▀▀▀▀▀▀▀▀▀▀▀▀▀▀▀▀▀▀ Alternatively, copy-paste this invite to your Delta Chat desktop client: OPENPGP4FPR:14ACB65317C4F6602D62A63327089749B82CFE73#a=ac1dvsjns%40c1.testrun.org&g=Team%3A%20ac1dvsjns%40c1%2Etestrun%2Eorg&x=xrMTcqfHBMf&i=wDWp2BW75Q5&s=3gCViY6zTU0 Waiting until you join the chat 0.29 [events] INFO src/imap.rs:391: Logging into IMAP server with LOGIN 0.32 [events] DC_EVENT_IMAP_CONNECTED data1=0 data2=IMAP-LOGIN as ac1dvsjns@c1.testrun.org 0.32 [events] DC_EVENT_CONNECTIVITY_CHANGED data1=0 data2=0 0.32 [events] INFO src/imap.rs:408: Successfully logged into IMAP server 0.32 [events] DC_EVENT_CONNECTIVITY_CHANGED data1=0 data2=0 0.32 [events] INFO src/sql.rs:806: Start housekeeping... 0.32 [events] INFO src/sql.rs:852: 0 files in use. 0.32 [events] INFO src/sql.rs:787: Housekeeping done. 0.33 [events] INFO src/imap.rs:733: No new emails in folder "INBOX". 0.33 [events] INFO src/imap/scan_folders.rs:27: Starting full folder scan 0.33 [events] INFO src/imap.rs:911: 0 mails read from "INBOX". 0.33 [events] DC_EVENT_CONNECTIVITY_CHANGED data1=0 data2=0 0.33 [events] DC_EVENT_IMAP_INBOX_IDLE data1=0 data2=None 0.33 [events] INFO src/scheduler.rs:629: IMAP session supports IDLE, using it. 0.33 [events] INFO src/imap/idle.rs:54: INBOX: Idle entering wait-on-remote state 25.69 [events] INFO src/imap/idle.rs:66: INBOX: Idle has NewData ResponseData { raw: 4096, response: MailboxData(Exists(1)) } 25.70 [events] INFO src/imap.rs:911: 1 mails read from "INBOX". 25.71 [events] DC_EVENT_IMAP_MESSAGE_MOVED data1=0 data2=IMAP messages 1 moved to DeltaChat 25.71 [events] DC_EVENT_CONNECTIVITY_CHANGED data1=0 data2=0 25.71 [events] DC_EVENT_IMAP_INBOX_IDLE data1=0 data2=None 25.71 [events] INFO src/scheduler.rs:629: IMAP session supports IDLE, using it. 25.71 [events] INFO src/imap.rs:1833: got unsolicited response Other(ResponseData { raw: 4096, response: Data { status: Ok, code: Some(CopyUid(1702670666, [Uid(1)], [Uid(1)])), information: Some("Moved UIDs.") } }) 25.71 [events] INFO src/imap/idle.rs:54: INBOX: Idle entering wait-on-remote state ``` Arrived mails at this point: ``` root@c1:~# cat /home/vmail/mail/c1.testrun.org/ac1dvsjns@c1.testrun.org/.DeltaChat/new/* Return-Path: <nami@nine.testrun.org> Delivered-To: ac1dvsjns@c1.testrun.org Received: from c1.testrun.org by c1 with LMTP id shs1LWOxfGXE/xUATIUtfQ (envelope-from <nami@nine.testrun.org>) for <ac1dvsjns@c1.testrun.org>; Fri, 15 Dec 2023 20:04:51 +0000 Authentication-Results: c1.testrun.org; dkim=pass (2048-bit key; unprotected) header.d=nine.testrun.org header.i=@nine.testrun.org header.a=rsa-sha256 header.s=dkim header.b=goTfwa/G; dkim-atps=neutral Received: from nine.testrun.org (nine.testrun.org [116.202.233.236]) by c1.testrun.org (Postfix) with ESMTPS id 7B60D1F5B7 for <ac1dvsjns@c1.testrun.org>; Fri, 15 Dec 2023 20:04:51 +0000 (UTC) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/simple; d=nine.testrun.org; s=dkim; t=1702670690; bh=LHBeJzy74mGEu33xoiSXZEUjY5UlacVGVji5z9K5BW8=; h=Subject:From:To:Date:References:From; b=goTfwa/GPm50Srt1Kp3mC0dxToR46GdQMdR4fnpJtbYFcUvCO7kNuX/kfJ+QpUC10 yRorV0imaNIgHDfw88xySkRtG3DFTGhzE1MFCaFUaFFLv3ywmzK6DK3y2PNXSzz0t6 ZRrtCo/zRYk4wiCOY4+K25VxwBwd5wqUDxqe6dqRH8PmhC5Y6mTwx/GWb21XsEg+0q weCUzwhIU6c+8m+kN9hoEHocKmAJ3H6Z+QChHVvgXiIm4L2H8geGiaypFTRltfRuKd kmvHFyy8FhyRbNcoPctLeMjwZAkHQFSNUs1evJogr4yCUQH6hAzqJbXs6s7bg/L64K wMKoNbjnHXZrg== Received: from [127.0.0.1] (localhost.localdomain [127.0.0.1]) by nine.testrun.org (Postfix) with ESMTP id EB9C917C0937; Fri, 15 Dec 2023 21:04:50 +0100 (CET) Received: from [127.0.0.1] (46.183.103.17.relaix.net [46.183.103.17]) by nine.testrun.org (Postfix) with UTF8SMTPSA; Fri, 15 Dec 2023 21:04:50 +0100 (CET) Subject: Message from Nami Secure-Join: vg-request Secure-Join-Invitenumber: wDWp2BW75Q5 Secure-Join-Fingerprint: F78A02546E5360608A450EBBC732676C53D60629 Secure-Join-Group: xrMTcqfHBMf Chat-User-Avatar: 0 From: Nami <nami@nine.testrun.org> To: <ac1dvsjns@c1.testrun.org> Date: Fri, 15 Dec 2023 20:04:51 +0000 Message-ID: <Mr.28HVp8rUC4a.yeIiagzZixY@nine.testrun.org> References: <Mr.28HVp8rUC4a.yeIiagzZixY@nine.testrun.org> Chat-Version: 1.0 Autocrypt: addr=nami@nine.testrun.org; prefer-encrypt=mutual; keydata=xjMEZS7N+xYJKwYBBAHaRw8BAQdADetj2PiV7JXDa3TwMW+rannKREJlokrfz3zFoZnxVv 3NFzxuYW1pQG5pbmUudGVzdHJ1bi5vcmc+wosEEBYIADMCGQEFAmUuzfsCGwMECwkIBwYVCAkKCwID FgIBFiEE94oCVG5TYGCKRQ67xzJnbFPWBikACgkQxzJnbFPWBikKiwD/ejO7DqEoH6PIUq8aaoNCGJ Yks8k0FVqogzKNMtQRWL0BAJNEORlikNoFjMuh/T3l7Ysohe+pfbqnhkL+H03qAS0IzjgEZS7N+xIK KwYBBAGXVQEFAQEHQD6Y8j/KXRoVqRnGpNyI3zNodqlCUBQW0aRK5oYWQ68PAwEIB8J4BBgWCAAgBQ JlLs37AhsMFiEE94oCVG5TYGCKRQ67xzJnbFPWBikACgkQxzJnbFPWBimEIgEAjPEyf7CCQurxBmFj gZIsozUfMwNvqJP7qnaUHAVMDIIA/jr0lwsXq9/D1niBCsZjdlw/mdATWORKnjWNe4mE8AwC MIME-Version: 1.0 Content-Type: text/plain; charset=utf-8; format=flowed; delsp=no Secure-Join: vg-request ``` After that, nothing happens.

link2xt commented

2023-12-17 11:36:32 +00:00

I have tested and confirm that it indeed does not work. Reproducing is very easy. I created a virtual environment, installed teams-bot there and ran teams-bot init --email somelogin@c2.testrun.org --password somepassword, then tried to join with my primary account, twice. Once it did not work, ^C and restart the bot, scan again - it worked.

pip freeze output for reference:

bcrypt==4.1.2
certifi==2023.11.17
cffi==1.16.0
charset-normalizer==3.3.2
click==8.1.7
colorama==0.4.6
configparser==6.0.0
cryptography==41.0.7
deltachat==1.132.0
distro==1.8.0
gevent==23.9.1
greenlet==3.0.2
idna==3.6
imap-tools==1.5.0
Jinja2==3.1.2
MarkupSafe==2.1.3
paramiko==2.12.0
pickleDB==0.9.2
pluggy==1.3.0
pycparser==2.21
pyinfra==2.8
PyNaCl==1.5.0
pypng==0.20220715.0
pyspnego==0.10.2
python-dateutil==2.8.2
pywinrm==0.4.3
qrcode==7.4.2
requests==2.31.0
requests-ntlm==1.2.0
six==1.16.0
-e git+ssh://git@git.0x90.space/missytake/teams-bot.git@8fc3fc6f5e37214952a2000f4b9ffc7d78dc620b#egg=teams_bot
typing_extensions==4.9.0
urllib3==2.1.0
xmltodict==0.13.0
zope.event==5.0
zope.interface==6.1

I have tested and confirm that it indeed does not work. Reproducing is very easy. I created a virtual environment, installed teams-bot there and ran `teams-bot init --email somelogin@c2.testrun.org --password somepassword`, then tried to join with my primary account, twice. Once it did not work, ^C and restart the bot, scan again - it worked. `pip freeze` output for reference: ``` bcrypt==4.1.2 certifi==2023.11.17 cffi==1.16.0 charset-normalizer==3.3.2 click==8.1.7 colorama==0.4.6 configparser==6.0.0 cryptography==41.0.7 deltachat==1.132.0 distro==1.8.0 gevent==23.9.1 greenlet==3.0.2 idna==3.6 imap-tools==1.5.0 Jinja2==3.1.2 MarkupSafe==2.1.3 paramiko==2.12.0 pickleDB==0.9.2 pluggy==1.3.0 pycparser==2.21 pyinfra==2.8 PyNaCl==1.5.0 pypng==0.20220715.0 pyspnego==0.10.2 python-dateutil==2.8.2 pywinrm==0.4.3 qrcode==7.4.2 requests==2.31.0 requests-ntlm==1.2.0 six==1.16.0 -e git+ssh://git@git.0x90.space/missytake/teams-bot.git@8fc3fc6f5e37214952a2000f4b9ffc7d78dc620b#egg=teams_bot typing_extensions==4.9.0 urllib3==2.1.0 xmltodict==0.13.0 zope.event==5.0 zope.interface==6.1 ```