[Dovecot] Two recent issues
I've been using dovecot for years, been working great. However recently I've come across two issues.
The first issue unfortunately I have little information on, mail_debug hasn't provided anything useful either (in fact it looks like the login request that fails doesn't even get logged at all).
During the morning rush of email, this server has around 11k mailboxes on it, it *appears* that one of the auth processes dies resulting in "dovecot: imap-login: Error: read(imap) failed: Connection reset by peer" errors followed by "dovecot: imap-login: Internal login failure ..." in the logs.
I've yet to get any useful debugging information on this error so I'm not expecting much/any help on this one, but if anyone has any ideas on how I can get more debug besides running strace 24/7 in the hopes it catches something before the hard drive is full of strace output I'd love to hear it.
The best I've gotten was a lucky strace once (at the time I didn't realize it was so lucky or I would have saved the output) that indicated the imap-login daemon was failing to connect to the auth process.
The second issue is lmtp/lda (tried both) delivery to a mailbox that has filesystem quotas enabled and the group quota is maxed is resulting in the below panic and crash.
This issue happens with 2.0.13, 2.0.15 and 2.0.16.
Here's the logs showing that it knows the disk quota is exceeded and then a subsequent zlib panic. Like it's trying to deliver it anyway.
11:21:07 [err] dovecot: lmtp(29691, admin@[redacted].com): Error: o_stream_send_istream(/email/d/r/[redacted]/[redacted]/admin/Maildir/tmp/1323458467.M245978P29691.fenrir.omnis.com) failed: Disk quota exceeded 11:21:07 [crit] dovecot: lmtp(29691, admin@[redacted].com): Panic: file ostream-zlib.c: line 144 (o_stream_zlib_send_flush): assertion failed: (zs->avail_in == 0) 11:21:07 [err] dovecot: lmtp(29691, admin@[redacted].com): Error: Raw backtrace: /usr/lib64/dovecot/libdovecot.so.0 [0x345443ca90] -> /usr/lib64/dovecot/libdovecot.so.0 [0x345443cae6] -> /usr/lib64/dovecot/libdovecot.so.0 [0x345443c4a3] -> /usr/lib64/dovecot/lib20_zlib_plugin.so [0x2ba2d31547f6] -> /usr/lib64/dovecot/lib20_zlib_plugin.so [0x2ba2d315481b] -> /usr/lib64/dovecot/libdovecot.so.0(o_stream_flush+0x2a) [0x345444f0ea] -> /usr/lib64/dovecot/libdovecot-storage.so.0(maildir_save_finish+0x6b) [0x3451c63b6b] -> /usr/lib64/dovecot/lib10_quota_plugin.so [0x2ba2d2f4ce7a] -> /usr/lib64/dovecot/libdovecot-storage.so.0(mailbox_save_finish+0x30) [0x3451c2fbb0] -> /usr/lib64/dovecot/libdovecot-storage.so.0(mail_storage_copy+0xb3) [0x3451c2aae3] -> /usr/lib64/dovecot/libdovecot-storage.so.0(maildir_copy+0x56) [0x3451c6fd36] -> /usr/lib64/dovecot/lib10_quota_plugin.so [0x2ba2d2f4d0ba] -> /usr/lib64/dovecot/libdovecot-storage.so.0(mailbox_copy+0x5a) [0x3451c301ba] -> /usr/lib64/dovecot/li 11:21:07 [err] dovecot: master: Error: service(lmtp): child 29691 killed with signal 6 (core dumps disabled)
Attached is the current "doveadm config" output.
-- Brad Schuetz
On Fri, 2011-12-09 at 12:13 -0800, Brad Schuetz wrote:
I've been using dovecot for years, been working great. However recently I've come across two issues.
The first issue unfortunately I have little information on, mail_debug hasn't provided anything useful either (in fact it looks like the login request that fails doesn't even get logged at all).
The *_debug settings aren't very helpful in debugging random failures.
During the morning rush of email, this server has around 11k mailboxes on it, it *appears* that one of the auth processes dies resulting in "dovecot: imap-login: Error: read(imap) failed: Connection reset by peer" errors followed by "dovecot: imap-login: Internal login failure ..." in the logs.
If auth process dies unexpectedly, master always logs an error, such as:
Dec 10 07:15:34 auth: Fatal: master: service(auth): child 27895 killed with signal 11 (core dumped)
Anyway, "read(imap) failed: Connection reset by peer" can happen if you reach the service imap { process_limit }. But then there should be a warning logged about it also:
Dec 10 07:17:39 master: Warning: service(imap): process_limit reached, client connections are being dropped
So, that error message alone shouldn't be happening..
The best I've gotten was a lucky strace once (at the time I didn't realize it was so lucky or I would have saved the output) that indicated the imap-login daemon was failing to connect to the auth process.
If that happens, there would also be an error message logged about it. One thing that v2.0 doesn't log about is if auth socket gets disconnected, but that would result in different problems. v2.1 logs about that too.
The second issue is lmtp/lda (tried both) delivery to a mailbox that has filesystem quotas enabled and the group quota is maxed is resulting in the below panic and crash.
11:21:07 [err] dovecot: lmtp(29691, admin@[redacted].com): Error: o_stream_send_istream(/email/d/r/[redacted]/[redacted]/admin/Maildir/tmp/1323458467.M245978P29691.fenrir.omnis.com) failed: Disk quota exceeded 11:21:07 [crit] dovecot: lmtp(29691, admin@[redacted].com): Panic: file ostream-zlib.c: line 144 (o_stream_zlib_send_flush): assertion failed: (zs->avail_in == 0)
I couldn't reproduce this with my tests, but http://hg.dovecot.org/dovecot-2.0/rev/75daa638281b should fix it.
On 12/09/2011 09:58 PM, Timo Sirainen wrote:
If auth process dies unexpectedly, master always logs an error, such as:
Dec 10 07:15:34 auth: Fatal: master: service(auth): child 27895 killed with signal 11 (core dumped)
Anyway, "read(imap) failed: Connection reset by peer" can happen if you reach the service imap { process_limit }. But then there should be a warning logged about it also:
Dec 10 07:17:39 master: Warning: service(imap): process_limit reached, client connections are being dropped
So, that error message alone shouldn't be happening..
Interesting, the log entries I provided were the only ones that did exist.
If that happens, there would also be an error message logged about it. One thing that v2.0 doesn't log about is if auth socket gets disconnected, but that would result in different problems. v2.1 logs about that too.
The problem has vanished in the last couple of days. When 2.1 comes out I will upgrade and if the problem returns I'll see if it's logs have any further information.
The second issue is lmtp/lda (tried both) delivery to a mailbox that has filesystem quotas enabled and the group quota is maxed is resulting in the below panic and crash.
11:21:07 [err] dovecot: lmtp(29691, admin@[redacted].com): Error: o_stream_send_istream(/email/d/r/[redacted]/[redacted]/admin/Maildir/tmp/1323458467.M245978P29691.fenrir.omnis.com) failed: Disk quota exceeded 11:21:07 [crit] dovecot: lmtp(29691, admin@[redacted].com): Panic: file ostream-zlib.c: line 144 (o_stream_zlib_send_flush): assertion failed: (zs->avail_in == 0)
I couldn't reproduce this with my tests, but http://hg.dovecot.org/dovecot-2.0/rev/75daa638281b should fix it.
This patch has corrected the issue I was seeing. Thank you very much.
participants (2)
-
Brad Schuetz
-
Timo Sirainen