Hello While setting up my first IMAP (cyrus, cyrus-sasl, postfix) server I have come to a stop.
Can someone tell what the following log messages mean and where things go wrong. To me it looks like the authenticaiton first succeeds (auth_success), but then subsequently something goes wrong probably with a null password. Is this a imap or a sasl-authentication problem? All parts seem to work fine when tested separately. I have tried with auxprop (/etc/sasldb2) and with saslauthd pam. However when I try to log in with my web-client (Squirrelmail at the moment) I get "Unknown user or password incorrect". "myuser" has been added to /etc/sasldb2 and to /etc/passwd and seems to be also in /etc/shadow Any pointers as to where to look would be greatly appreciated. More info about the setup at the end of the mail. Thank you Keimo imtest -m login -a myuser localhost (give correct password) imapd.log: Apr 29 16:34:08 mysun imap[2068]: [ID 921384 local6.debug] accepted connection Apr 29 16:34:10 mysun imap[2068]: [ID 277583 local6.notice] login: localhost [127.0.0.1] myuser plaintext User logged in auth.log: mysun# saslauthd[1999] :rel_accept_lock : released accept lock saslauthd[1999] :cache_get_rlock : attempting a read lock on slot: 532 saslauthd[1999] :cache_lookup : [login=myuser] [service=] [realm=imap]: found with valid passwd saslauthd[1999] :cache_un_lock : attempting to release lock on slot: 532 saslauthd[1999] :do_auth : auth success (cached): [user=myuser] [service=imap] [realm=] saslauthd[1999] :do_request : response: OK saslauthd[2003] :get_accept_lock : acquired accept lock imtest -m login -a myuser localhost (give wrong password) imapd.log: Apr 29 16:35:03 mysun imap[2068]: [ID 921384 local6.debug] accepted connection Apr 29 16:35:06 mysun imap[2068]: [ID 914338 local6.notice] badlogin: localhost [127.0.0.1] plaintext myuser SASL(-13): authentication failure: checkpass failed auth.log: mysun# saslauthd[2003] :rel_accept_lock : released accept lock saslauthd[2003] :cache_get_rlock : attempting a read lock on slot: 532 saslauthd[2003] :cache_lookup : [login=myuser] [service=] [realm=imap]: found with invalid passwd, update pending saslauthd[2003] :cache_un_lock : attempting to release lock on slot: 532 saslauthd[2003] :do_auth : auth failure: [user=myuser] [service=imap] [realm=] [mech=pam] [reason=PAM auth error] saslauthd[2005] :get_accept_lock : acquired accept lock >From my web client (give correct password) Here I would like to understand these log messages. Why are there 2 sets of messages on imapd.log both with badlogin? Also auth.log looks like things go right first but then the program probably makes a second pwd check which goes wrong? imapd.log: Apr 29 16:36:34 mysun imap[2068]: [ID 921384 local6.debug] accepted connection Apr 29 16:36:34 mysun imap[2068]: [ID 914338 local6.notice] badlogin: localhost [127.0.0.1] plaintext myuser SASL(-13): authentication failure: checkpass failed Apr 29 16:36:37 mysun imap[2068]: [ID 921384 local6.debug] accepted connection Apr 29 16:36:37 mysun imap[2068]: [ID 914338 local6.notice] badlogin: localhost [127.0.0.1] plaintext myuser SASL(-13): authentication failure: checkpass failed auth.log: mysun# saslauthd[2005] :rel_accept_lock : released accept lock saslauthd[2005] :cache_get_rlock : attempting a read lock on slot: 532 saslauthd[2005] :cache_lookup : [login=myuser] [service=] [realm=imap]: found with valid passwd saslauthd[2005] :cache_un_lock : attempting to release lock on slot: 532 saslauthd[2005] :do_auth : auth success (cached): [user=myuser] [service=imap] [realm=] saslauthd[2005] :do_request : response: OK saslauthd[1995] :get_accept_lock : acquired accept lock saslauthd[1995] :rel_accept_lock : released accept lock saslauthd[1995] :do_request : NULL password received saslauthd[1997] :get_accept_lock : acquired accept lock saslauthd[1997] :rel_accept_lock : released accept lock saslauthd[1997] :do_request : NULL password received saslauthd[1999] :get_accept_lock : acquired accept lock >From my web client (give wrong password) imapd.log: Apr 29 16:37:24 mysun imap[2068]: [ID 921384 local6.debug] accepted connection Apr 29 16:37:24 mysun imap[2068]: [ID 914338 local6.notice] badlogin: localhost [127.0.0.1] plaintext myuser SASL(-13): authentication failure: checkpass failed auth.log: mysun# saslauthd[1999] :rel_accept_lock : released accept lock saslauthd[1999] :cache_get_rlock : attempting a read lock on slot: 532 saslauthd[1999] :cache_lookup : [login=myuser] [service=] [realm=imap]: found with invalid passwd, update pending saslauthd[1999] :cache_un_lock : attempting to release lock on slot: 532 saslauthd[1999] :do_auth : auth failure: [user=myuser] [service=imap] [realm=] [mech=pam] [reason=PAM auth error] saslauthd[2003] :get_accept_lock : acquired accept lock /etc/imapd.conf: configdirectory: /var/imap partition-default: /var/spool/imap admins: cyrus sasl_pwcheck_method: saslauthd #sasl_pwcheck_method: auxprop sasl_mech_list: PLAIN LOGIN My setup cyrus-sasl-2.1.20 cyrus-imapd-2.2.12 Solaris 8 Configure Cyrus imapd ./configure \ --disable-krb4 \ --with-db-dir=/usr/local/BerkeleyDB.4.3 --with-bdb-libdir=/usr/local/BerkeleyDB.4.3/lib \ --with-bdb-incdir=/usr/local/BerkeleyDB.4.3/include \ --with-openssl=/usr/local/ssl \ --with-perl=/usr/local/bin/perl \ --with-ucdsnmp=/usr/local \ --with-sasl=/usr/local --with-auth=unix Configure SASL: ./configure \ --with-bdb-libdir=/usr/local/BerkeleyDB.4.3/lib \ --with-bdb-incdir=/usr/local/BerkeleyDB.4.3/include \ --with-openssl=/usr/local/ssl \ --enable-login \ --with-saslauthd=/var/run/saslauthd Start the programs /usr/local/sbin/saslauthd -d -c -a pam postfix start /usr/cyrus/bin/master & --- Cyrus Home Page: http://asg.web.cmu.edu/cyrus Cyrus Wiki/FAQ: http://cyruswiki.andrew.cmu.edu List Archives/Info: http://asg.web.cmu.edu/cyrus/mailing-list.html
