Dovecot says user does not exist although it's in MariaDB database

Question

I use a MariaDB to store users for Dovecot 2.2.10. The Dovecot keeps giving "Disconnected unexpectedly" errors, and I can't find a reason. Is there anything I could look at?

Mail logs

Aug 29 22:46:15 xxxx postfix/qmgr[3467]: 544A8BB01: from=<>, size=4034, nrcpt=1 (queue active)
Aug 29 22:46:15 xxxx postfix/qmgr[3467]: 65FF1B94D: from=<<myemailaccont>@gmail.com>, size=2769, nrcpt=1 (queue active)
Aug 29 22:46:15 xxxx postfix/qmgr[3467]: CC292B999: from=<root@xxxx.com>, size=411, nrcpt=1 (queue active)
Aug 29 22:46:15 xxxx dovecot: lmtp(1): Debug: none: root=, index=, indexpvt=, control=, inbox=, alt=
Aug 29 22:46:15 xxxx dovecot: lmtp(1): Connect from local
Aug 29 22:46:15 xxxx dovecot: auth: Debug: Loading modules from directory: /usr/lib64/dovecot/auth
Aug 29 22:46:15 xxxx dovecot: auth: Debug: Module loaded: /usr/lib64/dovecot/auth/libdriver_mysql.so
Aug 29 22:46:15 xxxx dovecot: auth: Debug: Module loaded: /usr/lib64/dovecot/auth/libdriver_sqlite.so
Aug 29 22:46:15 xxxx dovecot: lmtp(12025): Debug: none: root=, index=, indexpvt=, control=, inbox=, alt=
Aug 29 22:46:15 xxxx dovecot: lmtp(12025): Connect from local
Aug 29 22:46:15 xxxx dovecot: auth: Debug: Read auth token secret from /var/run/dovecot/auth-token-secret.dat
Aug 29 22:46:15 xxxx dovecot: auth: Debug: master in: USER#0111#011user1@xxxx.com#011service=lmtp
Aug 29 22:46:15 xxxx dovecot: auth: Debug: master in: USER#0111#011user1@xxxx.com#011service=lmtp
Aug 29 22:46:15 xxxx dovecot: lmtp(12027): Debug: none: root=, index=, indexpvt=, control=, inbox=, alt=
Aug 29 22:46:15 xxxx dovecot: lmtp(12027): Connect from local
Aug 29 22:46:15 xxxx dovecot: auth: Debug: master in: USER#0111#011user1@xxxx.com#011service=lmtp
Aug 29 22:46:15 xxxx dovecot: auth-worker(12028): Debug: Loading modules from directory: /usr/lib64/dovecot/auth
Aug 29 22:46:15 xxxx dovecot: auth-worker(12028): Debug: Module loaded: /usr/lib64/dovecot/auth/libdriver_mysql.so
Aug 29 22:46:15 xxxx dovecot: auth-worker(12028): Debug: Module loaded: /usr/lib64/dovecot/auth/libdriver_sqlite.so
Aug 29 22:46:15 xxxx dovecot: auth-worker(12028): Debug: passwd(user1@xxxx.com): lookup
Aug 29 22:46:15 xxxx dovecot: auth-worker(12028): passwd(user1@xxxx.com): unknown user
Aug 29 22:46:15 xxxx dovecot: auth: Debug: password(user1@xxxx.com): passdb doesn't support credential lookups
Aug 29 22:46:15 xxxx dovecot: auth-worker(12028): Debug: sql(user1@xxxx.com): query: SELECT email as user, password FROM virtual_users WHERE email='user1@xxxx.com';
Aug 29 22:46:15 xxxx dovecot: lmtp(1): Error: userdb lookup(user1@xxxx.com): Disconnected unexpectedly
Aug 29 22:46:15 xxxx dovecot: lmtp(12025): Error: userdb lookup(user1@xxxx.com): Disconnected unexpectedly
Aug 29 22:46:15 xxxx dovecot: lmtp(12027): Error: userdb lookup(user1@xxxx.com): Disconnected unexpectedly
Aug 29 22:46:15 xxxx dovecot: auth: Fatal: master: service(auth): child 12023 killed with signal 11 (core dumps disabled)
Aug 29 22:46:15 xxxx dovecot: auth-worker(12031): Debug: Loading modules from directory: /usr/lib64/dovecot/auth
Aug 29 22:46:15 xxxx dovecot: auth-worker(12031): Debug: Module loaded: /usr/lib64/dovecot/auth/libdriver_mysql.so
Aug 29 22:46:15 xxxx dovecot: auth-worker(12031): Debug: Module loaded: /usr/lib64/dovecot/auth/libdriver_sqlite.so
Aug 29 22:46:15 xxxx postfix/lmtp[12020]: 544A8BB01: to=<user1@xxxx.com>, relay=xxxx.com[private/dovecot-lmtp], delay=1782, delays=1782/0.02/0/0.06, dsn=4.3.0, status=deferred (host xxxx.com[private/dovecot-lmtp] said: 451 4.3.0 <user1@xxxx.com> Internal error occurred. Refer to server log for more information. (in reply to RCPT TO command))
Aug 29 22:46:15 xxxx dovecot: lmtp(1): Disconnect from local: Successful quit
Aug 29 22:46:15 xxxx dovecot: auth-worker(12031): Debug: passwd(user1@xxxx.com): lookup
Aug 29 22:46:15 xxxx dovecot: auth-worker(12031): passwd(user1@xxxx.com): unknown user
Aug 29 22:46:15 xxxx postfix/lmtp[12021]: 65FF1B94D: to=<user1@xxxx.com>, relay=xxxx.com[private/dovecot-lmtp], delay=1689, delays=1689/0.02/0.01/0.04, dsn=4.3.0, status=deferred (host xxxx.com[private/dovecot-lmtp] said: 451 4.3.0 <user1@xxxx.com> Internal error occurred. Refer to server log for more information. (in reply to RCPT TO command))
Aug 29 22:46:15 xxxx dovecot: lmtp(12025): Disconnect from local: Successful quit
Aug 29 22:46:15 xxxx postfix/lmtp[12024]: CC292B999: to=<user1@xxxx.com>, relay=xxxx.com[private/dovecot-lmtp], delay=1851, delays=1851/0.02/0.01/0.04, dsn=4.3.0, status=deferred (host xxxx.com[private/dovecot-lmtp] said: 451 4.3.0 <user1@xxxx.com> Internal error occurred. Refer to server log for more information. (in reply to RCPT TO command))
Aug 29 22:46:15 xxxx dovecot: lmtp(12027): Disconnect from local: Successful quit
Aug 29 22:46:15 xxxx dovecot: auth-worker(12036): Debug: Loading modules from directory: /usr/lib64/dovecot/auth
Aug 29 22:46:15 xxxx dovecot: auth-worker(12036): Debug: Module loaded: /usr/lib64/dovecot/auth/libdriver_mysql.so
Aug 29 22:46:15 xxxx dovecot: auth-worker(12036): Debug: Module loaded: /usr/lib64/dovecot/auth/libdriver_sqlite.so
Aug 29 22:46:15 xxxx dovecot: auth-worker(12036): Debug: passwd(user1@xxxx.com): lookup
Aug 29 22:46:15 xxxx dovecot: auth-worker(12036): passwd(user1@xxxx.com): unknown user

