May 2024 - dovecot - dovecot.org

Re: Failing to archive many messages
by Francis Augusto Medeiros-Logeay 09 May '24

09 May '24

> I noticed that my sieve rules are taking a very long time when archiving messages. I can see on my logs that every message takes about two-three seconds to be evaluated. > > I also noticed this happens for a few accounts. Do you know what could be causing this? > > Best, > Francis > Actually, I don’t know here if that’s the sieve that’s slowing down the process, or if it is something else. I see that yeah, sa-learn takes a little while to execute. But maybe the issue is that Dovecot doesn’t seem to release the IMAP connection until each message went through sieve. This gives me some timeout on Roundcube (it says just «server error»). All the messages are indeed archived. Is that something here I could do better? Best, Francis

2 1

OAUTH2 problem when migrating to Ubuntu 24.04
by Francis Augusto Medeiros-Logeay 09 May '24

09 May '24

Hi, I have a Dovecot server on Ubuntu 22.04, which works fine with Oauth2. I am building a new container based on Ubuntu 24.04. IMAP seems to work fine with plain authentication, but oauth2 fails (Dovecot v2.3.21). Same configuration as before. However, I got this message: May 09 09:41:57 auth: Error: oauth2(fran(a)mydomain.eu,10.110.41.32,<o+TCjQZZYJAaaige>): oauth2 failed: Introspection failed: No username returned Weird, as it does indeed seems to get the username (as seen on the log). Any clue on why this fails? Best, Francis

2 2

Namespace configuration for archive in different storage
by drinaldi＠trustitalia.it 06 May '24

06 May '24

Hello, i made this namespace configuration inside "10-mail.conf": namespace Archives { type = private disabled = no hidden = no list = yes ignore_on_failure = no inbox = no location = maildir:/mnt/archive-mail-storage/%n/Maildir prefix = "Archive." subscriptions = yes separator = . I need to set up the storage for archive on a different storage than the inbox is located. Thunderbird, now seems that can see the subfolders inside the archive that start with dot but cannot access the "cur" folder where inbox mail are stored. Can you help me?

3 3

Password storage
by Rupert Gallagher 06 May '24

06 May '24

What is dovecot's state of the art on password storage? Can we use bcrypt instead of plain text?

3 2

Pigeonhole : how to automatically subscribe to newly created folders
by Erwan David 06 May '24

06 May '24

Hello, In my sieve script I use fileinto :create "mailbox" Is it possible that the created mailbox is then automatically added to the subsccribe list for the account ? -- Erwan David

1 0

RE: temporary auth errors
by Michael Slusarz 02 May '24

02 May '24

> On 05/02/2024 7:48 AM MDT Marc via dovecot <dovecot(a)dovecot.org> wrote: > > > auth_failure_delay = 2 secs ? > > > > That will still simply wait before *rejecting* the login, compared to > > *dropping the connection*. > > > > We are thus looking for three different behaviours: > > > > 1. If backend confrims auth, ACK auth + proceed (grant access) to email. > > > > 2. If backend confirm "no such user" or "invalid creds", wait for > > auth_failure_delay and then *reject* the login. > > > > 3. If the backend fails (ie, can neither confirm nor deny), simply drop > > the connection. > > > > I hope this is more clear. > > > > Yes that is more clear, but no idea (seems a little out of scope to support by design) In complicated, localized authentication scenarios, Lua auth is likely the best answer. https://doc.dovecot.org/configuration_manual/authentication/lua_based_authe… michael

1 0

temporary auth errors
by Jaco Kroon 02 May '24

02 May '24

Hi All, Looking for some advise. We ran into a situation yesterday where our SQL cluster (mariadb-galera) stopped serving requests due to some DDL queries locking the wsrep provider. We're addressing this separately, so just background as to the cause of the problem. As far as I know both POP3 and IMAP protocols only have two possible responses when a user tries to authenticate, either ACK (yes, you're fine let's proceed) and NACK (no, something with authentication failed, and either you've got credential issues, or something is wrong with the backend). An ACK results in granting the user access. A NACK results in the user having to retry. This is all good and well, but the *typical* response by a MUA is to re-prompt the user for credentials, to which the response is usually to retry random passwords until it works again (confirmed with Outlook and Thunderbird). What I'm hoping is that dovecot has some way to in case of such "authentication backend" problem scenarios to ignore protocol and politeness and simply disconnect the client, ie, just shut the connection without saying anything, this could even be with a small delay (I'd say 1 second or so, just to avoid tight auth retry loops, up to 4 or 5 seconds IMHO would be fine). The hope is that this will result in the mail client treating this like a connection error rather than an authentication error, and hopefully not prompt for new credentials, but simply an alert of the "there has been a problem communicating with your mail server please retry or contact your service provider" kind of error messages. For reference, the errors in dovecot logs looks like: May 1 04:42:25 uriel dovecot[352]: auth-worker(11615): Warning: sqlpool(mysql): Query failed, retrying: WSREP has not yet prepared node for application use May 1 04:42:25 uriel dovecot[352]: auth-worker(11615): Error: conn unix:auth-worker (pid=11453,uid=76): auth-worker<68>: sql(user(a)domain,a.b.c.d,<XXXX>): Password query failed: WSREP has not yet prepared node for application use May 1 04:42:27 uriel dovecot[352]: pop3-login: Disconnected: Aborted login by logging out (auth service reported temporary failure): user=<user@domain>, method=PLAIN, rip=a.b.c.d, lip=e.f.g.h, TLS, session=<XXXX> Kind regards, Jaco

