dovecot - Aug 2010 - Panic, rawtrace, log, etc

While running some doveadm expunge -A mailbox Spam savedbefore 30d and
doveadm purge -A after

2010-08-26 16:20:51 auth: Error: net_accept() failed: Too many open files
2010-08-26 16:20:51 master: Warning: service(auth): process_limit
reached, client connections are being dropped
2010-08-26 16:21:21 auth: Panic: file auth-request-handler.c: line 85
(auth_request_handler_unref): assertion failed:
(hash_table_count(handler->requests) == 0)
2010-08-26 16:21:21 auth: Error: Raw backtrace:
/usr/local/lib/dovecot/libdovecot.so.0(+0x39c1a) [0x7fe41f5f5c1a] ->
/usr/local/lib/dovecot/libdovecot.so.0(+0x39c6a) [0x7fe41f5f5c6a] ->
/usr/local/lib/dovecot/libdovecot.so.0(i_error+0) [0x7fe41f5d3026] ->
dovecot/auth [8 wait, 0 passdb, 0 userdb]() [0x412153] -> dovecot/auth
[8 wait, 0 passdb, 0 userdb]() [0x40c3ad] -> dovecot/auth [8 wait, 0
passdb, 0 userdb](auth_client_connections_deinit+0x41) [0x40c461] ->
dovecot/auth [8 wait, 0 passdb, 0 userdb](main+0x2ea) [0x4168ca] ->
/lib/libc.so.6(__libc_start_main+0xfd) [0x7fe41e60ac4d] ->
dovecot/auth [8 wait, 0 passdb, 0 userdb]() [0x40b1f9]
2010-08-26 16:21:21 master: Error: service(auth): child 14880 killed
with signal 6 (core dumps disabled)
2010-08-26 16:21:21 auth: Error: Master requested auth for nonexistent
client 14875
2010-08-26 16:21:21 auth: Error: Master requested auth for nonexistent
client 14873
2010-08-26 16:21:21 auth: Error: Master requested auth for nonexistent
client 14873
2010-08-26 16:21:21 auth: Error: Master requested auth for client
14874 with invalid cookie
2010-08-26 16:21:21 auth: Error: Master requested auth for client
14874 with invalid cookie
2010-08-26 16:21:21 auth: Error: Master requested auth for client
14875 with invalid cookie
2010-08-26 16:21:21 auth: Error: Master requested auth for client
14876 with invalid cookie
2010-08-26 16:21:21 auth: Error: Master requested auth for client
14875 with invalid cookie

On Thu, Aug 26, 2010 at 4:35 PM, Brandon Lamb <brandonlamb at gmail.com>
wrote:
> While running some doveadm expunge -A mailbox Spam savedbefore 30d and
> doveadm purge -A after
>
> 2010-08-26 16:20:51 auth: Error: net_accept() failed: Too many open files
> 2010-08-26 16:20:51 master: Warning: service(auth): process_limit
> reached, client connections are being dropped
> 2010-08-26 16:21:21 auth: Panic: file auth-request-handler.c: line 85
> (auth_request_handler_unref): assertion failed:
> (hash_table_count(handler->requests) == 0)
> 2010-08-26 16:21:21 auth: Error: Raw backtrace:
> /usr/local/lib/dovecot/libdovecot.so.0(+0x39c1a) [0x7fe41f5f5c1a] ->
> /usr/local/lib/dovecot/libdovecot.so.0(+0x39c6a) [0x7fe41f5f5c6a] ->
> /usr/local/lib/dovecot/libdovecot.so.0(i_error+0) [0x7fe41f5d3026] ->
> dovecot/auth [8 wait, 0 passdb, 0 userdb]() [0x412153] -> dovecot/auth
> [8 wait, 0 passdb, 0 userdb]() [0x40c3ad] -> dovecot/auth [8 wait, 0
> passdb, 0 userdb](auth_client_connections_deinit+0x41) [0x40c461] ->
> dovecot/auth [8 wait, 0 passdb, 0 userdb](main+0x2ea) [0x4168ca] ->
> /lib/libc.so.6(__libc_start_main+0xfd) [0x7fe41e60ac4d] ->
> dovecot/auth [8 wait, 0 passdb, 0 userdb]() [0x40b1f9]
> 2010-08-26 16:21:21 master: Error: service(auth): child 14880 killed
> with signal 6 (core dumps disabled)
> 2010-08-26 16:21:21 auth: Error: Master requested auth for nonexistent
> client 14875
> 2010-08-26 16:21:21 auth: Error: Master requested auth for nonexistent
> client 14873
> 2010-08-26 16:21:21 auth: Error: Master requested auth for nonexistent
> client 14873
> 2010-08-26 16:21:21 auth: Error: Master requested auth for client
> 14874 with invalid cookie
> 2010-08-26 16:21:21 auth: Error: Master requested auth for client
> 14874 with invalid cookie
> 2010-08-26 16:21:21 auth: Error: Master requested auth for client
> 14875 with invalid cookie
> 2010-08-26 16:21:21 auth: Error: Master requested auth for client
> 14876 with invalid cookie
> 2010-08-26 16:21:21 auth: Error: Master requested auth for client
> 14875 with invalid cookie
And i see the process limit and stuff warnings, just reporting because
I seem to remember Timo saying any error is considered a bug, so just
in case...

Going to double my process limit from 100 to 256 and bump up the
vsz_limit and see if I can make it go away

On 27.8.2010, at 0.35, Brandon Lamb wrote:
> While running some doveadm expunge -A mailbox Spam savedbefore 30d and
> doveadm purge -A after
Hmm. Maybe it's opening a new auth connection for each user? I'll check
it out later.
> 2010-08-26 16:20:51 auth: Error: net_accept() failed: Too many open files
This should be solved somehow. I guess Dovecot doesn't warn that your file
limit is lower than the client_count (default=4096). Run ulimit -n 8192 or
something before starting Dovecot. I'll add a check for that.
> 2010-08-26 16:20:51 master: Warning: service(auth): process_limit
> reached, client connections are being dropped
This can be expected.
> 2010-08-26 16:21:21 auth: Panic: file auth-request-handler.c: line 85
> (auth_request_handler_unref): assertion failed:
> (hash_table_count(handler->requests) == 0)
Half a minute later. I guess the process was idle-killing itself.
> 2010-08-26 16:21:21 auth: Error: Master requested auth for nonexistent
> client 14875
> 2010-08-26 16:21:21 auth: Error: Master requested auth for client
> 14874 with invalid cookie
I guess this has to do with the crash and restart of auth process. I'll see
if I can reproduce and maybe avoid these somehow.