The important part being:

Aug 29 22:46:15 xxxx dovecot: auth-worker(12028): Debug: passwd(user1@xxxx.com): lookup
Aug 29 22:46:15 xxxx dovecot: auth-worker(12028): passwd(user1@xxxx.com): unknown user
Aug 29 22:46:15 xxxx dovecot: auth: Debug: password(user1@xxxx.com): passdb doesn't support credential lookups
Aug 29 22:46:15 xxxx dovecot: auth-worker(12028): Debug: sql(user1@xxxx.com): query: SELECT email as user, password FROM virtual_users WHERE email='user1@xxxx.com';
Aug 29 22:46:15 xxxx dovecot: lmtp(1): Error: userdb lookup(user1@xxxx.com): Disconnected unexpectedly
Aug 29 22:46:15 xxxx dovecot: lmtp(12025): Error: userdb lookup(user1@xxxx.com): Disconnected unexpectedly
Aug 29 22:46:15 xxxx dovecot: lmtp(12027): Error: userdb lookup(user1@xxxx.com): Disconnected unexpectedly
Aug 29 22:46:15 xxxx dovecot: auth: Fatal: master: service(auth): child 12023 killed with signal 11 (core dumps disabled)

What does the "doesn't support credential lookups" mean? Is this a problem with MariaDB or Dovecot?

