Re: 2.2.15 Panic in mbox_sync_read_next_mail()

On 10/29/2014 02:50 PM, Matthias Egger wrote:

As soon as i can catch a coredump i will send a gdb output.

Okay, here is the gdb ouput i could catch and some more information about the system.

System Infos: SunOS HOSTNAME 5.10 Generic_150400-10 sun4u sparc SUNW,Sun-Fire-V440

Logfile Entries: Oct 30 14:27:56 HOSTNAME dovecot: [ID 583609 mail.info] imap-login: Login: user=<USERNAME>, method=PLAIN, rip=1.1.1.1, lip=2.2.2.2, mpid=15565, TLS, session=<B6os2aMGoACBhDSe>

Oct 30 14:27:56 HOSTNAME dovecot: [ID 583609 mail.debug] imap(USERNAME): Debug: Effective uid=3224, gid=320, home=/home/USERNAME

Oct 30 14:27:56 HOSTNAME dovecot: [ID 583609 mail.debug] imap(USERNAME): Debug: Namespace : type=private, prefix=, sep=/, inbox=yes, hidden=no, list=yes, subscriptions=yes location=mbox:~/Mail/:INBOX=/var/mail/USERNAME:INDEX=/usr/HOSTNAME/vault2/dovecot/indexes/USERNAME

Oct 30 14:27:56 HOSTNAME dovecot: [ID 583609 mail.debug] imap(USERNAME): Debug: fs: root=/home/USERNAME/Mail, index=/usr/HOSTNAME/vault2/dovecot/indexes/USERNAME, indexpvt=, control=, inbox=/var/mail/USERNAME, alt=

Oct 30 14:27:56 HOSTNAME dovecot: [ID 583609 mail.debug] imap(USERNAME): Debug: Namespace : type=private, prefix=Mail/, sep=/, inbox=no, hidden=yes, list=no, subscriptions=yes location=mbox:~/Mail/:INBOX=/var/mail/USERNAME:INDEX=/usr/HOSTNAME/vault2/dovecot/indexes/USERNAME

Oct 30 14:27:56 HOSTNAME dovecot: [ID 583609 mail.debug] imap(USERNAME): Debug: fs: root=/home/USERNAME/Mail, index=/usr/HOSTNAME/vault2/dovecot/indexes/USERNAME, indexpvt=, control=, inbox=/var/mail/USERNAME, alt=

Oct 30 14:27:56 HOSTNAME dovecot: [ID 583609 mail.error] imap(USERNAME): Error: Next message unexpectedly corrupted in mbox file /home/USERNAME/Mail/review at 79036384

Oct 30 14:27:56 HOSTNAME dovecot: [ID 583609 mail.crit] imap(USERNAME): Panic: file mbox-sync.c: line 152 (mbox_sync_read_next_mail): assertion failed: (sync_ctx->input->v_offset != mail_ctx->mail.from_offset || sync_ctx->input->eof)

Oct 30 14:27:56 HOSTNAME dovecot: [ID 583609 mail.error] imap(USERNAME): Error: Raw backtrace: 0xffffffff7ed89f64 -> 0xffffffff7ed88f10 -> 0xffffffff7ef77a14 -> 0xffffffff7ef78a1c -> 0xffffffff7ef70720 -> 0xffffffff7c10289c -> 0xffffffff7ef96e60 -> 0xffffffff7ef8dd6c -> 0xffffffff7c102758 -> 0xffffffff7ef97130 -> 0xffffffff7ef97250 -> 0x10000c8c8 -> 0x10000ce24 -> 0x100019044 -> 0x100017b18 -> 0x100017ad8 -> 0x100017f3c -> 0x100018188 -> 0xffffffff7ed9c8a4 -> 0xffffffff7ed9d5a0 -> 0xffffffff7ed9c93c -> 0xffffffff7ed9ca0c -> 0xffffffff7ed3c314 -> 0x100024908 -> 0x10000a74c

Oct 30 14:27:57 HOSTNAME dovecot: [ID 583609 mail.crit] imap(USERNAME): Fatal: master: service(imap): child 15565 killed with signal 6 (core dumped)

