================================== FAILURES ===================================
_________________________ test_multidevice_sync_chat __________________________
[gw4] win32 -- Python 3.14.6 D:\a\core\core\deltachat-rpc-client\.tox\py\Scripts\python.EXE
acfactory = <deltachat_rpc_client.pytestplugin.ACFactory object at 0x000002763BB206E0>
def test_multidevice_sync_chat(acfactory: ACFactory) -> None:
"""
Test multidevice sync: syncing chat visibility and muting across multiple devices
"""
> alice, alice_second_device, bob, alice_chat_bob = get_multi_account_test_setup(acfactory)
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
tests\test_chatlist_events.py:198:
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _
tests\test_chatlist_events.py:156: in get_multi_account_test_setup
alice_second_device = alice.clone()
^^^^^^^^^^^^^
.tox\py\Lib\site-packages\deltachat_rpc_client\account.py:65: in clone
qr = self._rpc.get_backup_qr(self.id)
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
.tox\py\Lib\site-packages\deltachat_rpc_client\rpc.py:30: in __call__
return future()
^^^^^^^^
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _
def rpc_future():
"""Wait for the request to receive a result."""
response = queue.get()
if "error" in response:
> raise JsonRpcError(response["error"])
E deltachat_rpc_client.rpc.JsonRpcError: {'code': -1, 'message': 'Backup provider did not start in time: deadline has elapsed'}
.tox\py\Lib\site-packages\deltachat_rpc_client\rpc.py:48: JsonRpcError
----------------------------- Captured log setup ------------------------------
INFO root:rpc.py:129 RPC server ready. Core version: v2.59.0-dev
------------------------------ Captured log call ------------------------------
DEBUG root:rpc.py:194 account_id=1 got an event {'kind': 'Info', 'msg': 'src\\sql\\migrations.rs:35: Starting key-contact transition.'}
DEBUG root:rpc.py:194 account_id=1 got an event {'kind': 'Info', 'msg': 'src\\sql\\migrations.rs:82: Not yet configured, no need to migrate key-contacts'}
DEBUG root:rpc.py:194 account_id=1 got an event {'kind': 'Info', 'msg': 'src\\sql\\migrations.rs:1942: key-contacts migration took 2.5859ms in total.'}
DEBUG root:rpc.py:194 account_id=1 got an event {'kind': 'Info', 'msg': 'src\\sql\\migrations.rs:2623: Created new database. Migration done from v68.'}
DEBUG root:rpc.py:194 account_id=1 got an event {'kind': 'Info', 'msg': 'src\\sql\\migrations.rs:2625: Database version: v163.'}
DEBUG root:rpc.py:194 account_id=1 got an event {'kind': 'Info', 'msg': 'src\\sql.rs:264: Opened database "C:\\\\Users\\\\runneradmin\\\\AppData\\\\Local\\\\Temp\\\\pytest-of-unknown\\\\pytest-0\\\\popen-gw4\\\\test_multidevice_sync_chat0\\\\accounts\\\\04f25727-cf55-4edd-80e0-2d988ab2dc6f\\\\dc.db".'}
DEBUG root:rpc.py:194 account_id=0 got an event {'kind': 'AccountsChanged'}
DEBUG root:rpc.py:194 account_id=1 got an event {'kind': 'Info', 'msg': 'src\\configure.rs:310: Configure ...'}
DEBUG root:rpc.py:194 account_id=1 got an event {'comment': None, 'kind': 'ConfigureProgress', 'progress': 1}
DEBUG root:rpc.py:194 account_id=1 got an event {'comment': None, 'kind': 'ConfigureProgress', 'progress': 200}
DEBUG root:rpc.py:194 account_id=1 got an event {'kind': 'Info', 'msg': 'src\\net\\http.rs:388: Not found "https://autoconfig.ci-chatmail.testrun.org/mail/config-v1.1.xml?emailaddress=asfudkmlh%40ci%2Dchatmail.testrun.org" in cache, fetching.'}
DEBUG root:rpc.py:194 account_id=1 got an event {'kind': 'Info', 'msg': 'src\\net\\dns.rs:140: No memory-cached DNS resolution for autoconfig.ci-chatmail.testrun.org available, waiting for the resolver.'}
DEBUG root:rpc.py:194 account_id=1 got an event {'kind': 'Warning', 'msg': 'src\\net\\dns.rs:892: DNS resolution for autoconfig.ci-chatmail.testrun.org:443 failed: DNS lookup with memory cache failure: DNS lookup failure: No such host is known. (os error 11001).'}
DEBUG root:rpc.py:194 account_id=1 got an event {'comment': None, 'kind': 'ConfigureProgress', 'progress': 300}
DEBUG root:rpc.py:194 account_id=1 got an event {'kind': 'Info', 'msg': 'src\\net\\http.rs:388: Not found "https://ci-chatmail.testrun.org/.well-known/autoconfig/mail/config-v1.1.xml" in cache, fetching.'}
DEBUG root:rpc.py:194 account_id=1 got an event {'kind': 'Info', 'msg': 'src\\net\\dns.rs:140: No memory-cached DNS resolution for ci-chatmail.testrun.org available, waiting for the resolver.'}
DEBUG root:rpc.py:194 account_id=1 got an event {'kind': 'Info', 'msg': 'src\\net\\dns.rs:180: Resolved ci-chatmail.testrun.org into 49.12.217.82.'}
DEBUG root:rpc.py:194 account_id=1 got an event {'kind': 'Info', 'msg': 'src\\net\\http.rs:344: Inserting "https://ci-chatmail.testrun.org/.well-known/autoconfig/mail/config-v1.1.xml" into cache.'}
DEBUG root:rpc.py:194 account_id=1 got an event {'file': '$BLOBDIR/b66980bca086b8d0d13cf7e231307fd', 'kind': 'NewBlobFile'}
DEBUG root:rpc.py:194 account_id=1 got an event {'comment': None, 'kind': 'ConfigureProgress', 'progress': 500}
DEBUG root:rpc.py:194 account_id=1 got an event {'comment': None, 'kind': 'ConfigureProgress', 'progress': 550}
DEBUG root:rpc.py:194 account_id=1 got an event {'comment': None, 'kind': 'ConfigureProgress', 'progress': 600}
DEBUG root:rpc.py:194 account_id=1 got an event {'kind': 'Info', 'msg': 'src\\imap.rs:300: Connecting to IMAP server.'}
DEBUG root:rpc.py:194 account_id=1 got an event {'kind': 'ConnectivityChanged'}
DEBUG root:rpc.py:194 account_id=1 got an event {'kind': 'Info', 'msg': 'src\\imap.rs:315: IMAP trying to connect to ci-chatmail.testrun.org:993:tls.'}
DEBUG root:rpc.py:194 account_id=1 got an event {'kind': 'Info', 'msg': 'src\\net\\dns.rs:134: Using memory-cached DNS resolution for ci-chatmail.testrun.org.'}
DEBUG root:rpc.py:194 account_id=1 got an event {'kind': 'Info', 'msg': 'src\\net\\dns.rs:180: Resolved ci-chatmail.testrun.org into 49.12.217.82.'}
DEBUG root:rpc.py:194 account_id=1 got an event {'kind': 'Info', 'msg': 'src\\imap\\client.rs:134: Attempting IMAP connection to ci-chatmail.testrun.org (49.12.217.82:993).'}
DEBUG root:rpc.py:194 account_id=1 got an event {'kind': 'Info', 'msg': 'src\\smtp.rs:130: SMTP trying to connect to ci-chatmail.testrun.org:465:tls.'}
DEBUG root:rpc.py:194 account_id=1 got an event {'kind': 'Info', 'msg': 'src\\net\\dns.rs:134: Using memory-cached DNS resolution for ci-chatmail.testrun.org.'}
DEBUG root:rpc.py:194 account_id=1 got an event {'kind': 'Info', 'msg': 'src\\net\\dns.rs:180: Resolved ci-chatmail.testrun.org into 49.12.217.82.'}
DEBUG root:rpc.py:194 account_id=1 got an event {'kind': 'Info', 'msg': 'src\\smtp\\connect.rs:87: Attempting SMTP connection to ci-chatmail.testrun.org (49.12.217.82:465).'}
DEBUG root:rpc.py:194 account_id=2 got an event {'kind': 'Info', 'msg': 'src\\sql\\migrations.rs:35: Starting key-contact transition.'}
DEBUG root:rpc.py:194 account_id=2 got an event {'kind': 'Info', 'msg': 'src\\sql\\migrations.rs:82: Not yet configured, no need to migrate key-contacts'}
DEBUG root:rpc.py:194 account_id=2 got an event {'kind': 'Info', 'msg': 'src\\sql\\migrations.rs:1942: key-contacts migration took 1.4144ms in total.'}
DEBUG root:rpc.py:194 account_id=2 got an event {'kind': 'Info', 'msg': 'src\\sql\\migrations.rs:2623: Created new database. Migration done from v68.'}
DEBUG root:rpc.py:194 account_id=2 got an event {'kind': 'Info', 'msg': 'src\\sql\\migrations.rs:2625: Database version: v163.'}
DEBUG root:rpc.py:194 account_id=2 got an event {'kind': 'Info', 'msg': 'src\\sql.rs:264: Opened database "C:\\\\Users\\\\runneradmin\\\\AppData\\\\Local\\\\Temp\\\\pytest-of-unknown\\\\pytest-0\\\\popen-gw4\\\\test_multidevice_sync_chat0\\\\accounts\\\\85e83f60-0546-402c-a1e3-4e1bf473a31b\\\\dc.db".'}
DEBUG root:rpc.py:194 account_id=0 got an event {'kind': 'AccountsChanged'}
DEBUG root:rpc.py:194 account_id=2 got an event {'kind': 'Info', 'msg': 'src\\configure.rs:310: Configure ...'}
DEBUG root:rpc.py:194 account_id=2 got an event {'comment': None, 'kind': 'ConfigureProgress', 'progress': 1}
DEBUG root:rpc.py:194 account_id=2 got an event {'comment': None, 'kind': 'ConfigureProgress', 'progress': 200}
DEBUG root:rpc.py:194 account_id=2 got an event {'kind': 'Info', 'msg': 'src\\net\\http.rs:388: Not found "https://autoconfig.ci-chatmail.testrun.org/mail/config-v1.1.xml?emailaddress=cvgo7afcm%40ci%2Dchatmail.testrun.org" in cache, fetching.'}
DEBUG root:rpc.py:194 account_id=2 got an event {'kind': 'Info', 'msg': 'src\\net\\dns.rs:140: No memory-cached DNS resolution for autoconfig.ci-chatmail.testrun.org available, waiting for the resolver.'}
DEBUG root:rpc.py:194 account_id=2 got an event {'kind': 'Warning', 'msg': 'src\\net\\dns.rs:892: DNS resolution for autoconfig.ci-chatmail.testrun.org:443 failed: DNS lookup with memory cache failure: DNS lookup failure: No such host is known. (os error 11001).'}
DEBUG root:rpc.py:194 account_id=2 got an event {'comment': None, 'kind': 'ConfigureProgress', 'progress': 300}
DEBUG root:rpc.py:194 account_id=2 got an event {'kind': 'Info', 'msg': 'src\\net\\http.rs:388: Not found "https://ci-chatmail.testrun.org/.well-known/autoconfig/mail/config-v1.1.xml" in cache, fetching.'}
DEBUG root:rpc.py:194 account_id=2 got an event {'kind': 'Info', 'msg': 'src\\net\\dns.rs:134: Using memory-cached DNS resolution for ci-chatmail.testrun.org.'}
DEBUG root:rpc.py:194 account_id=2 got an event {'kind': 'Info', 'msg': 'src\\net\\dns.rs:180: Resolved ci-chatmail.testrun.org into 49.12.217.82.'}
DEBUG root:rpc.py:194 account_id=1 got an event {'kind': 'Info', 'msg': 'src\\imap.rs:340: Logging into IMAP server with LOGIN.'}
DEBUG root:rpc.py:194 account_id=2 got an event {'kind': 'Info', 'msg': 'src\\net\\http.rs:344: Inserting "https://ci-chatmail.testrun.org/.well-known/autoconfig/mail/config-v1.1.xml" into cache.'}
DEBUG root:rpc.py:194 account_id=2 got an event {'file': '$BLOBDIR/b66980bca086b8d0d13cf7e231307fd', 'kind': 'NewBlobFile'}
DEBUG root:rpc.py:194 account_id=2 got an event {'comment': None, 'kind': 'ConfigureProgress', 'progress': 500}
DEBUG root:rpc.py:194 account_id=2 got an event {'comment': None, 'kind': 'ConfigureProgress', 'progress': 550}
DEBUG root:rpc.py:194 account_id=2 got an event {'comment': None, 'kind': 'ConfigureProgress', 'progress': 600}
DEBUG root:rpc.py:194 account_id=2 got an event {'kind': 'Info', 'msg': 'src\\imap.rs:300: Connecting to IMAP server.'}
DEBUG root:rpc.py:194 account_id=2 got an event {'kind': 'ConnectivityChanged'}
DEBUG root:rpc.py:194 account_id=2 got an event {'kind': 'Info', 'msg': 'src\\imap.rs:315: IMAP trying to connect to ci-chatmail.testrun.org:993:tls.'}
DEBUG root:rpc.py:194 account_id=2 got an event {'kind': 'Info', 'msg': 'src\\net\\dns.rs:134: Using memory-cached DNS resolution for ci-chatmail.testrun.org.'}
DEBUG root:rpc.py:194 account_id=2 got an event {'kind': 'Info', 'msg': 'src\\net\\dns.rs:180: Resolved ci-chatmail.testrun.org into 49.12.217.82.'}
DEBUG root:rpc.py:194 account_id=2 got an event {'kind': 'Info', 'msg': 'src\\imap\\client.rs:134: Attempting IMAP connection to ci-chatmail.testrun.org (49.12.217.82:993).'}
DEBUG root:rpc.py:194 account_id=2 got an event {'kind': 'Info', 'msg': 'src\\smtp.rs:130: SMTP trying to connect to ci-chatmail.testrun.org:465:tls.'}
DEBUG root:rpc.py:194 account_id=2 got an event {'kind': 'Info', 'msg': 'src\\net\\dns.rs:134: Using memory-cached DNS resolution for ci-chatmail.testrun.org.'}
DEBUG root:rpc.py:194 account_id=2 got an event {'kind': 'Info', 'msg': 'src\\net\\dns.rs:180: Resolved ci-chatmail.testrun.org into 49.12.217.82.'}
DEBUG root:rpc.py:194 account_id=2 got an event {'kind': 'Info', 'msg': 'src\\smtp\\connect.rs:87: Attempting SMTP connection to ci-chatmail.testrun.org (49.12.217.82:465).'}
DEBUG root:rpc.py:194 account_id=1 got an event {'kind': 'ImapConnected', 'msg': 'IMAP-LOGIN as asfudkmlh@ci-chatmail.testrun.org'}
DEBUG root:rpc.py:194 account_id=1 got an event {'kind': 'ConnectivityChanged'}
DEBUG root:rpc.py:194 account_id=1 got an event {'kind': 'Info', 'msg': 'src\\imap.rs:400: Successfully logged into IMAP server.'}
DEBUG root:rpc.py:194 account_id=1 got an event {'comment': None, 'kind': 'ConfigureProgress', 'progress': 850}
DEBUG root:rpc.py:194 account_id=1 got an event {'kind': 'SmtpConnected', 'msg': 'SMTP-LOGIN as asfudkmlh@ci-chatmail.testrun.org ok'}
DEBUG root:rpc.py:194 account_id=1 got an event {'comment': None, 'kind': 'ConfigureProgress', 'progress': 900}
DEBUG root:rpc.py:194 account_id=1 got an event {'comment': None, 'kind': 'ConfigureProgress', 'progress': 910}
DEBUG root:rpc.py:194 account_id=1 got an event {'kind': 'Info', 'msg': 'src\\transport.rs:562: Sending transport synchronization message.'}
DEBUG root:rpc.py:194 account_id=1 got an event {'comment': None, 'kind': 'ConfigureProgress', 'progress': 920}
DEBUG root:rpc.py:194 account_id=1 got an event {'comment': None, 'kind': 'ConfigureProgress', 'progress': 940}
DEBUG root:rpc.py:194 account_id=1 got an event {'kind': 'Info', 'msg': 'src\\chat.rs:266: Scale up origin of Contact#Self to CreateChat.'}
DEBUG root:rpc.py:194 account_id=1 got an event {'chatId': 0, 'kind': 'MsgsChanged', 'msgId': 0}
DEBUG root:rpc.py:194 account_id=1 got an event {'kind': 'ChatlistChanged'}
DEBUG root:rpc.py:194 account_id=1 got an event {'chatId': 10, 'kind': 'ChatlistItemChanged'}
DEBUG root:rpc.py:194 account_id=1 got an event {'file': '$BLOBDIR/91f9bc261758b09b57844798ebb61f1.jpg', 'kind': 'NewBlobFile'}
DEBUG root:rpc.py:194 account_id=1 got an event {'kind': 'Info', 'msg': 'src\\chat.rs:2579: Attaching "C:\\Users\\runneradmin\\AppData\\Local\\Temp\\pytest-of-unknown\\pytest-0\\popen-gw4\\test_multidevice_sync_chat0\\accounts\\04f25727-cf55-4edd-80e0-2d988ab2dc6f\\dc.db-blobs\\91f9bc261758b09b57844798ebb61f1.jpg" for message type #Image.'}
DEBUG root:rpc.py:194 account_id=1 got an event {'chatId': 11, 'kind': 'MsgsChanged', 'msgId': 10}
DEBUG root:rpc.py:194 account_id=1 got an event {'kind': 'ChatlistChanged'}
DEBUG root:rpc.py:194 account_id=1 got an event {'chatId': 11, 'kind': 'ChatlistItemChanged'}
DEBUG root:rpc.py:194 account_id=1 got an event {'chatId': 11, 'kind': 'MsgsChanged', 'msgId': 11}
DEBUG root:rpc.py:194 account_id=1 got an event {'kind': 'ChatlistChanged'}
DEBUG root:rpc.py:194 account_id=1 got an event {'chatId': 11, 'kind': 'ChatlistItemChanged'}
DEBUG root:rpc.py:194 account_id=1 got an event {'kind': 'AccountsItemChanged'}
DEBUG root:rpc.py:194 account_id=1 got an event {'comment': None, 'kind': 'ConfigureProgress', 'progress': 1000}
DEBUG root:rpc.py:194 account_id=1 got an event {'kind': 'Info', 'msg': 'src\\scheduler.rs:72: starting IO'}
DEBUG root:rpc.py:194 account_id=1 got an event {'kind': 'Info', 'msg': 'src\\scheduler.rs:354: Starting inbox loop.'}
DEBUG root:rpc.py:194 account_id=1 got an event {'kind': 'Info', 'msg': 'src\\scheduler.rs:561: Starting SMTP loop.'}
DEBUG root:rpc.py:194 account_id=1 got an event {'kind': 'Info', 'msg': 'src\\scheduler.rs:374: Transport 1: Preparing new IMAP session for inbox.'}
DEBUG root:rpc.py:194 account_id=1 got an event {'kind': 'Info', 'msg': 'src\\imap.rs:300: Connecting to IMAP server.'}
DEBUG root:rpc.py:194 account_id=1 got an event {'kind': 'ConnectivityChanged'}
DEBUG root:rpc.py:194 account_id=1 got an event {'kind': 'Info', 'msg': 'src\\ephemeral.rs:610: Ephemeral loop waiting for deletion in 24h 0m 0s or interrupt'}
DEBUG root:rpc.py:194 account_id=1 got an event {'kind': 'Info', 'msg': 'src\\imap.rs:315: IMAP trying to connect to ci-chatmail.testrun.org:993:tls.'}
DEBUG root:rpc.py:194 account_id=1 got an event {'kind': 'Info', 'msg': 'src\\net\\dns.rs:134: Using memory-cached DNS resolution for ci-chatmail.testrun.org.'}
DEBUG root:rpc.py:194 account_id=1 got an event {'kind': 'Info', 'msg': 'src\\net\\dns.rs:180: Resolved ci-chatmail.testrun.org into 49.12.217.82.'}
DEBUG root:rpc.py:194 account_id=1 got an event {'kind': 'Info', 'msg': 'src\\imap\\client.rs:134: Attempting IMAP connection to ci-chatmail.testrun.org (49.12.217.82:993).'}
DEBUG root:rpc.py:194 account_id=1 got an event {'kind': 'Info', 'msg': 'src\\location.rs:731: Location loop is waiting for 24h 0m 0s or interrupt'}
DEBUG root:rpc.py:194 account_id=1 got an event {'kind': 'Info', 'msg': 'src\\contact.rs:2154: Recently seen loop waiting for 24h 0m 0s or interrupt'}
DEBUG root:rpc.py:194 account_id=1 got an event {'kind': 'Info', 'msg': 'src\\scheduler.rs:721: scheduler is running'}
DEBUG root:rpc.py:194 account_id=1 got an event {'kind': 'ConnectivityChanged'}
DEBUG root:rpc.py:194 account_id=1 got an event {'kind': 'Info', 'msg': 'src\\smtp.rs:538: Selected rows from SMTP queue: [].'}
DEBUG root:rpc.py:194 account_id=1 got an event {'kind': 'Info', 'msg': 'src\\smtp.rs:656: Sending MDNs.'}
DEBUG root:rpc.py:194 account_id=1 got an event {'kind': 'Info', 'msg': 'src\\scheduler.rs:601: SMTP fake idle started.'}
DEBUG root:rpc.py:194 account_id=1 got an event {'kind': 'ConnectivityChanged'}
DEBUG root:rpc.py:194 account_id=1 got an event {'kind': 'Info', 'msg': 'src\\scheduler.rs:629: SMTP has no messages to retry, waiting for interrupt.'}
DEBUG root:rpc.py:194 account_id=2 got an event {'kind': 'Info', 'msg': 'src\\imap.rs:340: Logging into IMAP server with LOGIN.'}
DEBUG root:rpc.py:194 account_id=1 got an event {'kind': 'Info', 'msg': 'src\\imap.rs:340: Logging into IMAP server with LOGIN.'}
DEBUG root:rpc.py:194 account_id=2 got an event {'kind': 'ImapConnected', 'msg': 'IMAP-LOGIN as cvgo7afcm@ci-chatmail.testrun.org'}
DEBUG root:rpc.py:194 account_id=2 got an event {'kind': 'ConnectivityChanged'}
DEBUG root:rpc.py:194 account_id=2 got an event {'kind': 'Info', 'msg': 'src\\imap.rs:400: Successfully logged into IMAP server.'}
DEBUG root:rpc.py:194 account_id=2 got an event {'comment': None, 'kind': 'ConfigureProgress', 'progress': 850}
DEBUG root:rpc.py:194 account_id=2 got an event {'kind': 'SmtpConnected', 'msg': 'SMTP-LOGIN as cvgo7afcm@ci-chatmail.testrun.org ok'}
DEBUG root:rpc.py:194 account_id=2 got an event {'comment': None, 'kind': 'ConfigureProgress', 'progress': 900}
DEBUG root:rpc.py:194 account_id=2 got an event {'comment': None, 'kind': 'ConfigureProgress', 'progress': 910}
DEBUG root:rpc.py:194 account_id=2 got an event {'kind': 'Info', 'msg': 'src\\transport.rs:562: Sending transport synchronization message.'}
DEBUG root:rpc.py:194 account_id=2 got an event {'comment': None, 'kind': 'ConfigureProgress', 'progress': 920}
DEBUG root:rpc.py:194 account_id=2 got an event {'comment': None, 'kind': 'ConfigureProgress', 'progress': 940}
DEBUG root:rpc.py:194 account_id=2 got an event {'kind': 'Info', 'msg': 'src\\chat.rs:266: Scale up origin of Contact#Self to CreateChat.'}
DEBUG root:rpc.py:194 account_id=2 got an event {'chatId': 0, 'kind': 'MsgsChanged', 'msgId': 0}
DEBUG root:rpc.py:194 account_id=2 got an event {'kind': 'ChatlistChanged'}
DEBUG root:rpc.py:194 account_id=2 got an event {'chatId': 10, 'kind': 'ChatlistItemChanged'}
DEBUG root:rpc.py:194 account_id=2 got an event {'file': '$BLOBDIR/91f9bc261758b09b57844798ebb61f1.jpg', 'kind': 'NewBlobFile'}
DEBUG root:rpc.py:194 account_id=2 got an event {'kind': 'Info', 'msg': 'src\\chat.rs:2579: Attaching "C:\\Users\\runneradmin\\AppData\\Local\\Temp\\pytest-of-unknown\\pytest-0\\popen-gw4\\test_multidevice_sync_chat0\\accounts\\85e83f60-0546-402c-a1e3-4e1bf473a31b\\dc.db-blobs\\91f9bc261758b09b57844798ebb61f1.jpg" for message type #Image.'}
DEBUG root:rpc.py:194 account_id=2 got an event {'chatId': 11, 'kind': 'MsgsChanged', 'msgId': 10}
DEBUG root:rpc.py:194 account_id=2 got an event {'kind': 'ChatlistChanged'}
DEBUG root:rpc.py:194 account_id=2 got an event {'chatId': 11, 'kind': 'ChatlistItemChanged'}
DEBUG root:rpc.py:194 account_id=2 got an event {'chatId': 11, 'kind': 'MsgsChanged', 'msgId': 11}
DEBUG root:rpc.py:194 account_id=2 got an event {'kind': 'ChatlistChanged'}
DEBUG root:rpc.py:194 account_id=2 got an event {'chatId': 11, 'kind': 'ChatlistItemChanged'}
DEBUG root:rpc.py:194 account_id=2 got an event {'kind': 'AccountsItemChanged'}
DEBUG root:rpc.py:194 account_id=2 got an event {'comment': None, 'kind': 'ConfigureProgress', 'progress': 1000}
DEBUG root:rpc.py:194 account_id=2 got an event {'kind': 'Info', 'msg': 'src\\scheduler.rs:72: starting IO'}
DEBUG root:rpc.py:194 account_id=2 got an event {'kind': 'Info', 'msg': 'src\\scheduler.rs:354: Starting inbox loop.'}
DEBUG root:rpc.py:194 account_id=2 got an event {'kind': 'Info', 'msg': 'src\\scheduler.rs:374: Transport 1: Preparing new IMAP session for inbox.'}
DEBUG root:rpc.py:194 account_id=2 got an event {'kind': 'Info', 'msg': 'src\\imap.rs:300: Connecting to IMAP server.'}
DEBUG root:rpc.py:194 account_id=2 got an event {'kind': 'ConnectivityChanged'}
DEBUG root:rpc.py:194 account_id=2 got an event {'kind': 'Info', 'msg': 'src\\scheduler.rs:561: Starting SMTP loop.'}
DEBUG root:rpc.py:194 account_id=2 got an event {'kind': 'Info', 'msg': 'src\\scheduler.rs:721: scheduler is running'}
DEBUG root:rpc.py:194 account_id=2 got an event {'kind': 'ConnectivityChanged'}
DEBUG root:rpc.py:194 account_id=2 got an event {'kind': 'Info', 'msg': 'src\\contact.rs:2154: Recently seen loop waiting for 24h 0m 0s or interrupt'}
DEBUG root:rpc.py:194 account_id=2 got an event {'kind': 'Info', 'msg': 'src\\smtp.rs:538: Selected rows from SMTP queue: [].'}
DEBUG root:rpc.py:194 account_id=2 got an event {'kind': 'Info', 'msg': 'src\\ephemeral.rs:610: Ephemeral loop waiting for deletion in 24h 0m 0s or interrupt'}
DEBUG root:rpc.py:194 account_id=2 got an event {'kind': 'Info', 'msg': 'src\\imap.rs:315: IMAP trying to connect to ci-chatmail.testrun.org:993:tls.'}
DEBUG root:rpc.py:194 account_id=2 got an event {'kind': 'Info', 'msg': 'src\\net\\dns.rs:134: Using memory-cached DNS resolution for ci-chatmail.testrun.org.'}
DEBUG root:rpc.py:194 account_id=2 got an event {'kind': 'Info', 'msg': 'src\\net\\dns.rs:180: Resolved ci-chatmail.testrun.org into 49.12.217.82.'}
DEBUG root:rpc.py:194 account_id=2 got an event {'kind': 'Info', 'msg': 'src\\smtp.rs:656: Sending MDNs.'}
DEBUG root:rpc.py:194 account_id=2 got an event {'kind': 'Info', 'msg': 'src\\imap\\client.rs:134: Attempting IMAP connection to ci-chatmail.testrun.org (49.12.217.82:993).'}
DEBUG root:rpc.py:194 account_id=2 got an event {'kind': 'Info', 'msg': 'src\\scheduler.rs:601: SMTP fake idle started.'}
DEBUG root:rpc.py:194 account_id=2 got an event {'kind': 'ConnectivityChanged'}
DEBUG root:rpc.py:194 account_id=2 got an event {'kind': 'Info', 'msg': 'src\\scheduler.rs:629: SMTP has no messages to retry, waiting for interrupt.'}
DEBUG root:rpc.py:194 account_id=2 got an event {'kind': 'Info', 'msg': 'src\\location.rs:731: Location loop is waiting for 24h 0m 0s or interrupt'}
DEBUG root:rpc.py:194 account_id=1 got an event {'kind': 'ImapConnected', 'msg': 'IMAP-LOGIN as asfudkmlh@ci-chatmail.testrun.org'}
DEBUG root:rpc.py:194 account_id=1 got an event {'kind': 'ConnectivityChanged'}
DEBUG root:rpc.py:194 account_id=1 got an event {'kind': 'Info', 'msg': 'src\\imap.rs:400: Successfully logged into IMAP server.'}
DEBUG root:rpc.py:194 account_id=1 got an event {'kind': 'Info', 'msg': 'src\\scheduler.rs:387: Transport 1: Prepared new IMAP session for inbox.'}
DEBUG root:rpc.py:194 account_id=1 got an event {'kind': 'Info', 'msg': 'src\\quota.rs:88: Transport 1: Updating quota.'}
DEBUG root:rpc.py:194 account_id=1 got an event {'kind': 'Info', 'msg': 'src\\quota.rs:106: Transport 1: Updated quota.'}
DEBUG root:rpc.py:194 account_id=1 got an event {'kind': 'ConnectivityChanged'}
DEBUG root:rpc.py:194 account_id=1 got an event {'kind': 'Info', 'msg': 'src\\sql.rs:990: Start housekeeping...'}
DEBUG root:rpc.py:194 account_id=1 got an event {'kind': 'Info', 'msg': 'src\\sql.rs:1051: 2 files in use.'}
DEBUG root:rpc.py:194 account_id=1 got an event {'kind': 'Info', 'msg': 'src\\sql.rs:775: Incremental vacuum freed 0 pages.'}
DEBUG root:rpc.py:194 account_id=2 got an event {'kind': 'Info', 'msg': 'src\\imap.rs:340: Logging into IMAP server with LOGIN.'}
DEBUG root:rpc.py:194 account_id=2 got an event {'kind': 'ImapConnected', 'msg': 'IMAP-LOGIN as cvgo7afcm@ci-chatmail.testrun.org'}
DEBUG root:rpc.py:194 account_id=2 got an event {'kind': 'ConnectivityChanged'}
DEBUG root:rpc.py:194 account_id=2 got an event {'kind': 'Info', 'msg': 'src\\imap.rs:400: Successfully logged into IMAP server.'}
DEBUG root:rpc.py:194 account_id=2 got an event {'kind': 'Info', 'msg': 'src\\scheduler.rs:387: Transport 1: Prepared new IMAP session for inbox.'}
DEBUG root:rpc.py:194 account_id=2 got an event {'kind': 'Info', 'msg': 'src\\quota.rs:88: Transport 1: Updating quota.'}
DEBUG root:rpc.py:194 account_id=2 got an event {'kind': 'Info', 'msg': 'src\\quota.rs:106: Transport 1: Updated quota.'}
DEBUG root:rpc.py:194 account_id=2 got an event {'kind': 'ConnectivityChanged'}
DEBUG root:rpc.py:194 account_id=2 got an event {'kind': 'Info', 'msg': 'src\\sql.rs:990: Start housekeeping...'}
DEBUG root:rpc.py:194 account_id=2 got an event {'kind': 'Info', 'msg': 'src\\sql.rs:1051: 2 files in use.'}
DEBUG root:rpc.py:194 account_id=2 got an event {'kind': 'Info', 'msg': 'src\\sql.rs:775: Incremental vacuum freed 0 pages.'}
DEBUG root:rpc.py:194 account_id=1 got an event {'kind': 'Info', 'msg': 'src\\sql.rs:682: wal_checkpoint: Total time: 666.86ms. Writers blocked for: 447.4µs. Readers blocked for: 355.3µs.'}
DEBUG root:rpc.py:194 account_id=1 got an event {'kind': 'Info', 'msg': 'src\\sql.rs:921: Housekeeping done.'}
DEBUG root:rpc.py:194 account_id=1 got an event {'kind': 'Info', 'msg': 'src\\imap.rs:1334: Server supports metadata, retrieving server comment and admin contact.'}
DEBUG root:rpc.py:194 account_id=2 got an event {'kind': 'Info', 'msg': 'src\\sql.rs:682: wal_checkpoint: Total time: 597.8585ms. Writers blocked for: 495.3µs. Readers blocked for: 410.6µs.'}
DEBUG root:rpc.py:194 account_id=2 got an event {'kind': 'Info', 'msg': 'src\\sql.rs:921: Housekeeping done.'}
DEBUG root:rpc.py:194 account_id=1 got an event {'kind': 'Info', 'msg': 'src\\imap\\select_folder.rs:78: Transport 1: Selected folder "INBOX".'}
DEBUG root:rpc.py:194 account_id=1 got an event {'kind': 'Info', 'msg': 'src\\imap\\select_folder.rs:222: transport 1: UID validity for folder INBOX changed from 0/0 to 1786514718/1.'}
DEBUG root:rpc.py:194 account_id=1 got an event {'kind': 'Info', 'msg': 'src\\imap.rs:561: fetch_new_msg_batch(INBOX): UIDVALIDITY=1786514718, UIDNEXT=1.'}
DEBUG root:rpc.py:194 account_id=1 got an event {'kind': 'Info', 'msg': 'src\\imap.rs:751: 0 mails read from "INBOX".'}
DEBUG root:rpc.py:194 account_id=1 got an event {'kind': 'Info', 'msg': 'src\\imap.rs:760: available_post_msgs: 0, download_later: 0.'}
DEBUG root:rpc.py:194 account_id=1 got an event {'kind': 'ConnectivityChanged'}
DEBUG root:rpc.py:194 account_id=1 got an event {'kind': 'ImapInboxIdle'}
DEBUG root:rpc.py:194 account_id=1 got an event {'kind': 'Info', 'msg': 'src\\imap\\idle.rs:73: Transport 1: IDLE entering wait-on-remote state in folder "INBOX".'}
DEBUG root:rpc.py:194 account_id=2 got an event {'kind': 'Info', 'msg': 'src\\imap.rs:1334: Server supports metadata, retrieving server comment and admin contact.'}
DEBUG root:rpc.py:194 account_id=2 got an event {'kind': 'Info', 'msg': 'src\\imap\\select_folder.rs:78: Transport 1: Selected folder "INBOX".'}
DEBUG root:rpc.py:194 account_id=2 got an event {'kind': 'Info', 'msg': 'src\\imap\\select_folder.rs:222: transport 1: UID validity for folder INBOX changed from 0/0 to 1786514718/1.'}
DEBUG root:rpc.py:194 account_id=2 got an event {'kind': 'Info', 'msg': 'src\\imap.rs:561: fetch_new_msg_batch(INBOX): UIDVALIDITY=1786514718, UIDNEXT=1.'}
DEBUG root:rpc.py:194 account_id=2 got an event {'kind': 'Info', 'msg': 'src\\imap.rs:751: 0 mails read from "INBOX".'}
DEBUG root:rpc.py:194 account_id=2 got an event {'kind': 'Info', 'msg': 'src\\imap.rs:760: available_post_msgs: 0, download_later: 0.'}
DEBUG root:rpc.py:194 account_id=2 got an event {'kind': 'ConnectivityChanged'}
DEBUG root:rpc.py:194 account_id=2 got an event {'kind': 'ImapInboxIdle'}
DEBUG root:rpc.py:194 account_id=2 got an event {'kind': 'Info', 'msg': 'src\\key.rs:482: Generating keypair.'}
DEBUG root:rpc.py:194 account_id=2 got an event {'kind': 'AccountsItemChanged'}
DEBUG root:rpc.py:194 account_id=2 got an event {'kind': 'Info', 'msg': 'src\\key.rs:488: Keypair generated in 0s.'}
DEBUG root:rpc.py:194 account_id=2 got an event {'kind': 'Info', 'msg': 'src\\key.rs:133: Converting secret key to public key.'}
DEBUG root:rpc.py:194 account_id=1 got an event {'kind': 'Info', 'msg': 'src\\contact.rs:370: Saved key with fingerprint 928A4C758BF207B5D50DACA80296126BC0B8A955 from the Autocrypt header'}
DEBUG root:rpc.py:194 account_id=1 got an event {'kind': 'Info', 'msg': 'src\\key.rs:482: Generating keypair.'}
DEBUG root:rpc.py:194 account_id=1 got an event {'kind': 'AccountsItemChanged'}
DEBUG root:rpc.py:194 account_id=1 got an event {'kind': 'Info', 'msg': 'src\\key.rs:488: Keypair generated in 0s.'}
DEBUG root:rpc.py:194 account_id=1 got an event {'kind': 'Info', 'msg': 'src\\key.rs:133: Converting secret key to public key.'}
DEBUG root:rpc.py:194 account_id=1 got an event {'kind': 'Info', 'msg': 'src\\contact.rs:1096: Added contact id=10 fpr=928A4C758BF207B5D50DACA80296126BC0B8A955 addr=cvgo7afcm@ci-chatmail.testrun.org.'}
DEBUG root:rpc.py:194 account_id=1 got an event {'contactId': 10, 'kind': 'ContactsChanged'}
DEBUG root:rpc.py:194 account_id=1 got an event {'contactId': 10, 'kind': 'ContactsChanged'}
DEBUG root:rpc.py:194 account_id=1 got an event {'kind': 'Info', 'msg': 'src\\scheduler.rs:633: SMTP fake idle interrupted.'}
DEBUG root:rpc.py:194 account_id=1 got an event {'kind': 'Info', 'msg': 'src\\smtp.rs:538: Selected rows from SMTP queue: [].'}
DEBUG root:rpc.py:194 account_id=1 got an event {'kind': 'Info', 'msg': 'src\\smtp.rs:656: Sending MDNs.'}
DEBUG root:rpc.py:194 account_id=1 got an event {'kind': 'Info', 'msg': 'src\\scheduler.rs:601: SMTP fake idle started.'}
DEBUG root:rpc.py:194 account_id=1 got an event {'kind': 'ConnectivityChanged'}
DEBUG root:rpc.py:194 account_id=1 got an event {'kind': 'Info', 'msg': 'src\\scheduler.rs:629: SMTP has no messages to retry, waiting for interrupt.'}
DEBUG root:rpc.py:194 account_id=1 got an event {'chatId': 12, 'kind': 'MsgsChanged', 'msgId': 12}
DEBUG root:rpc.py:194 account_id=1 got an event {'kind': 'ChatlistChanged'}
DEBUG root:rpc.py:194 account_id=1 got an event {'chatId': 12, 'kind': 'ChatlistItemChanged'}
DEBUG root:rpc.py:194 account_id=1 got an event {'kind': 'Info', 'msg': 'src\\chat.rs:266: Scale up origin of Contact#10 to CreateChat.'}
DEBUG root:rpc.py:194 account_id=1 got an event {'chatId': 0, 'kind': 'MsgsChanged', 'msgId': 0}
DEBUG root:rpc.py:194 account_id=1 got an event {'kind': 'ChatlistChanged'}
DEBUG root:rpc.py:194 account_id=1 got an event {'chatId': 12, 'kind': 'ChatlistItemChanged'}
DEBUG root:rpc.py:194 account_id=1 got an event {'kind': 'Info', 'msg': 'src\\ephemeral.rs:610: Ephemeral loop waiting for deletion in 24h 0m 0s or interrupt'}
DEBUG root:rpc.py:194 account_id=1 got an event {'kind': 'Info', 'msg': 'src\\mimefactory.rs:769: Scale up origin of Chat#12 recipients to OutgoingTo.'}
DEBUG root:rpc.py:194 account_id=1 got an event {'kind': 'Info', 'msg': 'src\\chat.rs:2921: Message Msg#13 will be sent in one shot (no pre- and post-message). Size: 2.82 KiB.'}
DEBUG root:rpc.py:194 account_id=1 got an event {'chatId': 12, 'kind': 'MsgsChanged', 'msgId': 13}
DEBUG root:rpc.py:194 account_id=1 got an event {'kind': 'ChatlistChanged'}
DEBUG root:rpc.py:194 account_id=1 got an event {'chatId': 12, 'kind': 'ChatlistItemChanged'}
DEBUG root:rpc.py:194 account_id=1 got an event {'kind': 'Info', 'msg': 'src\\scheduler.rs:633: SMTP fake idle interrupted.'}
DEBUG root:rpc.py:194 account_id=1 got an event {'kind': 'Info', 'msg': 'src\\smtp.rs:538: Selected rows from SMTP queue: [1].'}
DEBUG root:rpc.py:194 account_id=1 got an event {'kind': 'ConnectivityChanged'}
DEBUG root:rpc.py:194 account_id=1 got an event {'kind': 'Info', 'msg': 'src\\smtp.rs:130: SMTP trying to connect to ci-chatmail.testrun.org:465:tls.'}
DEBUG root:rpc.py:194 account_id=1 got an event {'kind': 'Info', 'msg': 'src\\net\\dns.rs:134: Using memory-cached DNS resolution for ci-chatmail.testrun.org.'}
DEBUG root:rpc.py:194 account_id=1 got an event {'kind': 'Info', 'msg': 'src\\net\\dns.rs:180: Resolved ci-chatmail.testrun.org into 49.12.217.82.'}
DEBUG root:rpc.py:194 account_id=1 got an event {'kind': 'Info', 'msg': 'src\\smtp\\connect.rs:87: Attempting SMTP connection to ci-chatmail.testrun.org (49.12.217.82:465).'}
DEBUG root:rpc.py:194 account_id=2 got an event {'kind': 'Info', 'msg': 'src\\imap\\idle.rs:73: Transport 1: IDLE entering wait-on-remote state in folder "INBOX".'}
DEBUG root:rpc.py:194 account_id=1 got an event {'kind': 'SmtpConnected', 'msg': 'SMTP-LOGIN as asfudkmlh@ci-chatmail.testrun.org ok'}
DEBUG root:rpc.py:194 account_id=1 got an event {'kind': 'Info', 'msg': 'src\\smtp.rs:386: Try number 1 to send message Msg#13 (entry 1) over SMTP.'}
DEBUG root:rpc.py:194 account_id=1 got an event {'kind': 'ConnectivityChanged'}
DEBUG root:rpc.py:194 account_id=1 got an event {'kind': 'Info', 'msg': 'src\\smtp\\send.rs:62: Message len=2890 was SMTP-sent to 1 recipients..'}
DEBUG root:rpc.py:194 account_id=1 got an event {'kind': 'SmtpMessageSent', 'msg': 'Message len=2890 was SMTP-sent to 1 recipients.'}
DEBUG root:rpc.py:194 account_id=1 got an event {'chatId': 12, 'kind': 'MsgDelivered', 'msgId': 13}
DEBUG root:rpc.py:194 account_id=1 got an event {'chatId': 12, 'kind': 'ChatlistItemChanged'}
DEBUG root:rpc.py:194 account_id=1 got an event {'kind': 'Info', 'msg': 'src\\smtp.rs:656: Sending MDNs.'}
DEBUG root:rpc.py:194 account_id=1 got an event {'kind': 'Info', 'msg': 'src\\scheduler.rs:601: SMTP fake idle started.'}
DEBUG root:rpc.py:194 account_id=1 got an event {'kind': 'ConnectivityChanged'}
DEBUG root:rpc.py:194 account_id=1 got an event {'kind': 'Info', 'msg': 'src\\scheduler.rs:629: SMTP has no messages to retry, waiting for interrupt.'}
DEBUG root:rpc.py:194 account_id=2 got an event {'kind': 'Info', 'msg': 'src\\imap\\idle.rs:96: "INBOX": Idle has NewData ResponseData { raw: 4096, response: MailboxData(Exists(1)) }'}
DEBUG root:rpc.py:194 account_id=2 got an event {'kind': 'Info', 'msg': 'src\\imap.rs:561: fetch_new_msg_batch(INBOX): UIDVALIDITY=1786514718, UIDNEXT=1.'}
DEBUG root:rpc.py:194 account_id=2 got an event {'kind': 'Info', 'msg': 'src\\contact.rs:1094: Added contact id=10 addr=asfudkmlh@ci-chatmail.testrun.org.'}
DEBUG root:rpc.py:194 account_id=2 got an event {'kind': 'Info', 'msg': 'src\\imap.rs:679: "f1f02eb1-3a57-4803-a939-a18e734f84a3@localhost" is not a post-message.'}
DEBUG root:rpc.py:194 account_id=2 got an event {'kind': 'ConnectivityChanged'}
DEBUG root:rpc.py:194 account_id=2 got an event {'kind': 'Info', 'msg': 'src\\imap.rs:1121: Starting UID FETCH of message set "1".'}
DEBUG root:rpc.py:194 account_id=2 got an event {'kind': 'Info', 'msg': 'src\\imap.rs:1213: Passing message UID 1 to receive_imf().'}
DEBUG root:rpc.py:194 account_id=2 got an event {'kind': 'Info', 'msg': 'src\\contact.rs:370: Saved key with fingerprint D45BB1B95C079A5F4698345BBB3D756C7C67BE64 from the Autocrypt header'}
DEBUG root:rpc.py:194 account_id=2 got an event {'kind': 'Info', 'msg': 'src\\receive_imf.rs:532: Receiving message "f1f02eb1-3a57-4803-a939-a18e734f84a3@localhost", seen=false...'}
DEBUG root:rpc.py:194 account_id=2 got an event {'kind': 'Info', 'msg': 'src\\contact.rs:1096: Added contact id=11 fpr=D45BB1B95C079A5F4698345BBB3D756C7C67BE64 addr=asfudkmlh@ci-chatmail.testrun.org.'}
DEBUG root:rpc.py:194 account_id=2 got an event {'kind': 'Info', 'msg': 'src\\receive_imf.rs:1378: Non-group message, no parent. num_recipients=1. from_id=Contact#11. Chat assignment = SingleChat.'}
DEBUG root:rpc.py:194 account_id=2 got an event {'chatId': 12, 'kind': 'MsgsChanged', 'msgId': 12}
DEBUG root:rpc.py:194 account_id=2 got an event {'kind': 'ChatlistChanged'}
DEBUG root:rpc.py:194 account_id=2 got an event {'chatId': 12, 'kind': 'ChatlistItemChanged'}
DEBUG root:rpc.py:194 account_id=2 got an event {'kind': 'Info', 'msg': 'src\\receive_imf.rs:2296: Message has 1 parts and is assigned to chat #Chat#12, timestamp=1786514719.'}
DEBUG root:rpc.py:194 account_id=2 got an event {'contactId': 11, 'kind': 'ContactsChanged'}
DEBUG root:rpc.py:194 account_id=2 got an event {'kind': 'Info', 'msg': 'src\\contact.rs:2154: Recently seen loop waiting for 0h 9m 59s or interrupt'}
DEBUG root:rpc.py:194 account_id=2 got an event {'contactId': 11, 'kind': 'ContactsChanged'}
DEBUG root:rpc.py:194 account_id=2 got an event {'chatId': 12, 'kind': 'ChatlistItemChanged'}
DEBUG root:rpc.py:194 account_id=2 got an event {'chatId': 12, 'kind': 'IncomingMsg', 'msgId': 13}
DEBUG root:rpc.py:194 account_id=2 got an event {'kind': 'ChatlistChanged'}
DEBUG root:rpc.py:194 account_id=2 got an event {'chatId': 12, 'kind': 'ChatlistItemChanged'}
DEBUG root:rpc.py:194 account_id=2 got an event {'kind': 'Info', 'msg': 'src\\imap.rs:1268: Successfully received 1 UIDs.'}
DEBUG root:rpc.py:194 account_id=2 got an event {'kind': 'Info', 'msg': 'src\\imap.rs:751: 1 mails read from "INBOX".'}
DEBUG root:rpc.py:194 account_id=2 got an event {'kind': 'IncomingMsgBunch'}
DEBUG root:rpc.py:194 account_id=2 got an event {'kind': 'Info', 'msg': 'src\\imap.rs:760: available_post_msgs: 0, download_later: 0.'}
DEBUG root:rpc.py:194 account_id=1 got an event {'kind': 'Info', 'msg': 'src\\scheduler.rs:113: stopping IO'}
DEBUG root:rpc.py:194 account_id=1 got an event {'kind': 'ConnectivityChanged'}
DEBUG root:rpc.py:194 account_id=1 got an event {'kind': 'Info', 'msg': 'src\\scheduler.rs:640: Shutting down SMTP loop.'}
DEBUG root:rpc.py:194 account_id=1 got an event {'kind': 'Info', 'msg': 'src\\scheduler.rs:411: Transport 1: Shutting down inbox loop.'}
DEBUG root:rpc.py:194 account_id=1 got an event {'kind': 'Info', 'msg': 'src\\imap\\idle.rs:87: "INBOX": Received interrupt, stopping IDLE.'}
DEBUG root:rpc.py:194 account_id=1 got an event {'kind': 'Info', 'msg': 'src\\sql.rs:990: Start housekeeping...'}
DEBUG root:rpc.py:194 account_id=1 got an event {'kind': 'Info', 'msg': 'src\\sql.rs:1051: 2 files in use.'}
DEBUG root:rpc.py:194 account_id=1 got an event {'kind': 'Info', 'msg': 'src\\sql.rs:775: Incremental vacuum freed 0 pages.'}
DEBUG root:rpc.py:194 account_id=2 got an event {'kind': 'ImapMessageDeleted', 'msg': 'IMAP messages 1 marked as deleted'}
DEBUG root:rpc.py:194 account_id=2 got an event {'kind': 'Info', 'msg': 'src\\imap\\select_folder.rs:41: Expunge messages in "INBOX".'}
DEBUG root:rpc.py:194 account_id=2 got an event {'kind': 'Info', 'msg': 'src\\imap\\select_folder.rs:44: Close/expunge succeeded.'}
DEBUG root:rpc.py:194 account_id=2 got an event {'kind': 'ConnectivityChanged'}
DEBUG root:rpc.py:194 account_id=2 got an event {'kind': 'ImapInboxIdle'}
DEBUG root:rpc.py:194 account_id=1 got an event {'kind': 'Info', 'msg': 'src\\sql.rs:682: wal_checkpoint: Total time: 281.2941ms. Writers blocked for: 223.1µs. Readers blocked for: 138.2µs.'}
DEBUG root:rpc.py:194 account_id=1 got an event {'kind': 'Info', 'msg': 'src\\sql.rs:921: Housekeeping done.'}
DEBUG root:rpc.py:194 account_id=2 got an event {'kind': 'Info', 'msg': 'src\\imap\\select_folder.rs:78: Transport 1: Selected folder "INBOX".'}
DEBUG root:rpc.py:194 account_id=2 got an event {'kind': 'Info', 'msg': 'src\\imap\\idle.rs:73: Transport 1: IDLE entering wait-on-remote state in folder "INBOX".'}
---------------------------- Captured log teardown ----------------------------
DEBUG root:rpc.py:194 account_id=0 got an event {'kind': 'Info', 'msg': 'src\\accounts.rs:360: Stopping IO for all accounts.'}
DEBUG root:rpc.py:194 account_id=2 got an event {'kind': 'Info', 'msg': 'src\\scheduler.rs:113: stopping IO'}
DEBUG root:rpc.py:194 account_id=2 got an event {'kind': 'ConnectivityChanged'}
DEBUG root:rpc.py:194 account_id=2 got an event {'kind': 'Info', 'msg': 'src\\scheduler.rs:411: Transport 1: Shutting down inbox loop.'}
DEBUG root:rpc.py:194 account_id=2 got an event {'kind': 'Info', 'msg': 'src\\scheduler.rs:640: Shutting down SMTP loop.'}
DEBUG root:rpc.py:194 account_id=2 got an event {'kind': 'Info', 'msg': 'src\\imap\\idle.rs:87: "INBOX": Received interrupt, stopping IDLE.'}
__________________________ test_no_old_msg_is_fresh ___________________________
[gw5] win32 -- Python 3.14.6 D:\a\core\core\deltachat-rpc-client\.tox\py\Scripts\python.EXE
acfactory = <deltachat_rpc_client.pytestplugin.ACFactory object at 0x000002041B6E8D60>
def test_no_old_msg_is_fresh(acfactory):
ac1, ac2 = acfactory.get_online_accounts(2)
> ac1_clone = ac1.clone()
^^^^^^^^^^^
tests\test_something.py:1080:
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _
.tox\py\Lib\site-packages\deltachat_rpc_client\account.py:65: in clone
qr = self._rpc.get_backup_qr(self.id)
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
.tox\py\Lib\site-packages\deltachat_rpc_client\rpc.py:30: in __call__
return future()
^^^^^^^^
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _
def rpc_future():
"""Wait for the request to receive a result."""
response = queue.get()
if "error" in response:
> raise JsonRpcError(response["error"])
E deltachat_rpc_client.rpc.JsonRpcError: {'code': -1, 'message': 'Backup provider did not start in time: deadline has elapsed'}
.tox\py\Lib\site-packages\deltachat_rpc_client\rpc.py:48: JsonRpcError
In the log I/O is stopped, but nothing else is logged afterwards.
Here is an error from https://github.com/chatmail/core/actions/runs/31568221118/job/94025700379?pr=8566:
The logic in
inner_get_backup_qris in JSON-RPC crate was added in e985588In the log I/O is stopped, but nothing else is logged afterwards.