Dovecot configuration

[root@myhost ~]# doveconf -n
# 2.2.10: /etc/dovecot/dovecot.conf
# OS: Linux 3.10.0-1160.95.1.el7.x86_64 x86_64 CentOS Linux release 7.9.2009 (Core) ext4
auth_debug = yes
auth_mechanisms = plain login
auth_verbose = yes
mail_debug = yes
mail_location = maildir:/var/mail/vhosts/%d/%n
mail_privileged_group = mail
mbox_write_locks = fcntl
namespace inbox {
  inbox = yes
  location = 
  mailbox Drafts {
    special_use = \Drafts
  }
  mailbox Junk {
    special_use = \Junk
  }
  mailbox Sent {
    special_use = \Sent
  }
  mailbox "Sent Messages" {
    special_use = \Sent
  }
  mailbox Trash {
    special_use = \Trash
  }
  prefix = 
}
passdb {
  driver = pam
}
passdb {
  args = /etc/dovecot/dovecot-sql.conf.ext
  driver = sql
}
service auth-worker {
  user = vmail
}
service auth {
  unix_listener /var/spool/postfix/private/auth {
    group = postfix
    mode = 0660
    user = postfix
  }
  unix_listener auth-userdb {
    mode = 0600
    user = vmail
  }
  user = dovecot
}
service imap-login {
  inet_listener imap {
    port = 0
  }
  inet_listener imaps {
    port = 993
    ssl = yes
  }
}
service lmtp {
  unix_listener /var/spool/postfix/private/dovecot-lmtp {
    group = postfix
    mode = 0600
    user = postfix
  }
}
service pop3-login {
  inet_listener pop3 {
    port = 0
  }
  inet_listener pop3s {
    port = 995
    ssl = yes
  }
}
ssl = required
ssl_cert = </etc/letsencrypt/live/xxxx.com/fullchain.pem
ssl_key = </etc/letsencrypt/live/xxxx.com/privkey.pem
userdb {
  driver = passwd
}
userdb {
  args = uid=vmail gid=vmail home=/var/mail/vhosts/%d/%n
  driver = static
}
verbose_ssl = yes

MariaDB tables

The user does exist:

MariaDB [(none)]> SELECT * FROM mailserver.virtual_domains;
+----+--------------------+
| id | name               |
+----+--------------------+
|  1 | xxxx.com           |
|  2 | xxxx.xxxx.com      |
|  3 | xxxx               |
|  4 | localhost.xxxx.com |
+----+--------------------+
4 rows in set (0.00 sec)

MariaDB [(none)]> SELECT * FROM mailserver.virtual_users;
+----+-----------+--------------+----------------+
| id | domain_id | password     | email          |
+----+-----------+--------------+----------------+
|  1 |         1 | <mypassword> | user1@xxxx.com |
|  2 |         1 | <mypassword> | user2@xxxx.com |
+----+-----------+--------------+----------------+
2 rows in set (0.00 sec)

score 0 · Answer 1 · answered Aug 30 '23 at 00:27

Well, I solved this question anyway. But, it is not actually a solution. I just simly update my dovecot to the newest version (from 2.2.10 to 2.2.36). I don't know why this works (maybe because of some supernatural power). So, if anyone knows why dovecot 2.2.10 cannot work correctly with MariaDB, please answer below.

Dovecot says user does not exist although it's in MariaDB database

Mail logs

Dovecot configuration

MariaDB tables

1 Answers1