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: jcblanco@fi.upm.es | | Campus de Montegancedo | | | Boadilla del Monte | Tel.: (+34) 91 336 7466 | | 28660 MADRID (Spain) | Fax : (+34) 91 336 6913 | +----------------------------------------------------------------+