Hello, I'm upgrading one of our servers to the last HG 2.2.13 versión
and I've found some problems with our configuration which has been
working fine with previous versions.
We have a LDAP userdb for the users and a master userdb for user
assistance, Until now the definition of usersdb in 10-auth.conf was:
!include auth-master.conf.ext
!include auth-system.conf.ext
!include auth-ldap.conf.ext
With the 2.2.12 version this worked fine but with 2.2.13+ version the
LDAP users can't login in dovecot (IMAP), however the master users can
login fine.
However, if I comment out the master userdb or change the order, i.e.
!include auth-system.conf.ext
!include auth-ldap.conf.ext
!include auth-master.conf.ext
In this case LDAP and master users can login normally.
Is this configuration change required for the new version or it's a bug?
Follows the log sections for both configurations
Regards
Juan C. Blanco
There is the log for the first case (master before ldap) with debugging
activated:
May 20 08:57:43 master: Info: Dovecot v2.2.13 starting up for imap,
pop3, lmtp, sieve (core dumps disabled)
May 20 08:57:51 auth: Debug: Loading modules from directory:
/usr/lib64/dovecot/auth
May 20 08:57:51 auth: Debug: Module loaded:
/usr/lib64/dovecot/auth/libdriver_mysql.so
May 20 08:57:51 auth: Debug: Loading modules from directory:
/usr/lib64/dovecot/auth
May 20 08:57:51 auth: Debug: Module loaded:
/usr/lib64/dovecot/auth/libauthdb_ldap.so
May 20 08:57:51 auth: Debug: Read auth token secret from
/var/run/dovecot/auth-token-secret.dat
May 20 08:57:51 auth: Debug: passwd-file /nas/mail/etc/passwd.master:
Read 1 users in 0 secs
May 20 08:57:51 auth: Debug: auth client connected (pid=22482)
May 20 08:57:56 auth: Debug: client in: AUTH 1 PLAIN
service=imap secured session=T/5QZs/54gB/AAAB lip=127.0.0.1
rip=127.0.0.1 lport=143 rport=56290 resp=<hidden>
May 20 08:57:56 auth: Debug: ldap(user1,127.0.0.1,<T/5QZs/54gB/AAAB>):
cache miss
May 20 08:57:56 auth: Debug: ldap(user1,127.0.0.1,<T/5QZs/54gB/AAAB>):
bind search: base=dc=some,dc=domain,dc=es filter=(uid=user1)
May 20 08:57:56 auth: Debug: ldap(user1,127.0.0.1,<T/5QZs/54gB/AAAB>):
result: Mailbox=/mail/user1 MailQuotaSize=10240; Mailbox,MailQuotaSize
unused
May 20 08:57:56 auth: Debug: ldap(user1,127.0.0.1,<T/5QZs/54gB/AAAB>):
result: Mailbox=/mail/user1 MailQuotaSize=10240
May 20 08:57:56 auth: Debug: client passdb out: OK 1 user=user1
May 20 08:57:56 auth: Debug: master in: REQUEST 4005167105 22482
1 f14d67dfcbfd5fdffe206fba32ef320b session_pid=22485
request_auth_token
May 20 08:57:56 auth: Debug:
passwd-file(user1,127.0.0.1,<T/5QZs/54gB/AAAB>): userdb cache miss
May 20 08:57:56 auth: Debug:
passwd-file(user1,127.0.0.1,<T/5QZs/54gB/AAAB>): lookup: user=user1
file=/nas/mail/etc/passwd.master
May 20 08:57:56 auth: Info:
passwd-file(user1,127.0.0.1,<T/5QZs/54gB/AAAB>): unknown user
May 20 08:57:56 auth: Debug:
prefetch(user1,127.0.0.1,<T/5QZs/54gB/AAAB>): success
May 20 08:57:56 auth: Debug: master userdb out: USER 4005167105
user1 auth_token=51719362e64e34996d44dfbde00993c989be6580
May 20 08:57:56 imap-login: Info: Login: user=<user1>, method=PLAIN,
rip=127.0.0.1, lip=127.0.0.1, mpid=22485, secured,
session=<T/5QZs/54gB/AAAB>
May 20 08:57:56 imap: Debug: Loading modules from directory:
/usr/lib64/dovecot
May 20 08:57:56 imap: Debug: Module loaded:
/usr/lib64/dovecot/lib01_acl_plugin.so
May 20 08:57:56 imap: Debug: Module loaded:
/usr/lib64/dovecot/lib02_imap_acl_plugin.so
May 20 08:57:56 imap: Debug: Module loaded:
/usr/lib64/dovecot/lib10_quota_plugin.so
May 20 08:57:56 imap: Debug: Module loaded:
/usr/lib64/dovecot/lib11_imap_quota_plugin.so
May 20 08:57:56 imap: Debug: Added userdb setting: plugin/=yes
May 20 08:57:56 imap(user1): Debug: Effective uid=98, gid=12, home=
May 20 08:57:56 imap(user1): Debug: Quota root: name=User quota
backend=maildir args=
May 20 08:57:56 imap(user1): Debug: Quota rule: root=User quota
mailbox=* bytes=10485760 messages=0
May 20 08:57:56 imap(user1): Debug: Quota rule: root=User quota
mailbox=Trash bytes=+1048576 (10%) messages=0
May 20 08:57:56 imap(user1): Debug: Quota warning: bytes=9961472 (95%)
messages=0 reverse=no command=quota-warning 95 user1
May 20 08:57:56 imap(user1): Debug: Quota warning: bytes=8388608 (80%)
messages=0 reverse=no command=quota-warning 80 user1
May 20 08:57:56 imap(user1): Debug: Quota grace: root=User quota
bytes=1048576 (10%)
May 20 08:57:56 imap(user1): Debug: Namespace inbox: type=private,
prefix=, sep=/, inbox=yes, hidden=no, list=yes, subscriptions=yes
location=maildir:~/Maildir
May 20 08:57:56 imap(user1): Error: user user1: Initialization failed:
Namespace '': Home directory not set for user. Can't expand ~/ for mail
root dir in: ~/Maildir
May 20 08:57:56 imap(user1): Error: Invalid user settings. Refer to
server log for more information.
Log for second case (master after LDAP)
May 20 09:06:38 master: Info: Dovecot v2.2.13 starting up for imap,
pop3, lmtp, sieve (core dumps disabled)
May 20 09:06:43 auth: Debug: Loading modules from directory:
/usr/lib64/dovecot/auth
May 20 09:06:43 auth: Debug: Module loaded:
/usr/lib64/dovecot/auth/libdriver_mysql.so
May 20 09:06:43 auth: Debug: Loading modules from directory:
/usr/lib64/dovecot/auth
May 20 09:06:43 auth: Debug: Module loaded:
/usr/lib64/dovecot/auth/libauthdb_ldap.so
May 20 09:06:43 auth: Debug: Read auth token secret from
/var/run/dovecot/auth-token-secret.dat
May 20 09:06:43 auth: Debug: passwd-file /nas/mail/etc/passwd.master:
Read 1 users in 0 secs
May 20 09:06:43 auth: Debug: auth client connected (pid=22533)
May 20 09:06:50 auth: Debug: client in: AUTH 1 PLAIN
service=imap secured session=RRYchs/55AB/AAAB lip=127.0.0.1
rip=127.0.0.1 lport=143 rport=56292 resp=<hidden>
May 20 09:06:50 auth: Debug: ldap(user1,127.0.0.1,<RRYchs/55AB/AAAB>):
cache miss
May 20 09:06:50 auth: Debug: ldap(user1,127.0.0.1,<RRYchs/55AB/AAAB>):
bind search: base=dc=some,dc=domain,dc=es filter=(uid=user1)
May 20 09:06:50 auth: Debug: ldap(user1,127.0.0.1,<RRYchs/55AB/AAAB>):
result: Mailbox=/mail/user1 MailQuotaSize=10240; Mailbox,MailQuotaSize
unused
May 20 09:06:50 auth: Debug: ldap(user1,127.0.0.1,<RRYchs/55AB/AAAB>):
result: Mailbox=/mail/user1 MailQuotaSize=10240
May 20 09:06:50 auth: Debug: client passdb out: OK 1 user=user1
May 20 09:06:50 auth: Debug: master in: REQUEST 899284993 22533
1 5497b866fa520f52f65b72b700b3e460 session_pid=22535
request_auth_token
May 20 09:06:50 auth: Debug:
prefetch(user1,127.0.0.1,<RRYchs/55AB/AAAB>): success
May 20 09:06:50 auth: Debug: master userdb out: USER 899284993
user1 home=/mail/user1 quota_rule=*:storage=10240
acl_groups=ccmail auth_token=672454c1a2671c22f334923aa11916aab58ed954
May 20 09:06:50 imap-login: Info: Login: user=<user1>, method=PLAIN,
rip=127.0.0.1, lip=127.0.0.1, mpid=22535, secured,
session=<RRYchs/55AB/AAAB>
May 20 09:06:50 imap: Debug: Loading modules from directory:
/usr/lib64/dovecot
May 20 09:06:50 imap: Debug: Module loaded:
/usr/lib64/dovecot/lib01_acl_plugin.so
May 20 09:06:50 imap: Debug: Module loaded:
/usr/lib64/dovecot/lib02_imap_acl_plugin.so
May 20 09:06:50 imap: Debug: Module loaded:
/usr/lib64/dovecot/lib10_quota_plugin.so
May 20 09:06:50 imap: Debug: Module loaded:
/usr/lib64/dovecot/lib11_imap_quota_plugin.so
May 20 09:06:50 imap: Debug: Added userdb setting: plugin/acl_groups=ccmail
May 20 09:06:50 imap: Debug: Added userdb setting:
plugin/quota_rule=*:storage=10240
May 20 09:06:50 imap(user1): Debug: Effective uid=98, gid=12,
home=/mail/user1
May 20 09:06:50 imap(user1): Debug: Quota root: name=User quota
backend=maildir args=
May 20 09:06:50 imap(user1): Debug: Quota rule: root=User quota
mailbox=* bytes=10485760 messages=0
May 20 09:06:50 imap(user1): Debug: Quota rule: root=User quota
mailbox=Trash bytes=+1048576 (10%) messages=0
May 20 09:06:50 imap(user1): Debug: Quota warning: bytes=9961472 (95%)
messages=0 reverse=no command=quota-warning 95 user1
May 20 09:06:50 imap(user1): Debug: Quota warning: bytes=8388608 (80%)
messages=0 reverse=no command=quota-warning 80 user1
May 20 09:06:50 imap(user1): Debug: Quota grace: root=User quota
bytes=1048576 (10%)
May 20 09:06:50 imap(user1): Debug: Namespace inbox: type=private,
prefix=, sep=/, inbox=yes, hidden=no, list=yes, subscriptions=yes
location=maildir:~/Maildir
May 20 09:06:50 imap(user1): Debug: maildir++: root=/mail/user1/Maildir,
index=, indexpvt=, control=, inbox=/mail/user1/Maildir, alt=
May 20 09:06:50 imap(user1): Debug: acl: initializing backend with data:
vfile
May 20 09:06:50 imap(user1): Debug: acl: acl username = user1
May 20 09:06:50 imap(user1): Debug: acl: owner = 1
May 20 09:06:50 imap(user1): Debug: acl vfile: Global ACLs disabled
May 20 09:06:50 imap(user1): Debug: Namespace : type=shared,
prefix=shared/%u/, sep=/, inbox=no, hidden=no, list=children,
subscriptions=no location=maildir:%h/Maildir:INDEX=~/Maildir/shared/%u
May 20 09:06:50 imap(user1): Debug: shared: root=/var/run/dovecot,
index=, indexpvt=, control=, inbox=, alt=
May 20 09:06:50 imap(user1): Debug: acl: initializing backend with data:
vfile
May 20 09:06:50 imap(user1): Debug: acl: acl username = user1
May 20 09:06:50 imap(user1): Debug: acl: owner = 0
May 20 09:06:50 imap(user1): Debug: acl vfile: Global ACLs disabled
May 20 09:06:53 imap(user1): Info: Disconnected: Logged out in=8 out=417
--
+----------------------------------------------------------------+
| Juan C. Blanco |
| |
| Centro de Calculo | |
| Facultad de Informatica U.P.M. | E-mail: [email protected] |
| Campus de Montegancedo | |
| Boadilla del Monte | Tel.: (+34) 91 336 7466 |
| 28660 MADRID (Spain) | Fax : (+34) 91 336 6913 |
+----------------------------------------------------------------+
