Hi,
Today I upgraded my dovecot to a newer version (2.2.9 debian wheezy-backports) At that moment I also reconfigured the whole thing a bit nicer.
Now I stumbled on the following issue.
In my configuration I use 2 backends (LDAP & passwd-file). passdb { args = scheme=CRYPT username_format=%u /etc/dovecot/users driver = passwd-file } passdb { args = /etc/dovecot/dovecot-ldap.conf.ext driver = ldap } userdb { args = uid=vmail gid=vmail home=/var/vmail/%d/%n driver = static }
Now this worked fine before. But if I tested it, LDAP logins worked, and passwd-file logins failed.
Failed log (user is only in the passwd-file):
Aug 01 21:31:55 auth: Debug: Loading modules from directory:
/usr/lib/dovecot/modules/auth
Aug 01 21:31:55 auth: Debug: Module loaded:
/usr/lib/dovecot/modules/auth/libdriver_mysql.so
Aug 01 21:31:55 auth: Debug: Module loaded:
/usr/lib/dovecot/modules/auth/libdriver_pgsql.so
Aug 01 21:31:55 auth: Debug: Module loaded:
/usr/lib/dovecot/modules/auth/libdriver_sqlite.so
Aug 01 21:31:55 auth: Debug: Loading modules from directory:
/usr/lib/dovecot/modules/auth
Aug 01 21:31:55 auth: Debug: Module loaded:
/usr/lib/dovecot/modules/auth/libauthdb_ldap.so
Aug 01 21:31:55 auth: Debug: Read auth token secret from
/var/run/dovecot/auth-token-secret.dat
Aug 01 21:31:55 auth: Debug: passwd-file /etc/dovecot/users: Read 10
users in 0 secs
Aug 01 21:31:55 auth: Debug: auth client connected (pid=5516)
Aug 01 21:31:55 auth: Debug: client in: AUTH 1 PLAIN
service=imap secured session=c34kcZb/uwBbtKLu lip=xxx
rip=xxxx lport=993 rport=52411
Aug 01 21:31:55 auth: Debug: client passdb out: CONT 1
Aug 01 21:31:55 auth: Debug: client in: CONT 1 xxxxx (previous
base64 data may contain sensitive data)
Aug 01 21:31:55 auth: Debug: cache(info@xxx.com,xxx,
user=info@xxx.com temp
Aug 01 21:31:57 auth: Debug: client in: AUTH 2 PLAIN
service=imap secured session=c34kcZb/uwBbtKLu lip=xxx
rip=xxx lport=993 rport=52411 resp=xxx (previous base64 data
may contain sensitive data)
Aug 01 21:32:01 auth: Debug: cache(info@xxx.com,xxx,
user=info@xxx.com temp
As you see it returned a FAIL, but the password was retrieved from the users file (see the cache hit).
Now I changed the order of the passdb's in my config, to make passwd-file come first, and then LDAP. And what happend now, it started working ...
Logs:
Aug 01 21:30:23 auth: Debug: Loading modules from directory:
/usr/lib/dovecot/modules/auth
Aug 01 21:30:23 auth: Debug: Module loaded:
/usr/lib/dovecot/modules/auth/libdriver_mysql.so
Aug 01 21:30:23 auth: Debug: Module loaded:
/usr/lib/dovecot/modules/auth/libdriver_pgsql.so
Aug 01 21:30:23 auth: Debug: Module loaded:
/usr/lib/dovecot/modules/auth/libdriver_sqlite.so
Aug 01 21:30:23 auth: Debug: Loading modules from directory:
/usr/lib/dovecot/modules/auth
Aug 01 21:30:23 auth: Debug: Module loaded:
/usr/lib/dovecot/modules/auth/libauthdb_ldap.so
Aug 01 21:30:23 auth: Debug: Read auth token secret from
/var/run/dovecot/auth-token-secret.dat
Aug 01 21:30:23 auth: Debug: passwd-file /etc/dovecot/users: Read 10
users in 0 secs
Aug 01 21:30:23 auth: Debug: auth client connected (pid=5459)
Aug 01 21:30:24 auth: Debug: client in: AUTH 1 PLAIN
service=imap secured session=TTm6a5b/swBbtKLu lip=xxx
rip=xxx lport=993 rport=52403
Aug 01 21:30:24 auth: Debug: client passdb out: CONT 1
Aug 01 21:30:24 auth: Debug: client in: CONT 1 xxxx (previous
base64 data may contain sensitive data)
Aug 01 21:30:24 auth: Debug: cache(info@xxx.com,xxx,
1 9976303da4c6eb55a008b0cae6ab12a1 session_pid=5462
request_auth_token
Aug 01 21:30:24 auth: Debug: master userdb out: USER 1973682177
info@xxx.com uid=1001 gid=1001 home=/var/vmail/xxx.com/info
auth_token=31afcf6ff0c5ed5150beb96ad3718cff452badae
The only thing I changed here was the order the passdb backends.
It works fine now, but it not clear to me why the order is so important. Could somebody explain this? Or is this some bug?
Thanks Jean-Louis