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([email protected],xxx,<c34kcZb/uwBbtKLu>):
miss
Aug 01 21:31:55 auth: Debug: ldap([email protected],xxx,<c34kcZb/uwBbtKLu>):
pass search: [email protected],ou=mail,dc=dupie,dc=be scope=subtree
filter=(&(objectClass=posixAccount)([email protected]))
fields=uid,userPassword
Aug 01 21:31:55 auth: Debug: cache([email protected],xxx,<c34kcZb/uwBbtKLu>):
miss
Aug 01 21:31:55 auth: Debug: cache([email protected],xxx,<c34kcZb/uwBbtKLu>):
miss
Aug 01 21:31:55 auth: Debug:
passwd-file([email protected],xxx,<c34kcZb/uwBbtKLu>): lookup:
[email protected] file=/etc/dovecot/users
Aug 01 21:31:57 auth: Debug: client passdb out: FAIL 1
[email protected] 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([email protected],xxx,<c34kcZb/uwBbtKLu>):
miss
Aug 01 21:32:01 auth: Debug: ldap([email protected],xxx,<c34kcZb/uwBbtKLu>):
pass search: [email protected],ou=mail,dc=dupie,dc=be scope=subtree
filter=(&(objectClass=posixAccount)([email protected]))
fields=uid,userPassword
Aug 01 21:32:01 auth: Debug: cache([email protected],xxx,<c34kcZb/uwBbtKLu>):
miss
Aug 01 21:32:01 auth: Debug: cache([email protected],xxx,<c34kcZb/uwBbtKLu>):
hit: {CRAM-MD5}19192922.....
Aug 01 21:32:03 auth: Debug: client passdb out: FAIL 2
[email protected] 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([email protected],xxx,<TTm6a5b/swBbtKLu>):
miss
Aug 01 21:30:24 auth: Debug:
passwd-file([email protected],xxx,<TTm6a5b/swBbtKLu>): lookup:
[email protected] file=/etc/dovecot/users
Aug 01 21:30:24 auth: Debug: client passdb out: OK 1 [email protected]
Aug 01 21:30:24 auth: Debug: master in: REQUEST 1973682177 5459
1 9976303da4c6eb55a008b0cae6ab12a1 session_pid=5462
request_auth_token
Aug 01 21:30:24 auth: Debug: master userdb out: USER 1973682177
[email protected] 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
