[Dovecot] Another 1.2.5 imap panic
We've had another random imap process crash. This is with the original 1.2.5 imap (I haven't applied the patch for two processes creating an index simultaneously):
Oct 03 13:24:56 imap-login: Info: Login: user=<xxxxxxxx>, method=PLAIN, rip=134.225.1.46, lip=134.225.16.6 Oct 03 13:25:59 IMAP 6067 xxxxxxxx 134.225.1.46 : Info: delete: uid=483, msgid=<xxxxxxxx> Oct 03 13:28:06 IMAP 6067 xxxxxxxx 134.225.1.46 : Info: expunge: uid=483, msgid=<xxxxxxxx>, size=63593 Oct 03 13:28:30 IMAP 6067 xxxxxxxx 134.225.1.46 : Info: delete: uid=482, msgid=<xxxxxxxx> Oct 03 13:28:30 IMAP 6067 xxxxxxxx 134.225.1.46 : Info: delete: uid=484, msgid=<xxxxxxxx> Oct 03 13:28:30 IMAP 6067 xxxxxxxx 134.225.1.46 : Info: delete: uid=485, msgid=<xxxxxxxx> Oct 03 13:28:42 IMAP 6067 xxxxxxxx 134.225.1.46 : Info: undelete: uid=485, msgid=<xxxxxxxx> Oct 03 13:28:51 IMAP 6067 xxxxxxxx 134.225.1.46 : Info: delete: uid=486, msgid=<xxxxxxxx> Oct 03 13:28:54 IMAP 6067 xxxxxxxx 134.225.1.46 : Info: expunge: uid=482, msgid=<xxxxxxxx>, size=273185 Oct 03 13:28:54 IMAP 6067 xxxxxxxx 134.225.1.46 : Info: expunge: uid=484, msgid=<xxxxxxxx>, size=12740 Oct 03 13:28:54 IMAP 6067 xxxxxxxx 134.225.1.46 : Info: expunge: uid=486, msgid=<xxxxxxxx>, size=52154 Oct 03 13:30:22 IMAP 6067 xxxxxxxx 134.225.1.46 : Info: delete: uid=470, msgid=<xxxxxxxx> Oct 03 13:30:36 IMAP 6067 xxxxxxxx 134.225.1.46 : Info: delete: uid=471, msgid=<xxxxxxxx> Oct 03 13:30:50 IMAP 6067 xxxxxxxx 134.225.1.46 : Info: delete: uid=472, msgid=<xxxxxxxx> Oct 03 13:33:27 IMAP 6067 xxxxxxxx 134.225.1.46 : Info: delete: uid=475, msgid=<xxxxxxxx> Oct 03 13:34:20 IMAP 6067 xxxxxxxx 134.225.1.46 : Panic: file istream-raw-mbox.c: line 578 (istream_raw_mbox_get_body_size): assertion failed: (rstream->body_offset != (uoff_t)-1)
Backtrace:
Core was generated by `imap [xxxxxxxx 134.225.1.46]'. Program terminated with signal 6, Abort. #0 0xff21fe78 in ?? () (gdb) bt #0 0xff21fe78 in ?? () #1 0xbe258 in ?? () #2 0xbeb14 in ?? () #3 0xbe414 in ?? () #4 0x5a238 in mail_index_update_flags (t=0xe29b8, seq=578, modify_type=37, flags=928984) at mail-index-transaction.c:697 #5 0x5a4d8 in mail_index_ext_resize (t=0x12a250, ext_id=4294967295, hdr_size=1221160, record_size=64549, record_align=0) at ../../src/lib/array.h:157 #6 0x5a7a0 in mail_index_update_ext (t=0x0, seq=0, ext_id=523301, data=0xffbeeb38, old_data_r=0x22094) at ../../src/lib/array.h:187 #7 0x5ae58 in _tview_close (view=0x1272a8) at mail-index-transaction-view.c:24 #8 0x5c7d8 in mail_index_sync_end (_ctx=0xffffffff) at mail-index-sync.c:636 #9 0x5cd74 in mail_index_sync_update_log_offset (ctx=0x12be80, map=0x11, eol=140) at mail-index-sync-update.c:59 #10 0x5cea4 in mail_index_map_msync (index=0x130d08, map=0x0) at mail-index-sync-update.c:72 #11 0x79354 in t_pop () at data-stack.c:160 #12 0x6a95c in mailbox_save_init () at mail-storage.c:526 #13 0x5ced0 in mail_index_map_msync (index=0x1296c0, map=0x11) at mail-index-sync-update.c:75 #14 0x79038 in buffer_get_size () at buffer.c:293
(see http://www.dovecot.org/list/dovecot/2009-September/043126.html for "dovecot -n" output etc.)
BTW there's been no crashes of imap-login since the last patch for literals in login parameters :)
Best Wishes, Chris
--+---+---+---+---+---+---+---+---+---+---+---+---+---+---+---+---+---+- Christopher Wakelin, c.d.wakelin@reading.ac.uk IT Services Centre, The University of Reading, Tel: +44 (0)118 378 8439 Whiteknights, Reading, RG6 2AF, UK Fax: +44 (0)118 975 3094
Chris Wakelin wrote:
We've had another random imap process crash. This is with the original 1.2.5 imap (I haven't applied the patch for two processes creating an index simultaneously):
Backtrace:
Sorry, wrong binary again (it *was* rather late at night!). Here's the proper backtrace
#0 0xff21fe78 in _libc_kill () from /usr/lib/libc.so.1 #1 0xff1b5a3c in abort () from /usr/lib/libc.so.1 #2 0xbe258 in default_fatal_finish (type=LOG_TYPE_PANIC, status=0) at failures.c:160 #3 0xbeb14 in i_internal_fatal_handler (type=LOG_TYPE_PANIC, status=0, fmt=0x0, args=0xffbee9c8) at failures.c:440 #4 0xbe414 in i_panic (format=0xe29b8 "file %s: line %d (%s): assertion failed: (%s)") at failures.c:207 #5 0x5a238 in istream_raw_mbox_get_body_size (stream=0x12a250, expected_body_size=18446744073709551615) at istream-raw-mbox.c:621 #6 0x5a4d8 in istream_raw_mbox_next (stream=0x12a250, expected_body_size=18428424857071839939) at istream-raw-mbox.c:665 #7 0x5a7a0 in istream_raw_mbox_seek (stream=0x0, offset=523301) at istream-raw-mbox.c:704 #8 0x5ae58 in mbox_file_seek (mbox=0x1272a8, view=0x127c60, seq=17, deleted_r=0xffbeebb7) at mbox-file.c:177 #9 0x5c7d8 in mbox_mail_seek (mail=0x12be80) at mbox-mail.c:85 #10 0x5cd74 in mbox_mail_init_stream (mail=0x12be80) at mbox-mail.c:276 #11 0x5cea4 in mbox_mail_get_stream (_mail=0x128e24, hdr_size=0x0, body_size=0x0, stream_r=0xffbeed8c) at mbox-mail.c:318 #12 0x79354 in mail_get_stream (mail=0x0, hdr_size=0x0, body_size=0x0, stream_r=0xffbeed8c) at mail.c:168 #13 0x6a958 in index_mail_set_seq (_mail=0x12be80, seq=17) at index-mail.c:1326 #14 0x5ced0 in mbox_mail_set_seq (_mail=0x12be80, seq=17) at mbox-mail.c:329 #15 0x79034 in mail_set_seq (mail=0x12be80, seq=17) at mail.c:29 #16 0x6f864 in index_storage_search_next_nonblock (_ctx=0x12a070, mail=0x12be80, tryagain_r=0xffbeefcf) at index-search.c:1296 #17 0x7f1a0 in mailbox_search_next_nonblock (ctx=0x12a070, mail=0x12be80, tryagain_r=0xffbeefcf) at mail-storage.c:770 #18 0x7f154 in mailbox_search_next (ctx=0x12a070, mail=0x12be80) at mail-storage.c:759 #19 0x2598c in fetch_and_copy (client=0x11e8d8, destbox=0x1272a8, t=0x128c98, search_args=0x1, src_uidset_r=0xffbef0f4, copy_count_r=0xffbef0f0) at cmd-copy.c:56 #20 0x25c24 in cmd_copy (cmd=0x11eb60) at cmd-copy.c:145 #21 0x2d064 in client_command_input (cmd=0x11eb60) at client.c:611 #22 0x2cf08 in client_command_input (cmd=0x11eb60) at client.c:660 #23 0x2d0ec in client_handle_next_command (client=0x11e8d8, remove_io_r=0xffbef2d7) at client.c:701 #24 0x2d1e0 in client_handle_input (client=0x11e8d8) at client.c:713 #25 0x2d318 in client_input (client=0x11e8d8) at client.c:752 #26 0xc7ea4 in io_loop_handler_run (ioloop=0x11b370) at ioloop-poll.c:203 #27 0xc7694 in io_loop_run (ioloop=0x11b370) at ioloop.c:335 #28 0x36e34 in main (argc=1119232, argv=0xffbef51c, envp=0xffbef52c) at main.c:327
I've had another crash since with a different user but what looks like exactly the same backtrace (except for stream numbers etc.).
Best Wishes, Chris
-- --+---+---+---+---+---+---+---+---+---+---+---+---+---+---+---+---+---+- Christopher Wakelin, c.d.wakelin@reading.ac.uk IT Services Centre, The University of Reading, Tel: +44 (0)118 378 8439 Whiteknights, Reading, RG6 2AF, UK Fax: +44 (0)118 975 3094
Hi Timo,
While we're on the subject of panics and segfaults before 1.2.7, did you get a chance to look at this one? It's not happened since those two users, so it's not at all important except perhaps for tidiness!
The panic was
Oct 03 13:34:20 IMAP 6067 xxxxxxxx 134.225.1.46 : Panic: file istream-raw-mbox.c: line 578 (istream_raw_mbox_get_body_size): assertion failed: (rstream->body_offset != (uoff_t)-1)
Best Wishes, Chris
Chris Wakelin wrote:
Chris Wakelin wrote:
We've had another random imap process crash. This is with the original 1.2.5 imap (I haven't applied the patch for two processes creating an index simultaneously):
Backtrace:
Sorry, wrong binary again (it *was* rather late at night!). Here's the proper backtrace
#0 0xff21fe78 in _libc_kill () from /usr/lib/libc.so.1 #1 0xff1b5a3c in abort () from /usr/lib/libc.so.1 #2 0xbe258 in default_fatal_finish (type=LOG_TYPE_PANIC, status=0) at failures.c:160 #3 0xbeb14 in i_internal_fatal_handler (type=LOG_TYPE_PANIC, status=0, fmt=0x0, args=0xffbee9c8) at failures.c:440 #4 0xbe414 in i_panic (format=0xe29b8 "file %s: line %d (%s): assertion failed: (%s)") at failures.c:207 #5 0x5a238 in istream_raw_mbox_get_body_size (stream=0x12a250, expected_body_size=18446744073709551615) at istream-raw-mbox.c:621 #6 0x5a4d8 in istream_raw_mbox_next (stream=0x12a250, expected_body_size=18428424857071839939) at istream-raw-mbox.c:665 #7 0x5a7a0 in istream_raw_mbox_seek (stream=0x0, offset=523301) at istream-raw-mbox.c:704 #8 0x5ae58 in mbox_file_seek (mbox=0x1272a8, view=0x127c60, seq=17, deleted_r=0xffbeebb7) at mbox-file.c:177 #9 0x5c7d8 in mbox_mail_seek (mail=0x12be80) at mbox-mail.c:85 #10 0x5cd74 in mbox_mail_init_stream (mail=0x12be80) at mbox-mail.c:276 #11 0x5cea4 in mbox_mail_get_stream (_mail=0x128e24, hdr_size=0x0, body_size=0x0, stream_r=0xffbeed8c) at mbox-mail.c:318 #12 0x79354 in mail_get_stream (mail=0x0, hdr_size=0x0, body_size=0x0, stream_r=0xffbeed8c) at mail.c:168 #13 0x6a958 in index_mail_set_seq (_mail=0x12be80, seq=17) at index-mail.c:1326 #14 0x5ced0 in mbox_mail_set_seq (_mail=0x12be80, seq=17) at mbox-mail.c:329 #15 0x79034 in mail_set_seq (mail=0x12be80, seq=17) at mail.c:29 #16 0x6f864 in index_storage_search_next_nonblock (_ctx=0x12a070, mail=0x12be80, tryagain_r=0xffbeefcf) at index-search.c:1296 #17 0x7f1a0 in mailbox_search_next_nonblock (ctx=0x12a070, mail=0x12be80, tryagain_r=0xffbeefcf) at mail-storage.c:770 #18 0x7f154 in mailbox_search_next (ctx=0x12a070, mail=0x12be80) at mail-storage.c:759 #19 0x2598c in fetch_and_copy (client=0x11e8d8, destbox=0x1272a8, t=0x128c98, search_args=0x1, src_uidset_r=0xffbef0f4, copy_count_r=0xffbef0f0) at cmd-copy.c:56 #20 0x25c24 in cmd_copy (cmd=0x11eb60) at cmd-copy.c:145 #21 0x2d064 in client_command_input (cmd=0x11eb60) at client.c:611 #22 0x2cf08 in client_command_input (cmd=0x11eb60) at client.c:660 #23 0x2d0ec in client_handle_next_command (client=0x11e8d8, remove_io_r=0xffbef2d7) at client.c:701 #24 0x2d1e0 in client_handle_input (client=0x11e8d8) at client.c:713 #25 0x2d318 in client_input (client=0x11e8d8) at client.c:752 #26 0xc7ea4 in io_loop_handler_run (ioloop=0x11b370) at ioloop-poll.c:203 #27 0xc7694 in io_loop_run (ioloop=0x11b370) at ioloop.c:335 #28 0x36e34 in main (argc=1119232, argv=0xffbef51c, envp=0xffbef52c) at main.c:327
I've had another crash since with a different user but what looks like exactly the same backtrace (except for stream numbers etc.).
Best Wishes, Chris
-- --+---+---+---+---+---+---+---+---+---+---+---+---+---+---+---+---+---+- Christopher Wakelin, c.d.wakelin@reading.ac.uk IT Services Centre, The University of Reading, Tel: +44 (0)118 378 8439 Whiteknights, Reading, RG6 2AF, UK Fax: +44 (0)118 975 3094
On Thu, 2009-10-15 at 21:14 +0100, Chris Wakelin wrote:
Hi Timo,
While we're on the subject of panics and segfaults before 1.2.7, did you get a chance to look at this one? It's not happened since those two users, so it's not at all important except perhaps for tidiness!
The panic was
Oct 03 13:34:20 IMAP 6067 xxxxxxxx 134.225.1.46 : Panic: file istream-raw-mbox.c: line 578 (istream_raw_mbox_get_body_size): assertion failed: (rstream->body_offset != (uoff_t)-1)
So it has only happened twice now in total? I've seen this before but I'm not really sure how it can happen. I guess something strange in mbox file causes it. But finding its cause is probably a lot of trouble, so for now I'll just ignore it. :)
Timo Sirainen wrote:
The panic was
Oct 03 13:34:20 IMAP 6067 xxxxxxxx 134.225.1.46 : Panic: file istream-raw-mbox.c: line 578 (istream_raw_mbox_get_body_size): assertion failed: (rstream->body_offset != (uoff_t)-1)
So it has only happened twice now in total? I've seen this before but I'm not really sure how it can happen. I guess something strange in mbox file causes it. But finding its cause is probably a lot of trouble, so for now I'll just ignore it. :)
Just twice in over 1.5 million logins by over 14,000 users since the beginning of October, occurring within 12 hours of each other (but different users) at a weekend when things are supposed to be less busy...
Recreating the mbox files may be just about possible (I can retrieve the last backup plus the mail deliveries since then, then plus try to do the same deletes/purges as suggested in the logs) but as you say, probably not worth it :)
Best Wishes, Chris
-- --+---+---+---+---+---+---+---+---+---+---+---+---+---+---+---+---+---+- Christopher Wakelin, c.d.wakelin@reading.ac.uk IT Services Centre, The University of Reading, Tel: +44 (0)118 378 8439 Whiteknights, Reading, RG6 2AF, UK Fax: +44 (0)118 975 3094
participants (2)
-
Chris Wakelin
-
Timo Sirainen