[Dovecot] auth-login crash with cram-md5 (plain works) on unknown user
Hello Timo and others..
14:09 mail:~# dovecot --version 1.0.rc31
Install prefix ...................... :
/usr/local
File offsets ........................ : 64bit
I/O loop method ..................... : poll
File change notification method ..... : inotify
Building with SSL support ........... : yes (OpenSSL)
Building with IPv6 support .......... : yes
Building with pop3 server ........... : yes
Building with mail delivery agent .. : yes
Building with GSSAPI support ........ : no
Building with user database modules . : static prefetch passwd
passwd-file checkpassword ldap (modules)
Building with password lookup modules : passwd passwd-file shadow
checkpassword ldap (modules)
Building with SQL drivers ............:
when logging in as an *unknown* user - with CRAM-MD5 and an LDAP pass/userdb i get this crash of the auth process:
==> /var/log/dovecot.log <==
dovecot: 2007-04-12 13:50:14 Error: auth(default): file auth-request.c: line 474 (auth_request_lookup_credentials_callback): assertion failed: (request->state = = AUTH_REQUEST_STATE_PASSDB) dovecot: 2007-04-12 13:50:14 Error: auth(default): Raw backtrace: dovecot-auth [0x80665a1] -> dovecot-auth [0x80664bc] -> dovecot-auth [0x805429e] -> dovecot-auth [0x805d7fd] -> dovecot-auth [0x805dbc4] -> dovecot-auth [0x8057f3b] -> dovecot-auth(io_loop_handler_run+0x110) [0x8069730] -> dovecot-auth(io_loop_run+0x1c) [0x8068c8c] -> dovecot-auth(main+0x2fe) [0x805920e] -> /lib/libc.so.6(__libc_start_main+0xdc) [0xb7db58cc] -> dovecot-auth [0x804fb51] dovecot: 2007-04-12 13:50:14 Error: child 7163 (auth) killed with signal 6
logging in via plain works nicely:
==> /var/log/dovecot.info <== dovecot: 2007-04-12 14:08:12 Info: Dovecot v1.0.rc31 starting up dovecot: 2007-04-12 14:08:27 Info: auth(default): ldap(yeled,19.8.5.23): unknown user
ldap entry of unknown user: dn: uid=yeled,ou=users,dc=playlouder,dc=com uid: yeled sn: yeled cn: Charles Allom userPassword:: ddd= objectClass: inetOrgPerson objectClass: CourierMailAlias mail: yeled@playlouder.com maildrop: charlie@playlouder.com
ldap entry of known user: uid: luke sn: luke cn: Luke userPassword:: ddd= objectClass: inetOrgPerson objectClass: mspUser objectClass: CourierMailAccount mail: luke@playlouder.com homeDirectory: /home/l/luke gidNumber: 5000 uidNumber: 5000
and my ldap config: hosts = beta.playlouder.com dn = cn=admin,dc=playlouder,dc=com dnpass = ddd auth_bind = no ldap_version = 3 base = ou=users,dc=playlouder,dc=com scope = subtree user_attrs = homeDirectory=home,uidNumber=uid,gidNumber=gid user_filter = (&(objectClass=CourierMailAccount)(uid=%n)) pass_attrs = uid=user,userPassword=password pass_filter = (&(objectClass=CourierMailAccount)(uid=%n)) default_pass_scheme = PLAIN user_global_uid = 5000 user_global_gid = 5000
as you can see I'm setting CourierMailAlias on users with no dovecot access, and CourierMailAccount on users with imap/pop logins. the passwords in openldap are plain (b64)
i have included the strace output...
13:49:54.112641 gettimeofday({1176385794, 112728}, {0, 0}) = 0 13:49:54.112757 gettimeofday({1176385794, 112771}, NULL) = 0 13:49:54.112792 poll([{fd=5, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=7, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=0, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=3, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=15, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=8, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=17, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=10, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=12, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=13, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=14, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=9, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}], 12, 579) = 0 13:49:54.691245 gettimeofday({1176385794, 691271}, {0, 0}) = 0 13:49:54.691295 gettimeofday({1176385794, 691307}, NULL) = 0 13:49:54.691328 poll([{fd=5, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=7, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=0, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=3, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=15, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=8, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=17, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=10, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=12, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=13, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=14, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=9, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}], 12, 2000) = 0 13:49:56.691229 gettimeofday({1176385796, 691257}, {0, 0}) = 0 13:49:56.691280 gettimeofday({1176385796, 691293}, NULL) = 0 13:49:56.691313 poll([{fd=5, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=7, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=0, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=3, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=15, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=8, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=17, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=10, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=12, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=13, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=14, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=9, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}], 12, 970) = 0 13:49:57.661354 gettimeofday({1176385797, 661389}, {0, 0}) = 0 13:49:57.661437 gettimeofday({1176385797, 661450}, NULL) = 0 13:49:57.661470 poll([{fd=5, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=7, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=0, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=3, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=15, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=8, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=17, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=10, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=12, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=13, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=14, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=9, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}], 12, 1030) = 0 13:49:58.691228 gettimeofday({1176385798, 691255}, {0, 0}) = 0 13:49:58.691278 gettimeofday({1176385798, 691292}, NULL) = 0 13:49:58.691312 poll([{fd=5, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=7, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=0, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=3, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=15, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=8, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=17, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=10, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=12, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=13, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=14, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=9, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}], 12, 2000) = 0 13:50:00.691326 gettimeofday({1176385800, 691362}, {0, 0}) = 0 13:50:00.691396 gettimeofday({1176385800, 691409}, NULL) = 0 13:50:00.691430 poll([{fd=5, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=7, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=0, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=3, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=15, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=8, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=17, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=10, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=12, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=13, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=14, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=9, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}], 12, 1970) = 0 13:50:02.661327 gettimeofday({1176385802, 661355}, {0, 0}) = 0 13:50:02.661387 gettimeofday({1176385802, 661401}, NULL) = 0 13:50:02.661421 poll([{fd=5, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=7, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=0, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=3, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=15, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=8, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=17, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=10, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=12, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=13, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=14, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=9, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}], 12, 30) = 0 13:50:02.691270 gettimeofday({1176385802, 691293}, {0, 0}) = 0 13:50:02.691316 gettimeofday({1176385802, 691329}, NULL) = 0 13:50:02.691348 poll([{fd=5, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=7, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=0, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=3, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=15, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=8, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=17, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=10, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=12, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=13, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=14, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=9, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}], 12, 2000) = 0 13:50:04.691291 gettimeofday({1176385804, 691327}, {0, 0}) = 0 13:50:04.691366 gettimeofday({1176385804, 691379}, NULL) = 0 13:50:04.691399 poll([{fd=5, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=7, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=0, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=3, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=15, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=8, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=17, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=10, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=12, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=13, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=14, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=9, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}], 12, 2000) = 0 13:50:06.691246 gettimeofday({1176385806, 691275}, {0, 0}) = 0 13:50:06.691298 gettimeofday({1176385806, 691312}, NULL) = 0 13:50:06.691332 poll([{fd=5, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=7, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=0, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=3, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=15, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=8, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=17, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=10, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=12, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=13, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=14, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=9, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}], 12, 970) = 0 13:50:07.661253 gettimeofday({1176385807, 661280}, {0, 0}) = 0 13:50:07.661314 gettimeofday({1176385807, 661327}, NULL) = 0 13:50:07.661347 poll([{fd=5, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=7, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=0, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=3, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=15, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=8, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=17, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=10, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=12, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=13, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=14, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=9, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}], 12, 1030) = 0 13:50:08.692164 gettimeofday({1176385808, 692193}, {0, 0}) = 0 13:50:08.692217 gettimeofday({1176385808, 692230}, NULL) = 0 13:50:08.692250 poll([{fd=5, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=7, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=0, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=3, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=15, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=8, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=17, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=10, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=12, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=13, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=14, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=9, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}], 12, 2000) = 0 13:50:10.691295 gettimeofday({1176385810, 691330}, {0, 0}) = 0 13:50:10.691352 gettimeofday({1176385810, 691365}, NULL) = 0 13:50:10.691387 poll([{fd=5, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=7, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=0, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=3, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=15, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=8, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=17, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=10, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=12, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=13, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=14, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=9, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}], 12, 1) = 0 13:50:10.702349 gettimeofday({1176385810, 702382}, {0, 0}) = 0 13:50:10.702406 gettimeofday({1176385810, 702419}, NULL) = 0 13:50:10.702439 poll([{fd=5, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=7, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=0, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=3, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=15, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=8, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=17, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=10, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=12, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=13, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=14, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=9, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}], 12, 1959) = 0 13:50:12.661239 gettimeofday({1176385812, 661268}, {0, 0}) = 0 13:50:12.661300 gettimeofday({1176385812, 661314}, NULL) = 0 13:50:12.661334 poll([{fd=5, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=7, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=0, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=3, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=15, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=8, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=17, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=10, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=12, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=13, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=14, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=9, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}], 12, 41) = 0 13:50:12.711302 gettimeofday({1176385812, 711336}, {0, 0}) = 0 13:50:12.711372 gettimeofday({1176385812, 711385}, NULL) = 0 13:50:12.711405 poll([{fd=5, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=7, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=0, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=3, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=15, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=8, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=17, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=10, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL, revents=POLLIN}, {fd=12, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=13, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=14, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=9, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}], 12, 2000) = 1 13:50:14.324672 gettimeofday({1176385814, 324698}, {0, 0}) = 0 13:50:14.324722 read(10, "AUTH\t1\tCRAM-MD5\tservice=IMAP\tlip"..., 4074) = 62 13:50:14.324786 read(4, "\275\215\332\242\353%\371\243\261\207\362c~8\365f", 16) = 16 13:50:14.324856 write(10, "CONT\t1\tPDkxODI1NzkzNzUyOTY2NTIuM"..., 76) = 76 13:50:14.324915 gettimeofday({1176385814, 324929}, NULL) = 0 13:50:14.324952 poll([{fd=5, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=7, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=0, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=3, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=15, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=8, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=17, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=10, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL, revents=POLLIN}, {fd=12, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=13, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=14, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=9, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}], 12, 387) = 1 13:50:14.330904 gettimeofday({1176385814, 330925}, {0, 0}) = 0 13:50:14.330956 read(10, "CONT\t1\teWVsZWQgMmYwZWVlZDI5M2RjO"..., 4012) = 60 13:50:14.331053 time(NULL) = 1176385814 13:50:14.331107 write(7, "0{\2\1\7cv\4\35ou=users,dc=playlouder,"..., 125) = 125 13:50:14.331184 gettimeofday({1176385814, 331198}, NULL) = 0 13:50:14.331217 poll([{fd=5, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=7, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL, revents=POLLIN}, {fd=0, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=3, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=15, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=8, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=17, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=10, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=12, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=13, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=14, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=9, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}], 12, 380) = 1 13:50:14.332637 gettimeofday({1176385814, 332653}, {0, 0}) = 0 13:50:14.332674 time(NULL) = 1176385814 13:50:14.332707 select(1024, [7], [], NULL, {0, 0}) = 1 (in [7], left {0, 0}) 13:50:14.332827 read(7, "0\f\2\1\7e\7\n", 8) = 8 13:50:14.332864 read(7, "\1\0\4\0\4\0", 6) = 6 13:50:14.332906 time(NULL) = 1176385814 13:50:14.332947 write(2, "\1Ildap(yeled,19.8.5.23): unkn"..., 41) = 41 13:50:14.333033 write(2, "\1Ffile auth-request.c: line 474 "..., 140) = 140 13:50:14.333120 open("/etc/ld.so.cache", O_RDONLY) = 11 13:50:14.333166 fstat64(11, {st_mode=S_IFREG|0644, st_size=11099, ...}) = 0 13:50:14.333217 mmap2(NULL, 11099, PROT_READ, MAP_PRIVATE, 11, 0) = 0xb7f28000 13:50:14.333256 close(11) = 0 13:50:14.333289 access("/etc/ld.so.nohwcap", F_OK) = -1 ENOENT (No such file or directory) 13:50:14.333354 open("/lib/libgcc_s.so.1", O_RDONLY) = 11 13:50:14.333391 read(11, "\177ELF\1\1\1\0\0\0\0\0\0\0\0\0\3\0\3\0\1\0\0\0\240\30"..., 512) = 512 13:50:14.333437 fstat64(11, {st_mode=S_IFREG|0644, st_size=40208, ...}) = 0 13:50:14.333488 mmap2(NULL, 43332, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 11, 0) = 0xb79e1000 13:50:14.333526 mmap2(0xb79eb000, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 11, 0x9) = 0xb79eb000 13:50:14.333571 close(11) = 0 13:50:14.333632 munmap(0xb7f28000, 11099) = 0 13:50:14.333685 futex(0xb7ebe9d8, FUTEX_WAKE, 2147483647) = 0 13:50:14.333753 futex(0xb79eb824, FUTEX_WAKE, 2147483647) = 0 13:50:14.333883 write(2, "\1ERaw backtrace: dovecot-auth [0"..., 406) = 406 13:50:14.333948 rt_sigprocmask(SIG_UNBLOCK, [ABRT], NULL, 8) = 0 13:50:14.333990 tgkill(7163, 7163, SIGABRT) = 0 13:50:14.334021 --- SIGABRT (Aborted) @ 0 (0) ---
-- hail eris http://rubberduck.com/
On Thu, 12 Apr 2007 15:27:17 +0100, Charlie Allom wrote:
Hello Timo and others..
thanks for fixing that over IRC Timo with rc32.
now it works but i think something is still awry -
dovecot: 2007-04-16 14:22:16 Info: auth(default): passwd(yeled,19.8.5.23): unknown user dovecot: 2007-04-16 14:22:16 Info: IMAP(yeled): Effective uid=5000, gid=5000, home=/home/y/yeled dovecot: 2007-04-16 14:22:16 Info: IMAP(yeled): maildir: data=/home/y/yeled/Maildir dovecot: 2007-04-16 14:22:16 Info: IMAP(yeled): maildir: root=/home/y/yeled/Maildir, index=/home/y/yeled/Maildir, control=, inbox= dovecot: 2007-04-16 14:22:16 Info: imap-login: Login: user=<yeled>, method=CRAM-MD5, rip=19.8.5.23, lip=19.3.2.6, TLS
the line in the strace seems to be: 3738 14:22:38.463205 write(2, "\1Ipasswd(yeled,193.82.57.23): un"..., 43) = 43......
(attached so it doesnt linebreak)
-- hail eris http://rubberduck.com/
more info with auth_debug=yes
==> /var/log/dovecot.info <==
dovecot: 2007-04-16 14:44:22 Info: Dovecot v1.0.rc32 starting up
dovecot: 2007-04-16 14:44:27 Info: auth(default): client in: AUTH
1 CRAM-MD5 service=IMAP secured lip=19.3.2.6 rip=19.8.5.23
dovecot: 2007-04-16 14:44:27 Info: auth(default): client out: CONT
1
PDg4Mjk2NzU1NTQwNjg1MTkuMTE3NjczNDY2N0BtYWlsLnBsYXlsb3VkZXIuY29tPg==
dovecot: 2007-04-16 14:44:27 Info: auth(default): client in:
CONT<hidden>
dovecot: 2007-04-16 14:44:27 Info: auth(default):
ldap(yeled,19.8.5.23): pass search: base=ou=users,dc=playlouder,dc=com
scope=subtree filter=(&(objectClass=CourierMailAccount)(uid=yeled))
fields=uid,userPassword
dovecot: 2007-04-16 14:44:27 Info: auth(default):
ldap(yeled,19.8.5.23): result: uid(user)=yeled
userPassword(password)=<hidden>
dovecot: 2007-04-16 14:44:27 Info: auth(default): client out: OK
1 user=yeled
dovecot: 2007-04-16 14:44:27 Info: auth(default): master in: REQUEST
1 3880 1
dovecot: 2007-04-16 14:44:27 Info: auth(default):
passwd(yeled,19.8.5.23): lookup
dovecot: 2007-04-16 14:44:27 Info: auth(default):
passwd(yeled,19.8.5.23): unknown user
dovecot: 2007-04-16 14:44:27 Info: auth(default):
ldap(yeled,19.8.5.23): user search: base=ou=users,dc=playlouder,dc=com
scope=subtree filter=(&(objectClass=CourierMailAccount)(uid=yeled))
fields=homeDirectory,uidNumber,gidNumber
dovecot: 2007-04-16 14:44:27 Info: auth(default): master out: USER
1 yeled home=/home/y/yeled gid=5000 uid=5000
dovecot: 2007-04-16 14:44:27 Info: IMAP(yeled): Effective uid=5000,
gid=5000, home=/home/y/yeled
dovecot: 2007-04-16 14:44:27 Info: IMAP(yeled): maildir:
data=/home/y/yeled/Maildir
dovecot: 2007-04-16 14:44:27 Info: IMAP(yeled): maildir:
root=/home/y/yeled/Maildir, index=/home/y/yeled/Maildir, control=,
inbox=
dovecot: 2007-04-16 14:44:27 Info: imap-login: Login: user=<yeled>,
method=CRAM-MD5, rip=19.8.5.23, lip=19.3.2.6, TLS
dovecot -n:
# /usr/local/etc/dovecot.conf log_path: /var/log/dovecot.log info_log_path: /var/log/dovecot.info log_timestamp: %Y-%m-%d %H:%M:%S protocols: imap pop3 ssl_cert_file: /etc/ssl/certs/mail.playlouder.com.pem ssl_key_file: /etc/ssl/private/mail.playlouder.com.key disable_plaintext_auth: no verbose_ssl: yes login_dir: /usr/local/var/run/dovecot/login login_executable(default): /usr/local/libexec/dovecot/imap-login login_executable(imap): /usr/local/libexec/dovecot/imap-login login_executable(pop3): /usr/local/libexec/dovecot/pop3-login login_greeting: mail.playlouder.com ready. login_greeting_capability(default): yes login_greeting_capability(imap): yes login_greeting_capability(pop3): no verbose_proctitle: yes first_valid_uid: 5000 last_valid_uid: 5000 first_valid_gid: 5000 last_valid_gid: 5000 mail_extra_groups: mail default_mail_env: maildir:~/Maildir mail_location: maildir:~/Maildir mail_debug: yes mail_executable(default): /usr/local/libexec/dovecot/imap mail_executable(imap): /usr/local/libexec/dovecot/imap mail_executable(pop3): /usr/local/libexec/dovecot/pop3 mail_plugin_dir(default): /usr/local/lib/dovecot/imap mail_plugin_dir(imap): /usr/local/lib/dovecot/imap mail_plugin_dir(pop3): /usr/local/lib/dovecot/pop3 imap_client_workarounds(default): outlook-idle netscape-eoh delay-newmail imap_client_workarounds(imap): outlook-idle netscape-eoh delay-newmail imap_client_workarounds(pop3): outlook-idle pop3_uidl_format(default): pop3_uidl_format(imap): pop3_uidl_format(pop3): %v-%u pop3_client_workarounds(default): pop3_client_workarounds(imap): pop3_client_workarounds(pop3): outlook-no-nuls oe-ns-eoh auth default: mechanisms: plain login digest-md5 cram-md5 apop verbose: yes passdb: driver: ldap args: /usr/etc/dovecot-ldap.conf userdb: driver: passwd userdb: driver: ldap args: /usr/etc/dovecot-ldap.conf socket: type: listen client: master: path: /var/spool/postfix/private/auth mode: 432 user: postfix group: postfix
-- hail eris http://rubberduck.com/
On Mon, 2007-04-16 at 15:46 +0100, Charlie Allom wrote:
ldap(yeled,19.8.5.23): pass search: base=ou=users,dc=playlouder,dc=com scope=subtree filter=(&(objectClass=CourierMailAccount)(uid=yeled)) fields=uid,userPassword dovecot: 2007-04-16 14:44:27 Info: auth(default): ldap(yeled,19.8.5.23): result: uid(user)=yeled userPassword(password)=<hidden>
yeled is found from LDAP passdb.
passwd(yeled,19.8.5.23): unknown user
Isn't found from passwd userdb.
dovecot: 2007-04-16 14:44:27 Info: auth(default): ldap(yeled,19.8.5.23): user search: base=ou=users,dc=playlouder,dc=com scope=subtree filter=(&(objectClass=CourierMailAccount)(uid=yeled)) fields=homeDirectory,uidNumber,gidNumber
Is again found from LDAP userdb, so the login succeeds.
passdb: driver: ldap args: /usr/etc/dovecot-ldap.conf userdb: driver: passwd userdb: driver: ldap args: /usr/etc/dovecot-ldap.conf
The lookups are done in this order. Is the userdb passwd supposed to be there at all? It's enough to find the user from one userdb.
On Mon, 16 Apr 2007 17:56:28 +0300, Timo Sirainen wrote:
On Mon, 2007-04-16 at 15:46 +0100, Charlie Allom wrote:
ldap(yeled,19.8.5.23): pass search: base=ou=users,dc=playlouder,dc=com scope=subtree filter=(&(objectClass=CourierMailAccount)(uid=yeled)) fields=uid,userPassword dovecot: 2007-04-16 14:44:27 Info: auth(default): ldap(yeled,19.8.5.23): result: uid(user)=yeled userPassword(password)=<hidden>
yeled is found from LDAP passdb.
passwd(yeled,19.8.5.23): unknown user
Isn't found from passwd userdb.
sorry timo - everyone :)
it was this
userdb passwd { }
that i couldn't see because .. i've run out of excuses.
C.
hail eris http://rubberduck.com/
participants (2)
-
Charlie Allom
-
Timo Sirainen