MySQL Auth Troubles during Migration to 2.4.1
I am between a rock and a hard place while doing my migration from 2.3.19.1 to 2.4.1 I have setup a clean system to test the running before I import my database of virtual users.
I haven't changed much from the config examples provided at My auth-sql.conf.ext: sql_driver = mysql mysql /var/run/mysqld/mysqld.sock { user = db_user password = XXXXX dbname = dbname }
passdb sql { default_password_scheme = SHA512 query = SELECT crypt AS password FROM users,domains WHERE users.username = '%{user}' AND users.enabled = '1' AND users.type='local' and domains.enabled='1' and domains.domain_id = users.domain_id }
userdb sql { query = SELECT pop as home, uid, gid FROM users WHERE username = '%{user}' iterate_query = SELECT username AS user FROM users }
dovecot -n:
root@mail:/etc/dovecot/conf.d# doveconf -n
# 2.4.1-4+debian12 (7d8c0e5759): /etc/dovecot/dovecot.conf
# Pigeonhole version 2.4.1-4+debian12 (0a86619f)
# OS: Linux 6.1.0-34-amd64 x86_64 Debian 12.10
# Hostname: mail.domain.name
dovecot_config_version = 2.4.1
auth_debug_passwords = yes
auth_verbose = yes
auth_verbose_passwords = yes
dovecot_storage_version = 2.4.1
fts_autoindex = yes
fts_autoindex_max_recent_msgs = 999
fts_search_add_missing = yes
info_log_path = /var/log/dovecot.log
log_debug = category=auth
mail_plugins {
notify = yes
mail_log = yes
}
protocols = imap pop3 lmtp sieve
sql_driver = mysql
mysql /var/run/mysqld/mysqld.sock {
dbname = exim4u
password = # hidden, use -P to show it
user = exim4u
}
passdb sql {
default_password_scheme = SHA512
query = SELECT crypt AS password FROM users,domains WHERE users.username
= '%{user}' AND users.enabled = '1' AND users.type='local' and
domains.enabled='1' and domains.domain_id = users.domain_id
}
userdb sql {
iterate_query = SELECT username AS user FROM users
query = SELECT pop as home, uid, gid FROM users WHERE username = '%{user}'
}
namespace inbox {
inbox = yes
mailbox Drafts {
special_use = "\\Drafts"
}
mailbox Junk {
special_use = "\\Junk"
}
mailbox Trash {
special_use = "\\Trash"
}
mailbox Sent {
special_use = "\\Sent"
}
mailbox "Sent Messages" {
special_use = "\\Sent"
}
}
service imap-login {
inet_listener imap {
}
inet_listener imaps {
}
}
service pop3-login {
inet_listener pop3 {
}
inet_listener pop3s {
}
}
service submission-login {
inet_listener submission {
}
inet_listener submissions {
}
}
service lmtp {
unix_listener lmtp {
}
}
service imap {
}
service pop3 {
}
service submission {
}
service auth {
unix_listener auth-userdb {
}
}
service auth-worker {
}
service dict {
unix_listener dict {
}
}
service managesieve-login {
inet_listener sieve {
port = 4190
}
inet_listener sieve_deprecated {
port = 2000
}
}
service managesieve {
}
I ran a test against the POP3 daemon:
telnet 0 110
Trying 0.0.0.0...
Connected to 0.
Escape character is '^]'.
+OK Dovecot ready.
user 'joh@doe.com
+OK
pass XXXXXXX
-ERR [SYS/TEMP] Temporary authentication failure.
And the debugging ends up in "pop3-login: Info: Login aborted: Logged out (auth service reported temporary failure". I am not sure where to look for this.
May 04 13:08:46 auth: Debug: sqlpool(mysql): Creating new connection May 04 13:08:46 auth: Debug: Read auth token secret from /run/auth-token-secret.dat May 04 13:08:46 auth: Debug: mysql(/var/run/mysqld/mysqld.sock): Connecting May 04 13:08:46 auth: Debug: conn unix:login (pid=9061,uid=117) [1]: Server accepted connection (fd=19) May 04 13:08:46 auth: Debug: conn unix:login (pid=9061,uid=117) [1]: auth client connected (pid=9061) May 04 13:09:12 auth: Debug: conn unix:login (pid=9061,uid=117) [1]: client in: AUTH 1 PLAIN protocol=pop3 final-resp-ok secured session=0sexkUw07I1/AAAB lip=127.0.0.1 rip=127.0.0.1 lport=110 rport=36332 resp=AHdhc2hAbWFyYS5jbG91ZAB3YXNoQG1hcmEuY2xvdWQ= (previous base64 data may contain sensitive data) May 04 13:09:12 auth(joh@doe.com,127.0.0.1,sasl:plain)<0sexkUw07I1/AAAB>: Debug: sql: Performing passdb lookup May 04 13:09:12 auth: Debug: conn unix:auth-worker: Connecting May 04 13:09:12 auth: Debug: conn unix:auth-worker (pid=9055,uid=0): Client connected (fd=20) May 04 13:09:12 auth: Debug: conn unix:auth-worker (pid=9055,uid=0): Sending version handshake May 04 13:09:12 auth-worker(9138): Debug: Loading modules from directory: /usr/lib/dovecot/modules/auth May 04 13:09:12 auth-worker(9138): Debug: Module loaded: /usr/lib/dovecot/modules/auth/libdriver_mysql.so May 04 13:09:12 auth-worker(9138): Debug: Module loaded: /usr/lib/dovecot/modules/auth/libdriver_pgsql.so May 04 13:09:12 auth-worker(9138): Debug: Module loaded: /usr/lib/dovecot/modules/auth/libdriver_sqlite.so May 04 13:09:12 auth-worker(9138): Debug: sqlpool(mysql): Creating new connection May 04 13:09:12 auth-worker(9138): Debug: mysql(/var/run/mysqld/mysqld.sock): Connecting May 04 13:09:12 auth-worker(9138): Debug: conn unix:auth-worker (pid=9063,uid=116): Server accepted connection (fd=13) May 04 13:09:12 auth-worker(9138): Debug: conn unix:auth-worker (pid=9063,uid=116): Sending version handshake May 04 13:09:12 auth-worker(9138): Debug: conn unix:auth-worker (pid=9063,uid=116): auth-worker<1>: Handling PASSV request May 04 13:09:12 auth-worker(joh@doe.com,127.0.0.1)<9138><0sexkUw07I1/AAAB>: request [1]: Debug: sql: Performing passdb lookup May 04 13:09:12 auth: Debug: auth-worker: Worker sent process limit '30' May 04 13:09:12 auth-worker(joh@doe.com,127.0.0.1)<9138><0sexkUw07I1/AAAB>: request [1]: Debug: sql: query: SELECT crypt AS password FROM users,domains WHERE users.username = 'joh@doe.com' AND users.enabled = '1' AND users.type='local' and domains.enabled='1' and domains.domain_id = users.domain_id May 04 13:09:12 auth-worker(9138): Debug: mysql(/var/run/mysqld/mysqld.sock): Finished query 'SELECT crypt AS password FROM users,domains WHERE users.username = 'joh@doe.com' AND users.enabled = '1' AND users.type='local' and domains.enabled='1' and domains.domain_id = users.domain_id' in 0 msecs May 04 13:09:12 auth-worker(joh@doe.com,127.0.0.1)<9138><0sexkUw07I1/AAAB>: request [1]: Debug: sql: Finished passdb lookup May 04 13:09:12 auth-worker(9138): Debug: conn unix:auth-worker (pid=9063,uid=116): auth-worker<1>: Finished: internal_failure May 04 13:09:12 auth(joh@doe.com,127.0.0.1,sasl:plain)<0sexkUw07I1/AAAB>: Debug: sql: Finished passdb lookup May 04 13:09:14 auth(joh@doe.com,127.0.0.1,sasl:plain)<0sexkUw07I1/AAAB>: Debug: Auth request finished May 04 13:09:14 auth(joh@doe.com,127.0.0.1,sasl:plain)<0sexkUw07I1/AAAB>: Debug: immediate auth failure due to internal failure May 04 13:09:14 auth: Debug: conn unix:login (pid=9061,uid=117) [1]: client passdb out: FAIL 1 user=joh@doe.com code=temp_fail May 04 13:09:18 pop3-login: Info: Login aborted: Logged out (auth service reported temporary failure, 1 attempts in 6 secs) (temp_fail): user=< joh@doe.com>, method=PLAIN, rip=127.0.0.1, lip=127.0.0.1, secured, session=<0sexkUw07I1/AAAB>
-- Best regards, Odhiambo WASHINGTON, Nairobi,KE +254 7 3200 0004/+254 7 2274 3223 In an Internet failure case, the #1 suspect is a constant: DNS. "Oh, the cruft.", egrep -v '^$|^.*#' ¯\_(ツ)_/¯ :-) [How to ask smart questions: http://www.catb.org/~esr/faqs/smart-questions.html]
I am between a rock and a hard place while doing my migration from 2.3.19.1 to 2.4.1 I have setup a clean system to test the running before I import my database of virtual users.
I haven't changed much from the config examples provided at My auth-sql.conf.ext: sql_driver = mysql mysql /var/run/mysqld/mysqld.sock { user = db_user password = XXXXX dbname = dbname }
passdb sql { default_password_scheme = SHA512 query = SELECT crypt AS password FROM users,domains WHERE users.username = '% {user}' AND users.enabled = '1' AND users.type='local' and domains.enabled='1' and domains.domain_id = users.domain_id }
userdb sql { query = SELECT pop as home, uid, gid FROM users WHERE username = '%{user}' iterate_query = SELECT username AS user FROM users }
dovecot -n:
root@mail:/etc/dovecot/conf.d# doveconf -n
# 2.4.1-4+debian12 (7d8c0e5759): /etc/dovecot/dovecot.conf
# Pigeonhole version 2.4.1-4+debian12 (0a86619f)
# OS: Linux 6.1.0-34-amd64 x86_64 Debian 12.10
# Hostname: mail.domain.name
dovecot_config_version = 2.4.1
auth_debug_passwords = yes
auth_verbose = yes
auth_verbose_passwords = yes
dovecot_storage_version = 2.4.1
fts_autoindex = yes
fts_autoindex_max_recent_msgs = 999
fts_search_add_missing = yes
info_log_path = /var/log/dovecot.log
log_debug = category=auth
mail_plugins {
notify = yes
mail_log = yes
}
protocols = imap pop3 lmtp sieve
sql_driver = mysql
mysql /var/run/mysqld/mysqld.sock {
dbname = exim4u
password = # hidden, use -P to show it
user = exim4u
}
passdb sql {
default_password_scheme = SHA512
query = SELECT crypt AS password FROM users,domains WHERE users.username = '%
{user}' AND users.enabled = '1' AND users.type='local' and domains.enabled='1'
and domains.domain_id = users.domain_id
}
userdb sql {
iterate_query = SELECT username AS user FROM users
query = SELECT pop as home, uid, gid FROM users WHERE username = '%{user}'
}
namespace inbox {
inbox = yes
mailbox Drafts {
special_use = "\\Drafts"
}
mailbox Junk {
special_use = "\\Junk"
}
mailbox Trash {
special_use = "\\Trash"
}
mailbox Sent {
special_use = "\\Sent"
}
mailbox "Sent Messages" {
special_use = "\\Sent"
}
}
service imap-login {
inet_listener imap {
}
inet_listener imaps {
}
}
service pop3-login {
inet_listener pop3 {
}
inet_listener pop3s {
}
}
service submission-login {
inet_listener submission {
}
inet_listener submissions {
}
}
service lmtp {
unix_listener lmtp {
}
}
service imap {
}
service pop3 {
}
service submission {
}
service auth {
unix_listener auth-userdb {
}
}
service auth-worker {
}
service dict {
unix_listener dict {
}
}
service managesieve-login {
inet_listener sieve {
port = 4190
}
inet_listener sieve_deprecated {
port = 2000
}
}
service managesieve {
}
I ran a test against the POP3 daemon:
telnet 0 110
Trying 0.0.0.0...
Connected to 0.
Escape character is '^]'.
+OK Dovecot ready.
user 'joh@doe.com
+OK
pass XXXXXXX
-ERR [SYS/TEMP] Temporary authentication failure.
And the debugging ends up in "pop3-login: Info: Login aborted: Logged out (auth service reported temporary failure". I am not sure where to look for this.
May 04 13:08:46 auth: Debug: sqlpool(mysql): Creating new connection May 04 13:08:46 auth: Debug: Read auth token secret from /run/auth-token- secret.dat May 04 13:08:46 auth: Debug: mysql(/var/run/mysqld/mysqld.sock): Connecting May 04 13:08:46 auth: Debug: conn unix:login (pid=9061,uid=117) [1]: Server accepted connection (fd=19) May 04 13:08:46 auth: Debug: conn unix:login (pid=9061,uid=117) [1]: auth client connected (pid=9061) May 04 13:09:12 auth: Debug: conn unix:login (pid=9061,uid=117) [1]: client in: AUTH 1 PLAIN protocol=pop3 final-resp-ok secured session=0sexkUw07I1/AAAB lip=127.0.0.1 rip=127.0.0.1 lport=110 rport=36332 resp=AHdhc2hAbWFyYS5jbG91ZAB3YXNoQG1hcmEuY2xvdWQ= (previous base64 data may contain sensitive data) May 04 13:09:12 auth(joh@doe.com,127.0.0.1,sasl:plain)<0sexkUw07I1/AAAB>: Debug: sql: Performing passdb lookup May 04 13:09:12 auth: Debug: conn unix:auth-worker: Connecting May 04 13:09:12 auth: Debug: conn unix:auth-worker (pid=9055,uid=0): Client connected (fd=20) May 04 13:09:12 auth: Debug: conn unix:auth-worker (pid=9055,uid=0): Sending version handshake May 04 13:09:12 auth-worker(9138): Debug: Loading modules from directory: /usr/ lib/dovecot/modules/auth May 04 13:09:12 auth-worker(9138): Debug: Module loaded: /usr/lib/dovecot/ modules/auth/libdriver_mysql.so May 04 13:09:12 auth-worker(9138): Debug: Module loaded: /usr/lib/dovecot/ modules/auth/libdriver_pgsql.so May 04 13:09:12 auth-worker(9138): Debug: Module loaded: /usr/lib/dovecot/ modules/auth/libdriver_sqlite.so May 04 13:09:12 auth-worker(9138): Debug: sqlpool(mysql): Creating new connection May 04 13:09:12 auth-worker(9138): Debug: mysql(/var/run/mysqld/mysqld.sock): Connecting May 04 13:09:12 auth-worker(9138): Debug: conn unix:auth-worker (pid=9063,uid=116): Server accepted connection (fd=13) May 04 13:09:12 auth-worker(9138): Debug: conn unix:auth-worker (pid=9063,uid=116): Sending version handshake May 04 13:09:12 auth-worker(9138): Debug: conn unix:auth-worker (pid=9063,uid=116): auth-worker<1>: Handling PASSV request May 04 13:09:12 auth-worker(joh@doe.com,127.0.0.1)<9138><0sexkUw07I1/AAAB>: request [1]: Debug: sql: Performing passdb lookup May 04 13:09:12 auth: Debug: auth-worker: Worker sent process limit '30' May 04 13:09:12 auth-worker(joh@doe.com,127.0.0.1)<9138><0sexkUw07I1/AAAB>: request [1]: Debug: sql: query: SELECT crypt AS password FROM users,domains WHERE users.username = 'joh@doe.com' AND users.enabled = '1' AND users.type='local' and domains.enabled='1' and domains.domain_id = users.domain_id May 04 13:09:12 auth-worker(9138): Debug: mysql(/var/run/mysqld/mysqld.sock): Finished query 'SELECT crypt AS password FROM users,domains WHERE users.username = 'joh@doe.com' AND users.enabled = '1' AND users.type='local' and domains.enabled='1' and domains.domain_id = users.domain_id' in 0 msecs May 04 13:09:12 auth-worker(joh@doe.com,127.0.0.1)<9138><0sexkUw07I1/AAAB>: request [1]: Debug: sql: Finished passdb lookup May 04 13:09:12 auth-worker(9138): Debug: conn unix:auth-worker (pid=9063,uid=116): auth-worker<1>: Finished: internal_failure May 04 13:09:12 auth(joh@doe.com,127.0.0.1,sasl:plain)<0sexkUw07I1/AAAB>: Debug: sql: Finished passdb lookup May 04 13:09:14 auth(joh@doe.com,127.0.0.1,sasl:plain)<0sexkUw07I1/AAAB>: Debug: Auth request finished May 04 13:09:14 auth(joh@doe.com,127.0.0.1,sasl:plain)<0sexkUw07I1/AAAB>: Debug: immediate auth failure due to internal failure May 04 13:09:14 auth: Debug: conn unix:login (pid=9061,uid=117) [1]: client passdb out: FAIL 1 user=joh@doe.com code=temp_fail May 04 13:09:18 pop3-login: Info: Login aborted: Logged out (auth service reported temporary failure, 1 attempts in 6 secs) (temp_fail): user=<joh@doe.com>, method=PLAIN, rip=127.0.0.1, lip=127.0.0.1, secured, session=<0sexkUw07I1/AAAB>
-- Best regards, Odhiambo WASHINGTON, Nairobi,KE +254 7 3200 0004/+254 7 2274 3223 In an Internet failure case, the #1 suspect is a constant: DNS. "Oh, the cruft.", egrep -v '^$|^.*#' ¯\_(ツ)_/¯ :-) [How to ask smart questions: http://www.catb.org/~esr/faqs/smart- questions.html]
On 4. May 2025, at 14.24, Odhiambo Washington via dovecot <dovecot@dovecot.org> wrote:
passdb sql { default_password_scheme = SHA512 query = SELECT crypt AS password FROM users,domains WHERE users.username = '% {user}' AND users.enabled = '1' AND users.type='local' and domains.enabled='1' and domains.domain_id = users.domain_id }
userdb sql { query = SELECT pop as home, uid, gid FROM users WHERE username = '%{user}' iterate_query = SELECT username AS user FROM users
Not a reason for your troubles, but should you be checking the enabled=1 here also? So LMTP deliveries won't succeed for disabled users/domains.
May 04 13:09:12 auth-worker(9138): Debug: mysql(/var/run/mysqld/mysqld.sock): Finished query 'SELECT crypt AS password FROM users,domains WHERE users.username = 'joh@doe.com' AND users.enabled = '1' AND users.type='local' and domains.enabled='1' and domains.domain_id = users.domain_id' in 0 msecs May 04 13:09:12 auth-worker(joh@doe.com,127.0.0.1)<9138><0sexkUw07I1/AAAB>: request [1]: Debug: sql: Finished passdb lookup
Okay..
May 04 13:09:12 auth-worker(9138): Debug: conn unix:auth-worker (pid=9063,uid=116): auth-worker<1>: Finished: internal_failure
There's an internal failure, but no reason for it in these logs. I'd have expected an error to be logged. Are the errors logged to a different file that you're not looking at? Check with "doveadm log find" and/or "doveadm log errors" if there's a reason for the internal failure.
On Tue, May 6, 2025 at 10:53 AM Timo Sirainen <timo@sirainen.com> wrote:
On 4. May 2025, at 14.24, Odhiambo Washington via dovecot < dovecot@dovecot.org> wrote:
passdb sql { default_password_scheme = SHA512 query = SELECT crypt AS password FROM users,domains WHERE
users.username = '%
{user}' AND users.enabled = '1' AND users.type='local' and domains.enabled='1' and domains.domain_id = users.domain_id }
userdb sql { query = SELECT pop as home, uid, gid FROM users WHERE username = '%{user}' iterate_query = SELECT username AS user FROM users
Not a reason for your troubles, but should you be checking the enabled=1 here also? So LMTP deliveries won't succeed for disabled users/domains.
May 04 13:09:12 auth-worker(9138): Debug: mysql(/var/run/mysqld/mysqld.sock): Finished query 'SELECT crypt AS password FROM users,domains WHERE users.username = 'joh@doe.com' AND users.enabled = '1' AND users.type='local' and domains.enabled='1' and domains.domain_id = users.domain_id' in 0 msecs May 04 13:09:12 auth-worker(joh@doe.com ,127.0.0.1)<9138><0sexkUw07I1/AAAB>: request [1]: Debug: sql: Finished passdb lookup
Okay..
May 04 13:09:12 auth-worker(9138): Debug: conn unix:auth-worker (pid=9063,uid=116): auth-worker<1>: Finished: internal_failure
There's an internal failure, but no reason for it in these logs. I'd have expected an error to be logged. Are the errors logged to a different file that you're not looking at? Check with "doveadm log find" and/or "doveadm log errors" if there's a reason for the internal failure.
I was relying on the sample configs provided at https://github.com/dovecot/tools/blob/main/dovecot-2.4.0-example-config.tar.... . BTW, tar -zxvf https://github.com/dovecot/tools/blob/main/dovecot-2.4.0-example-config.tar.... (on Debian 12) does not work for me with this file. Why.
Anyway, so when I extracted the above, I started by only changing the 10-auth.conf which contains: auth_mechanisms = plain login !include auth-sql.conf.ext
Then I created my auth-sql.conf.ext shown above. What I realized then is that the dovecot/auth service doesn't seem to be running. Not sure why.
May 06 12:02:20 pop3-login: Info: Login aborted: Logged out (auth service
reported temporary failure
doveadm log errors gives no output.
Looking at https://doc.dovecot.org/2.4.1/core/admin/running.html, and comparing with a system where I have installed Dovecot 2.4.1:
root@mail:/etc/dovecot/conf.d# ps auxw|grep "dovecot" root 9739 0.0 0.0 8872 4816 ? Ss 14:47 0:00 /usr/sbin/dovecot -F root 9741 0.0 0.0 5324 3280 ? S 14:47 0:00 dovecot/anvil root 9742 0.0 0.0 5428 3256 ? S 14:47 0:00 dovecot/log root 9743 0.0 0.1 51976 10248 ? S 14:47 0:00 dovecot/config
Why are my other services not running? For example, the dovecot/auth service is not running.
On an system running 2.3.21, I get:
wash@eu:~$ ps auxw|grep "dovecot" root 181404 0.0 0.0 8240 4408 ? Ss 14:33 0:00 /usr/sbin/dovecot -F dovecot 181408 0.0 0.0 10668 6936 ? S 14:33 0:00 dovecot/managesieve-login Debian-+ 181409 0.0 0.0 12192 8880 ? S 14:33 0:00 dovecot/lmtp -L dovecot 181410 0.0 0.0 4760 1436 ? S 14:33 0:00 dovecot/anvil root 181411 0.0 0.0 5028 2960 ? S 14:33 0:00 dovecot/log Debian-+ 181412 0.0 0.0 12192 8848 ? S 14:33 0:00 dovecot/lmtp -L Debian-+ 181413 0.0 0.0 12192 9040 ? S 14:33 0:00 dovecot/lmtp -L Debian-+ 181414 0.0 0.0 12192 8908 ? S 14:33 0:00 dovecot/lmtp -L Debian-+ 181415 0.0 0.0 12192 8876 ? S 14:33 0:00 dovecot/lmtp -L root 181416 0.0 0.0 8096 5444 ? S 14:33 0:00 dovecot/config dovecot 181418 0.0 0.0 5964 3496 ? S 14:33 0:00 dovecot/stats dovecot 181419 0.0 0.0 12216 8456 ? S 14:33 0:00 dovecot/auth
Is it normal that the dovecot/auth is not listed as a running service for
2.4.1?
I think that is one of my problems, besides also not getting any output
from doveadm log errors.
I wiped dovecot and reinstalled. My current config is minimal and I am not using the sample configs referred to above, but I still have the same problem:
root@mail:/var/www/html/exim4u/vexim2-master/setup# doveconf -n
2.4.1-4+debian12 (7d8c0e5759): /etc/dovecot/dovecot.conf
Pigeonhole version 2.4.1-4+debian12 (0a86619f)
OS: Linux 6.1.0-34-amd64 x86_64 Debian 12.10
Hostname: mail.mara.cloud
dovecot_config_version = 2.4.1 dovecot_storage_version = 2.4.1 info_log_path = /var/log/dovecot.log mail_driver = maildir mail_home = /home/%{user | username}/mail mail_inbox_path = /var/mail/%{user | username} mail_path = ~/mail mailbox_list_utf8 = yes protocols = imap lmtp sieve pop3 submission sql_driver = mysql passdb pam { } userdb passwd { } mysql /var/run/mysqld/mysqld.sock { dbname = exim4u password = # hidden, use -P to show it user = exim4u } passdb sql { default_password_scheme = SHA512 query = SELECT crypt AS password FROM users,domains WHERE users.username = '%{user}' AND users.enabled = '1' AND users.type='local' and domains.enabled='1' and domains.domain_id = users.domain_id } userdb sql { iterate_query = SELECT username AS user FROM users query = SELECT pop as home, uid, gid FROM users WHERE username = '%{user}' } namespace inbox { inbox = yes separator = / } ssl_server { cert_file = /etc/ssl/certs/ssl-cert-snakeoil.pem key_file = /etc/ssl/private/ssl-cert-snakeoil.key }
-- Best regards, Odhiambo WASHINGTON, Nairobi,KE +254 7 3200 0004/+254 7 2274 3223 In an Internet failure case, the #1 suspect is a constant: DNS. "Oh, the cruft.", egrep -v '^$|^.*#' ¯\_(ツ)_/¯ :-) [How to ask smart questions: http://www.catb.org/~esr/faqs/smart-questions.html]
On Tue, May 6, 2025 at 10:53 AM Timo Sirainen <timo@sirainen.com> wrote: On 4. May 2025, at 14.24, Odhiambo Washington via dovecot <dovecot@dovecot.org> wrote: > > passdb sql { > default_password_scheme = SHA512 > query = SELECT crypt AS password FROM users,domains WHERE users.username = '% > {user}' AND users.enabled = '1' AND users.type='local' and domains.enabled='1' > and domains.domain_id = users.domain_id > } > > userdb sql { > query = SELECT pop as home, uid, gid FROM users WHERE username = '%{user}' > iterate_query = SELECT username AS user FROM users
Not a reason for your troubles, but should you be checking the
enabled=1 here also? So LMTP deliveries won't succeed for disabled
users/domains.
> May 04 13:09:12 auth-worker(9138): Debug: mysql(/var/run/mysqld/
mysqld.sock):
> Finished query 'SELECT crypt AS password FROM users,domains WHERE
> users.username = 'joh@doe.com' AND users.enabled = '1' AND
users.type='local'
> and domains.enabled='1' and domains.domain_id = users.domain_id' in
0 msecs
> May 04 13:09:12 auth-worker
(joh@doe.com,127.0.0.1)<9138><0sexkUw07I1/AAAB>:
> request [1]: Debug: sql: Finished passdb lookup
Okay..
> May 04 13:09:12 auth-worker(9138): Debug: conn unix:auth-worker
> (pid=9063,uid=116): auth-worker<1>: Finished: internal_failure
There's an internal failure, but no reason for it in these logs. I'd
have expected an error to be logged. Are the errors logged to a
different file that you're not looking at? Check with "doveadm log
find" and/or "doveadm log errors" if there's a reason for the
internal failure.I was relying on the sample configs provided at https://github.com/dovecot/ tools/blob/main/dovecot-2.4.0-example-config.tar.gz. BTW, tar -zxvf https://github.com/dovecot/tools/blob/main/dovecot-2.4.0- example-config.tar.gz (on Debian 12) does not work for me with this file. Why.
Anyway, so when I extracted the above, I started by only changing the 10- auth.conf which contains: auth_mechanisms = plain login !include auth-sql.conf.ext
Then I created my auth-sql.conf.ext shown above. What I realized then is that the dovecot/auth service doesn't seem to be running. Not sure why.
May 06 12:02:20 pop3-login: Info: Login aborted: Logged out (auth service
reported temporary failure
doveadm log errors gives no output.
Looking at https://doc.dovecot.org/2.4.1/core/admin/running.html, and comparing with a system where I have installed Dovecot 2.4.1:
root@mail:/etc/dovecot/conf.d# ps auxw|grep "dovecot" root 9739 0.0 0.0 8872 4816 ? Ss 14:47 0:00 /usr/sbin/ dovecot -F root 9741 0.0 0.0 5324 3280 ? S 14:47 0:00 dovecot/ anvil root 9742 0.0 0.0 5428 3256 ? S 14:47 0:00 dovecot/log root 9743 0.0 0.1 51976 10248 ? S 14:47 0:00 dovecot/ config
Why are my other services not running? For example, the dovecot/auth service is not running.
On an system running 2.3.21, I get:
wash@eu:~$ ps auxw|grep "dovecot" root 181404 0.0 0.0 8240 4408 ? Ss 14:33 0:00 /usr/sbin/ dovecot -F dovecot 181408 0.0 0.0 10668 6936 ? S 14:33 0:00 dovecot/ managesieve-login Debian-+ 181409 0.0 0.0 12192 8880 ? S 14:33 0:00 dovecot/lmtp -L dovecot 181410 0.0 0.0 4760 1436 ? S 14:33 0:00 dovecot/ anvil root 181411 0.0 0.0 5028 2960 ? S 14:33 0:00 dovecot/log Debian-+ 181412 0.0 0.0 12192 8848 ? S 14:33 0:00 dovecot/lmtp -L Debian-+ 181413 0.0 0.0 12192 9040 ? S 14:33 0:00 dovecot/lmtp -L Debian-+ 181414 0.0 0.0 12192 8908 ? S 14:33 0:00 dovecot/lmtp -L Debian-+ 181415 0.0 0.0 12192 8876 ? S 14:33 0:00 dovecot/lmtp -L root 181416 0.0 0.0 8096 5444 ? S 14:33 0:00 dovecot/ config dovecot 181418 0.0 0.0 5964 3496 ? S 14:33 0:00 dovecot/ stats dovecot 181419 0.0 0.0 12216 8456 ? S 14:33 0:00 dovecot/auth
Is it normal that the dovecot/auth is not listed as a running service for
2.4.1?
I think that is one of my problems, besides also not getting any output from
doveadm log errors.
I wiped dovecot and reinstalled. My current config is minimal and I am not using the sample configs referred to above, but I still have the same problem:
root@mail:/var/www/html/exim4u/vexim2-master/setup# doveconf -n
2.4.1-4+debian12 (7d8c0e5759): /etc/dovecot/dovecot.conf
Pigeonhole version 2.4.1-4+debian12 (0a86619f)
OS: Linux 6.1.0-34-amd64 x86_64 Debian 12.10
Hostname: mail.mara.cloud
dovecot_config_version = 2.4.1 dovecot_storage_version = 2.4.1 info_log_path = /var/log/dovecot.log mail_driver = maildir mail_home = /home/%{user | username}/mail mail_inbox_path = /var/mail/%{user | username} mail_path = ~/mail mailbox_list_utf8 = yes protocols = imap lmtp sieve pop3 submission sql_driver = mysql passdb pam { } userdb passwd { } mysql /var/run/mysqld/mysqld.sock { dbname = exim4u password = # hidden, use -P to show it user = exim4u } passdb sql { default_password_scheme = SHA512 query = SELECT crypt AS password FROM users,domains WHERE users.username = '% {user}' AND users.enabled = '1' AND users.type='local' and domains.enabled='1' and domains.domain_id = users.domain_id } userdb sql { iterate_query = SELECT username AS user FROM users query = SELECT pop as home, uid, gid FROM users WHERE username = '%{user}' } namespace inbox { inbox = yes separator = / } ssl_server { cert_file = /etc/ssl/certs/ssl-cert-snakeoil.pem key_file = /etc/ssl/private/ssl-cert-snakeoil.key }
-- Best regards, Odhiambo WASHINGTON, Nairobi,KE +254 7 3200 0004/+254 7 2274 3223 In an Internet failure case, the #1 suspect is a constant: DNS. "Oh, the cruft.", egrep -v '^$|^.*#' ¯\_(ツ)_/¯ :-) [How to ask smart questions: http://www.catb.org/~esr/faqs/smart- questions.html]
On 6. May 2025, at 12.13, Odhiambo Washington via dovecot <dovecot@dovecot.org> wrote:
Then I created my auth-sql.conf.ext shown above. What I realized then is that the dovecot/auth service doesn't seem to be running. Not sure why.
It's only started when the first auth lookup is done. You could test also with "doveadm auth lookup" command what happens, and it should start the auth process then also.
May 06 12:02:20 pop3-login: Info: Login aborted: Logged out (auth service reported temporary failure
This again seems like there should be an error logged.
doveadm log errorsgives no output.
Well, that's weird..
Looking at https://doc.dovecot.org/2.4.1/core/admin/running.html, and comparing with a system where I have installed Dovecot 2.4.1:
root@mail:/etc/dovecot/conf.d# ps auxw|grep "dovecot" root 9739 0.0 0.0 8872 4816 ? Ss 14:47 0:00 /usr/sbin/ dovecot -F root 9741 0.0 0.0 5324 3280 ? S 14:47 0:00 dovecot/ anvil root 9742 0.0 0.0 5428 3256 ? S 14:47 0:00 dovecot/log root 9743 0.0 0.1 51976 10248 ? S 14:47 0:00 dovecot/ config
This is expected at startup.
On an system running 2.3.21, I get: ...
That seems to be actually serving clients, so more processes have started up.
Is it normal that the dovecot/auth is not listed as a running service for 2.4.1?
Yes, and it's the same for 2.3 when starting up (unless you have changed process_min_avail settings).
info_log_path = /var/log/dovecot.log
Set also log_path = /var/log/dovecot.log - any errors logged there then?
On Tue, May 6, 2025 at 1:26 PM Timo Sirainen <timo@sirainen.com> wrote:
On 6. May 2025, at 12.13, Odhiambo Washington via dovecot < dovecot@dovecot.org> wrote:
Then I created my auth-sql.conf.ext shown above. What I realized then is that the dovecot/auth service doesn't seem to be running. Not sure why.
It's only started when the first auth lookup is done. You could test also with "doveadm auth lookup" command what happens, and it should start the auth process then also.
May 06 12:02:20 pop3-login: Info: Login aborted: Logged out (auth service reported temporary failure
This again seems like there should be an error logged.
doveadm log errorsgives no output.Well, that's weird..
Looking at https://doc.dovecot.org/2.4.1/core/admin/running.html, and comparing with a system where I have installed Dovecot 2.4.1:
root@mail:/etc/dovecot/conf.d# ps auxw|grep "dovecot" root 9739 0.0 0.0 8872 4816 ? Ss 14:47 0:00 /usr/sbin/ dovecot -F root 9741 0.0 0.0 5324 3280 ? S 14:47 0:00 dovecot/ anvil root 9742 0.0 0.0 5428 3256 ? S 14:47 0:00 dovecot/log root 9743 0.0 0.1 51976 10248 ? S 14:47 0:00 dovecot/ config
This is expected at startup.
On an system running 2.3.21, I get: ...
That seems to be actually serving clients, so more processes have started up.
Is it normal that the dovecot/auth is not listed as a running service for 2.4.1?
Yes, and it's the same for 2.3 when starting up (unless you have changed process_min_avail settings).
info_log_path = /var/log/dovecot.log
Set also log_path = /var/log/dovecot.log - any errors logged there then?
Hi Timo,
I ultimately did pick up a dovecot.conf (for 2.4.x) that was shared on this
ML by @Joan Moreau <jom@grosjo.net> and customized the few obvious values
to match my install.
That helped so much to get Dovecot behaving sanely.
I was able to run doveadm log errors, which helped me figure out that
what I needed for default_password_scheme was SHA512-CRYPT instead of just
SHA512.
Why the default install of Dovecot on my system doesn't do this still is a mystery to me. A512-CRYPT512-CRYPT
Best regards, Odhiambo WASHINGTON, Nairobi,KE +254 7 3200 0004/+254 7 2274 3223 In an Internet failure case, the #1 suspect is a constant: DNS. "Oh, the cruft.", egrep -v '^$|^.*#' ¯\_(ツ)_/¯ :-) [How to ask smart questions: http://www.catb.org/~esr/faqs/smart-questions.html]
On Tue, May 6, 2025 at 1:26 PM Timo Sirainen <timo@sirainen.com> wrote: On 6. May 2025, at 12.13, Odhiambo Washington via dovecot <dovecot@dovecot.org> wrote: > > Then I created my auth-sql.conf.ext shown above. > What I realized then is that the dovecot/auth service doesn't seem to be > running. Not sure why.
It's only started when the first auth lookup is done. You could test
also with "doveadm auth lookup" command what happens, and it should
start the auth process then also.
> May 06 12:02:20 pop3-login: Info: Login aborted: Logged out (auth
service
> reported temporary failure
This again seems like there should be an error logged.
> `doveadm log errors` gives no output.
Well, that's weird..
> Looking at https://doc.dovecot.org/2.4.1/core/admin/running.html,
and comparing
> with a system where I have installed Dovecot 2.4.1:
>
> root@mail:/etc/dovecot/conf.d# ps auxw|grep "dovecot"
> root 9739 0.0 0.0 8872 4816 ? Ss 14:47 0:00
/usr/sbin/
> dovecot -F
> root 9741 0.0 0.0 5324 3280 ? S 14:47 0:00
dovecot/
> anvil
> root 9742 0.0 0.0 5428 3256 ? S 14:47 0:00
dovecot/log
> root 9743 0.0 0.1 51976 10248 ? S 14:47 0:00
dovecot/
> config
This is expected at startup.
> On an system running 2.3.21, I get:
...
That seems to be actually serving clients, so more processes have
started up.
> Is it normal that the dovecot/auth is not listed as a running
service for
> 2.4.1?
Yes, and it's the same for 2.3 when starting up (unless you have
changed process_min_avail settings).
> info_log_path = /var/log/dovecot.log
Set also log_path = /var/log/dovecot.log - any errors logged there
then?Hi Timo,
I ultimately did pick up a dovecot.conf (for 2.4.x) that was shared on this ML
by @Joan_Moreau and customized the few obvious values to match my install.
That helped so much to get Dovecot behaving sanely.
I was able to run doveadm log errors, which helped me figure out that what I
needed for default_password_scheme was SHA512-CRYPT instead of just SHA512.
Why the default install of Dovecot on my system doesn't do this still is a mystery to me. A512-CRYPT512-CRYPT
Best regards, Odhiambo WASHINGTON, Nairobi,KE +254 7 3200 0004/+254 7 2274 3223 In an Internet failure case, the #1 suspect is a constant: DNS. "Oh, the cruft.", egrep -v '^$|^.*#' ¯\_(ツ)_/¯ :-) [How to ask smart questions: http://www.catb.org/~esr/faqs/smart- questions.html]
participants (2)
-
Odhiambo Washington
-
Timo Sirainen