=================================== FAILURES ===================================
_________________________ test_set_get_contact_avatar __________________________
[gw4] linux -- Python 3.10.20 /home/runner/work/core/core/python/.tox/py/bin/python
acfactory = <deltachat.testplugin.ACFactory object at 0x7f861d36e320>
data = <deltachat.testplugin.data.<locals>.Data object at 0x7f861d36fcd0>
lp = <deltachat.testplugin.lp.<locals>.Printer object at 0x7f862abbf070>
def test_set_get_contact_avatar(acfactory, data, lp):
lp.sec("configuring ac1 and ac2")
ac1, ac2 = acfactory.get_online_accounts(2)
lp.sec("set ac1 and ac2 profile images")
p = data.get_path("d.png")
ac1.set_avatar(p)
ac2.set_avatar(p)
lp.sec("ac1: send message to ac2")
ac1.create_chat(ac2).send_text("with avatar!")
lp.sec("ac2: wait for receiving message and avatar from ac1")
msg2 = ac2._evtracker.wait_next_incoming_message()
assert msg2.chat.is_contact_request()
received_path = msg2.get_sender_contact().get_profile_image()
assert open(received_path, "rb").read() == open(p, "rb").read()
lp.sec("ac2: send back message")
msg3 = msg2.create_chat().send_text("yes, i received your avatar -- how do you like mine?")
assert msg3.is_encrypted()
lp.sec("ac1: wait for receiving message and avatar from ac2")
msg4 = ac1._evtracker.wait_next_incoming_message()
received_path = msg4.get_sender_contact().get_profile_image()
assert received_path is not None, "did not get avatar through encrypted message"
assert open(received_path, "rb").read() == open(p, "rb").read()
ac2._evtracker.consume_events()
ac1._evtracker.consume_events()
lp.sec("ac1: delete profile image from chat, and send message to ac2")
ac1.set_avatar(None)
msg5 = ac1.create_chat(ac2).send_text("removing my avatar")
assert msg5.is_encrypted()
lp.sec("ac2: wait for message along with avatar deletion of ac1")
msg6 = ac2._evtracker.wait_next_incoming_message()
> assert msg6.get_sender_contact().get_profile_image() is None
E AssertionError: assert '/tmp/pytest-of-runner/pytest-0/popen-gw4/test_set_get_contact_avatar0/ac2/dc.db-blobs/e68dc384097bfe55705704c61545afd.png' is None
E + where '/tmp/pytest-of-runner/pytest-0/popen-gw4/test_set_get_contact_avatar0/ac2/dc.db-blobs/e68dc384097bfe55705704c61545afd.png' = get_profile_image()
E + where get_profile_image = <Contact id=11 addr=ci-2php8f@ci-chatmail.testrun.org dc_context=<cdata 'struct _dc_context *' 0x5557dbd0c9d0>>.get_profile_image
E + where <Contact id=11 addr=ci-2php8f@ci-chatmail.testrun.org dc_context=<cdata 'struct _dc_context *' 0x5557dbd0c9d0>> = get_sender_contact()
E + where get_sender_contact = <Message incoming sys=False 'removing my avatar' id=15 sender=11/ci-2php8f@ci-chatmail.testrun.org chat=12/ci-2php8f@ci-chatmail.testrun.org>.get_sender_contact
tests/test_1_online.py:846: AssertionError
----------------------------- Captured stdout call -----------------------------
========== configuring ac1 and ac2 ==========
newtmpuser: addr=ci-2php8f@ci-chatmail.testrun.org
[acsetup] 0.067 started configure on <Account path=/tmp/pytest-of-runner/pytest-0/popen-gw4/test_set_get_contact_avatar0/ac1/dc.db>
newtmpuser: addr=ci-h83src@ci-chatmail.testrun.org
[acsetup] 0.136 started configure on <Account path=/tmp/pytest-of-runner/pytest-0/popen-gw4/test_set_get_contact_avatar0/ac2/dc.db>
bringing accounts online
bring_online finds accounts= {<Account path=/tmp/pytest-of-runner/pytest-0/popen-gw4/test_set_get_contact_avatar0/ac1/dc.db>: 'CONFIGURING', <Account path=/tmp/pytest-of-runner/pytest-0/popen-gw4/test_set_get_contact_avatar0/ac2/dc.db>: 'CONFIGURING'}
1.76 [events-ac1] INFO src/scheduler.rs:72: starting IO
1.76 [events-ac1] INFO src/scheduler.rs:354: Starting inbox loop.
1.76 [events-ac1] INFO src/scheduler.rs:374: Transport 1: Preparing new IMAP session for inbox.
1.76 [events-ac1] INFO src/imap.rs:304: Connecting to IMAP server.
1.76 [events-ac1] DC_EVENT_CONNECTIVITY_CHANGED data1=0 data2=0
1.76 [events-ac1] INFO src/scheduler.rs:561: Starting SMTP loop.
ac1 waiting for inbox IDLE to become ready
1.76 [events-ac1] INFO src/scheduler.rs:721: scheduler is running
1.76 [events-ac1] DC_EVENT_CONNECTIVITY_CHANGED data1=0 data2=0
1.76 [events-ac1] INFO src/location.rs:731: Location loop is waiting for 24h 0m 0s or interrupt
1.76 [events-ac1] INFO src/contact.rs:2152: Recently seen loop waiting for 24h 0m 0s or interrupt
1.76 [events-ac1] INFO src/imap.rs:319: IMAP trying to connect to ci-chatmail.testrun.org:993:tls.
1.76 [events-ac1] INFO src/net/dns.rs:134: Using memory-cached DNS resolution for ci-chatmail.testrun.org.
1.76 [events-ac1] INFO src/net/dns.rs:180: Resolved ci-chatmail.testrun.org into 49.12.217.82.
1.76 [events-ac1] INFO src/ephemeral.rs:610: Ephemeral loop waiting for deletion in 24h 0m 0s or interrupt
1.76 [events-ac1] INFO src/net/dns.rs:180: Resolved ci-chatmail.testrun.org into 2a01:4f8:c013:13c3::1.
1.76 [events-ac1] INFO src/imap/client.rs:134: Attempting IMAP connection to ci-chatmail.testrun.org (49.12.217.82:993).
1.77 [events-ac1] INFO src/smtp.rs:538: Selected rows from SMTP queue: [].
1.77 [events-ac1] INFO src/scheduler.rs:601: SMTP fake idle started.
1.77 [events-ac1] DC_EVENT_CONNECTIVITY_CHANGED data1=0 data2=0
1.77 [events-ac1] INFO src/scheduler.rs:629: SMTP has no messages to retry, waiting for interrupt.
2.06 [events-ac1] INFO src/imap.rs:344: Logging into IMAP server with LOGIN.
2.26 [events-ac1] DC_EVENT_IMAP_CONNECTED data1=0 data2=IMAP-LOGIN as ci-2php8f@ci-chatmail.testrun.org
2.26 [events-ac1] DC_EVENT_CONNECTIVITY_CHANGED data1=0 data2=0
2.26 [events-ac1] INFO src/imap.rs:404: Successfully logged into IMAP server.
2.26 [events-ac1] INFO src/scheduler.rs:387: Transport 1: Prepared new IMAP session for inbox.
2.26 [events-ac1] INFO src/quota.rs:88: Transport 1: Updating quota.
2.36 [events-ac1] INFO src/quota.rs:106: Transport 1: Updated quota.
2.36 [events-ac1] DC_EVENT_CONNECTIVITY_CHANGED data1=0 data2=0
2.36 [events-ac1] INFO src/sql.rs:990: Start housekeeping...
2.36 [events-ac1] INFO src/sql.rs:1051: 2 files in use.
2.36 [events-ac1] INFO src/sql.rs:775: Incremental vacuum freed 0 pages.
2.37 [events-ac1] INFO src/sql.rs:682: wal_checkpoint: Total time: 5.726499ms. Writers blocked for: 715.708µs. Readers blocked for: 634.396µs.
2.37 [events-ac1] INFO src/sql.rs:921: Housekeeping done.
2.37 [events-ac1] INFO src/imap.rs:1347: Server supports metadata, retrieving server comment and admin contact.
2.57 [events-ac1] INFO src/imap/select_folder.rs:78: Transport 1: Selected folder "INBOX".
2.57 [events-ac1] INFO src/imap/select_folder.rs:222: transport 1: UID validity for folder INBOX changed from 0/0 to 1786877532/1.
2.57 [events-ac1] INFO src/imap.rs:565: fetch_new_msg_batch(INBOX): UIDVALIDITY=1786877532, UIDNEXT=1.
2.67 [events-ac1] INFO src/imap.rs:755: 0 mails read from "INBOX".
2.67 [events-ac1] INFO src/imap.rs:764: available_post_msgs: 0, download_later: 0.
2.67 [events-ac1] DC_EVENT_CONNECTIVITY_CHANGED data1=0 data2=0
2.67 [events-ac1] DC_EVENT_IMAP_INBOX_IDLE data1=0 data2=None
2.67 [MAIN-ac1] inbox IDLE ready
2.77 [events-ac1] INFO src/imap/idle.rs:73: Transport 1: IDLE entering wait-on-remote state in folder "INBOX".
3.41 [events-ac2] INFO src/scheduler.rs:72: starting IO
3.41 [events-ac2] INFO src/scheduler.rs:354: Starting inbox loop.ac2 waiting for inbox IDLE to become ready
3.41 [events-ac2] INFO src/scheduler.rs:374: Transport 1: Preparing new IMAP session for inbox.
3.41 [events-ac2] INFO src/imap.rs:304: Connecting to IMAP server.
3.41 [events-ac2] DC_EVENT_CONNECTIVITY_CHANGED data1=0 data2=0
3.41 [events-ac2] INFO src/scheduler.rs:561: Starting SMTP loop.
3.41 [events-ac2] INFO src/scheduler.rs:721: scheduler is running
3.41 [events-ac2] DC_EVENT_CONNECTIVITY_CHANGED data1=0 data2=0
3.41 [events-ac2] INFO src/contact.rs:2152: Recently seen loop waiting for 24h 0m 0s or interrupt
3.41 [events-ac2] INFO src/imap.rs:319: IMAP trying to connect to ci-chatmail.testrun.org:993:tls.
3.41 [events-ac2] INFO src/location.rs:731: Location loop is waiting for 24h 0m 0s or interrupt
3.41 [events-ac2] INFO src/smtp.rs:538: Selected rows from SMTP queue: [].
3.41 [events-ac2] INFO src/scheduler.rs:601: SMTP fake idle started.
3.41 [events-ac2] DC_EVENT_CONNECTIVITY_CHANGED data1=0 data2=0
3.41 [events-ac2] INFO src/scheduler.rs:629: SMTP has no messages to retry, waiting for interrupt.
3.41 [events-ac2] INFO src/ephemeral.rs:610: Ephemeral loop waiting for deletion in 24h 0m 0s or interrupt
3.41 [events-ac2] INFO src/net/dns.rs:134: Using memory-cached DNS resolution for ci-chatmail.testrun.org.
3.41 [events-ac2] INFO src/net/dns.rs:180: Resolved ci-chatmail.testrun.org into 49.12.217.82.
3.41 [events-ac2] INFO src/net/dns.rs:180: Resolved ci-chatmail.testrun.org into 2a01:4f8:c013:13c3::1.
3.41 [events-ac2] INFO src/imap/client.rs:134: Attempting IMAP connection to ci-chatmail.testrun.org (49.12.217.82:993).
3.71 [events-ac2] INFO src/imap.rs:344: Logging into IMAP server with LOGIN.
3.92 [events-ac2] DC_EVENT_IMAP_CONNECTED data1=0 data2=IMAP-LOGIN as ci-h83src@ci-chatmail.testrun.org
3.92 [events-ac2] DC_EVENT_CONNECTIVITY_CHANGED data1=0 data2=0
3.92 [events-ac2] INFO src/imap.rs:404: Successfully logged into IMAP server.
3.92 [events-ac2] INFO src/scheduler.rs:387: Transport 1: Prepared new IMAP session for inbox.
3.92 [events-ac2] INFO src/quota.rs:88: Transport 1: Updating quota.
4.01 [events-ac2] INFO src/quota.rs:106: Transport 1: Updated quota.
4.01 [events-ac2] DC_EVENT_CONNECTIVITY_CHANGED data1=0 data2=0
4.01 [events-ac2] INFO src/sql.rs:990: Start housekeeping...
4.01 [events-ac2] INFO src/sql.rs:1051: 2 files in use.
4.01 [events-ac2] INFO src/sql.rs:775: Incremental vacuum freed 0 pages.
4.02 [events-ac2] INFO src/sql.rs:682: wal_checkpoint: Total time: 4.657777ms. Writers blocked for: 752.527µs. Readers blocked for: 680.383µs.
4.02 [events-ac2] INFO src/sql.rs:921: Housekeeping done.
4.02 [events-ac2] INFO src/imap.rs:1347: Server supports metadata, retrieving server comment and admin contact.
4.22 [events-ac2] INFO src/imap/select_folder.rs:78: Transport 1: Selected folder "INBOX".
4.22 [events-ac2] INFO src/imap/select_folder.rs:222: transport 1: UID validity for folder INBOX changed from 0/0 to 1786877534/1.
4.22 [events-ac2] INFO src/imap.rs:565: fetch_new_msg_batch(INBOX): UIDVALIDITY=1786877534, UIDNEXT=1.
4.32 [events-ac2] INFO src/imap.rs:755: 0 mails read from "INBOX".
4.32 [events-ac2] INFO src/imap.rs:764: available_post_msgs: 0, download_later: 0.
4.32 [events-ac2] DC_EVENT_CONNECTIVITY_CHANGED data1=0 data2=0
4.32 [events-ac2] DC_EVENT_IMAP_INBOX_IDLE data1=0 data2=None
4.32 [MAIN-ac2] inbox IDLE ready
finished, account2state {<Account path=/tmp/pytest-of-runner/pytest-0/popen-gw4/test_set_get_contact_avatar0/ac1/dc.db>: 'IDLEREADY', <Account path=/tmp/pytest-of-runner/pytest-0/popen-gw4/test_set_get_contact_avatar0/ac2/dc.db>: 'IDLEREADY'}
all accounts online
========== set ac1 and ac2 profile images ==========
4.32 [events-ac1] INFO src/blob.rs:76: Source file not in blobdir. Copying instead of moving in order to prevent moving a file that was still needed.
4.32 [events-ac1] DC_EVENT_NEW_BLOB_FILE data1=0 data2=$BLOBDIR/e68dc384097bfe55705704c61545afd.png
4.32 [events-ac1] DC_EVENT_SELFAVATAR_CHANGED data1=0 data2=0
4.32 [events-ac1] DC_EVENT_ACCOUNTS_ITEM_CHANGED data1=0 data2=0
4.32 [events-ac1] DC_EVENT_CONFIG_SYNCED data1=0 data2=0
4.32 [events-ac1] INFO src/scheduler.rs:633: SMTP fake idle interrupted.
4.32 [events-ac1] INFO src/smtp.rs:538: Selected rows from SMTP queue: [].
4.32 [events-ac1] INFO src/scheduler.rs:601: SMTP fake idle started.
4.32 [events-ac1] DC_EVENT_CONNECTIVITY_CHANGED data1=0 data2=0
4.32 [events-ac1] INFO src/scheduler.rs:629: SMTP has no messages to retry, waiting for interrupt.
4.32 [events-ac2] INFO src/blob.rs:76: Source file not in blobdir. Copying instead of moving in order to prevent moving a file that was still needed.
4.32 [events-ac2] DC_EVENT_NEW_BLOB_FILE data1=0 data2=$BLOBDIR/e68dc384097bfe55705704c61545afd.png
4.32 [events-ac2] DC_EVENT_SELFAVATAR_CHANGED data1=0 data2=0
4.32 [events-ac2] DC_EVENT_ACCOUNTS_ITEM_CHANGED data1=0 data2=0
4.32 [events-ac2] DC_EVENT_CONFIG_SYNCED data1=0 data2=0
========== ac1: send message to ac2 ==========
4.32 [events-ac2] INFO src/scheduler.rs:633: SMTP fake idle interrupted.
4.32 [events-ac2] INFO src/smtp.rs:538: Selected rows from SMTP queue: [].
4.32 [events-ac2] INFO src/scheduler.rs:601: SMTP fake idle started.
4.32 [events-ac2] DC_EVENT_CONNECTIVITY_CHANGED data1=0 data2=0
4.32 [events-ac2] INFO src/scheduler.rs:629: SMTP has no messages to retry, waiting for interrupt.
4.32 [events-ac1] INFO src/contact.rs:370: Saved key with fingerprint CCCB5AA9F6E1141C943165F1DB18B18CBCF70487 from the Autocrypt header
4.32 [events-ac1] INFO src/contact.rs:1096: Added contact id=10 fpr=CCCB5AA9F6E1141C943165F1DB18B18CBCF70487 addr=ci-h83src@ci-chatmail.testrun.org.
4.32 [events-ac1] DC_EVENT_CONTACTS_CHANGED data1=10 data2=0
4.32 [events-ac1] DC_EVENT_NEW_BLOB_FILE data1=0 data2=$BLOBDIR/e68dc384097bfe55705704c61545afd.png
4.32 [events-ac1] DC_EVENT_CONTACTS_CHANGED data1=10 data2=0
4.32 [events-ac1] DC_EVENT_MSGS_CHANGED data1=12 data2=12
4.32 [events-ac1] DC_EVENT_CHATLIST_CHANGED data1=0 data2=0
4.32 [events-ac1] DC_EVENT_CHATLIST_ITEM_CHANGED data1=12 data2=0
4.32 [events-ac1] INFO src/chat.rs:266: Scale up origin of Contact#10 to CreateChat.
4.32 [events-ac1] DC_EVENT_MSGS_CHANGED data1=0 data2=0
4.32 [events-ac1] DC_EVENT_CHATLIST_CHANGED data1=0 data2=0
4.32 [events-ac1] DC_EVENT_CHATLIST_ITEM_CHANGED data1=12 data2=0
4.32 [events-ac1] INFO src/ephemeral.rs:610: Ephemeral loop waiting for deletion in 24h 0m 0s or interrupt
4.32 [events-ac1] INFO src/mimefactory.rs:784: Scale up origin of Chat#12 recipients to OutgoingTo.
========== ac2: wait for receiving message and avatar from ac1 ==========
4.33 [events-ac1] INFO src/chat.rs:2921: Message Msg#13 will be sent in one shot (no pre- and post-message). Size: 6.99 KiB.
4.33 [events-ac1] DC_EVENT_MSGS_CHANGED data1=12 data2=13
4.33 [events-ac1] DC_EVENT_CHATLIST_CHANGED data1=0 data2=0
4.33 [events-ac1] DC_EVENT_CHATLIST_ITEM_CHANGED data1=12 data2=0
4.33 [events-ac1] INFO src/scheduler.rs:633: SMTP fake idle interrupted.
4.33 [events-ac1] INFO src/smtp.rs:538: Selected rows from SMTP queue: [1].
4.33 [events-ac1] DC_EVENT_CONNECTIVITY_CHANGED data1=0 data2=0
4.33 [events-ac1] INFO src/smtp.rs:130: SMTP trying to connect to ci-chatmail.testrun.org:465:tls.
4.33 [events-ac1] INFO src/net/dns.rs:134: Using memory-cached DNS resolution for ci-chatmail.testrun.org.
4.33 [events-ac1] INFO src/net/dns.rs:180: Resolved ci-chatmail.testrun.org into 49.12.217.82.
4.33 [events-ac1] INFO src/net/dns.rs:180: Resolved ci-chatmail.testrun.org into 2a01:4f8:c013:13c3::1.
4.33 [events-ac1] INFO src/smtp/connect.rs:87: Attempting SMTP connection to ci-chatmail.testrun.org (49.12.217.82:465).
4.41 [events-ac2] INFO src/imap/idle.rs:73: Transport 1: IDLE entering wait-on-remote state in folder "INBOX".
4.63 [events-ac1] INFO src/smtp/connect.rs:87: Attempting SMTP connection to ci-chatmail.testrun.org ([2a01:4f8:c013:13c3::1]:465).
4.63 [events-ac1] WARNING src/smtp/connect.rs:132: SMTP failed to connect to ci-chatmail.testrun.org ([2a01:4f8:c013:13c3::1]:465): Connection to [2a01:4f8:c013:13c3::1]:465 failed: Network is unreachable (os error 101).
4.96 [events-ac1] DC_EVENT_SMTP_CONNECTED data1=0 data2=SMTP-LOGIN as ci-2php8f@ci-chatmail.testrun.org ok
4.96 [events-ac1] INFO src/smtp.rs:386: Try number 1 to send message Msg#13 (entry 1) over SMTP.
4.96 [events-ac1] DC_EVENT_CONNECTIVITY_CHANGED data1=0 data2=0
5.30 [events-ac1] INFO src/smtp/send.rs:62: Message len=7162 was SMTP-sent to 1 recipients..
5.30 [events-ac1] DC_EVENT_SMTP_MESSAGE_SENT data1=0 data2=Message len=7162 was SMTP-sent to 1 recipients.
5.31 [events-ac1] DC_EVENT_MSG_DELIVERED data1=12 data2=13
5.31 [events-ac1] DC_EVENT_CHATLIST_ITEM_CHANGED data1=12 data2=0
5.31 [events-ac1] INFO src/scheduler.rs:601: SMTP fake idle started.
5.31 [events-ac1] DC_EVENT_CONNECTIVITY_CHANGED data1=0 data2=0
5.31 [events-ac1] INFO src/scheduler.rs:629: SMTP has no messages to retry, waiting for interrupt.
5.32 [events-ac2] INFO src/imap/idle.rs:96: "INBOX": Idle has NewData ResponseData { raw: 4096, response: MailboxData(Exists(1)) }
5.41 [events-ac2] INFO src/imap.rs:565: fetch_new_msg_batch(INBOX): UIDVALIDITY=1786877534, UIDNEXT=1.
5.51 [events-ac2] INFO src/contact.rs:1094: Added contact id=10 addr=ci-2php8f@ci-chatmail.testrun.org.
5.51 [events-ac2] INFO src/imap.rs:683: "ae4e8ae9-9f80-43ac-be6a-787c6fde3a3d@localhost" is not a post-message.
5.51 [events-ac2] DC_EVENT_CONNECTIVITY_CHANGED data1=0 data2=0
5.51 [events-ac2] INFO src/imap.rs:1124: Starting UID FETCH of message set "1".
5.61 [events-ac2] INFO src/imap.rs:1216: Passing message UID 1 to receive_imf().
5.65 [events-ac2] INFO src/contact.rs:370: Saved key with fingerprint 2E6FA2CB23B532D728634B5864B08F61A9ED9443 from the Autocrypt header
5.66 [events-ac2] DC_EVENT_NEW_BLOB_FILE data1=0 data2=$BLOBDIR/e68dc384097bfe55705704c61545afd.png
5.66 [events-ac2] INFO src/receive_imf.rs:532: Receiving message "ae4e8ae9-9f80-43ac-be6a-787c6fde3a3d@localhost", seen=false...
5.66 [events-ac2] INFO src/contact.rs:1096: Added contact id=11 fpr=2E6FA2CB23B532D728634B5864B08F61A9ED9443 addr=ci-2php8f@ci-chatmail.testrun.org.
5.66 [events-ac2] INFO src/receive_imf.rs:1379: Non-group message, no parent. num_recipients=1. from_id=Contact#11. Chat assignment = SingleChat.
5.66 [events-ac2] DC_EVENT_MSGS_CHANGED data1=12 data2=12
5.66 [events-ac2] DC_EVENT_CHATLIST_CHANGED data1=0 data2=0
5.66 [events-ac2] DC_EVENT_CHATLIST_ITEM_CHANGED data1=12 data2=0
5.66 [events-ac2] INFO src/receive_imf.rs:2297: Message has 1 parts and is assigned to chat #Chat#12, timestamp=1786877535.
5.66 [events-ac2] DC_EVENT_CONTACTS_CHANGED data1=11 data2=0
5.66 [events-ac2] INFO src/contact.rs:2152: Recently seen loop waiting for 0h 9m 59s or interrupt
5.66 [events-ac2] DC_EVENT_CONTACTS_CHANGED data1=11 data2=0
5.66 [events-ac2] DC_EVENT_CHATLIST_ITEM_CHANGED data1=12 data2=0
5.66 [events-ac2] DC_EVENT_INCOMING_MSG data1=12 data2=13
5.66 [events-ac2] DC_EVENT_CHATLIST_CHANGED data1=0 data2=0
5.66 [events-ac2] DC_EVENT_CHATLIST_ITEM_CHANGED data1=12 data2=0
5.66 [events-ac2] INFO src/imap.rs:1271: Successfully received 1 UIDs.
5.66 [events-ac2] INFO src/imap.rs:755: 1 mails read from "INBOX".
5.66 [events-ac2] DC_EVENT_INCOMING_MSG_BUNCH data1=0 data2=0
5.66 [events-ac2] INFO src/imap.rs:764: available_post_msgs: 0, download_later: 0.
========== ac2: send back message ==========
5.66 [events-ac2] DC_EVENT_CHAT_MODIFIED data1=12 data2=0
5.66 [events-ac2] DC_EVENT_CHATLIST_ITEM_CHANGED data1=12 data2=0
5.66 [events-ac2] INFO src/scheduler.rs:633: SMTP fake idle interrupted.
5.66 [events-ac2] INFO src/smtp.rs:538: Selected rows from SMTP queue: [].
5.66 [events-ac2] INFO src/ephemeral.rs:610: Ephemeral loop waiting for deletion in 24h 0m 0s or interrupt
5.66 [events-ac2] INFO src/scheduler.rs:601: SMTP fake idle started.
5.66 [events-ac2] DC_EVENT_CONNECTIVITY_CHANGED data1=0 data2=0
5.66 [events-ac2] INFO src/scheduler.rs:629: SMTP has no messages to retry, waiting for interrupt.
5.66 [events-ac2] INFO src/mimefactory.rs:784: Scale up origin of Chat#12 recipients to OutgoingTo.
5.68 [events-ac2] INFO src/chat.rs:2921: Message Msg#14 will be sent in one shot (no pre- and post-message). Size: 8.84 KiB.
5.68 [events-ac2] DC_EVENT_MSGS_CHANGED data1=12 data2=14
========== ac1: wait for receiving message and avatar from ac2 ==========
5.68 [events-ac2] DC_EVENT_CHATLIST_CHANGED data1=0 data2=0
5.68 [events-ac2] DC_EVENT_CHATLIST_ITEM_CHANGED data1=12 data2=0
5.68 [events-ac2] INFO src/scheduler.rs:633: SMTP fake idle interrupted.
5.68 [events-ac2] INFO src/smtp.rs:538: Selected rows from SMTP queue: [1].
5.68 [events-ac2] DC_EVENT_CONNECTIVITY_CHANGED data1=0 data2=0
5.68 [events-ac2] INFO src/smtp.rs:130: SMTP trying to connect to ci-chatmail.testrun.org:465:tls.
5.68 [events-ac2] INFO src/net/dns.rs:134: Using memory-cached DNS resolution for ci-chatmail.testrun.org.
5.68 [events-ac2] INFO src/net/dns.rs:180: Resolved ci-chatmail.testrun.org into 49.12.217.82.
5.68 [events-ac2] INFO src/net/dns.rs:180: Resolved ci-chatmail.testrun.org into 2a01:4f8:c013:13c3::1.
5.68 [events-ac2] INFO src/smtp/connect.rs:87: Attempting SMTP connection to ci-chatmail.testrun.org (49.12.217.82:465).
5.76 [events-ac2] DC_EVENT_IMAP_MESSAGE_DELETED data1=0 data2=IMAP messages 1 marked as deleted
5.76 [events-ac2] INFO src/imap/select_folder.rs:41: Expunge messages in "INBOX".
5.85 [events-ac2] INFO src/imap/select_folder.rs:44: Close/expunge succeeded.
5.85 [events-ac2] DC_EVENT_CONNECTIVITY_CHANGED data1=0 data2=0
5.85 [events-ac2] DC_EVENT_IMAP_INBOX_IDLE data1=0 data2=None
5.95 [events-ac2] INFO src/imap/select_folder.rs:78: Transport 1: Selected folder "INBOX".
5.98 [events-ac2] INFO src/smtp/connect.rs:87: Attempting SMTP connection to ci-chatmail.testrun.org ([2a01:4f8:c013:13c3::1]:465).
5.98 [events-ac2] WARNING src/smtp/connect.rs:132: SMTP failed to connect to ci-chatmail.testrun.org ([2a01:4f8:c013:13c3::1]:465): Connection to [2a01:4f8:c013:13c3::1]:465 failed: Network is unreachable (os error 101).
6.05 [events-ac2] INFO src/imap/idle.rs:73: Transport 1: IDLE entering wait-on-remote state in folder "INBOX".
6.31 [events-ac2] DC_EVENT_SMTP_CONNECTED data1=0 data2=SMTP-LOGIN as ci-h83src@ci-chatmail.testrun.org ok
6.31 [events-ac2] INFO src/smtp.rs:386: Try number 1 to send message Msg#14 (entry 1) over SMTP.
6.31 [events-ac2] DC_EVENT_CONNECTIVITY_CHANGED data1=0 data2=0
6.66 [events-ac2] INFO src/smtp/send.rs:62: Message len=9056 was SMTP-sent to 1 recipients..
6.66 [events-ac2] DC_EVENT_SMTP_MESSAGE_SENT data1=0 data2=Message len=9056 was SMTP-sent to 1 recipients.
6.66 [events-ac2] DC_EVENT_MSG_DELIVERED data1=12 data2=14
6.66 [events-ac2] DC_EVENT_CHATLIST_ITEM_CHANGED data1=12 data2=0
6.66 [events-ac2] INFO src/scheduler.rs:601: SMTP fake idle started.
6.66 [events-ac2] DC_EVENT_CONNECTIVITY_CHANGED data1=0 data2=0
6.66 [events-ac2] INFO src/scheduler.rs:629: SMTP has no messages to retry, waiting for interrupt.
6.67 [events-ac1] INFO src/imap/idle.rs:96: "INBOX": Idle has NewData ResponseData { raw: 4096, response: MailboxData(Exists(1)) }
6.77 [events-ac1] INFO src/imap.rs:565: fetch_new_msg_batch(INBOX): UIDVALIDITY=1786877532, UIDNEXT=1.
6.86 [events-ac1] INFO src/imap.rs:683: "03db3c6a-6b89-4a63-82d6-73d78b071cb6@localhost" is not a post-message.
6.87 [events-ac1] DC_EVENT_CONNECTIVITY_CHANGED data1=0 data2=0
6.87 [events-ac1] INFO src/imap.rs:1124: Starting UID FETCH of message set "1".
6.96 [events-ac1] INFO src/imap.rs:1216: Passing message UID 1 to receive_imf().
6.97 [events-ac1] DC_EVENT_NEW_BLOB_FILE data1=0 data2=$BLOBDIR/e68dc384097bfe55705704c61545afd.png
6.97 [events-ac1] INFO src/receive_imf.rs:532: Receiving message "03db3c6a-6b89-4a63-82d6-73d78b071cb6@localhost", seen=false...
6.97 [events-ac1] INFO src/receive_imf.rs:1379: Non-group reply. num_recipients=1. from_id=Contact#10. Chat assignment = SingleChat.
6.97 [events-ac1] INFO src/receive_imf.rs:2297: Message has 1 parts and is assigned to chat #Chat#12, timestamp=1786877536.
6.97 [events-ac1] DC_EVENT_CONTACTS_CHANGED data1=10 data2=0
6.97 [events-ac1] INFO src/contact.rs:2152: Recently seen loop waiting for 0h 9m 59s or interrupt
6.97 [events-ac1] DC_EVENT_CONTACTS_CHANGED data1=10 data2=0
6.98 [events-ac1] DC_EVENT_CHATLIST_ITEM_CHANGED data1=12 data2=0
6.98 [events-ac1] DC_EVENT_INCOMING_MSG data1=12 data2=14
========== ac1: delete profile image from chat, and send message to ac2 ==========
6.98 [events-ac1] DC_EVENT_CHATLIST_CHANGED data1=0 data2=0
6.98 [events-ac1] DC_EVENT_CHATLIST_ITEM_CHANGED data1=12 data2=0
6.98 [events-ac1] INFO src/imap.rs:1271: Successfully received 1 UIDs.
6.98 [events-ac1] INFO src/imap.rs:755: 1 mails read from "INBOX".
6.98 [events-ac1] DC_EVENT_INCOMING_MSG_BUNCH data1=0 data2=0
6.98 [events-ac1] INFO src/imap.rs:764: available_post_msgs: 0, download_later: 0.
6.98 [events-ac1] WARNING deltachat-ffi/src/lib.rs:246: dc_set_config() failed: Can't set selfavatar to None: database is locked: Error code 5: The database file is locked
6.98 [events-ac1] INFO src/ephemeral.rs:610: Ephemeral loop waiting for deletion in 24h 0m 0s or interrupt
6.98 [events-ac1] INFO src/mimefactory.rs:784: Scale up origin of Chat#12 recipients to OutgoingTo.
6.99 [events-ac1] INFO src/chat.rs:2921: Message Msg#15 will be sent in one shot (no pre- and post-message). Size: 7.10 KiB.
6.99 [events-ac1] DC_EVENT_MSGS_CHANGED data1=12 data2=15
========== ac2: wait for message along with avatar deletion of ac1 ==========
6.99 [events-ac1] DC_EVENT_CHATLIST_CHANGED data1=0 data2=0
6.99 [events-ac1] DC_EVENT_CHATLIST_ITEM_CHANGED data1=12 data2=0
BLOBDIR=/tmp/pytest-of-runner/pytest-0/popen-gw4/test_set_get_contact_avatar0/ac1/dc.db-blobs
BOT=0
DATABASE_DIR=/tmp/pytest-of-runner/pytest-0/popen-gw4/test_set_get_contact_avatar0/ac1/dc.db
DATABASE_ENCRYPTED=false DATABASE_VERSION=163
DEBUG_ASSERTIONS=On - DO NOT RELEASE THIS BUILD DEBUG_LOGGING=0
DELETE_DEVICE_AFTER=0 DELTACHAT_CORE_VERSION=v2.60.0-dev DISABLE_IDLE=false
DONATION_REQUEST_NEXT_CHECK=1789469535 DOWNLOAD_LIMIT=0
FIRST_KEY_CONTACTS_MSG_ID= FIX_IS_CHATMAIL=false FORCE_ENCRYPTION=true
GOSSIP_PERIOD=172800 IMAP_SERVER_ADMIN="mailto:root@ci-chatmail.testrun.org"
IMAP_SERVER_COMMENT="Chatmail server" IMAP_SERVER_ID={"name": "Dovecot"}
IS_CHATMAIL=true IS_MUTED=false JOURNAL_MODE=wal
LAST_AUTOMATIC_RELAY_MANAGEMENT=0 LAST_CANT_DECRYPT_OUTGOING_MSGS=0
LAST_HOUSEKEEPING=1786877533 LAST_MSG_ID=0 LAST_REACTIONS_BROADCAST=1786877533
LEVEL=awesome MDNS_ENABLED=1 MEDIA_QUALITY=0 MESSAGES_IN_CONTACT_REQUESTS=0
NUM_CPUS=4 NUMBER_OF_CHAT_MESSAGES=6 NUMBER_OF_CHATS=3 NUMBER_OF_CONTACTS=1
PRIVATE_KEY_COUNT=1 PRIVATE_TAG=<unset> PROXY_ENABLED=0 PUBLIC_KEY_COUNT=1
SELFAVATAR=/tmp/pytest-of-runner/pytest-0/popen-gw4/test_set_get_contact_avatar0/ac1/dc.db-blobs/e68dc384097bfe55705704c61545afd.png
SQLITE_VERSION=3.46.1 STATS_ID=<unset> STATS_LAST_SENT=0 STATS_SENDING=false
STD_HEADER_PROTECTION_COMPOSING= SYNC_MSGS=0 TEAM_PROFILE=false TEST_HOOKS=
UPTIME=0h 0m 7s
USED_TRANSPORT_SETTINGS=1: ***@ci-chatmail.testrun.org imap:[ci-chatmail.testrun.org:993:tls, ci-chatmail.testrun.org:143:starttls, ci-chatmail.testrun.org:443:tls] smtp:[ci-chatmail.testrun.org:465:tls, ci-chatmail.testrun.org:587:starttls, ci-chatmail.testrun.org:443:tls] cert_strict
WEBXDC_REALTIME_ENABLED=true WHO_CAN_CALL_ME=1
--------- EMPTY FOLDERS: ['INBOX']
=============== ===============
ARCH=64 AUTOMATIC_RELAY_MANAGEMENT=false
AUTOMATIC_RELAY_MANAGEMENT_FINISHED=false BCC_SELF=0
BLOBDIR=/tmp/pytest-of-runner/pytest-0/popen-gw4/test_set_get_contact_avatar0/ac2/dc.db-blobs
BOT=0
DATABASE_DIR=/tmp/pytest-of-runner/pytest-0/popen-gw4/test_set_get_contact_avatar0/ac2/dc.db
DATABASE_ENCRYPTED=false DATABASE_VERSION=163
DEBUG_ASSERTIONS=On - DO NOT RELEASE THIS BUILD DEBUG_LOGGING=0
DELETE_DEVICE_AFTER=0 DELTACHAT_CORE_VERSION=v2.60.0-dev DISABLE_IDLE=false
DONATION_REQUEST_NEXT_CHECK=1789469536 DOWNLOAD_LIMIT=0
FIRST_KEY_CONTACTS_MSG_ID= FIX_IS_CHATMAIL=false FORCE_ENCRYPTION=true
GOSSIP_PERIOD=172800 IMAP_SERVER_ADMIN="mailto:root@ci-chatmail.testrun.org"
IMAP_SERVER_COMMENT="Chatmail server" IMAP_SERVER_ID={"name": "Dovecot"}
IS_CHATMAIL=true IS_MUTED=false JOURNAL_MODE=wal
LAST_AUTOMATIC_RELAY_MANAGEMENT=0 LAST_CANT_DECRYPT_OUTGOING_MSGS=0
LAST_HOUSEKEEPING=1786877534 LAST_MSG_ID=0 LAST_REACTIONS_BROADCAST=1786877534
LEVEL=awesome MDNS_ENABLED=1 MEDIA_QUALITY=0 MESSAGES_IN_CONTACT_REQUESTS=0
NUM_CPUS=4 NUMBER_OF_CHAT_MESSAGES=6 NUMBER_OF_CHATS=3 NUMBER_OF_CONTACTS=2
PRIVATE_KEY_COUNT=1 PRIVATE_TAG=<unset> PROXY_ENABLED=0 PUBLIC_KEY_COUNT=1
SELFAVATAR=/tmp/pytest-of-runner/pytest-0/popen-gw4/test_set_get_contact_avatar0/ac2/dc.db-blobs/e68dc384097bfe55705704c61545afd.png
SQLITE_VERSION=3.46.1 STATS_ID=<unset> STATS_LAST_SENT=0 STATS_SENDING=false
STD_HEADER_PROTECTION_COMPOSING= SYNC_MSGS=0 TEAM_PROFILE=false TEST_HOOKS=
UPTIME=0h 0m 7s
USED_TRANSPORT_SETTINGS=1: ***@ci-chatmail.testrun.org imap:[ci-chatmail.testrun.org:993:tls, ci-chatmail.testrun.org:143:starttls, ci-chatmail.testrun.org:443:tls] smtp:[ci-chatmail.testrun.org:465:tls, ci-chatmail.testrun.org:587:starttls, ci-chatmail.testrun.org:443:tls] cert_strict
WEBXDC_REALTIME_ENABLED=true WHO_CAN_CALL_ME=1
--------- EMPTY FOLDERS: ['INBOX']
8.44 [MAIN-ac2] stop_ongoing
8.44 [MAIN-ac2] dc_stop_io (stop core IO scheduler)
8.44 [events-ac2] EVENT THREAD FINISHED
8.44 [MAIN-ac2] wait for event thread to finish
8.44 [MAIN-ac2] remove dc_context references, making the Account unusable
8.44 [MAIN-ac2] shutdown finished
8.54 [MAIN-ac1] stop_ongoing
8.54 [MAIN-ac1] dc_stop_io (stop core IO scheduler)
8.54 [events-ac1] EVENT THREAD FINISHED
8.54 [MAIN-ac1] wait for event thread to finish
8.54 [MAIN-ac1] remove dc_context references, making the Account unusable
8.54 [MAIN-ac1] shutdown finished
=========================== short test summary info ============================
SKIPPED [1] tests/test_3_offline.py:563: We didn't find a way to correctly reset an account after a failed import attempt while simultaneously making sure that the password of an encrypted account survives a failed import attempt. Since passphrases are not really supported anymore, we decided to just disable the test.
SKIPPED [1] examples/test_examples.py:17: The test is flaky in CI and crashes the interpreter as of 2025-11-12
============= 1 failed, 110 passed, 2 skipped in 71.49s (0:01:11) ==============
py: exit 1 (71.93 seconds) /home/runner/work/core/core/python> pytest -n6 --extra-info -v -rsXx --ignored --strict-tls tests examples pid=2734
From https://github.com/chatmail/core/actions/runs/31942528812/job/95154104869?pr=8596: