[Dovecot] Inactivity, Thunderbird -> bad password

[Peter Veerman]

On Sun, 2006-11-19 at 19:30 +0100, Peter Veerman wrote:
>> Nov 19 17:32:10 Info: imap-login: Disconnected: Inactivity:
>> rip=88.211.149.123, lip=62.45.54.4, TLS
>>     
>
> So at least the TLS handshake gets finished.
>
>   
>> Nov 19 17:32:13 Info: IMAP(userA at domain): Disconnected in IDLE
>> Nov 19 17:32:13 Info: IMAP(userC at domain): Disconnected in IDLE
>> Nov 19 17:32:13 Info: IMAP(userB at domain): Disconnected in IDLE
>> Nov 19 17:32:13 Info: IMAP(userD at domain): Disconnected in IDLE
>> Nov 19 17:32:13 Info: IMAP(userE at domain): Disconnected
>> Nov 19 17:32:13 Info: IMAP(userD at domain): Disconnected in IDLE
>> Nov 19 17:32:13 Info: IMAP(userF at domain): Disconnected
>> Nov 19 17:32:13 Info: IMAP(userF at domain): Disconnected in IDLE
>> Nov 19 17:32:13 Info: IMAP(userA at domain): Disconnected in IDLE
>> Nov 19 17:32:13 Info: IMAP(userB at domain): Disconnected in IDLE
>>
>> But after these problems the next line is also in my logs when after
>> these messages another user tries to authenticate:
>> Nov 19 17:35:09 Info: auth-worker(default): mysql: Connected to
>> localhost (postfix)
>>
>> Could it be that the mysql username-password backend times out and takes
>> it time to reconnect to mysql and in the meantime an account gets the
>> "you have got a wrong password" response?
>>     
>
> Maybe.. Set auth_debug=yes and see what happens around the time it logs
> inactivity?
>   
auth_debug=yes was already in my logfiles and i didn't see any suspicious other than the mysql: Connected to
localhost (postfix) that related to the mysql database.. though

After a very long period of inactivity (me watching television) my /messages logfile reported the following errors:

Nov 21 22:41:03 bubbles kernel: pid 90306 (imap), uid 125: exited on signal 6
Nov 21 22:41:03 bubbles kernel: pid 90302 (imap), uid 125: exited on signal 6
Nov 21 22:41:03 bubbles kernel: pid 95719 (imap), uid 125: exited on signal 6
Nov 21 22:41:03 bubbles kernel: pid 90308 (imap), uid 125: exited on signal 6
Nov 21 22:41:03 bubbles kernel: pid 90299 (imap), uid 125: exited on signal 6
Nov 21 22:41:03 bubbles kernel: pid 90301 (imap), uid 125: exited on signal 6
Nov 21 22:41:04 bubbles kernel: pid 93803 (imap), uid 125: exited on signal 6
Nov 21 22:51:03 bubbles kernel: pid 95917 (imap), uid 125: exited on signal 6
Nov 21 22:51:06 bubbles kernel: pid 93685 (imap), uid 125: exited on signal 6


but and my dovecot reports:

Nov 21 22:41:00 Info: imap-login: Disconnected: Inactivity: rip=x.x.149.123, lip=x.x.54.4, TLS
Nov 21 22:41:01 Info: imap-login: Disconnected: Inactivity: rip=x.x.149.123, lip=x.x.54.4, TLS
Nov 21 22:41:03 Info: IMAP(user at domain): Disconnected in IDLE
Nov 21 22:41:03 Info: IMAP(user at domain): Disconnected
Nov 21 22:41:03 Info: IMAP(user at domain): Disconnected
Nov 21 22:41:03 Info: IMAP(user at domain): Disconnected in IDLE
Nov 21 22:41:03 Info: IMAP(user at domain): Disconnected in IDLE
Nov 21 22:41:03 Info: IMAP(user at domain): Disconnected in IDLE
Nov 21 22:41:03 Info: IMAP(user at domain): Disconnected in IDLE
Nov 21 22:41:03 Info: IMAP(user at domain): Disconnected in IDLE
Nov 21 22:41:04 Info: IMAP(user at domain): Disconnected in IDLE
Nov 21 22:41:20 Info: auth-worker(default): mysql: Connected to localhost (postfix)


So something that is not shown in logs is not going that well.

grtz
Peter