Hello all,
I'm facing the problem below:
- 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
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
....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
- 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
- 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.