dovecot - Jan 2016 - [BUG] 2.2.21 Panic: file imap-client.c: line 841 (client_check_command_hangs): assertion failed: (!have_wait_unfinished || unfinished_count > 0)

Hi,

I'm seeing the following in my logs. Twice so far, no idea what caused
it. I do however have the core dump if that is of any use.
> Jan  4 11:14:11 karif dovecot[20876]: imap(username): Panic: file
imap-client.c: line 841 (client_check_command_hangs): assertion failed:
(!have_wait_unfinished || unfinished_count > 0)
> Jan  4 11:14:11 karif dovecot[20876]: imap(username): Error: Raw backtrace:
/usr/lib/dovecot/libdovecot.so.0(+0xa64ea) [0x7f6f99fa64ea] ->
/usr/lib/dovecot/libdovecot.so.0(+0xa7a18) [0x7f6f99fa7a18] ->
/usr/lib/dovecot/libdovecot.so.0(i_
> fatal+0) [0x7f6f99fa686d] -> dovecot/imap() [0x41dde6] ->
dovecot/imap(client_continue_pending_input+0xd6) [0x41df50] -> dovecot/imap()
[0x4122a9] -> /usr/lib/dovecot/libdovecot.so.0(io_loop_call_io+0xcd)
[0x7f6f99fc3b01] -> /usr/lib/dovec
> ot/libdovecot.so.0(io_loop_handler_run_internal+0x209) [0x7f6f99fc606e]
-> /usr/lib/dovecot/libdovecot.so.0(io_loop_handler_run+0x24)
[0x7f6f99fc3caa] -> /usr/lib/dovecot/libdovecot.so.0(io_loop_run+0xaf)
[0x7f6f99fc3bf6] -> /usr/lib/dovec
> ot/libdovecot.so.0(master_service_run+0x2e) [0x7f6f99f317af] ->
dovecot/imap(main+0x2da) [0x430da2] ->
/usr/lib/libc.so.6(__libc_start_main+0xf0) [0x7f6f99b7c610] ->
dovecot/imap(_start+0x29) [0x40c639]
> Jan  4 11:14:11 karif dovecot[20876]: imap(username): Fatal: master:
service(imap): child 19463 killed with signal 6 (core dumped)
In case it is easier to read, here's a gdb backtrace:
> #0  0x00007f6f99b8f5f8 in raise () from /usr/lib/libc.so.6
> #1  0x00007f6f99b90a7a in abort () from /usr/lib/libc.so.6
> #2  0x00007f6f99fa6539 in default_fatal_finish (type=LOG_TYPE_PANIC,
status=0) at failures.c:201
> #3  0x00007f6f99fa7a18 in i_internal_fatal_handler (ctx=0x7ffe660d4700,
format=0x438a60 "file %s: line %d (%s): assertion failed: (%s)",
args=0x7ffe660d4720) at failures.c:670
> #4  0x00007f6f99fa686d in i_panic (format=0x438a60 "file %s: line %d
(%s): assertion failed: (%s)") at failures.c:275
> #5  0x000000000041dde6 in client_check_command_hangs (client=0x2363450) at
imap-client.c:841
> #6  0x000000000041df50 in client_continue_pending_input (client=0x2363450)
at imap-client.c:884
> #7  0x00000000004122a9 in idle_client_input (ctx=0x23642a8) at
cmd-idle.c:111
> #8  0x00007f6f99fc3b01 in io_loop_call_io (io=0x2374600) at ioloop.c:559
> #9  0x00007f6f99fc606e in io_loop_handler_run_internal (ioloop=0x232c740)
at ioloop-epoll.c:220
> #10 0x00007f6f99fc3caa in io_loop_handler_run (ioloop=0x232c740) at
ioloop.c:607
> #11 0x00007f6f99fc3bf6 in io_loop_run (ioloop=0x232c740) at ioloop.c:583
> #12 0x00007f6f99f317af in master_service_run (service=0x232c5e0,
callback=0x430a35 <client_connected>) at master-service.c:640
> #13 0x0000000000430da2 in main (argc=1, argv=0x232c390) at main.c:442
Florian

-------------- next part --------------
A non-text attachment was scrubbed...
Name: signature.asc
Type: application/pgp-signature
Size: 801 bytes
Desc: OpenPGP digital signature
URL:
<http://dovecot.org/pipermail/dovecot/attachments/20160104/25bc521c/attachment-0001.sig>

