Dovecot 2.2.15 imap crash/panic (with core dumped)
Hi,
after upgrade to Dovecot >= 2.2.14rc1 sometimes I found this error/crash in the log (never happened with 2.2.13),
I'm the only one? Can be fix?
Nov 11 17:44:26 imap(info@myemail.com): Error: Corrupted transaction log file /home/domains/myemail.com/info/Maildir/dovecot.index.log seq 190: Invalid transaction log size (32756 vs 32772): /home/domains/myemail.com/info/Maildir/dovecot.index.log (sync_offset=32756) Nov 11 17:44:26 imap(info@myemail.com): Error: Log synchronization error at seq=0,offset=0 for /home/domains/myemail.com/info/Maildir/dovecot.index: Append with UID 10777, but next_uid = 10778 Nov 11 17:44:26 imap(info@myemail.com): Error: /home/domains/myemail.com/info/Maildir/dovecot.index view syncing failed to apply changes Nov 11 17:44:26 imap(info@myemail.com): Panic: file index-sync.c: line 265 (index_mailbox_sync_next_expunge): assertion failed: (range->seq2 <= ctx->messages_count) Nov 11 17:44:26 imap(info@myemail.com): Error: Raw backtrace: /usr/lib/dovecot/libdovecot.so.0(+0x75e1a) [0x7fbbd213ae1a] -> /usr/lib/dovecot/libdovecot.so.0(+0x75e96) [0x7fbbd213ae96] -> /usr/lib/dovecot/libdovecot.so.0(i_error+0) [0x7fbbd20ec2bf] -> /usr/lib/dovecot/libdovecot-storage.so.0(+0xb219c) [0x7fbbd245719c] -> dovecot/imap(imap_sync_more+0xc3) [0x41fd13] -> dovecot/imap() [0x420437] -> dovecot/imap(cmd_sync_delayed+0x209) [0x4208f9] -> dovecot/imap(client_handle_input+0x1ed) [0x4178dd] -> dovecot/imap(client_input+0x6f) [0x417b9f] -> /usr/lib/dovecot/libdovecot.so.0(io_loop_call_io+0x5b) [0x7fbbd214c0db] -> /usr/lib/dovecot/libdovecot.so.0(io_loop_handler_run_internal+0xaf) [0x7fbbd214d27f] -> /usr/lib/dovecot/libdovecot.so.0(io_loop_handler_run+0x9) [0x7fbbd214c169] -> /usr/lib/dovecot/libdovecot.so.0(io_loop_run+0x38) [0x7fbbd214c1f8] -> /usr/lib/dovecot/libdovecot.so.0(master_service_run+0x13) [0x7fbbd20f1193] -> dovecot/imap(main+0x2b0) [0x4210d0] -> /lib/libc.so.6(__libc_start_main+0xfd) [0x7fbbd1d81cad] -> dovecot/imap() [0x40bea9] Nov 11 17:44:26 imap(info@myemail.com): Fatal: master: service(imap): child 13586 killed with signal 6 (core dumped)
# gdb /usr/libexec/dovecot/imap /home/domains/myemail.com/info/core
Reading symbols from /usr/libexec/dovecot/imap...done.
warning: Can't read pathname for load map: Input/output error. Reading symbols from /usr/lib/dovecot/libdovecot-storage.so.0...done. Loaded symbols for /usr/lib/dovecot/libdovecot-storage.so.0 Reading symbols from /usr/lib/dovecot/libdovecot.so.0...done. Loaded symbols for /usr/lib/dovecot/libdovecot.so.0 Reading symbols from /lib/libc.so.6...(no debugging symbols found)...done. Loaded symbols for /lib/libc.so.6 Reading symbols from /lib/librt.so.1...(no debugging symbols found)...done. Loaded symbols for /lib/librt.so.1 Reading symbols from /lib/libdl.so.2...(no debugging symbols found)...done. Loaded symbols for /lib/libdl.so.2 Reading symbols from /lib64/ld-linux-x86-64.so.2...(no debugging symbols found)...done. Loaded symbols for /lib64/ld-linux-x86-64.so.2 Reading symbols from /lib/libpthread.so.0...(no debugging symbols found)...done. Loaded symbols for /lib/libpthread.so.0 Reading symbols from /usr/lib/dovecot/lib01_acl_plugin.so...done. Loaded symbols for /usr/lib/dovecot/lib01_acl_plugin.so Reading symbols from /usr/lib/dovecot/lib02_imap_acl_plugin.so...done. Loaded symbols for /usr/lib/dovecot/lib02_imap_acl_plugin.so Reading symbols from /usr/lib/dovecot/lib10_quota_plugin.so...done. Loaded symbols for /usr/lib/dovecot/lib10_quota_plugin.so Reading symbols from /usr/lib/dovecot/lib11_imap_quota_plugin.so...done. Loaded symbols for /usr/lib/dovecot/lib11_imap_quota_plugin.so Reading symbols from /usr/lib/dovecot/lib20_expire_plugin.so...done. Loaded symbols for /usr/lib/dovecot/lib20_expire_plugin.so Reading symbols from /lib/libgcc_s.so.1...(no debugging symbols found)...done. Loaded symbols for /lib/libgcc_s.so.1 Core was generated by `dovecot/imap'. Program terminated with signal 6, Aborted. #0 0x00007fbbd1d94ed5 in raise () from /lib/libc.so.6 (gdb) bt full #0 0x00007fbbd1d94ed5 in raise () from /lib/libc.so.6 No symbol table info available. #1 0x00007fbbd1d97ce0 in abort () from /lib/libc.so.6 No symbol table info available. #2 0x00007fbbd213ae10 in default_fatal_finish (type=<value optimized out>, status=0) at failures.c:202 backtrace = 0x13a71d8 "/usr/lib/dovecot/libdovecot.so.0(+0x75e1a) [0x7fbbd213ae1a] -> /usr/lib/dovecot/libdovecot.so.0(+0x75e96) [0x7fbbd213ae96] -> /usr/lib/dovecot/libdovecot.so.0(i_error+0) [0x7fbbd20ec2bf] -> /usr/lib/d"... #3 0x00007fbbd213ae96 in i_internal_fatal_handler (ctx=0x7fff8637e780, format=<value optimized out>, args=<value optimized out>) at failures.c:666 status = 0 #4 0x00007fbbd20ec2bf in i_panic (format=0x3512
) at failures.c:276 ctx = {type = LOG_TYPE_PANIC, exit_status = 0, timestamp = 0x0, timestamp_usecs = 0} args = {{gp_offset = 40, fp_offset = 48, overflow_arg_area = 0x7fff8637e860, reg_save_area = 0x7fff8637e7a0}} #5 0x00007fbbd245719c in index_mailbox_sync_next_expunge (ctx=0x142b410, sync_rec_r=<value optimized out>) at index-sync.c:265 range = 0x13cdfd0 __FUNCTION__ = "index_mailbox_sync_next_expunge" #6 0x000000000041fd13 in imap_sync_more (ctx=0x13c3d80) at imap-sync.c:536 str = 0x13a7050 ret = <value optimized out> __FUNCTION__ = "imap_sync_more" #7 0x0000000000420437 in cmd_sync_continue (sync_cmd=0x1431700) at imap-sync.c:658 cmd = <value optimized out> prev = <value optimized out> client = 0x1430b00 ctx = 0x13c3d80 ret = <value optimized out> __FUNCTION__ = "cmd_sync_continue" #8 0x00000000004208f9 in cmd_sync_client (client=<value optimized out>) at imap-sync.c:748 ctx = 0x0 flags = <value optimized out> client = 0x1430b00 imap_flags = <value optimized out> no_newmail = <value optimized out> #9 cmd_sync_delayed_real (client=<value optimized out>) at imap-sync.c:878 cmd = <value optimized out> #10 cmd_sync_delayed (client=<value optimized out>) at imap-sync.c:886 _data_stack_cur_id = 3 ret = <value optimized out> #11 0x00000000004178dd in client_handle_input (client=0x1430b00) at imap-client.c:908 ret = true remove_io = false handled_commands = true __FUNCTION__ = "client_handle_input" #12 0x0000000000417b9f in client_input (client=0x1430b00) at imap-client.c:935 cmd = <value optimized out> output = 0x1431540 bytes = <value optimized out> __FUNCTION__ = "client_input" #13 0x00007fbbd214c0db in io_loop_call_io (io=0x1431610) at ioloop.c:498 ioloop = 0x13af730 t_id = 2 __FUNCTION__ = "io_loop_call_io" ---Type <return> to continue, or q <return> to quit--- #14 0x00007fbbd214d27f in io_loop_handler_run_internal (ioloop=<value optimized out>) at ioloop-epoll.c:220 ctx = 0x13b03c0 event = 0x13b1230 list = 0x13d3630 io = 0x3512 tv = {tv_sec = 1799, tv_usec = 999656} msecs = <value optimized out> ret = <value optimized out> i = 0 call = false __FUNCTION__ = "io_loop_handler_run_internal" #15 0x00007fbbd214c169 in io_loop_handler_run (ioloop=0x3512) at ioloop.c:545 No locals. #16 0x00007fbbd214c1f8 in io_loop_run (ioloop=0x13af730) at ioloop.c:522 __FUNCTION__ = "io_loop_run" #17 0x00007fbbd20f1193 in master_service_run (service=0x13af5c0, callback=0x3512) at master-service.c:566 No locals. #18 0x00000000004210d0 in main (argc=1, argv=0x13af390) at main.c:412 set_roots = {0x429200, 0x0} login_set = {auth_socket_path = 0x13a7050 "\210p:\001", postlogin_socket_path = 0x0, postlogin_timeout_secs = 60, callback = 0x4212d0# 2.2.15: /etc/dovecot/dovecot.conf # Pigeonhole version 0.4.6 (3e924b1b6c5c+) # OS: Linux 2.6.32-5-amd64 x86_64 Debian 6.0.10 auth_cache_negative_ttl = 10 mins auth_cache_size = 8 M auth_cache_ttl = 20 mins auth_worker_max_count = 50 deliver_log_format = msgid=%m, from=%f, subject="%s": %$ dict { acl = mysql:/etc/dovecot/dovecot-dict-sql.conf.ext expire = mysql:/etc/dovecot/dovecot-dict-sql.conf.ext sqlquota = mysql:/etc/dovecot/dovecot-dict-sql.conf.ext } disable_plaintext_auth = no dotlock_use_excl = no first_valid_gid = 89 first_valid_uid = 89 imap_client_workarounds = delay-newmail tb-extra-mailbox-sep tb-lsub-flags imap_idle_notify_interval = 29 mins imap_logout_format = in=%i out=%o session=<%{session}> last_valid_gid = 89 last_valid_uid = 89 lda_mailbox_autocreate = yes lda_mailbox_autosubscribe = yes listen = * mail_fsync = always mail_location = maildir:~/Maildir mail_nfs_index = yes mail_nfs_storage = yes mail_plugins = quota acl expire mailbox_list_index = yes maildir_very_dirty_syncs = yes managesieve_notify_capability = mailto managesieve_sieve_capability = fileinto reject envelope encoded-character subaddress comparator-i;ascii-numeric relational regex imap4flags copy include variables body enotify environment mailbox date ihave duplicate vnd.dovecot.duplicate mmap_disable = yes namespace { list = children location = maildir:%%h/Maildir:INDEX=~/Maildir/shared/%%u prefix = shared/%%n/ separator = / subscriptions = no type = shared } namespace inbox { inbox = yes location = mailbox Drafts { auto = subscribe special_use = \Drafts } mailbox Sent { auto = subscribe special_use = \Sent } mailbox "Sent Messages" { special_use = \Sent } mailbox Spam { auto = subscribe special_use = \Junk } mailbox Trash { auto = subscribe special_use = \Trash } prefix = separator = / } passdb { args = username_format=%Ld /etc/dovecot/denylogin.txt deny = yes driver = passwd-file } passdb { args = cache_key=%s%u webmail=192.168.1.2 driver = vpopmail } plugin { acl = vfile acl_shared_dict = proxy::acl expire = Trash expire2 = Spam expire_dict = proxy::expire quota = maildir:UserQuota quota2 = dict:Quota Usage::noenforcing:proxy::sqlquota quota_grace = 10M quota_rule2 = Trash:storage=+100M quota_warning = storage=95%% quota-warning 95 %u quota_warning2 = storage=80%% quota-warning 80 %u sieve = ~/.dovecot.sieve sieve_before = /etc/dovecot/sieve/before.sieve sieve_dir = ~/sieve sieve_extensions = +vnd.dovecot.duplicate -vacation } pop3_client_workarounds = outlook-no-nuls oe-ns-eoh pop3_fast_size_lookups = yes pop3_logout_format = top=%t/%p, retr=%r/%b, del=%d/%m, size=%s, bytes=%i/%o, session=<%{session}> protocols = imap pop3 sieve sendmail_path = /var/qmail/bin/sendmail service auth { client_limit = 6500 unix_listener auth-userdb { group = vchkpw mode = 0660 user = vpopmail } } service dict { process_limit = 500 unix_listener dict { group = vchkpw mode = 0660 user = vpopmail } } service imap-login { process_min_avail = 4 service_count = 0 } service imap { process_limit = 5000 service_count = 100 } service managesieve-login { inet_listener sieve { port = 4190 } } service pop3-login { service_count = 0 } service pop3 { process_limit = 1023 service_count = 100 } service quota-warning { executable = script /etc/dovecot/quota-warning.sh unix_listener quota-warning { user = vpopmail } user = vpopmail } ssl_cert =
On 12 Nov 2014, at 05:32, Alessio Cecchi alessio@skye.it wrote:
after upgrade to Dovecot >= 2.2.14rc1 sometimes I found this error/crash in the log (never happened with 2.2.13),
I'm the only one? Can be fix?
Nov 11 17:44:26 imap(info@myemail.com): Error: Corrupted transaction log file /home/domains/myemail.com/info/Maildir/dovecot.index.log seq 190: Invalid transaction log size (32756 vs 32772): /home/domains/myemail.com/info/Maildir/dovecot.index.log (sync_offset=32756) Nov 11 17:44:26 imap(info@myemail.com): Error: Log synchronization error at seq=0,offset=0 for /home/domains/myemail.com/info/Maildir/dovecot.index: Append with UID 10777, but next_uid = 10778 Nov 11 17:44:26 imap(info@myemail.com): Error: /home/domains/myemail.com/info/Maildir/dovecot.index view syncing failed to apply changes Nov 11 17:44:26 imap(info@myemail.com): Panic: file index-sync.c: line 265 (index_mailbox_sync_next_expunge): assertion failed: (range->seq2 <= ctx->messages_count)
I can't really think of what would have started causing these. There aren't that big changes done to index handling code. I've also been running a ton of stress testing for Dovecot without these errors, so it's not a common problem at least. Although..:
mail_nfs_index = yes mail_nfs_storage = yes
What kind of a setup is this? Are there multiple Dovecot backend servers and are you using director? These two settings never worked 100% and they're not supported anymore. In a single dovecot server / or multi-dovecot+director setup these can be "no".
participants (2)
-
Alessio Cecchi
-
Timo Sirainen