GDB Output: GNU gdb (GDB) 7.8.1 Copyright (C) 2014 Free Software Foundation, Inc. License GPLv3+: GNU GPL version 3 or later http://gnu.org/licenses/gpl.html This is free software: you are free to change and redistribute it. There is NO WARRANTY, to the extent permitted by law. Type "show copying" and "show warranty" for details. This GDB was configured as "sparc-sun-solaris2.10". Type "show configuration" for configuration details. For bug reporting instructions, please see: http://www.gnu.org/software/gdb/bugs/. Find the GDB manual and other documentation resources online at: http://www.gnu.org/software/gdb/documentation/. For help, type "help". Type "apropos word" to search for commands related to "word"... Reading symbols from /usr/pack/dovecot-2.2.15-me/sun4u-sun-solaris2.10/libexec/dovecot/imap...done. [New LWP 1] [Thread debugging using libthread_db enabled] [New Thread 1 (LWP 1)] Core was generated by `dovecot/imap'. Program terminated with signal SIGABRT, Aborted. #0 0xffffffff7cddcb68 in _lwp_kill () from /lib/64/libc.so.1 (gdb) bt full #0 0xffffffff7cddcb68 in _lwp_kill () from /lib/64/libc.so.1 No symbol table info available. #1 0xffffffff7cd74444 in raise () from /lib/64/libc.so.1 No symbol table info available. #2 0xffffffff7cd4c1c8 in abort () from /lib/64/libc.so.1 No symbol table info available. #3 0xffffffff7ed88d7c in default_fatal_finish (type=LOG_TYPE_PANIC, status=0) at failures.c:202 backtrace = 0x100133db0 "0xffffffff7ed89f64 -> 0xffffffff7ed88f10 -> 0xffffffff7ef77a14 -> 0xffffffff7ef78a1c -> 0xffffffff7ef70720 -> 0xffffffff7c10289c -> 0xffffffff7ef96e60 -> 0xffffffff7ef8dd6c -> 0xffffffff7c102758 -> 0x"... #4 0xffffffff7ed89f6c in i_internal_fatal_handler (ctx=0xffffffff7fffe2e0, format=0xffffffff7effba48 "file %s: line %d (%s): assertion failed: (%s)", args=0x0) at failures.c:666 status = 0 #5 0xffffffff7ed88f18 in i_panic (format=0xffffffff7effba48 "file %s: line %d (%s): assertion failed: (%s)") at failures.c:276 ctx = {type = LOG_TYPE_PANIC, exit_status = 0, timestamp = 0x0, timestamp_usecs = 0} #6 0xffffffff7ef77a1c in mbox_sync_do (sync_ctx=0xffffffff7fffe760, flags=(MBOX_SYNC_FORCE_SYNC | MBOX_SYNC_READONLY | unknown: 2147477248)) at mbox-sync.c:1506 seq = 1611168 view = 0xffffffff7eeddcf8 st = 0x0 first_recent_uid = 0 seq2 = 1 mbox_hdr = 0x1 mail_ctx = {sync_ctx = 0xffffffff7fffe760, mail = {uid = 0, idx_seq = 0, keywords = {arr = {buffer = 0x0, element_size = 0}, v = 0x0, v_modifiable = 0x0}, flags = 32 ' ', uid_broken = 0, expunged = 0, pseudo = 0, status_broken = 0, xstatus_broken = 0, from_offset = 558, body_size = 0, offset = 558, space = 0}, seq = 2, hdr_offset = 558, body_offset = 558, header_first_change = 18446744073709551615, header_last_change = 0, header = 0x100140230, hdr_md5_sum = "\324\035\214\331\217\000\262\004\351\200\t\230\354\370B~", content_length = 18446744073709551615, hdr_pos = {18446744073709551615, 18446744073709551615, 18446744073709551615, 18446744073709551615, 18446744073709551615}, parsed_uid = 0, last_uid_updated_value = 0, last_uid_value_start_pos = 0, have_eoh = 0, need_rewrite = 0, seen_imapbase = 0, updated = 0, recent = 0, dirty = 0, imapbase_rewrite = 0, imapbase_updated = 0} st = 0x1001895c8 i = 0 ret = 1389811195 partial = 1389811195 #7 0xffffffff7ef78a24 in mbox_sync (mbox=0x100163a50, flags=(unknown: 0)) at mbox-sync.c:1947 sync_ctx = {mbox = 0x100163a50, flags = (unknown: 0), input = 0x100189750, file_input = 0x1001895a0, write_fd = 16, orig_mtime = 1414623452, orig_atime = 1414675298, orig_size = 80880344, last_stat = { st_dev = 1657857376531, st_ino = 128607, st_mode = 33152, st_nlink = 1, st_uid = 3224, st_gid = 320, st_rdev = 0, st_size = 80880344, st_atim = {tv_sec = 1414675298, tv_nsec = 859380000}, st_mtim = { tv_sec = 1414623452, tv_nsec = 0}, st_ctim = {tv_sec = 1414623453, tv_nsec = 933899000}, st_blksize = 8192, st_blocks = 158080, st_fstype = "nfs", '\000' }, index_sync_ctx = 0x1001855d0, sync_view = 0x100185640, t = 0x100185c40, reset_hdr = {major_version = 0 '\000', minor_version = 0 '\000', base_header_size = 0, header_size = 0, record_size = 0, compat_flags = 0 '\000', unused = "\000\000", indexid = 0, flags = 0, uid_validity = 0, next_uid = 0, messages_count = 0, unused_old_recent_messages_count = 0, seen_messages_count = 0, deleted_messages_count = 0, first_recent_uid = 0, first_unseen_uid_lowwater = 0, first_deleted_uid_lowwater = 0, log_file_seq = 0, log_file_tail_offset = 0, log_file_head_offset = 0, unused_old_sync_size = 0, unused_old_sync_stamp = 0, day_stamp = 0, day_first_uid = {0, 0, 0, 0, 0, 0, 0, 0}}, hdr = 0x100167a90, header = 0x100140230, from_line = 0x1001401e0, base_uid_validity = 1389811195, base_uid_last = 770, base_uid_last_offset = 264, mails = {arr = {buffer = 0x100140280, element_size = 64}, v = 0x100140280, v_modifiable = 0x100140280}, sync_changes = 0x100161130, mail_keyword_pool = 0x1001870d0, saved_keywords_pool = 0x1001872e0, prev_msg_uid = 0, next_uid = 771, idx_next_uid = 744, seq = 2, idx_seq = 1, need_space_seq = 0, last_nonrecent_uid = 0, expunged_space = 0, space_diff = 0, dest_first_mail = 0, first_mail_crlf_expunged = 0, keep_recent = 1, readonly = 0, delay_writes = 1, renumber_uids = 0, moved_offsets = 0, ext_modified = 0, index_reset = 0, errors = 0} sync_flags = (MAIL_INDEX_SYNC_FLAG_DROP_RECENT | MAIL_INDEX_SYNC_FLAG_AVOID_FLAG_UPDATES | MAIL_INDEX_SYNC_FLAG_DELETING_INDEX | MAIL_INDEX_SYNC_FLAG_TRY_DELETING_INDEX | unknown: 640) index_sync_ctx = 0x1001855d0 sync_view = 0x100185640 ret = 1259088 trans = 0x100185c40 changed = 1 delay_writes = true readonly = false lock_id = 3 ret = 1 __FUNCTION__ = "mbox_sync" #8 0xffffffff7ef70728 in mbox_save_begin (_ctx=0x100178880, input=0x100184bc0) at mbox-save.c:317 mbox = 0x100163a50 storage = 0x1001566e0 empty = false ret = 1 mdata = 0x100178890 t = 0x100171ab0 save_flags = 1456720 offset = 18446744069414584321 __FUNCTION__ = "mbox_save_begin" #9 0xffffffff7c1028a4 in notify_save_begin (ctx=0x100178880, input=0x100184bc0) at notify-storage.c:132 lt = 0x10013bf10 lbox = 0x1001640c0 #10 0xffffffff7ef96e68 in mailbox_save_begin (ctx=0xffffffff7fffee30, input=0x100184bc0) at mail-storage.c:2087 _data_stack_cur_id = 5 box = 0x100163a50 ret = 1456720 #11 0xffffffff7ef8dd74 in mail_storage_copy (ctx=0x100178880, mail=0x1001740a0) at mail-copy.c:76 input = 0x100184bc0 #12 0xffffffff7c102760 in notify_copy (ctx=0x100178880, mail=0x1001740a0) at notify-storage.c:108 lt = 0xffffffffffffffff lbox = 0x1001640c0 ret = 1458368 #13 0xffffffff7ef97138 in mailbox_copy (_ctx=0xffffffff7ffff0e0, mail=0x1001740a0) at mail-storage.c:2212 _data_stack_cur_id = 4 ctx = 0x100178880 t = 0x100171ab0 keywords = 0x0 pvt_flags = 0 backend_mail = 0x1001740a0 ret = 2147479776 __FUNCTION__ = "mailbox_copy" #14 0xffffffff7ef97258 in mailbox_move (_ctx=0xffffffff7ffff0e0, mail=0x1001740a0) at mail-storage.c:2234 ctx = 0x100178880 #15 0x000000010000c8d0 in cmd_copy_full (cmd=0x100157ab0, move=true) at cmd-copy.c:67 search_ctx = 0x100173f30 src_trans = 0x100172cf0 srcset_ctx = {str = 0x100133c00, first_uid = 0, last_uid = 4294967295} ret = 1 save_ctx = 0x0 mail = 0x1001740a0 copy_count = 1 src_uidset = 0x100133c00 move = true search_args = 0x1 client = 0x1001572a0 dest_storage = 0x1 destbox = 0x100163a50 t = 0x100171ab0 src_trans = 0x84 search_args = 0x100162a40 messageset = 0x1001514e0 "237752" mailbox = 0x1001514e8 "review" src_uidset = 0x81 sync_flags = (unknown: 0) imap_flags = (unknown: 0) changes = {pool = 0x3132392e3133322e, uid_validity = 892481073, saved_uids = {arr = {buffer = 0x81, element_size = 18446744071544102136}, v = 0x81, v_modifiable = 0x81}, ignored_modseq_changes = 1, changed = false, no_read_perm = 21} copy_count = 8 msg = 0x100171ab0 ret = 1 __FUNCTION__ = "cmd_copy_full" #16 0x000000010000ce2c in cmd_move (cmd=0x100157ab0) at cmd-copy.c:211 No locals. #17 0x000000010001904c in command_exec (cmd=0x100157ab0) at imap-commands.c:158 hook = 0x10013e700 ret = 63 #18 0x0000000100017b20 in client_command_input (cmd=0x100157ab0) at imap-client.c:782 client = 0x1001572a0 command = 0x0 __FUNCTION__ = "client_command_input" #19 0x0000000100017ae0 in client_command_input (cmd=0x100157ab0) at imap-client.c:843 client = 0x1001572a0 command = 0x0 __FUNCTION__ = "client_command_input" #20 0x0000000100017f44 in client_handle_input (client=0x1001572a0) at imap-client.c:880 _data_stack_cur_id = 3 ret = false remove_io = false handled_commands = false __FUNCTION__ = "client_handle_input" #21 0x0000000100018190 in client_input (client=0x1001572a0) at imap-client.c:935 cmd = 0xf1942 output = 0x100151250 bytes = 30 __FUNCTION__ = "client_input" #22 0xffffffff7ed9c8ac in io_loop_call_io (io=0x100143b60) at ioloop.c:498 ioloop = 0x10013cd80 t_id = 2 __FUNCTION__ = "io_loop_call_io" #23 0xffffffff7ed9d5a8 in io_loop_handler_run_internal (ioloop=0x10013cd80) at ioloop-poll.c:211 ctx = 0x10013ce60 pollfd = 0x100142470 tv = {tv_sec = 4, tv_usec = 990294} io = 0x100143b60 ret = 0 call = false #24 0xffffffff7ed9c944 in io_loop_handler_run (ioloop=0x10013cd80) at ioloop.c:545 No locals. #25 0xffffffff7ed9ca14 in io_loop_run (ioloop=0x10013cd80) at ioloop.c:523 __FUNCTION__ = "io_loop_run" #26 0xffffffff7ed3c31c in master_service_run (service=0x10013cc50, callback=0x100024318 ) at master-service.c:566 No locals. #27 0x0000000100024910 in main (argc=1, argv=0xffffffff7ffffca8) at main.c:412 set_roots = {0x10002d5e0 , 0x0} login_set = {auth_socket_path = 0x100133920 "", postlogin_socket_path = 0x0, postlogin_timeout_secs = 60, callback = 0x100024054 , failure_callback = 0x1000242bc , request_auth_token = 1} service_flags = (MASTER_SERVICE_FLAG_KEEP_CONFIG_OPEN | MASTER_SERVICE_FLAG_NO_CONFIG_SETTINGS | MASTER_SERVICE_FLAG_UPDATE_PROCTITLE | MASTER_SERVICE_FLAG_USE_SSL_SETTINGS | unknown: 147456) storage_service_flags = MAIL_STORAGE_SERVICE_FLAG_DISALLOW_ROOT username = 0x133400 c = 1297488

Best regards Matthias

Matthias Egger ETH Zurich Department of Information Technology maegger@ee.ethz.ch and Electrical Engineering IT Support Group (ISG.EE), ETL/F/24.1 Phone +41 (0)44 632 03 90 Physikstrasse 3, CH-8092 Zurich Fax +41 (0)44 632 11 95