dovecot - Oct 2009 - 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 at 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 at 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