2 3

Re: Failing to archive many messages
by Francis Augusto Medeiros-Logeay 01 May '24

01 May '24

It is weird. At first, it seems that the logs are going fine. It goes like this for many minutes: May 01 14:20:04 imap(francis(a)mydomain.com)<226><zNW3d2MX9uku45qA>: Debug: Mailbox Archive: UID 25719: Looked up field hdr.IN-REPLY-TO from mail cache May 01 14:20:04 imap(francis(a)mydomain.com)<226><zNW3d2MX9uku45qA>: Debug: Mailbox Archive: UID 25719: Looked up field hdr.MESSAGE-ID from mail cache May 01 14:20:04 imap(francis(a)mydomain.com)<226><zNW3d2MX9uku45qA>: Debug: Mailbox Archive: UID 25719: Looked up field hdr.SUBJECT from mail cache May 01 14:20:04 imap(francis(a)mydomain.com)<226><zNW3d2MX9uku45qA>: Debug: Mailbox Archive: UID 25719: Looked up field hdr.TO from mail cache May 01 14:20:04 imap(francis(a)mydomain.com)<226><zNW3d2MX9uku45qA>: Debug: Mailbox Archive: UID 25719: Looked up field hdr.X-PRIORITY from mail cache May 01 14:20:04 imap(francis(a)mydomain.com)<226><zNW3d2MX9uku45qA>: Debug: Mailbox Archive: UID 25719: Looked up field hdr.BCC from mail cache May 01 14:20:04 imap(francis(a)mydomain.com)<226><zNW3d2MX9uku45qA>: Debug: Mailbox Archive: UID 25719: Looked up field hdr.REPLY-TO from mail cache May 01 14:20:04 imap(francis(a)mydomain.com)<226><zNW3d2MX9uku45qA>: Debug: Mailbox Archive: UID 25719: Looked up field hdr.DISPOSITION-NOTIFICATION-TO from mail cache May 01 14:20:04 imap(francis(a)mydomain.com)<226><zNW3d2MX9uku45qA>: Debug: Mailbox Archive: UID 25719: Looked up field hdr.LIST-POST from mail cache May 01 14:20:04 imap(francis(a)mydomain.com)<226><zNW3d2MX9uku45qA>: Debug: sieve: multi-script: Start execute sequence May 01 14:20:04 imap(francis(a)mydomain.com)<226><zNW3d2MX9uku45qA>: Debug: sieve: Executing script from `/var/mail/vmail/mail/sieve/global/report-ham.svbin' May 01 14:20:04 imap(francis(a)mydomain.com)<226><zNW3d2MX9uku45qA>: Debug: sieve: multi-script: Run script `/var/mail/vmail/mail/sieve/global/report-ham.svbin' May 01 14:20:04 imap(francis(a)mydomain.com)<226><zNW3d2MX9uku45qA>: Debug: sieve: Started running script `/var/mail/vmail/mail/sieve/global/report-ham.svbin' May 01 14:20:04 imap(francis(a)mydomain.com)<226><zNW3d2MX9uku45qA>: Debug: sieve: Finished running script `ok' (status=/var/mail/vmail/mail/sieve/global/report-ham.svbin, resource usage: no usage recorded) May 01 14:20:04 imap(francis(a)mydomain.com)<226><zNW3d2MX9uku45qA>: Debug: sieve: multi-script: Execute result May 01 14:20:04 imap(francis(a)mydomain.com)<226><zNW3d2MX9uku45qA>: Debug: sieve: uid=25719: Executing result (status=ok, commit=no) May 01 14:20:04 imap(francis(a)mydomain.com)<226><zNW3d2MX9uku45qA>: Debug: sieve: uid=25719: Starting execution of actions May 01 14:20:04 imap(francis(a)mydomain.com)<226><zNW3d2MX9uku45qA>: Debug: sieve: uid=25719: Executing actions May 01 14:20:04 imap(francis(a)mydomain.com)<226><zNW3d2MX9uku45qA>: Debug: sieve: uid=25719: Executing pipe action May 01 14:20:04 imap(francis(a)mydomain.com)<226><zNW3d2MX9uku45qA>: Debug: sieve: action pipe: running program: sa-learn-ham.sh May 01 14:20:04 imap(francis(a)mydomain.com)<226><zNW3d2MX9uku45qA>: Debug: program exec:/var/mail/vmail/mail/sieve/global/scripts/sa-learn-ham.sh: Created May 01 14:20:04 imap(francis(a)mydomain.com)<226><zNW3d2MX9uku45qA>: Debug: program exec:/var/mail/vmail/mail/sieve/global/scripts/sa-learn-ham.sh: Pass environment: USER=francis(a)mydomain.com May 01 14:20:04 imap(francis(a)mydomain.com)<226><zNW3d2MX9uku45qA>: Debug: program exec:/var/mail/vmail/mail/sieve/global/scripts/sa-learn-ham.sh: Pass environment: HOME=/var/mail/vmail/med-lo.eu/francis May 01 14:20:04 imap(francis(a)mydomain.com)<226><zNW3d2MX9uku45qA>: Debug: program exec:/var/mail/vmail/mail/sieve/global/scripts/sa-learn-ham.sh: Pass environment: HOST=fb58607074fd May 01 14:20:04 imap(francis(a)mydomain.com)<226><zNW3d2MX9uku45qA>: Debug: Mailbox Archive: UID 25719: Opened mail because: mail stream May 01 14:20:04 imap(francis(a)mydomain.com)<226><zNW3d2MX9uku45qA>: Debug: sieve: uid=25719: Finished executing pipe action (status=ok, keep=implicit) May 01 14:20:04 imap(francis(a)mydomain.com)<226><zNW3d2MX9uku45qA>: Debug: sieve: uid=25719: Finished executing actions (status=ok, keep=implicit) May 01 14:20:04 imap(francis(a)mydomain.com)<226><zNW3d2MX9uku45qA>: Debug: sieve: uid=25719: Finished executing result (no commit, status=ok, keep=yes) May 01 14:20:04 imap(francis(a)mydomain.com)<226><zNW3d2MX9uku45qA>: Debug: sieve: multi-script: Sequence active May 01 14:20:04 imap(francis(a)mydomain.com)<226><zNW3d2MX9uku45qA>: Debug: sieve: multi-script: Finishing sequence (status=ok) May 01 14:20:04 imap(francis(a)mydomain.com)<226><zNW3d2MX9uku45qA>: Debug: sieve: uid=25719: Executing result (status=ok, commit=yes) May 01 14:20:04 imap(francis(a)mydomain.com)<226><zNW3d2MX9uku45qA>: Debug: sieve: uid=25719: Starting execution of actions May 01 14:20:04 imap(francis(a)mydomain.com)<226><zNW3d2MX9uku45qA>: Debug: sieve: uid=25719: Executing actions May 01 14:20:04 imap(francis(a)mydomain.com)<226><zNW3d2MX9uku45qA>: Debug: sieve: uid=25719: Finished executing actions (status=ok, keep=implicit) May 01 14:20:04 imap(francis(a)mydomain.com)<226><zNW3d2MX9uku45qA>: Debug: sieve: uid=25719: Execute implicit keep (failure=no) May 01 14:20:04 imap(francis(a)mydomain.com)<226><zNW3d2MX9uku45qA>: Debug: sieve: uid=25719: Start storing into mailbox Archive May 01 14:20:04 imap(francis(a)mydomain.com)<226><zNW3d2MX9uku45qA>: Debug: sieve: uid=25719: Executing implicit keep action May 01 14:20:04 imap(francis(a)mydomain.com)<226><zNW3d2MX9uku45qA>: Debug: sieve: uid=25719: Execute storing into mailbox 'Archive' May 01 14:20:04 imap(francis(a)mydomain.com)<226><zNW3d2MX9uku45qA>: Debug: sieve: uid=25719: Updated existing mail in mailbox 'Archive' May 01 14:20:04 imap(francis(a)mydomain.com)<226><zNW3d2MX9uku45qA>: Debug: sieve: uid=25719: Finished executing implicit keep action (status=ok) May 01 14:20:04 imap(francis(a)mydomain.com)<226><zNW3d2MX9uku45qA>: Debug: sieve: uid=25719: Finalizing actions May 01 14:20:04 imap(francis(a)mydomain.com)<226><zNW3d2MX9uku45qA>: Debug: sieve: uid=25719: Finalize pipe action (status=ok, action_status=ok, commit_status=ok, pre-commit=yes) May 01 14:20:04 imap(francis(a)mydomain.com)<226><zNW3d2MX9uku45qA>: Debug: sieve: uid=25719: Commit pipe action May 01 14:20:04 imap(francis(a)mydomain.com)<226><zNW3d2MX9uku45qA>: Debug: program exec:/var/mail/vmail/mail/sieve/global/scripts/sa-learn-ham.sh: Establishing connection May 01 14:20:04 imap(francis(a)mydomain.com)<226><zNW3d2MX9uku45qA>: Debug: program exec:/var/mail/vmail/mail/sieve/global/scripts/sa-learn-ham.sh: Forked child process May 01 14:20:04 imap(francis(a)mydomain.com)<226><zNW3d2MX9uku45qA>: Debug: program exec:/var/mail/vmail/mail/sieve/global/scripts/sa-learn-ham.sh (416): Connected to program May 01 14:20:04 imap(francis(a)mydomain.com)<226><zNW3d2MX9uku45qA>: Debug: program exec:/var/mail/vmail/mail/sieve/global/scripts/sa-learn-ham.sh (416): Finished streaming payload to program May 01 14:20:04 imap(francis(a)mydomain.com)<226><zNW3d2MX9uku45qA>: Debug: program exec:/var/mail/vmail/mail/sieve/global/scripts/sa-learn-ham.sh (416): Finished input to program May 01 14:20:04 imap(francis(a)mydomain.com)<226><zNW3d2MX9uku45qA>: Debug: program exec:/var/mail/vmail/mail/sieve/global/scripts/sa-learn-ham.sh (416): Disconnected May 01 14:20:04 imap(francis(a)mydomain.com)<226><zNW3d2MX9uku45qA>: Debug: program exec:/var/mail/vmail/mail/sieve/global/scripts/sa-learn-ham.sh (416): Waiting for program to finish after 6 msecs (timeout = 9994 msecs) The client stays just like «Moving 1 of 4000 messages». Then the logs start to go like this: May 01 14:43:09 imap: Error: ERROR: the Bayes learn function returned an error, please re-run with -D for more information at /usr/bin/sa-learn line 500. May 01 14:43:12 imap: Error: ERROR: the Bayes learn function returned an error, please re-run with -D for more information at /usr/bin/sa-learn line 500. ^C root@fb58607074fd:/# tail -f /var/log/dovecot.log | grep Error May 01 14:43:15 imap: Error: plugin: eval failed: interrupted at /usr/bin/sa-learn line 513. May 01 14:43:15 imap: Error: ERROR: the Bayes learn function returned an error, please re-run with -D for more information at /usr/bin/sa-learn line 500. May 01 14:43:15 imap(francis(a)mydomain.com)<295><TwG1fGMXCuou45qA>: Error: sieve: failed to pipe message to program `sa-learn-ham.sh': refer to server log for more information. [2024-05-01 14:43:15] May 01 14:43:15 imap(francis(a)mydomain.com)<295><TwG1fGMXCuou45qA>: Error: sieve: Execution of script /var/mail/vmail/mail/sieve/global/report-ham.sieve failed May 01 14:43:16 imap(francis(a)mydomain.com)<292><Ei2ofGMXBeou45qA>: Error: program exec:/var/mail/vmail/mail/sieve/global/scripts/sa-learn-ham.sh (2978): Forcibly terminated with signal 15 May 01 14:43:16 imap(francis(a)mydomain.com)<292><Ei2ofGMXBeou45qA>: Error: sieve: failed to pipe message to program `sa-learn-ham.sh': refer to server log for more information. [2024-05-01 14:43:16] May 01 14:43:16 imap(francis(a)mydomain.com)<292><Ei2ofGMXBeou45qA>: Error: sieve: Execution of script /var/mail/vmail/mail/sieve/global/report-ham.sieve failed May 01 14:43:17 imap: Error: plugin: eval failed: interrupted at /usr/bin/sa-learn line 513. May 01 14:43:17 imap: Error: ERROR: the Bayes learn function returned an error, please re-run with -D for more information at /usr/bin/sa-learn line 500. For many minutes, the mail client gets an error about reaching the max connections from ip, and the logs go on and on with the errors above. What could be the issue? Best, Francis -- Francis Augusto Medeiros-Logeay Oslo, Norway

