auth: Error - Request timed out

[Aki Tuomi]

On 29.05.2018 09:54, Hajo Locke wrote:
> Hello List,
>
> i use dovecot 2.2.22 and have the same problem described here:
> https://dovecot.org/pipermail/dovecot/2017-November/110020.html
>
> I can confirm that sometimes there is a problem with connection to
> mysql-db, but sometimes not.
> Reasons for failing are still under investigation by my mates.
>
> My current main problem is, that this fail seems to be a one way
> ticket for dovecot. Even if mysql is verifyable working again and
> waiting for connection dovecot stucks furthermore with errors like this:
>
> May 29 07:00:49 hostname dovecot: auth: Error:
> plain(mail at example.com,xxx.xxx.xx.xxx,<HGI4FVFt2Oy80j3P>): Request
> 999.7 timed out after 150 secs, state=1
>
> When restarting dovecot all is immediately working again.
> Is there a way to tell dovecot to restart auth services or
> reinitialize mysql-connection after these hard fails? I could insert
> "idle_kill = 1 mins" into service auth and service auth-worker, but i
> dont know if this would work. Unfortunately i am not able to reproduce
> this error and there are always a couple of days between errors.
>
> Thanks,
> Hajo
>
>

Hi!

I was not able to repeat this problem using 2.2.36. Can you provide
steps to reproduce?

May 29 10:20:24 auth: Debug: client in: AUTH    1    PLAIN   
service=imap    secured    session=XtpgEVNtQeUAAAAAAAAAAAAAAAAAAAAB   
lip=::1    rip=::1    lport=143    rport=58689    resp=<hidden>
May 29 10:20:24 auth-worker(31098): Debug:
sql(test at domain.org,::1,<XtpgEVNtQeUAAAAAAAAAAAAAAAAAAAAB>): query:
SELECT userid AS username, domain, password FROM users WHERE userid =
'test' AND domain = 'domain.org'
May 29 10:20:54 auth-worker(31098): Warning: mysql: Query failed,
retrying: Lost connection to MySQL server during query (idled for 28 secs)
May 29 10:20:59 auth-worker(31098): Error: mysql(127.0.0.1): Connect
failed to database (dovecot): Can't connect to MySQL server on
'127.0.0.1' (4) - waiting for 5 seconds before retry
May 29 10:21:04 auth-worker(31098): Error: mysql(127.0.0.1): Connect
failed to database (dovecot): Can't connect to MySQL server on
'127.0.0.1' (4) - waiting for 5 seconds before retry
May 29 10:21:14 auth: Debug: auth client connected (pid=31134)
May 29 10:21:14 imap-login: Warning: Growing pool 'imap login commands'
with: 1024
May 29 10:21:14 auth-worker(31098): Error: mysql(127.0.0.1): Connect
failed to database (dovecot): Can't connect to MySQL server on
'127.0.0.1' (4) - waiting for 25 seconds before retry

This is what it looks like for me and after restoring connectivity, it
started working normally.

Aki