[Dovecot] Problems with the IMAP proxy after upgrading from dovecot 1.1.16 to 1.211
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.
On pe, 2010-05-07 at 15:35 +0200, Holger Richter wrote:
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)
"Lookup timed out" really shouldn't be happening.. That sounds like Dovecot's MySQL connections hangs after a while? You have some stateful firewall between Dovecot and MySQL that drops idling connections and afterwards starts dropping the connection's packets?
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)"Lookup timed out" really shouldn't be happening.. That sounds like Dovecot's MySQL connections hangs after a while? You have some stateful firewall between Dovecot and MySQL that drops idling connections and afterwards starts dropping the connection's packets?
Indeed, there is a firewall with stateful inspection between Dovecot
and MySQL. The only workaround is a downgrade to Dovecot 1.1.20. I
think my problem has to do with the changes in
src/auth/auth-worker-server.c in changeset 8859.
participants (2)
-
Holger Richter
-
Timo Sirainen