Slow SQL query in store_seen_flags_on_imap

[adbenitez]

I have an account with 3 relays, same account in desktop 2.43.0 is fine in idle state, in android with latest core (and also with #8018 by @link2xt ) I still notice the account takes quite a while in "updating..." state every time I startIO (in ArcaneChat I can start/stop IO for each account with a toggle so I can test this) for example in the following two logging sessions where I stopIO and then startIO, and collect logs from startIO until it finish displaying "updating...", first one took around 13 seconds, second time 8 seconds, sometimes it can even take more than 13sec

I was suspecting it could be some of the relays being slow, but I created a new profile with 3 relays using the same servers and then when IO starts it instantaneusly switches to idle/ready

2026-03-23 13:10:45.813 11931-11953 DeltaChat               app_process64                        I  [accId=2] src/scheduler.rs:68: starting IO
2026-03-23 13:10:45.814 11931-11953 DeltaChat               app_process64                        I  [accId=2] src/scheduler.rs:352: Starting inbox loop.
2026-03-23 13:10:45.814 11931-11953 DeltaChat               app_process64                        I  [accId=2] src/scheduler.rs:371: Preparing new IMAP session for inbox.
2026-03-23 13:10:45.814 11931-11953 DeltaChat               app_process64                        I  [accId=2] src/imap.rs:338: Connecting to IMAP server.
2026-03-23 13:10:45.814 11931-11953 DeltaChat               app_process64                        I  [accId=2] src/imap.rs:353: IMAP trying to connect to arcanechat.me:993:tls.
2026-03-23 13:10:45.814 11931-11953 DeltaChat               app_process64                        I  [accId=2] src/net/dns.rs:140: No memory-cached DNS resolution for arcanechat.me available, waiting for the resolver.
2026-03-23 13:10:45.814 11931-11953 DeltaChat               app_process64                        I  [accId=2] src/scheduler.rs:352: Starting inbox loop.
2026-03-23 13:10:45.814 11931-11953 DeltaChat               app_process64                        I  [accId=2] src/scheduler.rs:371: Preparing new IMAP session for inbox.
2026-03-23 13:10:45.814 11931-11953 DeltaChat               app_process64                        I  [accId=2] src/imap.rs:338: Connecting to IMAP server.
2026-03-23 13:10:45.814 11931-11953 DeltaChat               app_process64                        I  [accId=2] src/imap.rs:353: IMAP trying to connect to arcanechat.me:993:tls.
2026-03-23 13:10:45.815 11931-11953 DeltaChat               app_process64                        I  [accId=2] src/net/dns.rs:140: No memory-cached DNS resolution for arcanechat.me available, waiting for the resolver.
2026-03-23 13:10:45.815 11931-11953 DeltaChat               app_process64                        I  [accId=2] src/scheduler.rs:352: Starting inbox loop.
2026-03-23 13:10:45.815 11931-11953 DeltaChat               app_process64                        I  [accId=2] src/scheduler.rs:648: Starting SMTP loop.
2026-03-23 13:10:45.815 11931-11953 DeltaChat               app_process64                        I  [accId=2] src/scheduler.rs:371: Preparing new IMAP session for inbox.
2026-03-23 13:10:45.815 11931-11953 DeltaChat               app_process64                        I  [accId=2] src/scheduler.rs:820: scheduler is running
2026-03-23 13:10:45.815 11931-11953 DeltaChat               app_process64                        I  [accId=2] src/imap.rs:338: Connecting to IMAP server.
2026-03-23 13:10:45.815 11931-11953 DeltaChat               app_process64                        I  [accId=2] src/location.rs:746: Location loop is waiting for 24h 0m 0s or interrupt
2026-03-23 13:10:45.816 11931-11953 DeltaChat               app_process64                        I  [accId=2] src/smtp.rs:516: Selected rows from SMTP queue: [].
2026-03-23 13:10:45.817 11931-11953 DeltaChat               app_process64                        I  [accId=2] src/imap.rs:353: IMAP trying to connect to chat.in-the.eu:993:tls.
2026-03-23 13:10:45.817 11931-11953 DeltaChat               app_process64                        I  [accId=2] src/net/dns.rs:140: No memory-cached DNS resolution for chat.in-the.eu available, waiting for the resolver.
2026-03-23 13:10:45.817 11931-11953 DeltaChat               app_process64                        I  [accId=2] src/smtp.rs:633: Sending MDNs.
2026-03-23 13:10:45.817 11931-11953 DeltaChat               app_process64                        I  [accId=2] src/scheduler.rs:688: SMTP fake idle started.
2026-03-23 13:10:45.817 11931-11953 DeltaChat               app_process64                        I  [accId=2] src/scheduler.rs:716: SMTP has no messages to retry, waiting for interrupt.
2026-03-23 13:10:45.818 11931-11953 DeltaChat               app_process64                        I  [accId=2] src/net/dns.rs:180: Resolved arcanechat.me into 159.195.34.47.
2026-03-23 13:10:45.818 11931-11953 DeltaChat               app_process64                        I  [accId=2] src/net/dns.rs:180: Resolved arcanechat.me into 159.195.34.47.
2026-03-23 13:10:45.818 11931-11953 DeltaChat               app_process64                        I  [accId=2] src/imap/client.rs:122: Attempting IMAP connection to arcanechat.me (159.195.34.47:993).
2026-03-23 13:10:45.819 11931-11953 DeltaChat               app_process64                        I  [accId=2] src/net/dns.rs:180: Resolved chat.in-the.eu into 78.46.190.129.
2026-03-23 13:10:45.819 11931-11953 DeltaChat               app_process64                        I  [accId=2] src/imap/client.rs:122: Attempting IMAP connection to arcanechat.me (159.195.34.47:993).
2026-03-23 13:10:45.819 11931-11953 DeltaChat               app_process64                        I  [accId=2] src/net/dns.rs:180: Resolved chat.in-the.eu into 2a01:4f8:1c17:7b06::1.
2026-03-23 13:10:45.821 11931-11953 DeltaChat               app_process64                        I  [accId=2] src/imap/client.rs:122: Attempting IMAP connection to chat.in-the.eu (78.46.190.129:993).
2026-03-23 13:10:45.821 11931-11953 DeltaChat               app_process64                        I  [accId=2] src/contact.rs:2157: Recently seen loop waiting for 0h 1m 1s or interrupt
2026-03-23 13:10:45.904 11931-11953 DeltaChat               app_process64                        I  [accId=2] src/ephemeral.rs:612: Ephemeral loop waiting for deletion in 2h 2m 5s or interrupt
2026-03-23 13:10:45.917 11931-11953 DeltaChat               app_process64                        I  [accId=2] src/imap.rs:391: Logging into IMAP server with LOGIN.
2026-03-23 13:10:45.917 11931-11953 DeltaChat               app_process64                        I  [accId=2] src/imap.rs:391: Logging into IMAP server with LOGIN.
2026-03-23 13:10:45.932 11931-11953 DeltaChat               app_process64                        I  [accId=2] src/imap.rs:391: Logging into IMAP server with LOGIN.
2026-03-23 13:10:46.012 11931-11953 DeltaChat               app_process64                        I  [accId=2] src/imap.rs:434: Successfully logged into IMAP server.
2026-03-23 13:10:46.015 11931-11953 DeltaChat               app_process64                        I  [accId=2] src/imap.rs:434: Successfully logged into IMAP server.
2026-03-23 13:10:46.039 11931-11953 DeltaChat               app_process64                        I  [accId=2] src/imap.rs:1485: Server supports metadata, retrieving server comment and admin contact.
2026-03-23 13:10:46.051 11931-11953 DeltaChat               app_process64                        I  [accId=2] src/imap.rs:434: Successfully logged into IMAP server.
2026-03-23 13:10:46.073 11931-11953 DeltaChat               app_process64                        W  [accId=2] src/imap.rs:1518: Got invalid URL from iroh relay metadata: "\"\"".
2026-03-23 13:10:46.780 11931-11953 DeltaChat               app_process64                        I  [accId=2] src/imap/select_folder.rs:80: Selected folder "INBOX".
2026-03-23 13:10:46.782 11931-11953 DeltaChat               app_process64                        I  [accId=2] src/imap.rs:598: fetch_new_msg_batch(INBOX): UIDVALIDITY=1774178646, UIDNEXT=913.
2026-03-23 13:10:46.820 11931-11953 DeltaChat               app_process64                        I  [accId=2] src/imap.rs:722: "8de4cb1b-f3f1-46e6-9af5-a9fb7c6d5aae@localhost" is not a post-message.
2026-03-23 13:10:46.822 11931-11953 DeltaChat               app_process64                        I  [accId=2] src/imap.rs:722: "b32568d0-4eae-415e-ba76-385c1126c870@localhost" is not a post-message.
2026-03-23 13:10:46.822 11931-11953 DeltaChat               app_process64                        I  [accId=2] src/imap.rs:1285: Starting UID FETCH of message set "913:914".
2026-03-23 13:10:46.854 11931-11953 DeltaChat               app_process64                        I  [accId=2] src/imap.rs:1375: Passing message UID 913 to receive_imf().
2026-03-23 13:10:46.862 11931-11953 DeltaChat               app_process64                        I  [accId=2] src/receive_imf.rs:520: Receiving message "8de4cb1b-f3f1-46e6-9af5-a9fb7c6d5aae@localhost", seen=true...
2026-03-23 13:10:46.862 11931-11953 DeltaChat               app_process64                        I  [accId=2] src/receive_imf.rs:1197: Message is an MDN (TRASH).
2026-03-23 13:10:46.956 11931-11953 DeltaChat               app_process64                        I  [accId=2] src/receive_imf.rs:2356: Message has 1 parts and is assigned to chat #Chat#Trash.
2026-03-23 13:10:46.956 11931-11953 DeltaChat               app_process64                        I  [accId=2] src/contact.rs:2157: Recently seen loop waiting for 0h 1m 0s or interrupt
2026-03-23 13:10:46.956 11931-11952 G0                      app_process64                        I  executing debounced chatlist loading
2026-03-23 13:10:46.996 11931-11953 DeltaChat               app_process64                        I  [accId=2] src/imap.rs:1375: Passing message UID 914 to receive_imf().
2026-03-23 13:10:47.001 11931-11953 DeltaChat               app_process64                        I  [accId=2] src/receive_imf.rs:520: Receiving message "b32568d0-4eae-415e-ba76-385c1126c870@localhost", seen=true...
2026-03-23 13:10:47.003 11931-11953 DeltaChat               app_process64                        I  [accId=2] src/receive_imf.rs:1197: Message is an MDN (TRASH).
2026-03-23 13:10:47.130 11931-11953 DeltaChat               app_process64                        I  [accId=2] src/receive_imf.rs:2356: Message has 1 parts and is assigned to chat #Chat#Trash.
2026-03-23 13:10:47.131 11931-11953 DeltaChat               app_process64                        I  [accId=2] src/contact.rs:2157: Recently seen loop waiting for 0h 0m 59s or interrupt
2026-03-23 13:10:47.134 11931-11953 DeltaChat               app_process64                        I  [accId=2] src/imap.rs:1420: Successfully received 2 UIDs.
2026-03-23 13:10:47.134 11931-11953 DeltaChat               app_process64                        I  [accId=2] src/imap.rs:794: 2 mails read from "INBOX".
2026-03-23 13:10:47.134 11931-11953 DeltaChat               app_process64                        I  [accId=2] src/imap.rs:803: available_post_msgs: 0, download_later: 0.
2026-03-23 13:10:47.223 11931-11952 G0                      app_process64                        I  executing debounced chatlist loading
2026-03-23 13:10:47.271 11931-11953 DeltaChat               app_process64                        I  [accId=2] src/scheduler.rs:558: IMAP session in folder "INBOX" supports IDLE, using it.
2026-03-23 13:10:47.272 11931-11953 DeltaChat               app_process64                        I  [accId=2] src/imap/idle.rs:45: Skip IDLE in "INBOX" because we got interrupt.
2026-03-23 13:10:47.272 11931-11953 DeltaChat               app_process64                        I  [accId=2] src/scheduler.rs:384: IMAP loop iteration for inbox finished, keeping the session.
2026-03-23 13:10:47.562 11931-11953 DeltaChat               app_process64                        I  [accId=2] src/imap/select_folder.rs:80: Selected folder "INBOX".
2026-03-23 13:10:47.562 11931-11953 DeltaChat               app_process64                        I  [accId=2] src/imap.rs:569: No new emails in folder "INBOX".
2026-03-23 13:10:47.676 11931-11953 DeltaChat               app_process64                        I  [accId=2] src/scheduler.rs:558: IMAP session in folder "INBOX" supports IDLE, using it.
2026-03-23 13:10:47.676 11931-11953 DeltaChat               app_process64                        I  [accId=2] src/imap/idle.rs:45: Skip IDLE in "INBOX" because we got interrupt.
2026-03-23 13:10:47.676 11931-11953 DeltaChat               app_process64                        I  [accId=2] src/scheduler.rs:384: IMAP loop iteration for inbox finished, keeping the session.
2026-03-23 13:10:47.768 11931-11953 DeltaChat               app_process64                        I  [accId=2] src/imap.rs:1129: Marked messages 913:914 in folder INBOX as seen.
2026-03-23 13:10:47.769 11931-11953 DeltaChat               app_process64                        I  [accId=2] src/imap.rs:569: No new emails in folder "INBOX".
2026-03-23 13:10:47.853 11931-11953 DeltaChat               app_process64                        I  [accId=2] src/scheduler.rs:558: IMAP session in folder "INBOX" supports IDLE, using it.
2026-03-23 13:10:47.878 11931-11953 DeltaChat               app_process64                        I  [accId=2] src/imap/idle.rs:62: IDLE entering wait-on-remote state in folder "INBOX".
2026-03-23 13:10:49.203 11931-11953 DeltaChat               app_process64                        I  [accId=2] src/imap.rs:569: No new emails in folder "INBOX".
2026-03-23 13:10:49.285 11931-11953 DeltaChat               app_process64                        I  [accId=2] src/scheduler.rs:558: IMAP session in folder "INBOX" supports IDLE, using it.
2026-03-23 13:10:49.310 11931-11953 DeltaChat               app_process64                        I  [accId=2] src/imap/idle.rs:62: IDLE entering wait-on-remote state in folder "INBOX".
2026-03-23 13:10:53.532 11931-11953 DeltaChat               app_process64                        I  [accId=2] src/imap/select_folder.rs:80: Selected folder "INBOX".
2026-03-23 13:10:53.534 11931-11953 DeltaChat               app_process64                        I  [accId=2] src/imap.rs:569: No new emails in folder "INBOX".
2026-03-23 13:10:53.567 11931-12038 FcmReceiveService       app_process64                        I  FCM push notification received
2026-03-23 13:10:53.567 11931-11953 DeltaChat               app_process64                        I  [accId=0] Starting background fetch for 5 accounts.
2026-03-23 13:10:53.568 11931-11953 DeltaChat               app_process64                        I  [accId=2] src/context.rs:616: background_fetch started fetching wlnewteb8kntjjqhlx9w@chat.in-the.eu.
2026-03-23 13:10:53.568 11931-11953 DeltaChat               app_process64                        I  [accId=2] src/imap/idle.rs:76: "INBOX": Received interrupt, stopping IDLE.
2026-03-23 13:10:53.568 11931-11953 DeltaChat               app_process64                        I  [accId=2] src/scheduler.rs:720: SMTP fake idle interrupted.
2026-03-23 13:10:53.568 11931-11953 DeltaChat               app_process64                        I  [accId=2] src/imap/idle.rs:91: "INBOX": Idle wait was interrupted manually.
2026-03-23 13:10:53.568 11931-11953 DeltaChat               app_process64                        I  [accId=2] src/imap/idle.rs:76: "INBOX": Received interrupt, stopping IDLE.
2026-03-23 13:10:53.568 11931-11953 DeltaChat               app_process64                        I  [accId=2] src/imap/idle.rs:91: "INBOX": Idle wait was interrupted manually.
2026-03-23 13:10:53.568 11931-11953 DeltaChat               app_process64                        I  [accId=2] src/smtp.rs:516: Selected rows from SMTP queue: [].
2026-03-23 13:10:53.568 11931-11953 DeltaChat               app_process64                        I  [accId=2] src/smtp.rs:633: Sending MDNs.
2026-03-23 13:10:53.591 11931-11953 DeltaChat               app_process64                        I  [accId=2] src/scheduler.rs:384: IMAP loop iteration for inbox finished, keeping the session.
2026-03-23 13:10:53.601 11931-11953 DeltaChat               app_process64                        I  [accId=2] src/scheduler.rs:384: IMAP loop iteration for inbox finished, keeping the session.
2026-03-23 13:10:53.616 11931-11953 DeltaChat               app_process64                        I  [accId=2] src/scheduler.rs:688: SMTP fake idle started.
2026-03-23 13:10:53.617 11931-11953 DeltaChat               app_process64                        I  [accId=2] src/scheduler.rs:716: SMTP has no messages to retry, waiting for interrupt.
2026-03-23 13:10:53.641 11931-11953 DeltaChat               app_process64                        I  [accId=2] src/scheduler.rs:558: IMAP session in folder "INBOX" supports IDLE, using it.
2026-03-23 13:10:53.641 11931-11953 DeltaChat               app_process64                        I  [accId=2] src/imap/idle.rs:45: Skip IDLE in "INBOX" because we got interrupt.
2026-03-23 13:10:53.641 11931-11953 DeltaChat               app_process64                        I  [accId=2] src/scheduler.rs:384: IMAP loop iteration for inbox finished, keeping the session.
2026-03-23 13:10:53.980 11931-11953 DeltaChat               app_process64                        I  [accId=2] src/imap.rs:598: fetch_new_msg_batch(INBOX): UIDVALIDITY=1774178646, UIDNEXT=915.
2026-03-23 13:10:54.011 11931-11953 DeltaChat               app_process64                        I  [accId=2] src/imap.rs:794: 0 mails read from "INBOX".
2026-03-23 13:10:54.011 11931-11953 DeltaChat               app_process64                        I  [accId=2] src/imap.rs:803: available_post_msgs: 0, download_later: 0.
2026-03-23 13:10:54.121 11931-11953 DeltaChat               app_process64                        I  [accId=2] src/scheduler.rs:558: IMAP session in folder "INBOX" supports IDLE, using it.
2026-03-23 13:10:54.121 11931-11953 DeltaChat               app_process64                        I  [accId=2] src/imap.rs:1807: Need to refetch "INBOX", got unsolicited EXISTS Exists(874)
2026-03-23 13:10:54.121 11931-11953 DeltaChat               app_process64                        I  [accId=2] src/imap/idle.rs:37: Skipping IDLE in "INBOX" because there may be new mail.
2026-03-23 13:10:54.121 11931-11953 DeltaChat               app_process64                        I  [accId=2] src/scheduler.rs:384: IMAP loop iteration for inbox finished, keeping the session.
2026-03-23 13:10:54.703 11931-11953 DeltaChat               app_process64                        I  [accId=2] src/imap.rs:598: fetch_new_msg_batch(INBOX): UIDVALIDITY=1774178646, UIDNEXT=915.
2026-03-23 13:10:54.740 11931-11953 DeltaChat               app_process64                        I  [accId=2] src/imap.rs:722: "31f28704-3361-4da2-afdb-109664959427@localhost" is not a post-message.
2026-03-23 13:10:54.740 11931-11953 DeltaChat               app_process64                        I  [accId=2] src/imap.rs:1285: Starting UID FETCH of message set "915".
2026-03-23 13:10:54.767 11931-11953 DeltaChat               app_process64                        I  [accId=2] src/imap.rs:1375: Passing message UID 915 to receive_imf().
2026-03-23 13:10:54.770 11931-11953 DeltaChat               app_process64                        I  [accId=2] src/receive_imf.rs:520: Receiving message "31f28704-3361-4da2-afdb-109664959427@localhost", seen=true...
2026-03-23 13:10:54.770 11931-11953 DeltaChat               app_process64                        I  [accId=2] src/receive_imf.rs:1197: Message is an MDN (TRASH).
2026-03-23 13:10:54.861 11931-11953 DeltaChat               app_process64                        I  [accId=2] src/receive_imf.rs:2356: Message has 1 parts and is assigned to chat #Chat#Trash.
2026-03-23 13:10:54.861 11931-11953 DeltaChat               app_process64                        I  [accId=2] src/contact.rs:2157: Recently seen loop waiting for 0h 0m 52s or interrupt
2026-03-23 13:10:54.861 11931-11952 G0                      app_process64                        I  executing debounced chatlist loading
2026-03-23 13:10:54.916 11931-11953 DeltaChat               app_process64                        I  [accId=2] src/imap.rs:1420: Successfully received 1 UIDs.
2026-03-23 13:10:54.916 11931-11953 DeltaChat               app_process64                        I  [accId=2] src/imap.rs:794: 1 mails read from "INBOX".
2026-03-23 13:10:54.916 11931-11953 DeltaChat               app_process64                        I  [accId=2] src/imap.rs:803: available_post_msgs: 0, download_later: 0.
2026-03-23 13:10:55.055 11931-11953 DeltaChat               app_process64                        I  [accId=2] src/scheduler.rs:558: IMAP session in folder "INBOX" supports IDLE, using it.
2026-03-23 13:10:55.055 11931-11953 DeltaChat               app_process64                        I  [accId=2] src/imap/idle.rs:45: Skip IDLE in "INBOX" because we got interrupt.
2026-03-23 13:10:55.055 11931-11953 DeltaChat               app_process64                        I  [accId=2] src/scheduler.rs:384: IMAP loop iteration for inbox finished, keeping the session.
2026-03-23 13:10:55.137 11931-11953 DeltaChat               app_process64                        I  [accId=2] src/imap.rs:598: fetch_new_msg_batch(INBOX): UIDVALIDITY=1736775997, UIDNEXT=8782970.
2026-03-23 13:10:55.162 11931-11953 DeltaChat               app_process64                        I  [accId=2] src/imap.rs:794: 0 mails read from "INBOX".
2026-03-23 13:10:55.162 11931-11953 DeltaChat               app_process64                        I  [accId=2] src/imap.rs:803: available_post_msgs: 0, download_later: 0.
2026-03-23 13:10:55.255 11931-11953 DeltaChat               app_process64                        I  [accId=2] src/scheduler.rs:558: IMAP session in folder "INBOX" supports IDLE, using it.
2026-03-23 13:10:55.255 11931-11953 DeltaChat               app_process64                        I  [accId=2] src/imap/idle.rs:45: Skip IDLE in "INBOX" because we got interrupt.
2026-03-23 13:10:55.255 11931-11953 DeltaChat               app_process64                        I  [accId=2] src/scheduler.rs:384: IMAP loop iteration for inbox finished, keeping the session.
2026-03-23 13:10:55.302 11931-11953 DeltaChat               app_process64                        I  [accId=2] src/context.rs:658: background_fetch done for wlnewteb8kntjjqhlx9w@chat.in-the.eu took 1.73442916s.
2026-03-23 13:10:55.302 11931-11953 DeltaChat               app_process64                        I  [accId=0] Finished background fetch for 5 accounts.
2026-03-23 13:10:55.504 11931-11953 DeltaChat               app_process64                        I  [accId=2] src/imap.rs:1129: Marked messages 915 in folder INBOX as seen.
2026-03-23 13:10:55.506 11931-11953 DeltaChat               app_process64                        I  [accId=2] src/imap.rs:569: No new emails in folder "INBOX".
2026-03-23 13:10:55.634 11931-11953 DeltaChat               app_process64                        I  [accId=2] src/scheduler.rs:558: IMAP session in folder "INBOX" supports IDLE, using it.
2026-03-23 13:10:55.659 11931-11953 DeltaChat               app_process64                        I  [accId=2] src/imap/idle.rs:62: IDLE entering wait-on-remote state in folder "INBOX".
2026-03-23 13:10:56.897 11931-11953 DeltaChat               app_process64                        I  [accId=2] src/imap.rs:569: No new emails in folder "INBOX".
2026-03-23 13:10:57.030 11931-11953 DeltaChat               app_process64                        I  [accId=2] src/scheduler.rs:558: IMAP session in folder "INBOX" supports IDLE, using it.
2026-03-23 13:10:57.055 11931-11953 DeltaChat               app_process64                        I  [accId=2] src/imap/idle.rs:62: IDLE entering wait-on-remote state in folder "INBOX".

another time:

2026-03-23 13:16:20.966 11931-11953 DeltaChat               com.github.arcanechat                I  [accId=2] src/scheduler.rs:68: starting IO
2026-03-23 13:16:20.967 11931-11953 DeltaChat               com.github.arcanechat                I  [accId=2] src/scheduler.rs:352: Starting inbox loop.
2026-03-23 13:16:20.967 11931-11953 DeltaChat               com.github.arcanechat                I  [accId=2] src/scheduler.rs:371: Preparing new IMAP session for inbox.
2026-03-23 13:16:20.967 11931-11953 DeltaChat               com.github.arcanechat                I  [accId=2] src/imap.rs:338: Connecting to IMAP server.
2026-03-23 13:16:20.967 11931-11953 DeltaChat               com.github.arcanechat                I  [accId=2] src/scheduler.rs:352: Starting inbox loop.
2026-03-23 13:16:20.968 11931-11953 DeltaChat               com.github.arcanechat                I  [accId=2] src/scheduler.rs:371: Preparing new IMAP session for inbox.
2026-03-23 13:16:20.968 11931-11953 DeltaChat               com.github.arcanechat                I  [accId=2] src/imap.rs:338: Connecting to IMAP server.
2026-03-23 13:16:20.968 11931-11953 DeltaChat               com.github.arcanechat                I  [accId=2] src/imap.rs:353: IMAP trying to connect to arcanechat.me:993:tls.
2026-03-23 13:16:20.968 11931-11953 DeltaChat               com.github.arcanechat                I  [accId=2] src/net/dns.rs:134: Using memory-cached DNS resolution for arcanechat.me.
2026-03-23 13:16:20.968 11931-11953 DeltaChat               com.github.arcanechat                I  [accId=2] src/net/dns.rs:180: Resolved arcanechat.me into 159.195.34.47.
2026-03-23 13:16:20.968 11931-11953 DeltaChat               com.github.arcanechat                I  [accId=2] src/imap.rs:353: IMAP trying to connect to arcanechat.me:993:tls.
2026-03-23 13:16:20.968 11931-11953 DeltaChat               com.github.arcanechat                I  [accId=2] src/net/dns.rs:134: Using memory-cached DNS resolution for arcanechat.me.
2026-03-23 13:16:20.968 11931-11953 DeltaChat               com.github.arcanechat                I  [accId=2] src/net/dns.rs:180: Resolved arcanechat.me into 159.195.34.47.
2026-03-23 13:16:20.968 11931-11953 DeltaChat               com.github.arcanechat                I  [accId=2] src/scheduler.rs:352: Starting inbox loop.
2026-03-23 13:16:20.968 11931-11953 DeltaChat               com.github.arcanechat                I  [accId=2] src/scheduler.rs:371: Preparing new IMAP session for inbox.
2026-03-23 13:16:20.968 11931-11953 DeltaChat               com.github.arcanechat                I  [accId=2] src/imap.rs:338: Connecting to IMAP server.
2026-03-23 13:16:20.969 11931-11953 DeltaChat               com.github.arcanechat                I  [accId=2] src/scheduler.rs:648: Starting SMTP loop.
2026-03-23 13:16:20.969 11931-11953 DeltaChat               com.github.arcanechat                I  [accId=2] src/scheduler.rs:820: scheduler is running
2026-03-23 13:16:20.974 11931-11953 DeltaChat               com.github.arcanechat                I  [accId=2] src/location.rs:746: Location loop is waiting for 24h 0m 0s or interrupt
2026-03-23 13:16:20.975 11931-11953 DeltaChat               com.github.arcanechat                I  [accId=2] src/imap/client.rs:122: Attempting IMAP connection to arcanechat.me (159.195.34.47:993).
2026-03-23 13:16:20.978 11931-11953 DeltaChat               com.github.arcanechat                I  [accId=2] src/smtp.rs:516: Selected rows from SMTP queue: [].
2026-03-23 13:16:20.978 11931-11953 DeltaChat               com.github.arcanechat                I  [accId=2] src/imap.rs:353: IMAP trying to connect to chat.in-the.eu:993:tls.
2026-03-23 13:16:20.978 11931-11953 DeltaChat               com.github.arcanechat                I  [accId=2] src/net/dns.rs:134: Using memory-cached DNS resolution for chat.in-the.eu.
2026-03-23 13:16:20.978 11931-11953 DeltaChat               com.github.arcanechat                I  [accId=2] src/net/dns.rs:180: Resolved chat.in-the.eu into 78.46.190.129.
2026-03-23 13:16:20.978 11931-11953 DeltaChat               com.github.arcanechat                I  [accId=2] src/imap/client.rs:122: Attempting IMAP connection to arcanechat.me (159.195.34.47:993).
2026-03-23 13:16:20.978 11931-11953 DeltaChat               com.github.arcanechat                I  [accId=2] src/smtp.rs:633: Sending MDNs.
2026-03-23 13:16:20.978 11931-11953 DeltaChat               com.github.arcanechat                I  [accId=2] src/net/dns.rs:180: Resolved chat.in-the.eu into 2a01:4f8:1c17:7b06::1.
2026-03-23 13:16:20.979 11931-11953 DeltaChat               com.github.arcanechat                I  [accId=2] src/contact.rs:2157: Recently seen loop waiting for 0h 5m 2s or interrupt
2026-03-23 13:16:20.979 11931-11953 DeltaChat               com.github.arcanechat                I  [accId=2] src/scheduler.rs:688: SMTP fake idle started.
2026-03-23 13:16:20.979 11931-11953 DeltaChat               com.github.arcanechat                I  [accId=2] src/scheduler.rs:716: SMTP has no messages to retry, waiting for interrupt.
2026-03-23 13:16:20.982 11931-11953 DeltaChat               com.github.arcanechat                I  [accId=2] src/imap/client.rs:122: Attempting IMAP connection to chat.in-the.eu (78.46.190.129:993).
2026-03-23 13:16:21.018 11931-11953 DeltaChat               com.github.arcanechat                I  [accId=2] src/ephemeral.rs:612: Ephemeral loop waiting for deletion in 1h 56m 29s or interrupt
2026-03-23 13:16:21.096 11931-11953 DeltaChat               com.github.arcanechat                I  [accId=2] src/imap.rs:391: Logging into IMAP server with LOGIN.
2026-03-23 13:16:21.096 11931-11953 DeltaChat               com.github.arcanechat                I  [accId=2] src/imap.rs:391: Logging into IMAP server with LOGIN.
2026-03-23 13:16:21.098 11931-11953 DeltaChat               com.github.arcanechat                I  [accId=2] src/imap.rs:391: Logging into IMAP server with LOGIN.
2026-03-23 13:16:21.183 11931-11953 DeltaChat               com.github.arcanechat                I  [accId=2] src/imap.rs:434: Successfully logged into IMAP server.
2026-03-23 13:16:21.191 11931-11953 DeltaChat               com.github.arcanechat                I  [accId=2] src/imap.rs:434: Successfully logged into IMAP server.
2026-03-23 13:16:21.198 11931-11953 DeltaChat               com.github.arcanechat                I  [accId=2] src/imap.rs:434: Successfully logged into IMAP server.
2026-03-23 13:16:21.761 11931-11953 DeltaChat               com.github.arcanechat                I  [accId=2] src/imap/select_folder.rs:80: Selected folder "INBOX".
2026-03-23 13:16:21.761 11931-11953 DeltaChat               com.github.arcanechat                I  [accId=2] src/imap.rs:569: No new emails in folder "INBOX".
2026-03-23 13:16:21.880 11931-11953 DeltaChat               com.github.arcanechat                I  [accId=2] src/scheduler.rs:558: IMAP session in folder "INBOX" supports IDLE, using it.
2026-03-23 13:16:21.907 11931-11953 DeltaChat               com.github.arcanechat                I  [accId=2] src/imap/idle.rs:62: IDLE entering wait-on-remote state in folder "INBOX".
2026-03-23 13:16:22.754 11931-11953 DeltaChat               com.github.arcanechat                I  [accId=2] src/imap/select_folder.rs:80: Selected folder "INBOX".
2026-03-23 13:16:22.754 11931-11953 DeltaChat               com.github.arcanechat                I  [accId=2] src/imap.rs:569: No new emails in folder "INBOX".
2026-03-23 13:16:22.829 11931-11953 DeltaChat               com.github.arcanechat                I  [accId=2] src/scheduler.rs:558: IMAP session in folder "INBOX" supports IDLE, using it.
2026-03-23 13:16:22.851 11931-11953 DeltaChat               com.github.arcanechat                I  [accId=2] src/imap/idle.rs:62: IDLE entering wait-on-remote state in folder "INBOX".
2026-03-23 13:16:28.564 11931-11953 DeltaChat               com.github.arcanechat                I  [accId=2] src/imap/select_folder.rs:80: Selected folder "INBOX".
2026-03-23 13:16:28.567 11931-11953 DeltaChat               com.github.arcanechat                I  [accId=2] src/imap.rs:569: No new emails in folder "INBOX".
2026-03-23 13:16:28.649 11931-11953 DeltaChat               com.github.arcanechat                I  [accId=2] src/scheduler.rs:558: IMAP session in folder "INBOX" supports IDLE, using it.
2026-03-23 13:16:28.673 11931-11953 DeltaChat               com.github.arcanechat                I  [accId=2] src/imap/idle.rs:62: IDLE entering wait-on-remote state in folder "INBOX".

[adbenitez]

in the logs it is always src/imap/idle.rs:62: IDLE entering wait-on-remote state in folder "INBOX". the step that seems to be taking long time before any other log is printed

[link2xt]

In the second log all relays are logged in at almost the same time:

2026-03-23 13:16:21.183 11931-11953 DeltaChat               com.github.arcanechat                I  [accId=2] src/imap.rs:434: Successfully logged into IMAP server.
2026-03-23 13:16:21.191 11931-11953 DeltaChat               com.github.arcanechat                I  [accId=2] src/imap.rs:434: Successfully logged into IMAP server.
2026-03-23 13:16:21.198 11931-11953 DeltaChat               com.github.arcanechat                I  [accId=2] src/imap.rs:434: Successfully logged into IMAP server.

But then the slowest one selected INBOX much later:

2026-03-23 13:16:28.564 11931-11953 DeltaChat               com.github.arcanechat                I  [accId=2] src/imap/select_folder.rs:80: Selected folder "INBOX".

prepare() function here mostly does the connecting part and ends with "Successfully logged into IMAP server":

core/src/scheduler.rs

Line 372 in 59be03a

match connection.prepare(&ctx).await {

There is something about configuring folders at the end of prepare() but it should not run and it will log something if it runs.

After logging in, inbox_fetch_idle starts and the first thing it does is updating quota. Maybe requesting quota is slow on an actually used relay. I will add more logging around there and transport IDs so it is possible to tell which one is which. We can also do quota update later, e.g. before going IDLE, and say we have already finished "updating" because checking the quota is not going to deliver new messages except possibly the device message about quota limit.

[link2xt]

I created PR with logging improvements at #8025 to make it possible to see how long quota update takes. Quota update may take time. We can move it to right before IDLE and pretend to be idle while updating quota, but better do it after merging #7780 so we have only the inbox loop to modify, otherwise it will cause merge conflicts for #7780 again.

[adbenitez]

thanks a lot I will try your PR now

btw, since I became online today I let the problematic account with started IO and it really drained my battery (and also now I only have 2 relays, removed one, but lowliness keeps):

[adbenitez]

I created PR with logging improvements at #8025 to make it possible to see how long quota update takes. Quota update may take time. We can move it to right before IDLE and pretend to be idle while updating quota, but better do it after merging #7780 so we have only the inbox loop to modify, otherwise it will cause merge conflicts for #7780 again.

here is the log with this PR (even with only 2 relays now the delay updating... is around 8 secs):

---------------------------- PROCESS STARTED (19306) for package com.b44t.messenger.beta ----------------------------
2026-03-25 20:12:12.231 19306-19306 DeltaChat               com.b44t.messenger.beta              I  ++++++++++++++++++ ApplicationContext.onCreate() ++++++++++++++++++
2026-03-25 20:12:12.246 19306-19324 DeltaChat               com.b44t.messenger.beta              I  ++++++++++++++++++ NetworkCallback.onAvailable() #0
2026-03-25 20:12:12.300 19306-19325 DeltaChat               com.b44t.messenger.beta              I  [accId=7] src/sql/migrations.rs:2378: Database version: v149.
2026-03-25 20:12:12.300 19306-19325 DeltaChat               com.b44t.messenger.beta              I  [accId=7] src/sql.rs:264: Opened database "/data/user/0/com.b44t.messenger.beta/files/accounts/a2185dd4-cef8-4683-ac2a-be93d1cee30a/dc.db".
2026-03-25 20:12:12.321 19306-19325 DeltaChat               com.b44t.messenger.beta              W  [accId=7] deltachat-ffi/src/lib.rs:312: Invalid stock message ID 99
2026-03-25 20:12:12.324 19306-19324 DeltaChat               com.b44t.messenger.beta              I  ++++++++++++++++++ NetworkCallback.onCapabilitiesChanged() #0
2026-03-25 20:12:12.324 19306-19324 DeltaChat               com.b44t.messenger.beta              I  ++++++++++++++++++ NetworkCallback.onLinkPropertiesChanged() #0
2026-03-25 20:12:12.324 19306-19324 DeltaChat               com.b44t.messenger.beta              I  ++++++++++++++++++ NetworkCallback.onBlockedStatusChanged() #0
2026-03-25 20:12:12.324 19306-19325 DeltaChat               com.b44t.messenger.beta              W  [accId=7] deltachat-ffi/src/lib.rs:312: Invalid stock message ID 100
2026-03-25 20:12:12.324 19306-19325 DeltaChat               com.b44t.messenger.beta              I  [accId=7] src/scheduler.rs:68: starting IO
2026-03-25 20:12:12.325 19306-19325 DeltaChat               com.b44t.messenger.beta              I  [accId=7] src/scheduler.rs:352: Starting inbox loop.
2026-03-25 20:12:12.325 19306-19325 DeltaChat               com.b44t.messenger.beta              I  [accId=7] src/scheduler.rs:372: Transport 4: Preparing new IMAP session for inbox.
2026-03-25 20:12:12.325 19306-19325 DeltaChat               com.b44t.messenger.beta              I  [accId=7] src/imap.rs:343: Connecting to IMAP server.
2026-03-25 20:12:12.325 19306-19325 DeltaChat               com.b44t.messenger.beta              I  [accId=7] src/imap.rs:358: IMAP trying to connect to arcanechat.me:993:tls.
2026-03-25 20:12:12.325 19306-19325 DeltaChat               com.b44t.messenger.beta              I  [accId=7] src/net/dns.rs:140: No memory-cached DNS resolution for arcanechat.me available, waiting for the resolver.
2026-03-25 20:12:12.325 19306-19325 DeltaChat               com.b44t.messenger.beta              I  [accId=7] src/scheduler.rs:352: Starting inbox loop.
2026-03-25 20:12:12.325 19306-19325 DeltaChat               com.b44t.messenger.beta              I  [accId=7] src/scheduler.rs:372: Transport 14: Preparing new IMAP session for inbox.
2026-03-25 20:12:12.325 19306-19325 DeltaChat               com.b44t.messenger.beta              I  [accId=7] src/imap.rs:343: Connecting to IMAP server.
2026-03-25 20:12:12.325 19306-19325 DeltaChat               com.b44t.messenger.beta              I  [accId=7] src/scheduler.rs:668: Starting SMTP loop.
2026-03-25 20:12:12.325 19306-19325 DeltaChat               com.b44t.messenger.beta              I  [accId=7] src/scheduler.rs:840: scheduler is running
2026-03-25 20:12:12.325 19306-19325 DeltaChat               com.b44t.messenger.beta              I  [accId=7] src/location.rs:733: Location loop is waiting for 24h 0m 0s or interrupt
2026-03-25 20:12:12.325 19306-19325 DeltaChat               com.b44t.messenger.beta              I  [accId=7] src/imap.rs:358: IMAP trying to connect to chat.in-the.eu:993:tls.
2026-03-25 20:12:12.325 19306-19325 DeltaChat               com.b44t.messenger.beta              I  [accId=7] src/net/dns.rs:140: No memory-cached DNS resolution for chat.in-the.eu available, waiting for the resolver.
2026-03-25 20:12:12.326 19306-19325 DeltaChat               com.b44t.messenger.beta              I  [accId=7] src/smtp.rs:516: Selected rows from SMTP queue: [].
2026-03-25 20:12:12.326 19306-19325 DeltaChat               com.b44t.messenger.beta              I  [accId=7] src/smtp.rs:633: Sending MDNs.
2026-03-25 20:12:12.326 19306-19325 DeltaChat               com.b44t.messenger.beta              I  [accId=7] src/scheduler.rs:708: SMTP fake idle started.
2026-03-25 20:12:12.326 19306-19325 DeltaChat               com.b44t.messenger.beta              I  [accId=7] src/scheduler.rs:736: SMTP has no messages to retry, waiting for interrupt.
2026-03-25 20:12:12.326 19306-19325 DeltaChat               com.b44t.messenger.beta              I  [accId=7] src/scheduler.rs:740: SMTP fake idle interrupted.
2026-03-25 20:12:12.326 19306-19325 DeltaChat               com.b44t.messenger.beta              I  [accId=7] src/smtp.rs:516: Selected rows from SMTP queue: [].
2026-03-25 20:12:12.326 19306-19325 DeltaChat               com.b44t.messenger.beta              I  [accId=7] src/smtp.rs:633: Sending MDNs.
2026-03-25 20:12:12.326 19306-19325 DeltaChat               com.b44t.messenger.beta              I  [accId=7] src/scheduler.rs:708: SMTP fake idle started.
2026-03-25 20:12:12.327 19306-19325 DeltaChat               com.b44t.messenger.beta              I  [accId=7] src/scheduler.rs:736: SMTP has no messages to retry, waiting for interrupt.
2026-03-25 20:12:12.330 19306-19325 DeltaChat               com.b44t.messenger.beta              I  [accId=7] src/net/dns.rs:180: Resolved chat.in-the.eu into 2a01:4f8:1c17:7b06::1.
2026-03-25 20:12:12.330 19306-19325 DeltaChat               com.b44t.messenger.beta              I  [accId=7] src/net/dns.rs:180: Resolved chat.in-the.eu into 78.46.190.129.
2026-03-25 20:12:12.331 19306-19325 DeltaChat               com.b44t.messenger.beta              I  [accId=7] src/imap/client.rs:122: Attempting IMAP connection to chat.in-the.eu ([2a01:4f8:1c17:7b06::1]:993).
2026-03-25 20:12:12.332 19306-19325 DeltaChat               com.b44t.messenger.beta              I  [accId=7] src/contact.rs:2157: Recently seen loop waiting for 0h 1m 25s or interrupt
2026-03-25 20:12:12.341 19306-19325 DeltaChat               com.b44t.messenger.beta              I  [accId=7] src/net/dns.rs:180: Resolved arcanechat.me into 159.195.34.47.
2026-03-25 20:12:12.341 19306-19325 DeltaChat               com.b44t.messenger.beta              I  [accId=7] src/imap/client.rs:122: Attempting IMAP connection to arcanechat.me (159.195.34.47:993).
2026-03-25 20:12:12.341 19306-19306 DeltaChat               com.b44t.messenger.beta              I  +++++++++++ ApplicationContext.onCreate() finished ++++++++++
2026-03-25 20:12:12.347 19306-19306 DeltaChat               com.b44t.messenger.beta              I  ++++++++++++++++++ Connected #0
2026-03-25 20:12:12.370 19306-19325 DeltaChat               com.b44t.messenger.beta              I  [accId=7] src/ephemeral.rs:612: Ephemeral loop waiting for deletion in 10h 2m 41s or interrupt
2026-03-25 20:12:12.422 19306-19325 DeltaChat               com.b44t.messenger.beta              I  [accId=7] src/imap.rs:396: Logging into IMAP server with LOGIN.
2026-03-25 20:12:12.436 19306-19325 DeltaChat               com.b44t.messenger.beta              I  [accId=7] src/imap.rs:396: Logging into IMAP server with LOGIN.
2026-03-25 20:12:12.443 19306-19325 DeltaChat               com.b44t.messenger.beta              I  [accId=7] src/key.rs:133: Converting secret key to public key.
2026-03-25 20:12:12.471 19306-19306 DeltaChat               com.b44t.messenger.beta              I  ++++++++++++++++++ first ForegroundDetector.onActivityStarted() ++++++++++++++++++
2026-03-25 20:12:12.471 19306-19396 DeltaChat               com.b44t.messenger.beta              I  calling maybeNetwork()
2026-03-25 20:12:12.472 19306-19396 DeltaChat               com.b44t.messenger.beta              I  maybeNetwork() returned
2026-03-25 20:12:12.472 19306-19325 DeltaChat               com.b44t.messenger.beta              I  [accId=7] src/scheduler.rs:740: SMTP fake idle interrupted.
2026-03-25 20:12:12.473 19306-19325 DeltaChat               com.b44t.messenger.beta              I  [accId=7] src/smtp.rs:516: Selected rows from SMTP queue: [].
2026-03-25 20:12:12.473 19306-19325 DeltaChat               com.b44t.messenger.beta              I  [accId=7] src/smtp.rs:633: Sending MDNs.
2026-03-25 20:12:12.473 19306-19325 DeltaChat               com.b44t.messenger.beta              I  [accId=7] src/scheduler.rs:708: SMTP fake idle started.
2026-03-25 20:12:12.473 19306-19325 DeltaChat               com.b44t.messenger.beta              I  [accId=7] src/scheduler.rs:736: SMTP has no messages to retry, waiting for interrupt.
2026-03-25 20:12:12.511 19306-19325 DeltaChat               com.b44t.messenger.beta              I  [accId=7] src/imap.rs:439: Successfully logged into IMAP server.
2026-03-25 20:12:12.511 19306-19325 DeltaChat               com.b44t.messenger.beta              I  [accId=7] src/scheduler.rs:385: Transport 14: Prepared new IMAP session for inbox.
2026-03-25 20:12:12.511 19306-19325 DeltaChat               com.b44t.messenger.beta              I  [accId=7] src/quota.rs:129: Transport 14: Updating quota.
2026-03-25 20:12:12.537 19306-19325 DeltaChat               com.b44t.messenger.beta              I  [accId=7] src/imap.rs:439: Successfully logged into IMAP server.
2026-03-25 20:12:12.537 19306-19325 DeltaChat               com.b44t.messenger.beta              I  [accId=7] src/scheduler.rs:385: Transport 4: Prepared new IMAP session for inbox.
2026-03-25 20:12:12.537 19306-19325 DeltaChat               com.b44t.messenger.beta              I  [accId=7] src/quota.rs:129: Transport 4: Updating quota.
2026-03-25 20:12:12.538 19306-19325 DeltaChat               com.b44t.messenger.beta              I  [accId=7] src/quota.rs:173: Transport 14: Updated quota.
2026-03-25 20:12:12.538 19306-19325 DeltaChat               com.b44t.messenger.beta              I  [accId=7] src/imap.rs:1502: Server supports metadata, retrieving server comment and admin contact.
2026-03-25 20:12:12.564 19306-19325 DeltaChat               com.b44t.messenger.beta              I  [accId=7] src/quota.rs:173: Transport 4: Updated quota.
2026-03-25 20:12:13.956 19306-19325 DeltaChat               com.b44t.messenger.beta              I  [accId=7] src/imap/select_folder.rs:82: Transport 14: Selected folder "INBOX".
2026-03-25 20:12:13.956 19306-19325 DeltaChat               com.b44t.messenger.beta              I  [accId=7] src/imap.rs:576: Transport 14: No new emails in folder "INBOX".
2026-03-25 20:12:14.090 19306-19325 DeltaChat               com.b44t.messenger.beta              I  [accId=7] src/imap/idle.rs:47: Transport 14: Skip IDLE in "INBOX" because we got interrupt.
2026-03-25 20:12:15.337 19306-19325 DeltaChat               com.b44t.messenger.beta              I  [accId=7] src/imap.rs:576: Transport 14: No new emails in folder "INBOX".
2026-03-25 20:12:15.428 19306-19325 DeltaChat               com.b44t.messenger.beta              I  [accId=7] src/imap/idle.rs:67: Transport 14: IDLE entering wait-on-remote state in folder "INBOX".
2026-03-25 20:12:18.102 19306-19325 DeltaChat               com.b44t.messenger.beta              I  [accId=7] src/imap/idle.rs:90: "INBOX": Idle has NewData ResponseData { raw: 4096, response: MailboxData(Exists(3148)) }
2026-03-25 20:12:19.413 19306-19325 DeltaChat               com.b44t.messenger.beta              I  [accId=7] src/imap.rs:614: fetch_new_msg_batch(INBOX): UIDVALIDITY=1774178646, UIDNEXT=3269.
2026-03-25 20:12:19.456 19306-19325 DeltaChat               com.b44t.messenger.beta              I  [accId=7] src/imap.rs:738: "0c142df2-1553-4626-9204-d60c3df4fcf6@localhost" is not a post-message.
2026-03-25 20:12:19.457 19306-19325 DeltaChat               com.b44t.messenger.beta              I  [accId=7] src/imap.rs:1302: Starting UID FETCH of message set "3269".
2026-03-25 20:12:19.494 19306-19325 DeltaChat               com.b44t.messenger.beta              I  [accId=7] src/imap.rs:1392: Passing message UID 3269 to receive_imf().
2026-03-25 20:12:19.503 19306-19325 DeltaChat               com.b44t.messenger.beta              I  [accId=7] src/receive_imf.rs:520: Receiving message "0c142df2-1553-4626-9204-d60c3df4fcf6@localhost", seen=true...
2026-03-25 20:12:19.504 19306-19325 DeltaChat               com.b44t.messenger.beta              I  [accId=7] src/receive_imf.rs:1197: Message is an MDN (TRASH).
2026-03-25 20:12:19.559 19306-19325 DeltaChat               com.b44t.messenger.beta              I  [accId=7] src/receive_imf.rs:2356: Message has 1 parts and is assigned to chat #Chat#Trash.
2026-03-25 20:12:19.559 19306-19325 DeltaChat               com.b44t.messenger.beta              I  [accId=7] src/contact.rs:2157: Recently seen loop waiting for 0h 1m 18s or interrupt
2026-03-25 20:12:19.559 19306-19325 DeltaChat               com.b44t.messenger.beta              I  [accId=7] src/imap.rs:1437: Successfully received 1 UIDs.
2026-03-25 20:12:19.560 19306-19325 DeltaChat               com.b44t.messenger.beta              I  [accId=7] src/imap.rs:810: 1 mails read from "INBOX".
2026-03-25 20:12:19.560 19306-19325 DeltaChat               com.b44t.messenger.beta              I  [accId=7] src/imap.rs:819: available_post_msgs: 0, download_later: 0.
2026-03-25 20:12:19.687 19306-19325 DeltaChat               com.b44t.messenger.beta              I  [accId=7] src/imap/idle.rs:47: Transport 14: Skip IDLE in "INBOX" because we got interrupt.
2026-03-25 20:12:20.388 19306-19325 DeltaChat               com.b44t.messenger.beta              I  [accId=7] src/imap/select_folder.rs:82: Transport 4: Selected folder "INBOX".
2026-03-25 20:12:20.389 19306-19325 DeltaChat               com.b44t.messenger.beta              I  [accId=7] src/imap.rs:576: Transport 4: No new emails in folder "INBOX".
2026-03-25 20:12:20.536 19306-19325 DeltaChat               com.b44t.messenger.beta              I  [accId=7] src/imap/idle.rs:47: Transport 4: Skip IDLE in "INBOX" because we got interrupt.
2026-03-25 20:12:20.999 19306-19325 DeltaChat               com.b44t.messenger.beta              I  [accId=7] src/imap.rs:1145: Marked messages 3269 in folder INBOX as seen.
2026-03-25 20:12:21.000 19306-19325 DeltaChat               com.b44t.messenger.beta              I  [accId=7] src/imap.rs:576: Transport 14: No new emails in folder "INBOX".
2026-03-25 20:12:21.150 19306-19325 DeltaChat               com.b44t.messenger.beta              I  [accId=7] src/imap/idle.rs:67: Transport 14: IDLE entering wait-on-remote state in folder "INBOX".

[link2xt]

At least quota update is really fast, so it is not quota:

2026-03-25 20:12:12.511 19306-19325 DeltaChat               com.b44t.messenger.beta              I  [accId=7] src/quota.rs:129: Transport 14: Updating quota.
2026-03-25 20:12:12.538 19306-19325 DeltaChat               com.b44t.messenger.beta              I  [accId=7] src/quota.rs:173: Transport 14: Updated quota.

2026-03-25 20:12:12.537 19306-19325 DeltaChat               com.b44t.messenger.beta              I  [accId=7] src/quota.rs:129: Transport 4: Updating quota.
2026-03-25 20:12:12.564 19306-19325 DeltaChat               com.b44t.messenger.beta              I  [accId=7] src/quota.rs:173: Transport 4: Updated quota.

[link2xt]

From another log:

2026-03-25 22:45:40.098 1737-1759 DeltaChat com.b44t.messenger.beta I [accId=7] src/imap.rs:345: Transport 4: Connecting to IMAP server.
...
2026-03-25 22:45:40.446 1737-1759 DeltaChat com.b44t.messenger.beta I [accId=7] src/imap.rs:1591: Transport 4: Got IMAP metadata.
2026-03-25 22:45:49.081 1737-1759 DeltaChat com.b44t.messenger.beta I [accId=7] src/imap/select_folder.rs:82: Transport 4: Selected folder "INBOX".

After updating metadata the only thing that happens is registering a token (which does not appear in the logs beacuse the token is registered only once even with app restarts, so it should not be the problem) before we enter fetch_idle:

core/src/scheduler.rs

Lines 488 to 497 in c99b8a4

	session
	.update_metadata(ctx)
	.await
	.context("update_metadata")?;
	session
	.register_token(ctx)
	.await
	.context("Failed to register push token")?;
	let session = fetch_idle(ctx, imap, session, FolderMeaning::Inbox).await?;

fetch_idle must select the folder at some point, so the delay of ~9 seconds is somewhere inside fetch_idle, need more logs there.

[link2xt]

From the new log with #8039:

2026-03-25 23:10:03.694 3694-3715 DeltaChat com.b44t.messenger.beta I [accId=7] src/imap.rs:1147: Transport 4: Storing seen flags.
...
2026-03-25 23:10:11.758 3694-3715 DeltaChat com.b44t.messenger.beta I [accId=7] src/imap.rs:1205: Transport 4: Finished storing seen flags.

And in between only transport 14 doing something.

[link2xt]

So it is likely that this SQL query is very slow:

core/src/imap.rs

Lines 1107 to 1123 in c99b8a4

	let rows = context
	.sql
	.query_map_vec(
	"SELECT imap.id, uid, folder FROM imap, imap_markseen
	WHERE imap.id = imap_markseen.id
	AND imap.transport_id=?
	AND target = folder
	ORDER BY folder, uid",
	(transport_id,),
	|row| {
	let rowid: i64 = row.get(0)?;
	let uid: u32 = row.get(1)?;
	let folder: String = row.get(2)?;
	Ok((rowid, uid, folder))
	},
	)
	.await?;

[adbenitez]

running the query in sql browser:

Execution finished without errors.
Result: 10 rows returned in 30192ms
At line 1:
SELECT imap.id, uid, folder FROM imap, imap_markseen WHERE imap.id = imap_markseen.id 
                  AND imap.transport_id=4
                  AND target = folder 
                  ORDER BY folder, uid