On 04.01.2016 12:28, Florian Pritz wrote:
> Hi,
> 
> I'm seeing the following in my logs. Twice so far, no idea what caused
> it. I do however have the core dump if that is of any use.
> 
>> Jan  4 11:14:11 karif dovecot[20876]: imap(username): Panic: file
imap-client.c: line 841 (client_check_command_hangs): assertion failed:
(!have_wait_unfinished || unfinished_count > 0)
>> Jan  4 11:14:11 karif dovecot[20876]: imap(username): Error: Raw
backtrace: /usr/lib/dovecot/libdovecot.so.0(+0xa64ea) [0x7f6f99fa64ea] ->
/usr/lib/dovecot/libdovecot.so.0(+0xa7a18) [0x7f6f99fa7a18] ->
/usr/lib/dovecot/libdovecot.so.0(i_
>> fatal+0) [0x7f6f99fa686d] -> dovecot/imap() [0x41dde6] ->
dovecot/imap(client_continue_pending_input+0xd6) [0x41df50] -> dovecot/imap()
[0x4122a9] -> /usr/lib/dovecot/libdovecot.so.0(io_loop_call_io+0xcd)
[0x7f6f99fc3b01] -> /usr/lib/dovec
>> ot/libdovecot.so.0(io_loop_handler_run_internal+0x209) [0x7f6f99fc606e]
-> /usr/lib/dovecot/libdovecot.so.0(io_loop_handler_run+0x24)
[0x7f6f99fc3caa] -> /usr/lib/dovecot/libdovecot.so.0(io_loop_run+0xaf)
[0x7f6f99fc3bf6] -> /usr/lib/dovec
>> ot/libdovecot.so.0(master_service_run+0x2e) [0x7f6f99f317af] ->
dovecot/imap(main+0x2da) [0x430da2] ->
/usr/lib/libc.so.6(__libc_start_main+0xf0) [0x7f6f99b7c610] ->
dovecot/imap(_start+0x29) [0x40c639]
>> Jan  4 11:14:11 karif dovecot[20876]: imap(username): Fatal: master:
service(imap): child 19463 killed with signal 6 (core dumped)
> 
> In case it is easier to read, here's a gdb backtrace:
> 
>> #0  0x00007f6f99b8f5f8 in raise () from /usr/lib/libc.so.6
>> #1  0x00007f6f99b90a7a in abort () from /usr/lib/libc.so.6
>> #2  0x00007f6f99fa6539 in default_fatal_finish (type=LOG_TYPE_PANIC,
status=0) at failures.c:201
>> #3  0x00007f6f99fa7a18 in i_internal_fatal_handler (ctx=0x7ffe660d4700,
format=0x438a60 "file %s: line %d (%s): assertion failed: (%s)",
args=0x7ffe660d4720) at failures.c:670
>> #4  0x00007f6f99fa686d in i_panic (format=0x438a60 "file %s: line
%d (%s): assertion failed: (%s)") at failures.c:275
>> #5  0x000000000041dde6 in client_check_command_hangs (client=0x2363450)
at imap-client.c:841
>> #6  0x000000000041df50 in client_continue_pending_input
(client=0x2363450) at imap-client.c:884
>> #7  0x00000000004122a9 in idle_client_input (ctx=0x23642a8) at
cmd-idle.c:111
>> #8  0x00007f6f99fc3b01 in io_loop_call_io (io=0x2374600) at
ioloop.c:559
>> #9  0x00007f6f99fc606e in io_loop_handler_run_internal
(ioloop=0x232c740) at ioloop-epoll.c:220
>> #10 0x00007f6f99fc3caa in io_loop_handler_run (ioloop=0x232c740) at
ioloop.c:607
>> #11 0x00007f6f99fc3bf6 in io_loop_run (ioloop=0x232c740) at
ioloop.c:583
>> #12 0x00007f6f99f317af in master_service_run (service=0x232c5e0,
callback=0x430a35 <client_connected>) at master-service.c:640
>> #13 0x0000000000430da2 in main (argc=1, argv=0x232c390) at main.c:442
Thank you for the report. Could you execute "bt full" in gdb please.
Also the output of doveconf -n would be useful.

br,
Teemu Huovila

