[Dovecot] mbox bug in 1.0.0

[bhayden at umn.edu]

On Jun 19 2007, bhayden at umn.edu wrote:

>On May 13 2007, Timo Sirainen wrote:
>
>>On Mon, 2007-04-23 at 13:40 -0500, bhayden at umn.edu wrote:
>>> Apr 23 13:22:41 server.umn.edu dovecot: [ID 107833 local6.error]
>>> [9073] 
>>> IMAP(USER): mbox /var/mail/user: seq=1 uid=8808 uid_broken=0 originally 
>>> needed 10 bytes, now needs 23 bytes
>>
>>Anything else than Dovecot accessing these mboxes (besides MDA)?
>
>Nope. Dovecot IMAP and deliver. 
>
>>Do you have a core file from that crash? It would show a bit more
>>information. If not, see http://dovecot.org/bugreport.html

So, I'm including a backtrace for this. Sorry if you replied earlier and I 
missed it! Please let me know what else you might need. We're seeing this 
on about three dozen inboxes (which is a very small percentage, but a large 
enough number to hear about it :) ).

(dbx) where
  [1] 0xff1c16e8(0x6, 0x0, 0xff1a4d28, 0xffffffff, 0xff1e8298, 0x6), at 
0xff1c16e8
  [2] _getutxline(0x9d8b0, 0x1, 0xb00e0, 0xa8244, 0xff1eb298, 0x0), at 
0xff140158 =>[3] i_internal_panic_handler(fmt = 0x93b88 "mbox %s: seq=%u 
uid=%u uid_broken=%d originally needed %llu bytes, now needs %u bytes", 
args = 0xffbfe7d0), line 403 in "failures.c"
  [4] i_panic(format = 0x93b88 "mbox %s: seq=%u uid=%u uid_broken=%d 
originally needed %llu bytes, now needs %u bytes", ...), line 183 in 
"failures.c"
  [5] mbox_sync_rewrite(sync_ctx = 0xffbfefd0, mail_ctx = (nil), end_offset 
= 4448ULL, move_diff = 30LL, extra_space = 4294971774ULL, first_seq = 1U, 
last_seq = 163U), line 422 in "mbox-sync-rewrite.c"
  [6] mbox_sync_do(sync_ctx = 0xffbfefd0, flags = -4198952), line 920 in 
"mbox-sync.c"
  [7] mbox_sync(mbox = 0xc99e0, flags = MBOX_SYNC_UNDIRTY), line 1873 in 
"mbox-sync.c"
  [8] mbox_storage_sync_init(box = 0xc99e0, flags = 
MAILBOX_SYNC_FLAG_FULL_READ), line 1957 in "mbox-sync.c"
  [9] mailbox_sync_init(box = 0xc99e0, flags = 
MAILBOX_SYNC_FLAG_FULL_READ), line 406 in "mail-storage.c"
  [10] imap_sync_nonselected(box = 0xc99e0, flags = 
MAILBOX_SYNC_FLAG_FULL_READ), line 196 in "imap-sync.c"
  [11] _cmd_select_full(cmd = 0xc39e4, readonly = 0), line 39 in 
"cmd-select.c"
  [12] cmd_select(cmd = 0xc39e4), line 92 in "cmd-select.c"
  [13] client_handle_input(cmd = 0xc39e4), line 335 in "client.c"
  [14] client_handle_input(cmd = 0xc39e4), line 389 in "client.c"
  [15] _client_input(context = 0xc39a0), line 432 in "client.c"
  [16] io_loop_handler_run(ioloop = 0xb9f08), line 199 in "ioloop-poll.c"
  [17] io_loop_run(ioloop = 0xb9f08), line 326 in "ioloop.c"
  [18] main(argc = -4195453, argv = 0xb0800, envp = 0xb1be4), line 290 in 
"main.c"

And in case it helps, a dump from frame [5] which is the last bit before 
the crash:

(dbx) frame 5
Current function is mbox_sync_rewrite
  422 i_panic("mbox %s: seq=%u uid=%u uid_broken=%d " (dbx) dump
 first_nonexpunged = 255U
 move_diff = 30LL
 ret = 0
 mails = 0xcd810
 idx = 0
 padding_per_mail = 20U
 first_nonexpunged_idx = 0
 expunged_space = 0
 sync_ctx = 0xffbfefd0
 extra_space = 4294971774ULL
 mail_ctx = (nil)
 dest_offset = 0
 count = 2U
 last_seq = 163U
 orig_prev_msg_uid = 1359U
 next_move_diff = 10ULL
 end_offset = 4448ULL
 __PRETTY_FUNCTION__ = "mbox_sync_rewrite"
 start_offset = 0
 offset = 4294971774ULL
 first_seq = 1U
 next_end_offset = 52ULL

>>If these happen frequently, I could also send a debug patch that writes
>>the broken mbox headers to some temp file. That with the core file would
>>provide enough information to figure out what exactly is the problem.

This is still an option, if it would help. 

-Brian Hayden
Internet Services
University of MN