1 0

ENV{"PATH"}. errors on my log
by Francis Augusto Medeiros-Logeay 01 May '24

01 May '24

Hi, I'm getting this error a lot on my logs: May 01 12:57:03 imap: Error: Use of uninitialized value $ENV{"PATH"} in split at /usr/lib/x86_64-linux-gnu/perl-base/File/Spec/Unix.pm line 136. I googled a bit and the only reference I found was related to the possibility of imapsieve scripts that could be generating this. I haven't found any perl script on my install, but I momentarily turned off spamassassin, but the logs continued. Any hint on how I can debug this? Turning the debug logs on dovecot didn't bring me any extra information of what the source of this could be. Best, Francis -- Francis Augusto Medeiros-Logeay Oslo, Norway

2 2

Failing to archive many messages
by Francis Augusto Medeiros-Logeay 01 May '24

01 May '24

Hi, When I archive one or two messages, the messages are correctly moved to the Archive. However, when I archive more messages - like 50 or more, dovecot seems to fail. The error I get is this one: Warning: Failed to do incremental sync for mailbox Archive, retry with a full sync (Modseq 17277 no longer in transaction log (highest=17323, last_common_uid=12216, nextuid=15767)) No messages end up being moved to the Archive folder. I tried to do this both from a mail client and from roundcube. What could be the problem here?

1 0