0

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)
Esa Jokinen
  • 46,944
  • 3
  • 83
  • 129

1 Answers1

0

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.