On 04.01.2016 11:54, Teemu Huovila wrote:
> Thank you for the report. Could you execute "bt full" in gdb
please. Also the output of doveconf -n would be useful.
Hi,

Requested info below.

Florian

bt f
> #0  0x00007f6f99b8f5f8 in raise () from /usr/lib/libc.so.6
> No symbol table info available.
> #1  0x00007f6f99b90a7a in abort () from /usr/lib/libc.so.6
> No symbol table info available.
> #2  0x00007f6f99fa6539 in default_fatal_finish (type=LOG_TYPE_PANIC,
status=0) at failures.c:201
>         backtrace = 0x2324158
"/usr/lib/dovecot/libdovecot.so.0(+0xa64ea) [0x7f6f99fa64ea] ->
/usr/lib/dovecot/libdovecot.so.0(+0xa7a18) [0x7f6f99fa7a18] ->
/usr/lib/dovecot/libdovecot.so.0(i_fatal+0) [0x7f6f99fa686d] ->
dovecot/im"...
> #3  0x00007f6f99fa7a18 in i_internal_fatal_handler (ctx=0x7ffe660d4700,
format=0x438a60 "file %s: line %d (%s): assertion failed: (%s)",
args=0x7ffe660d4720) at failures.c:670
>         status = 0
> #4  0x00007f6f99fa686d in i_panic (format=0x438a60 "file %s: line %d
(%s): assertion failed: (%s)") at failures.c:275
>         ctx = {
>           type = LOG_TYPE_PANIC, 
>           exit_status = 0, 
>           timestamp = 0x0, 
>           timestamp_usecs = 0
>         }
>         args = {[0] = {
>             gp_offset = 40, 
>             fp_offset = 48, 
>             overflow_arg_area = 0x7ffe660d4800, 
>             reg_save_area = 0x7ffe660d4740
>           }}
> #5  0x000000000041dde6 in client_check_command_hangs (client=0x2363450) at
imap-client.c:841
>         cmd = 0x0
>         unfinished_count = 0
>         have_wait_unfinished = true
>         __FUNCTION__ = "client_check_command_hangs"
> #6  0x000000000041df50 in client_continue_pending_input (client=0x2363450)
at imap-client.c:884
>         __FUNCTION__ = "client_continue_pending_input"
> #7  0x00000000004122a9 in idle_client_input (ctx=0x23642a8) at
cmd-idle.c:111
>         client = 0x2363450
> #8  0x00007f6f99fc3b01 in io_loop_call_io (io=0x2374600) at ioloop.c:559
>         ioloop = 0x232c740
>         t_id = 2
>         __FUNCTION__ = "io_loop_call_io"
> #9  0x00007f6f99fc606e in io_loop_handler_run_internal (ioloop=0x232c740)
at ioloop-epoll.c:220
>         ctx = 0x232e250
>         events = 0x232f0c0
>         event = 0x232f0c0
>         list = 0x232fc80
>         io = 0x2374600
>         tv = {
>           tv_sec = 29, 
>           tv_usec = 999771
>         }
>         events_count = 5
>         msecs = 30000
>         ret = 1
>         i = 0
>         j = 0
>         call = true
>         __FUNCTION__ = "io_loop_handler_run_internal"
> #10 0x00007f6f99fc3caa in io_loop_handler_run (ioloop=0x232c740) at
ioloop.c:607
> No locals.
> #11 0x00007f6f99fc3bf6 in io_loop_run (ioloop=0x232c740) at ioloop.c:583
>         __FUNCTION__ = "io_loop_run"
> #12 0x00007f6f99f317af in master_service_run (service=0x232c5e0,
callback=0x430a35 <client_connected>) at master-service.c:640
> No locals.
> #13 0x0000000000430da2 in main (argc=1, argv=0x232c390) at main.c:442
>         set_roots = {[0] = 0x43b7a0 <imap_setting_parser_info>, [1] =
0x0}
>         login_set = {
>           auth_socket_path = 0x2324048 "\001", 
>           postlogin_socket_path = 0x0, 
>           postlogin_timeout_secs = 60, 
>           callback = 0x43074f <login_client_connected>, 
>           failure_callback = 0x4309a0 <login_client_failed>, 
>           request_auth_token = 1
>         }
>         service_flags = MASTER_SERVICE_FLAG_KEEP_CONFIG_OPEN
>         storage_service_flags = MAIL_STORAGE_SERVICE_FLAG_DISALLOW_ROOT
>         username = 0x0
>         c = -1
doveconf -n
> # 2.2.21 (5345f22): /etc/dovecot/dovecot.conf
> # Pigeonhole version 0.4.10 (d61ff8a5af9e+)
> # OS: Linux 4.2.2-1-ARCH x86_64 Arch Linux 
> auth_mechanisms = plain login
> auth_username_format = %Ln
> imap_id_log = *
> login_log_format_elements = user=<%u> method=%m rip=%r lip=%l mpid=%e
%c %k
> mail_location = mdbox:~/.mdbox
> mail_plugins = " zlib notify mail_log"
> mailbox_list_index = yes
> managesieve_notify_capability = mailto
> managesieve_sieve_capability = fileinto reject envelope encoded-character
vacation subaddress comparator-i;ascii-numeric relational regex imap4flags copy
include variables body enotify environment mailbox date index ihave duplicate
mime foreverypart
> mdbox_rotate_size = 20 M
> namespace inbox {
>   hidden = no
>   inbox = yes
>   list = yes
>   location = 
>   mailbox Drafts {
>     auto = subscribe
>     special_use = \Drafts
>   }
>   mailbox Junk {
>     auto = subscribe
>     special_use = \Junk
>   }
>   mailbox Sent {
>     auto = subscribe
>     special_use = \Sent
>   }
>   mailbox Trash {
>     auto = subscribe
>     special_use = \Trash
>   }
>   prefix = 
>   separator = .
>   type = private
> }
> passdb {
>   driver = pam
> }
> plugin {
>   mail_log_events = delete undelete expunge copy mailbox_delete
mailbox_rename
>   mail_log_fields = uid box msgid size
>   sieve = ~/.dovecot.sieve
>   sieve_dir = ~/.sieve
>   sieve_global_dir = /etc/dovecot/sieve/global/
>   sieve_global_path = /etc/dovecot/sieve/default.sieve
>   zlib_save = gz
>   zlib_save_level = 6
> }
> protocols = imap pop3 sieve lmtp
> service auth {
>   unix_listener auth-client {
>     group = postfix
>     mode = 0660
>     user = postfix
>   }
>   user = root
> }
> service imap-login {
>   process_limit = 400
>   process_min_avail = 5
> }
> service lmtp {
>   drop_priv_before_exec = yes
>   unix_listener /var/spool/postfix/private/dovecot-lmtp {
>     group = postfix
>     mode = 0660
>     user = postfix
>   }
> }
> service managesieve-login {
>   inet_listener sieve-obsolete {
>     port = 2000
>   }
> }
> ssl_cert = </etc/ssl/my-certs/mail.pem
> ssl_cipher_list =
EDH+CAMELLIA:EDH+aRSA:EECDH+aRSA+AESGCM:EECDH+aRSA+SHA384:EECDH+aRSA+SHA256:EECDH:+CAMELLIA256:+AES256:+CAMELLIA128:+AES128:+SSLv3:!aNULL:!eNULL:!LOW:!3DES:!MD5:!EXP:!PSK:!DSS:!RC4:!SEED:!ECDSA:CAMELLIA256-SHA:AES256-SHA:CAMELLIA128-SHA:AES128-SHA
> ssl_key = </etc/ssl/private/server.key
> ssl_options = no_compression
> ssl_prefer_server_ciphers = yes
> ssl_protocols = !SSLv2 !SSLv3
> userdb {
>   driver = passwd
> }
> protocol imap {
>   imap_client_workarounds = tb-extra-mailbox-sep
>   mail_max_userip_connections = 30
>   mail_plugins = " zlib notify mail_log imap_zlib"
> }
> protocol lda {
>   mail_plugins = " zlib notify mail_log sieve"
>   postmaster_address = postmaster at server-speed.net
> }
> protocol lmtp {
>   mail_plugins = " zlib notify mail_log sieve"
>   postmaster_address = postmaster at server-speed.net
> }
> protocol sieve {
>   managesieve_logout_format = bytes ( in=%i : out=%o )
> }

-------------- next part --------------
A non-text attachment was scrubbed...
Name: signature.asc
Type: application/pgp-signature
Size: 801 bytes
Desc: OpenPGP digital signature
URL:
<http://dovecot.org/pipermail/dovecot/attachments/20160104/5a488220/attachment.sig>