[Dovecot] POP3 auth failures
-----BEGIN PGP SIGNED MESSAGE----- Hash: SHA1
Have a strange problem with just POP3 users. Their email clients will fail every so often with the following:
Logging into POP Server, PASS [09:16:29 PM]
There has been an error transferring your mail. I said PASS
This example is from a Eudora client, but same things happen with Thunderbird and Outlook.
Here are logs. This user has his client checking every 10 minutes. First log entry here is last good one before it fails:
Oct 28 21:06:27 goku dovecot: [ID 107833 mail.info] auth(default): client in: AUTH 1 PLAIN service=pop3 secured lip=129.82.224.16 rip=129.82.224.206 lport=110 rport=3716 resp=<hidden>Oct 28 21:06:27 goku dovecot: [ID 107833 mail.info] auth-worker(default): pam(us er,129.82.224.206): lookup service=dovecotOct 28 21:06:27 goku dovecot: [ID 107833 mail.info] auth-worker(default): pam(us er,129.82.224.206): #1/1 style=1 msg=Password:Oct 28 21:06:27 goku dovecot: [ID 107833 mail.info] auth(default): client out: O K 1 user=user Oct 28 21:06:27 goku dovecot: [ID 107833 mail.info] auth(default): master in: REQUEST 387983 2809 1 Oct 28 21:06:27 goku dovecot: [ID 107833 mail.info] auth-worker(default): passwd(user,129.82.224.206): lookup Oct 28 21:06:27 goku dovecot: [ID 107833 mail.info] auth(default): master out: USER 387983 user system_user=user uid=12550 gid=32 home=/to p/admin/ENS/people/user/home Oct 28 21:06:27 goku dovecot: [ID 107833 mail.info] pop3-login: Login: user=<use r>, method=PLAIN, rip=129.82.224.206, lip=129.82.224.16, TLS Oct 28 21:06:27 goku dovecot: [ID 107833 mail.info] POP3(user): Effective uid=12 550, gid=32
Everything went fine here, then the next auth attempt fails:
Oct 28 21:16:27 goku dovecot: [ID 107833 mail.info] auth(default): client in: AUTH 1 PLAIN service=pop3 secured lip=129.82.224.16 rip=129.82.224.206 lport=110 rport=3757 resp=<hidden>Oct 28 21:16:27 goku dovecot: [ID 107833 mail.info] auth-worker(default): pam(user,129.82.224.206): lookup service=dovecotOct 28 21:16:27 goku dovecot: [ID 107833 mail.info] auth-worker(default): pam(user,129.82.224.206): #1/1 style=1 msg=Password:Oct 28 21:16:27 goku dovecot: [ID 107833 mail.error] auth-worker(default): pam(user,129.82.224.206): pam_authenticate() failed: No account present for user Oct 28 21:16:27 goku dovecot: [ID 107833 mail.info] auth-worker(default): passwd(user,129.82.224.206): lookup Oct 28 21:16:27 goku dovecot: [ID 107833 mail.info] auth-worker(default): passwd(user,129.82.224.206): Password mismatch
Running dovecot 1.1.3 on Solaris 10
goku % ./dovecot -n # 1.1.3: /userM/mail-services/dovecot/etc/dovecot.conf Warning: fd limit 256 is lower than what Dovecot can use under full load (more than 3072). Either grow the limit or change login_max_processes_count and max_mail_processes settings base_dir: /userM/mail-services/dovecot/var/run/dovecot/ protocols: imap imaps pop3 pop3s ssl_cert_file: /userM/mail-services/dovecot/etc/ssl/dovecot.pem ssl_key_file: /userM/mail-services/dovecot/etc/ssl/privkey.pem ssl_parameters_regenerate: 0 ssl_cipher_list: MEDIUM:!LOW disable_plaintext_auth: no login_dir: /userM/mail-services/dovecot/var/run/dovecot/login login_executable(default): /userM/mail-services/dovecot/libexec/dovecot/imap-login login_executable(imap): /userM/mail-services/dovecot/libexec/dovecot/imap-login login_executable(pop3): /userM/mail-services/dovecot/libexec/dovecot/pop3-login login_greeting: Cyrus ready. login_max_processes_count: 1024 max_mail_processes: 1024 mail_location: mbox:~/:INBOX=/userM/mail/%u mail_debug: yes mmap_disable: yes mail_nfs_index: yes mbox_write_locks: fcntl dotlock mbox_dotlock_change_timeout: 60 mail_executable(default): /userM/mail-services/dovecot/libexec/dovecot/imap mail_executable(imap): /userM/mail-services/dovecot/libexec/dovecot/imap mail_executable(pop3): /userM/mail-services/dovecot/libexec/dovecot/pop3 mail_plugins(default): convert mail_plugins(imap): convert mail_plugins(pop3): mail_plugin_dir(default): /userM/mail-services/dovecot/lib/dovecot/imap mail_plugin_dir(imap): /userM/mail-services/dovecot/lib/dovecot/imap mail_plugin_dir(pop3): /userM/mail-services/dovecot/lib/dovecot/pop3 auth default: mechanisms: plain login verbose: yes debug: yes worker_max_count: 1024 worker_max_request_count: 20000 passdb: driver: pam passdb: driver: passwd args: blocking=yes userdb: driver: passwd args: blocking=yes socket: type: listen client: path: /var/lib/postfix/private/auth mode: 438 user: postfix group: postfix master: path: /userM/mail-services/dovecot/var/run/dovecot//auth-master mode: 384 plugin: convert_mail: Maildir:~/Maildir:INBOX=/userM/mail/%u
C. J. Keist Email: cj.keist@colostate.edu UNIX/Network Manager Phone: 970-491-0630 Engineering Network Services Fax: 970-491-5569 College of Engineering, CSU Ft. Collins, CO 80523-1301
All I want is a chance to prove 'Money can't buy happiness' -----BEGIN PGP SIGNATURE----- Version: GnuPG v1.4.5 (Darwin) Comment: Using GnuPG with Mozilla - http://enigmail.mozdev.org
iD8DBQFJCHr3A29OFr7C6jcRAsBrAJ4h5f0naC1N4VHIlz4Z9rTWucicNACgxCJx 4lF8xzzBITsoboppIZD37n8= =TIUR -----END PGP SIGNATURE-----
On Wed, 2008-10-29 at 09:02 -0600, CJ Keist wrote:
Have a strange problem with just POP3 users. Their email clients will fail every so often with the following: .. auth-worker(default): pam(user,129.82.224.206): pam_authenticate() failed: No account present for user
So PAM thinks it doesn't exist. The only solution to issues with PAM that I can think of is to decrease how many lookups it can do before restarting the process:
worker_max_request_count: 20000
Try e.g. a value of 1000 to see if that happens to fix it.
participants (2)
-
CJ Keist
-
Timo Sirainen