I use the DeltaChat Desktop Client (1.2.0) and on Android 9 the Android Client (1.14.5). The IMAP mail account used by Delta.Chat is hosted on GMX.net. Both clients are set to default settings (monitoring of the DeltaChat folder and the inbox). So far this setup worked flawlessly until January 22nd, 2021.
Unfortunately since January 22nd it suddenly stopped working: All messages sent by DeltaChat and also received messages still occur in the outbox respectively the inbox of my GMX account. But neither the desktop client nor the Android client show these messages. Messages that I send to other contacts still arrive, but the answer is no longer displayed in my clients (although I still see the answer in my GMX inbox).
I think it is very likely that this problem is somehow caused by my email provider. I have already checked whether the GMX (freemail) quota is exceeded - which is not the case. Of course I have configured the GMX account to accept access from third-party apps. Further incoming DeltaChat messages are still successfully displayed in Thunderbird.
Is this error already known, and what could I do to debug it?
from your description, i would guess it’s the host indeed. sometimes the log do offer useful error messages.
i probably can’t help you to look at yours, and no idea if this is a common error, but there’s a good chance whoever might be able to help ya could use the logs too.
should you consider changing hosts, here’s a list of options with some reasoning why some hosts are better than others, which might also give you a few clues: https://providers.delta.chat/
Below I attached the log file for a complete program run of my DeltaChat desktop client. I took the desktop client, since it was easier for me to extract the log, but the problem exisits for the Android client as well.
Normally, all new messages in the inbox should be displayed after opening. According to the first error in the log, this may fail because the data in my home folder are “inaccessible”?! Does anyone have any idea what could be the cause of that or whether this error has something to do with my problem? (Password and account settings have always been correct in the past and sending messages still works with both clients.)
"2021-01-24T12:42:08.001Z" "main/find_logins" "ERROR" "\n/opt/DeltaChat/resources/app.asar/tsc-dist/main/logins.js:70:17,\nfulfilled (/opt/DeltaChat/resources/app.asar/tsc-dist/main/logins.js:4:58)" "Account /home/<myhome>/.config/DeltaChat/<account_no> is inaccessible" {} "2021-01-24T12:42:08.005Z" "main/index" "INFO" "cwd /home/<myhome>/.config/DeltaChat" "2021-01-24T12:42:08.007Z" "main/deltachat/login" "INFO" "Using deltachat instance /home/<myhome>/.config/DeltaChat/<account_no>" "2021-01-24T12:42:08.069Z" "main/menu" "INFO" "rebuilding menu with locale de" "2021-01-24T12:42:08.086Z" "main/deltachat/login" "INFO" "Ready" "2021-01-24T12:42:08.098Z" "main/deltachat/login" "INFO" "dc_get_info" {"entered_account_settings":"<mymail>@gmx.de imap:unset:***:unset:0:cert_automatic smtp:unset:0:unset:0:cert_automatic 0","database_version":"63","number_of_contacts":"22","sqlite_version":"3.30.1","number_of_chat_messages":"14569","e2ee_enabled":"1","database_dir":"/home/<myhome>/.config/DeltaChat/<account_no>/db.sqlite","fingerprint":"<MY_FINGERPRINT>","arch":"64","inbox_watch":"1","sentbox_watch":"1","number_of_chats":"8","mvbox_move":"1","mvbox_watch":"1","is_configured":"1","private_key_count":"2","folders_configured":"3","configured_mvbox_folder":"DeltaChat","messages_in_contact_requests":"0","public_key_count":"5","selfavatar":"/home/<myhome>/.config/DeltaChat/<account_no>/db.sqlite-blobs/myavatar.jpg","mdns_enabled":"0","configured_sentbox_folder":"Gesendet","level":"awesome","used_account_settings":"<mymail>@gmx.de imap:<mymail>@gmx.de:***:imap.gmx.net:993:cert_automatic smtp:<mymail>@gmx.de:***:mail.gmx.net:465:cert_automatic AUTH_NORMAL 0x4IMAP_SSL 0x200SMTP_SSL 0x20000","deltachat_core_version":"v1.28.0","blobdir":"/home/<myhome>/.config/DeltaChat/<account_no>/db.sqlite-blobs","display_name":"<myname>","bcc_self":"1"} "2021-01-24T12:42:08.125Z" "logger/log-cleanup" "INFO" "Successfuly deleted 1 old logfiles" "2021-01-24T12:42:09.088Z" "main/state" "INFO" "Saving state to /home/<myhome>/.config/DeltaChat/config.json" "2021-01-24T12:42:10.820Z" "main/state" "INFO" "Saving state to /home/<myhome>/.config/DeltaChat/config.json" "2021-01-24T12:43:14.579Z" "main/state" "INFO" "Saving state to /home/<myhome>/.config/DeltaChat/config.json" "2021-01-24T12:43:14.582Z" "main/index" "INFO" "Quitting now. Bye."
account inaccessible means it won’t be displayed in the account selection. if this happens to an fully configured account, please contact me and tell me if the addr config value in the database is missing/null.
PS: You can update your desktop version (version 1.14.1 is already out)
I upgraded the desktop client to 1.14.1. However I still have the “account inaccessible - Error” (and the same behavior with GMX).
How can I query the database manually? Do you want me to do that?
account inaccessible means that the account won’t show on the “switch account” account selection screen at all.
you can open the database: /home/<myhome>/.config/DeltaChat/<account_no>/db.sqlite with https://sqlitebrowser.org/ and look inside of the config table if everything is still right there. (no null/empty values at addr or other config values)
Also you could pass these arguments, when starting DC to it: --debug --log-debug --log-to-console
this enables more logging. also look for log messages from the core (core/event) containing the term IMAP. (the question here is why doesn’t it pull the messages from imap, am I right?)
I’m looking a part of the log that looks similar to:
[TS] core/event INFO "DC_EVENT_INFO" 0 "src/sql.rs:1417: Opened \"/home/username/.config/DeltaChat/accounts/ac_no/db.sqlite\"."
[TS] core/event INFO "DC_EVENT_INFO" 0 "src/context.rs:146: starting IO"
[TS] core/event INFO "DC_EVENT_INFO" 0 "src/scheduler.rs:48: starting inbox loop"
[TS] core/event INFO "DC_EVENT_INFO" 0 "src/job.rs:1190: loading job for Imap-thread"
[TS] core/event INFO "DC_EVENT_INFO" 0 "src/scheduler.rs:174: starting simple loop for configured_mvbox_folder"
[TS] core/event INFO "DC_EVENT_INFO" 0 "src/scheduler.rs:174: starting simple loop for configured_sentbox_folder"
[TS] core/event INFO "DC_EVENT_INFO" 0 "src/scheduler.rs:205: starting smtp loop"
[TS] core/event INFO "DC_EVENT_INFO" 0 "src/job.rs:1190: loading job for Smtp-thread"
[TS] core/event INFO "DC_EVENT_INFO" 0 "src/scheduler.rs:323: scheduler is running"
[TS] core/event INFO "DC_EVENT_INFO" 0 "src/scheduler.rs:228: smtp fake idle - started"
[TS] core/event WARNING "DC_EVENT_WARNING" 0 "src/imap/mod.rs:385: try_setup_handle: io: could not resolve address `(\"imap.mail.server", 993)`"
[TS] core/event WARNING "DC_EVENT_WARNING" 0 "src/imap/mod.rs:385: try_setup_handle: io: could not resolve address `(\"imap.mail.server\", 993)`"
[TS] core/event INFO "DC_EVENT_INFO" 0 "src/imap/idle.rs:122: IMAP-fake-IDLEing folder=Some(\"Sent\")"
[TS] core/event INFO "DC_EVENT_INFO" 0 "src/imap/idle.rs:122: IMAP-fake-IDLEing folder=Some(\"DeltaChat\")"
[TS] = timestamps which I removed for readability
I’m a bit confused, because I can not see stuff like src/context.rs:146: starting IO nor can I see “could not connect”-warnings in the log you sent.
Here are the contents of my config-table in the SQLite database. Apart from the “server_flags = null” everything seems to be set correctly.
dbversion
69
addr
mymail_at_gmx.de
mail_pw
my_pw
server_flags
null
e2ee_enabled
1
mdns_enabled
0
save_mime_headers
0
folders_configured
3
configured_mvbox_folder
DeltaChat
configured_sentbox_folder
Gesendet
configured_addr
mymail_at_gmx.de
configured_mail_server
imap_gmx_net
configured_mail_port
993
configured_mail_user
mymail_at_gmx.de
configured_mail_pw
my_pw
configured_send_server
mail_gmx_net
configured_send_port
465
configured_send_user
mymail_at_gmx.de
configured_send_pw
my_pw
configured_server_flags
131588
configured
1
imap.mailbox.DeltaChat
1553766461:16452
imap.mailbox.Gesendet
1280674842:0
imap.mailbox.INBOX
1280674841:23592
bcc_self
1
self-chat-added
1
displayname
my_name
attach_selfavatar
1
selfavatar
$BLOBDIR/avatar.jpg
configured_mail_security
1
configured_send_security
1
[removed links by s/./_/g since I can only post two links at once]
Further attached is my log file with debug output (used 0bin - I don’t know how to post long logs in a readable way here). According to these log files, the “account inaccessible” message comes from the remainings of an old account. That may be true, because I’ve been using DC since 2019 and I had a different account in the past. Actually two different account numbers (account_no1, account_no2) appear in the log files, which I didn’t notice the first time.
I did the following little experiment today. I renamed the folder ~/.config/Deltachat on the desktop and recreated my GMX account on the accountless vanilla client. After running an autocrypt setup initiated by the Android client, the account on the desktop client as well as on the Android client worked again without any problems. (Note that I didn’t touch the Android client for this experiment).
Then I tried to restore my message history. So I re-renamed the DC folder on the desktop, then used the DC backup feature and created a backup of my contacts and history. After importing the backup onto the vanilla desktop client, I got the same error on both platforms (desktop and mobile phone)! - Messages can still be sent by both clients, but no longer received.
(The log messages simply state that there are no messages in the inbox.)
Could you get these values for recreated account? Possibly something happened to UIDs and new messages started reusing old UIDs while UID validity (first value) stayed the same?
Your old account has UID validity 1280674841 and last seen UID 23592 for INBOX.
This means Delta Chat once have seen a message with UID 23592, so it will never download anything with UID less than this value. But GMX started reusing old UIDs, and tags latest message with UID 16691. This should only be done together with changing UID validity. Now until you the counter reaches 23592, DC will not download any more messages.
Unless there is a bug in DC that resulted in setting last seen UID to 23592 without actually ever seeing any message with such high UID, then it’s a failure of GMX server.
Thanks for that final hint and the kind help in this forum! I have now manually modified the value in the database and set the message UID of the INBOX to 16691 (the value from the vanilla database). As a result, DC now appears to be working again.
To investigate the problem a little further, I manually setup a connection to GMX via openssl to find out which UID is delivered for the INBOX:
1 Login my_mail@gmx.de my_pw
1 OK LOGIN completed
2 select INBOX
* 319 EXISTS
* 0 RECENT
* FLAGS (\Answered \Flagged \Deleted \Seen \Draft Junk NonJunk)
* OK [PERMANENTFLAGS (\Answered \Flagged \Draft \Deleted \Seen Junk NonJunk \*)] Unlimited
* OK [UNSEEN 5] Message 5 is first unseen
* OK [UIDNEXT 16770] Predicted next UID
* OK [UIDVALIDITY 1280674841] UIDs valid
3 OK [READ-WRITE] SELECT completed
Since the next UID (UIDNEXT) during my test is set to 16770, I see this as an indication that GMX has changed the value. However, as far as I understand the procedure, the email provider could change such message UIDs at will, as long as it remains unique. At the moment I tend to think of it as an DC issue - should’t DC implement a strategy to deal with such behavior?
What is particularly annoying here is that this failure is silent (all of your contacts suddenly stop answering you ). Perhaps DC should implement functions to initiate a fetch of all (or the last 25) IMAP mails regardless of the UID, even if that means that messages may occur twice.
Another question that arises here is: Why does DC not rely on the IMAP/DeltaChat folders as a history, but store the message history in its own database? I’m just curious and don’t want to criticize this decision.
However, as far as I understand the procedure, the email provider could change such message UIDs at will, as long as it remains unique.
Email server can only increase the UIDNEXT. If it wants to decrease the UIDNEXT, it should change UIDVALIDITY. However, we can detect this case and rewind our counter if we detect that UIDNEXT is lower than our saved value.
Why does DC not rely on the IMAP/DeltaChat folders as a history, but store the message history in its own database?
The original motivation was probably to simplify the implementation. It was built by @r10s so I don’t know for sure.
Using IMAP folder as a storage could indeed improve multi-device support. However, efficient synchronization of the message state, even detecting which ones were removed from the server, is impossible without extensions such as QRESYNC. These IMAP extensions are not supported by all servers. Delta Chat uses only basic IMAP functions to get the message “feed”, stores incoming messages in the database and can use all the power of SQLite to organize the messages however it wants without dealing with all the IMAP quirks. As a bonus, all your chats are readable completely offline.
Overall, this design proved to be really good for metered connections and email providers with extremely limited inbox quota. Some providers don’t allow storing more than tenths or hundreds megabytes, this is much lower than what you can put on average mobile phone or laptop.