We have frequent timeout problems after upgrading our imap servers
from dovecot 1.1.16 to dovecot 1.2.11. One server acts as proxy only,
and the other one is the "real" imap server". The credentials for the
proxy service are stored in a remote MYSQL database.
There were no trouble with dovecot 1.1.16. But now, with the most
recent version, we get frequent login failures. It seems dovecot
reconnects too late to the MySQL database after a timeout, after
sending the SQL query. Here's a piece of my log file:
May 7 14:46:32 ttt dovecot: auth(default): new auth connection: pid=5136
May 7 14:46:42 ttt dovecot: auth(default): client in:
AUTH^I1^IPLAIN^Iservice=imap^Isecured^Ilip=xxx.xxx.xxx.xxx^Irip=yyy.yyy.yyy.yyy^Ilport=sss^Irport=26480^Iresp=<hidden>
May 7 14:46:42 ttt dovecot: auth-worker(default):
sql(uid,yyy.yyy.yyy.yyy): query: SELECT NULL as password, destuser,
host, 'zzz' as port, 'Y' as proxy, '0' as proxy_timeout, 'Y' as
nopassword, 'Y' as nodelay from accounts where user ='uid';
May 7 14:47:42 ttt dovecot: auth(default):
worker-server(uid,yyy.yyy.yyy.yyy): Aborted: Lookup timed out
May 7 14:47:42 ttt dovecot: auth-worker(default): mysql: Connected to
lll.lll.lll.lll (imapauth)
May 7 14:47:44 ttt dovecot: auth(default): client out:
FAIL^I1^Iuser=uid^Itemp
May 7 14:47:49 ttt dovecot: imap-login: Disconnected (auth failed, 1
attempts): user=<uid>, method=PLAIN, rip=yyy.yyy.yyy.yyy,
lip=xxx.xxx.xxx.xxx, TLS
May 7 14:48:26 ttt dovecot: auth(default): new auth connection: pid=5159
May 7 14:48:47 ttt dovecot: auth(default): client in:
AUTH^I1^IPLAIN^Iservice=imap^Isecured^Ilip=xxx.xxx.xxx.xxx^Irip=yyy.yyy.yyy.yyy^Ilport=sss^Irport=6243^Iresp=<hidden>
May 7 14:48:47 ttt dovecot: auth-worker(default):
sql(uid,yyy.yyy.yyy.yyy): query: SELECT NULL as password, destuser,
host, 'zzz' as port, 'Y' as proxy, '0' as proxy_timeout, 'Y' as
nopassword, 'Y' as nodelay from accounts where user ='uid';
May 7 14:48:47 ttt dovecot: auth(default): client out:
OK^I1^Iuser=uid^Idestuser=luid^Ihost=mmm.mmm.mmm.mmm^Iport=zzz^Iproxy^Iproxy_timeout=0^Ipass=<hidden>
May 7 14:48:47 ttt dovecot: imap-login: proxy(uid): started proxying
to mmm.mmm.mmm.mmm:zzz/luid: user=<uid>, method=PLAIN,
rip=yyy.yyy.yyy.yyy, lip=xxx.xxx.xxx.xxx, TLS
May 7 14:48:48 ttt dovecot: imap-login: proxy(uid): disconnecting
yyy.yyy.yyy.yyy
As you can see, the second login attempt is always successful. Of
course I've tried out various values (0, 60, 90, 300) for the
proxy_timeout parameter - but without any success.