[Dovecot] POP3 auth failures

Wed Oct 29 17:02:15 EET 2008

-----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 <shhhh!
Don't tell anyone.> and then the POP server
(user at mail.engr.colostate.edu) said: ERR Authentication failed.

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 at 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-----