thr3ads.net - dovecot - [Dovecot] auth-login crash with cram-md5 (plain works) on unknown user [Apr 2007]

If this information is useful, please help other people find it:
Share via:

Charlie Allom

2007-Apr-12 14:27 UTC

[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 at playlouder.com
	maildrop: charlie at playlouder.com

ldap entry of known user:
	uid: luke
	sn: luke
	cn: Luke
	userPassword:: ddd	objectClass: inetOrgPerson
	objectClass: mspUser
	objectClass: CourierMailAccount
	mail: luke at 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/

Charlie Allom

2007-Apr-16 14:30 UTC

head link

[Dovecot] unknown user now logged - but auth works (Re: auth-login crash with cram-md5 (plain works) on unknown user)

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=, 
inboxdovecot: 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/

-------------- next part --------------
A non-text attachment was scrubbed...
Name: unknown_user.gz
Type: application/x-gzip
Size: 3183 bytes
Desc: not available
URL:
<http://dovecot.org/pipermail/dovecot/attachments/20070416/169d4747/attachment.gz>

Charlie Allom

2007-Apr-16 14:46 UTC

head link

[Dovecot] unknown user now logged - but auth works (Re: auth-login crash with cram-md5 (plain works) on unknown user)

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=, 
inboxdovecot: 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/

Apparently Analagous Threads

Search for more apparently analagous threads

dovecot - Apr 2007 - auth-login crash with cram-md5 (plain works) on unknown user

[Dovecot] auth-login crash with cram-md5 (plain works) on unknown user

[Dovecot] unknown user now logged - but auth works (Re: auth-login crash with cram-md5 (plain works) on unknown user)

[Dovecot] unknown user now logged - but auth works (Re: auth-login crash with cram-md5 (plain works) on unknown user)

Apparently Analagous Threads