dovecot - Jan 2013 - assert in mail-transaction-log-file.c

I setup new server with dovecot 2.1.12 and mboxes from backup (moboxes
was used with dovecot 1.1.6).
OS: FreeBSD 8.3-STABLE, amd64.

All index files from dovecot 1.1.6 has been deleted.

Some times dovecot processes aborted.

E. g.

Jan 25 03:01:52 ost dovecot: lda(user at example.ru): Panic: file
mail-transaction-log-file.c: line 1694 (mail_transaction_log_file_map):
assertion failed: (file->buffer != NULL)

(gdb) bt
#0  0x0000000800bd610c in kill () from /lib/libc.so.7
#1  0x0000000800bd4f0b in abort () from /lib/libc.so.7
#2  0x000000080099b339 in default_fatal_finish (type=72898, status=0) at
failures.c:191
#3  0x000000080099b3be in i_syslog_fatal_handler (ctx=<value optimized
out>, format=<value optimized out>, args=<value optimized out>)
at failures.c:413
#4  0x000000080099a8a3 in i_panic (format=<value optimized out>) at
failures.c:263
#5  0x000000080081bdb6 in mail_transaction_log_file_map (file=0x801670e00,
start_offset=40, end_offset=18446744073709551615) at
mail-transaction-log-file.c:1694
#6  0x000000080081da41 in mail_transaction_log_view_set (view=0x801654a80,
min_file_seq=1, min_file_offset=40, max_file_seq=2,
max_file_offset=18446744073709551615,
    reset_r=0x7fffffffbedf) at mail-transaction-log-view.c:228
#7  0x000000080081519d in mail_index_sync_map (_map=0x801670b08,
type=MAIL_INDEX_SYNC_HANDLER_HEAD, force=false) at mail-index-sync-update.c:950
#8  0x0000000800805be0 in mail_index_map (index=0x801670a80,
type=MAIL_INDEX_SYNC_HANDLER_HEAD) at mail-index-map-read.c:415
#9  0x0000000800800bde in mail_index_refresh (index=<value optimized out>)
at mail-index.c:735
#10 0x00000008007b2344 in mbox_sync_header_refresh (mbox=0x801680840) at
mbox-sync.c:1652
#11 0x00000008007b24e2 in mbox_sync_has_changed_full (mbox=0x801680840,
leave_dirty=true, empty_r=0x7fffffffe2e8) at mbox-sync.c:1729
#12 0x00000008007ae1a7 in mbox_save_begin (_ctx=0x80161a500, input=0x801669660)
at mbox-save.c:296
#13 0x00000008018025ae in notify_save_begin (ctx=0x80161a500, input=0x801669660)
at notify-storage.c:130
#14 0x00000008014261fd in quota_save_begin (ctx=0x80161a500, input=0x801669660)
at quota-storage.c:251
#15 0x00000008007cfecc in mailbox_save_begin (ctx=0x7fffffffe3d0,
input=0x801669660) at mail-storage.c:1652
#16 0x00000008007ca48d in mail_storage_copy (ctx=0x80161a500, mail=0x801637040)
at mail-copy.c:68
#17 0x000000080180269d in notify_copy (ctx=0x80161a500, mail=0x801637040) at
notify-storage.c:105
#18 0x00000008014262f6 in quota_copy (ctx=0x80161a500, mail=0x801637040) at
quota-storage.c:200
#19 0x00000008007cfe04 in mailbox_copy (_ctx=<value optimized out>,
mail=0x801637040) at mail-storage.c:1721
#20 0x0000000801b4b706 in act_store_execute (action=<value optimized out>,
aenv=0x8016a3070, tr_context=<value optimized out>) at sieve-actions.c:551
#21 0x0000000801b428de in sieve_result_execute (result=0x8016a3040, keep=0x0) at
sieve-result.c:1117
#22 0x0000000801b52d5a in sieve_execute (sbin=<value optimized out>,
msgdata=<value optimized out>, senv=<value optimized out>,
ehandler=<value optimized out>,
    flags=<value optimized out>, keep=0x0) at sieve.c:508
#23 0x0000000801a0aec6 in lda_sieve_deliver_mail (mdctx=0x7fffffffe970,
storage_r=0x7fffffffe8e8) at lda-sieve-plugin.c:424
#24 0x0000000800651735 in mail_deliver (ctx=0x7fffffffe970,
storage_r=0x7fffffffe8e8) at mail-deliver.c:390
#25 0x0000000000402ffa in main (argc=6, argv=0x7fffffffea78) at main.c:434
(gdb) f 5
(gdb) p *file
$1 = {log = 0x8016463d0, next = 0x0, refcount = 5, filepath = 0x801620420
"(in-memory index).log", fd = -1, st_ino = 13919248, st_dev = 109,
last_mtime = 1359082912,
  last_size = 0, hdr = {major_version = 1 '\001', minor_version = 2
'\002', hdr_size = 40, indexid = 1359082912, file_seq = 2, prev_file_seq
= 0, prev_file_offset = 0,
    create_stamp = 1359082912, initial_modseq = 0, compat_flags = 1
'\001', unused = "\000\000", unused2 = 0}, mmap_buffer = {data
= 0x0, used = 0, priv = {0x0, 0x0, 0x0, 0x0,
      0x0}}, buffer = 0x0, buffer_offset = 0, mmap_base = 0x0, mmap_size = 0,
sync_offset = 40, sync_highest_modseq = 0, saved_tail_offset = 0,
max_tail_offset = 0,
  saved_tail_sync_offset = 0, index_deleted_offset = 0, index_undeleted_offset =
0, modseq_cache = {{offset = 0, highest_modseq = 0}, {offset = 0, highest_modseq
= 0}, {
      offset = 0, highest_modseq = 0}, {offset = 0, highest_modseq = 0}, {offset
= 0, highest_modseq = 0}, {offset = 0, highest_modseq = 0}, {offset = 0,
highest_modseq = 0}, {
      offset = 0, highest_modseq = 0}, {offset = 0, highest_modseq = 0}, {offset
= 0, highest_modseq = 0}}, file_lock = 0x0, lock_created = 0, locked = 0,
  locked_sync_offset_updated = 0, corrupted = 0}


Also same aborts can happen in imap processes:
Jan 24 16:35:04 ost dovecot: imap(user at example.ru): Panic: file
mail-transaction-log-file.c: line 1694 (mail_transaction_log_file_map):
assertion failed: (file->buffer != NULL)

-- 
 Anton Yuzhaninov

On 25.1.2013, at 13.28, Anton Yuzhaninov <citrin at citrin.ru> wrote:
> I setup new server with dovecot 2.1.12 and mboxes from backup (moboxes
> was used with dovecot 1.1.6).
> OS: FreeBSD 8.3-STABLE, amd64.
> 
> All index files from dovecot 1.1.6 has been deleted.
> 
> Some times dovecot processes aborted.
> 
> E. g.
> 
> Jan 25 03:01:52 ost dovecot: lda(user at example.ru): Panic: file
mail-transaction-log-file.c: line 1694 (mail_transaction_log_file_map):
assertion failed: (file->buffer != NULL)
Hmm. Not sure about this .. I guess either you're running out of quota for
the user, or mbox_min_index_size isn't 0. It still should work though, but
maybe too much trouble to figure out what exactly is wrong. Anyway, this should
cause it to give an error message instead of crash:
http://hg.dovecot.org/dovecot-2.1/rev/e33fe1a7bb89