I have been having a strange issue with authdaemond ever since it split into a seperate auth port. I am running FreeBSD 5.4, net-qmail, vpopmail, Courier-IMAP, and using a mysql backend to vpopmail. The only authentication package I use or need is the vchkpw. Most or all of these are pretty late versions of these programs.

Well, what seems to be the problem is during a server *reboot*
1. authdaemond boots up, using an rc.d script (FreeBSD's autoexec files)
2. I think this is before mysql is loaded.
3. auth requests come in to the IMAP server almost immediately.
4. ALL AUTHs FAIL until I do the following.

When I get to the root shell a few hours later, I can get AUTHs working by restarting the daemons (I frantically restart imap, authdaemond, and mysql). But, by the way, the authdaemond script is broken, and I have to stop and start it (typing /usr/local/etc/rc.d/courier-authdaemond.sh restart only stops the daemon).

At this stage, all AUTHs now work! Yeah! But what is going on? During the AUTH failures, nobody can login, and everyone has to retype their mail passwords (Mozilla, for example, resets the IMAP password)

Here is what mysql logs said. Notice, it appears that mysql started *AFTER* the first AUTH attempt.

050601 02:28:45  mysqld started
050601  2:28:49  InnoDB: Started; log sequence number 0 43740
/usr/local/libexec/mysqld: ready for connections.
Version: '4.1.11' socket: '/tmp/mysql.sock' port: 3306 FreeBSD port: mysql-server-4.1.11_1

Here is my mail and debug log. I tried to put in spaces just to show different user login attempts.

Jun  1 02:28:40 ibm authdaemond: modules="authvchkpw", daemons=5
Jun  1 02:28:40 ibm authdaemond: Installing libauthvchkpw
Jun  1 02:28:40 ibm authdaemond: Installation complete: authvchkpw
Jun  1 02:28:41 ibm imapd: Connection, ip=[192.168.0.11]
Jun 1 02:28:41 ibm authdaemond: received auth request, service=imap, authtype=login
Jun  1 02:28:41 ibm authdaemond: authvchkpw: trying this module
Jun  1 02:28:41 ibm authdaemond: vchkpw: user does not exist
Jun  1 02:28:41 ibm authdaemond: authvchkpw: REJECT - try next module
Jun  1 02:28:41 ibm authdaemond: FAIL, all modules rejected
Jun  1 02:28:41 ibm imapd: LOGIN FAILED, user=test, ip=[192.168.0.11]


Jun  1 02:28:42 ibm pop3d: Connection, ip=[192.168.0.18]
Jun 1 02:28:42 ibm authdaemond: received auth request, service=pop3, authtype=login
Jun  1 02:28:42 ibm authdaemond: authvchkpw: trying this module
Jun  1 02:28:42 ibm authdaemond: vchkpw: user does not exist
Jun  1 02:28:42 ibm authdaemond: authvchkpw: REJECT - try next module
Jun  1 02:28:42 ibm authdaemond: FAIL, all modules rejected
Jun  1 02:28:42 ibm pop3d: LOGIN FAILED, user=tester, ip=[192.168.0.18]

Jun  1 02:28:44 ibm pop3d: Connection, ip=[192.168.0.17]
Jun 1 02:28:44 ibm authdaemond: received auth request, service=pop3, authtype=login
Jun  1 02:28:44 ibm authdaemond: authvchkpw: trying this module
Jun  1 02:28:44 ibm authdaemond: vchkpw: user does not exist
Jun  1 02:28:44 ibm authdaemond: authvchkpw: REJECT - try next module
Jun  1 02:28:44 ibm authdaemond: FAIL, all modules rejected
Jun  1 02:28:44 ibm pop3d: LOGIN FAILED, user=ppp, ip=[192.168.0.17]

Jun  1 02:28:44 ibm imapd: Connection, ip=[127.0.0.1]
Jun  1 02:28:44 ibm imapd: LOGOUT, ip=[127.0.0.1]

Jun  1 02:28:45 ibm pop3d: Connection, ip=[192.168.0.9]
Jun 1 02:28:45 ibm authdaemond: received auth request, service=pop3, authtype=login
Jun  1 02:28:45 ibm authdaemond: authvchkpw: trying this module
Jun  1 02:28:45 ibm authdaemond: vchkpw: user does not exist
Jun  1 02:28:45 ibm authdaemond: authvchkpw: REJECT - try next module
Jun  1 02:28:45 ibm authdaemond: FAIL, all modules rejected
Jun  1 02:28:45 ibm pop3d: LOGIN FAILED, user=gggg, ip=[192.168.0.9]

Jun  1 02:28:46 ibm imapd: Disconnected, ip=[192.168.0.11], time=5

Jun  1 02:28:46 ibm pop3d: Connection, ip=[192.168.0.6]
Jun 1 02:28:46 ibm authdaemond: received auth request, service=pop3, authtype=login
Jun  1 02:28:46 ibm authdaemond: authvchkpw: trying this module
Jun  1 02:28:46 ibm authdaemond: vchkpw: user does not exist
Jun  1 02:28:46 ibm authdaemond: authvchkpw: REJECT - try next module
Jun  1 02:28:46 ibm authdaemond: FAIL, all modules rejected
Jun 1 02:28:46 ibm authdaemond: vmysql: sql error[3]: MySQL server has gone away
Jun  1 02:28:46 ibm pop3d: LOGIN FAILED, user=jjj, ip=[192.168.0.6]

Jun  1 02:28:47 ibm pop3d: Disconnected, ip=[192.168.0.18]
Jun  1 02:28:49 ibm pop3d: Disconnected, ip=[192.168.0.17]
Jun  1 02:28:50 ibm pop3d: Disconnected, ip=[192.168.0.9]

Jun  1 02:28:51 ibm pop3d: Connection, ip=[192.168.0.21]
Jun 1 02:28:51 ibm authdaemond: received auth request, service=pop3, authtype=login
Jun  1 02:28:51 ibm authdaemond: authvchkpw: trying this module
Jun 1 02:28:51 ibm authdaemond: authvchkpw: sysusername=<null>, sysuserid=89, sysgroupid=89, homedir=/usr/local/vpopmail/domains/aaa.com/ccc, [EMAIL PROTECTED], fullname=ccc, maildir=<null>, quota=<null>, options=disablewebmail=0,disablepop3=0,disableimap=0
Jun  1 02:28:51 ibm authdaemond: password matches successfully
Jun 1 02:28:51 ibm authdaemond: Authenticated: sysusername=<null>, sysuserid=89, sysgroupid=89, homedir=/usr/local/vpopmail/domains/aaa.com/ccc, [EMAIL PROTECTED], fullname=CCC CCC, maildir=<null>, quota=<null>, options=disablewebmail=0,disablepop3=0,disableimap=0
Jun  1 02:28:51 ibm pop3d: LOGIN, [EMAIL PROTECTED], ip=[192.168.0.21]
Jun 1 02:28:51 ibm pop3d: LOGOUT, [EMAIL PROTECTED], ip=[192.168.0.21], top=0,
Jun  1 02:28:51 ibm pop3d: Disconnected, ip=[192.168.0.6]

Jun  1 02:28:53 ibm imapd: Connection, ip=[192.168.0.18]
Jun 1 02:28:53 ibm authdaemond: received auth request, service=imap, authtype=login
Jun  1 02:28:53 ibm authdaemond: authvchkpw: trying this module
Jun  1 02:28:53 ibm authdaemond: vchkpw: user does not exist
Jun  1 02:28:53 ibm authdaemond: authvchkpw: REJECT - try next module
Jun  1 02:28:53 ibm authdaemond: FAIL, all modules rejected
Jun 1 02:28:53 ibm authdaemond: vmysql: sql error[3]: MySQL server has gone away
Jun  1 02:28:53 ibm imapd: LOGIN FAILED, user=jee, ip=[192.168.0.18]

Jun  1 02:28:53 ibm imapd: Connection, ip=[192.168.0.6]
Jun 1 02:28:53 ibm authdaemond: received auth request, service=imap, authtype=login
Jun  1 02:28:53 ibm authdaemond: authvchkpw: trying this module
Jun  1 02:28:53 ibm authdaemond: vchkpw: user does not exist
Jun  1 02:28:53 ibm authdaemond: authvchkpw: REJECT - try next module
Jun  1 02:28:53 ibm authdaemond: FAIL, all modules rejected
Jun 1 02:28:53 ibm authdaemond: vmysql: sql error[3]: MySQL server has gone away
Jun  1 02:28:53 ibm imapd: LOGIN FAILED, user=jjj, ip=[192.168.0.6]

Jun  1 02:28:53 ibm imapd: Connection, ip=[192.168.0.6]
Jun 1 02:28:53 ibm authdaemond: received auth request, service=imap, authtype=login
Jun  1 02:28:53 ibm authdaemond: authvchkpw: trying this module
Jun  1 02:28:53 ibm authdaemond: vchkpw: user does not exist
Jun  1 02:28:53 ibm authdaemond: authvchkpw: REJECT - try next module
Jun  1 02:28:53 ibm authdaemond: FAIL, all modules rejected
Jun 1 02:28:53 ibm authdaemond: vmysql: sql error[3]: MySQL server has gone away
Jun  1 02:28:53 ibm imapd: LOGIN FAILED, user=c11, ip=[192.1068.0.6]
Jun 1 02:28:53 ibm authdaemond: vmysql: sql error[3]: MySQL server has gone away

Thanks for your help,
Billy

Reply via email to