[Dovecot] Dovecot inactive after an intermittent connection with LDAP

[Thu Nguyen]

Hello all, 

I'm facing the problem below:

1. Firstly, the connection between dovecot and ldap was down.

dovecot: Oct 10 09:11:12 Info: auth(default): ldap(user1,x.x.x.x): Aborting
(timeout), we're not connected to LDAP server
dovecot: Oct 10 09:11:12 Info: auth(default): master out: USER  265490
user1

2. There is many new connection from user created....
dovecot: Oct 10 09:11:12 Info: auth(default): new auth connection: pid=21114
dovecot: Oct 10 09:11:12 Info: auth(default): new auth connection: pid=21113

3. ....but it obviously failed.

dovecot: Oct 10 09:11:12 Info: pop3-login: Internal login failure (auth
failed,1 attempts): user=<user1>, method=PLAIN, rip=x.x.x.x, lip= x.x.x.x
dovecot: Oct 10 09:11:12 Info: pop3-login: Internal login failure (auth
failed,1 attempts): user=<user2>, method=PLAIN, rip= x.x.x.x,lip= x.x.x.x
.................
dovecot: Oct 10 09:11:15 Info: auth(default): new auth connection: pid=21125
dovecot: Oct 10 09:11:15 Info: auth(default): new auth connection: pid=21126
dovecot: Oct 10 09:11:22 Info: auth(default): client in: AUTH 1 PLAIN
service=pop3    lip= x.x.x.x rip= x.x.x.x lport=110 rport=4504 resp=<hidden>
dovecot: Oct 10 09:11:22 Info: auth(default): client in: AUTH 1 PLAIN
service=pop3    lip= x.x.x.x rip= x.x.x.x lport=110 rport=6316 resp=<hidden>
dovecot: Oct 10 09:11:22 Info: auth(default): new auth connection: pid=21132
dovecot: Oct 10 09:11:24 Info: auth(default): client in: AUTH   1
PLAIN service=pop3    lip= x.x.x.x rip= x.x.x.x lport=110

4. LDAP connection is back to normal, however, it still failed.

dovecot: Oct 10 09:14:14 Info: auth(default): new auth connection: pid=21250
dovecot: Oct 10 09:14:14 Info: auth(default): new auth connection: pid=21251
dovecot: Oct 10 09:14:14 Info: auth(default): client in: AUTH 1 PLAIN
service=pop3 lip= x.x.x.x rip= x.x.x.x lport=110 rport=2959 resp=<hidden>
dovecot: Oct 10 09:14:14 Info: pop3-login: Disconnected: Inactivity (auth
failed, 1 attempts): method=PLAIN, lip= x.x.x.x rip= x.x.x.x
dovecot: Oct 10 09:14:15 Info: pop3-login: Disconnected: Inactivity (auth
failed, 1 attempts): method=PLAIN, lip= x.x.x.x rip= x.x.x.x 
dovecot: Oct 10 09:14:15 Info: pop3-login: Disconnected: Inactivity (auth
failed, 1 attempts): method=PLAIN, lip= x.x.x.x rip= x.x.x.x
dovecot: Oct 10 09:14:15 Info: auth(default): client in: AUTH   1
PLAIN service=pop3    lip= x.x.x.x rip= x.x.x.x  lport=110 rport=3765
resp=<hidden>
dovecot: Oct 10 09:14:15 Info: auth(default): client in: AUTH   1
PLAIN service=pop3    lip= x.x.x.x rip= x.x.x.x  lport=110       rport=48
08      resp=<hidden>
dovecot: Oct 10 09:14:15 Info: pop3-login: Disconnected: Inactivity (auth
failed, 1 attempts): method=PLAIN, rip=199.30.31.48, lip=199.30.26.18


5. Then the request queue is full ... Dovecot is completely inactive. Of
course it try to fail back to pam but as the password is not the same so
it's failed also.

dovecot: Oct 10 09:38:53 Error: auth(default): ldap(user1,10.0.0.7): Request
queue is full (oldest added 1660 secs ago)
dovecot: Oct 10 09:38:53 Info: auth-worker(default): pam(user1,10.0.0.7):
lookup service=dovecot
dovecot: Oct 10 09:38:53 Info: auth-worker(default): pam(user1.vn,10.0.0.7):
#1/1 style=1 msg=Password:
dovecot: Oct 10 09:38:53 Info: auth(default): new auth connection: pid=22405
dovecot: Oct 10 09:38:54 Info: auth(default): client in: AUTH   1
PLAIN service=pop3 lip= x.x.x.x rip= x.x.x.x  lport=110 rport=2789
resp=<hidden>
dovecot: Oct 10 09:38:56 Info: auth-worker(default): pam(user1,x.x.x.x):
pam_authenticate() failed: Authentication failure (password mismatch?)
----------------------------------------------------------------

Bref, I suggest that when the connection between LDAP and dovecot is
dropped, the connection from user is still there and as they don't receive a
result from dovecot [Fail or Success]... And it still "pending" somehow to
wait a response from dovecot. But when ldap is connected to the system,
these pending connection (from user) is still pending .... so it makes the
"request queue is full". Isn't it?

Should I do something to work-through or work-around this problem? May I did
something wrong in my configuration. Below is usual information may it helps
us analyze the problem!

Thanks many much for your help!

-----------------------------------------------------------------
[root ~]# dovecot -n
# 1.1.14: /etc/dovecot.conf
# OS: Linux 2.6.18-92.el5PAE i686 CentOS release 5.2 (Final) ext3
log_path: /var/log/dovecot.log
protocols: imap pop3
ssl_disable: yes
login_dir: /var/run/dovecot/login
login_executable(default): /usr/libexec/dovecot/imap-login
login_executable(imap): /usr/libexec/dovecot/imap-login
login_executable(pop3): /usr/libexec/dovecot/pop3-login
verbose_proctitle: yes
mail_gid: 100
mail_location: maildir:/home/%u/Maildir
mail_debug: yes
mail_executable(default): /usr/libexec/dovecot/imap
mail_executable(imap): /usr/libexec/dovecot/imap
mail_executable(pop3): /usr/libexec/dovecot/pop3
mail_plugin_dir(default): /usr/lib/dovecot/imap
mail_plugin_dir(imap): /usr/lib/dovecot/imap
mail_plugin_dir(pop3): /usr/lib/dovecot/pop3
auth default:
  verbose: yes
  debug: yes
  passdb:
    driver: ldap
    args: /etc/dovecot-ldap.conf
  passdb:
    driver: pam
  userdb:
    driver: ldap
    args: /etc/dovecot-ldap.conf
  userdb:
    driver: static
  socket:
    type: listen
    master:
      path: /var/run/dovecot/auth-master
      mode: 384
      user: dovecot
      group: dovecot
plugin:
  sieve: /home/%u/.dovecot.sieve
--------------------------------------------------------------------
[root ~]# grep -v '^ *\(#.*\)\?$' /etc/dovecot-ldap.conf
hosts = ldap.tma.com.vn
dn = #####
dnpass = ######
auth_bind = yes
auth_bind_userdn = uid=%u,ou=Users,dc=tma,dc=com,dc=vn
ldap_version = 3
base = ou=Users,dc=,dc=com,dc=vn
scope = subtree
user_attrs = uid=uid,mailQuota=quota_rule=*:storage=%$M
user_filter = (&(objectClass=posixAccount)(uid=%u))
pass_attrs = uid=user,userPassword=password
pass_filter = (&(objectClass=posixAccount)(uid=%u))
default_pass_scheme = CRYPT
--------------------------------------------------------------------

Regards,
Thu NGUYEN.