[Dovecot] corrupted transaction log error resulting in multiple deliveries

[Justin McAleer]

Timo Sirainen wrote:
>
> Yes, it's supposed to recover from that. I couldn't reproduce this. It
> always fixed the problem with the next try, or 3rd try at latest. If
> this happens again, could you send me the dovecot.index and
> dovecot.index.log files?
>
>   
While attempting to recreate this I managed to crash imap. Here, I had 
Thunderbird sitting with the inbox open, I renamed the indexes directory 
and moved an older copy of the dir into place, and sent a test message. 
Ironically the message was delivered, but imap went boom:

Mar 16 12:51:15 node7 dovecot: IMAP(justin): Corrupted transaction log 
file /var/indexes//j/ju/justin/.INBOX/dovecot.index.log: file_seq=1, 
min_file_offset (63380) > max_file_offset (24)
Mar 16 12:51:15 node7 dovecot: IMAP(justin): fscking index file 
/var/indexes//j/ju/justin/.INBOX/dovecot.index
Mar 16 12:51:15 node7 dovecot: IMAP(justin): Corrupted transaction log 
file /var/indexes//j/ju/justin/.INBOX/dovecot.index.log: invalid indexid 
(1174063875 != 1174051611)
Mar 16 12:51:15 node7 dovecot: IMAP(justin): fscking index file 
/var/indexes//j/ju/justin/.INBOX/dovecot.index
Mar 16 12:51:15 node7 dovecot: IMAP(justin): Corrupted transaction log 
file /var/indexes//j/ju/justin/.INBOX/dovecot.index.log: invalid new 
transaction log sequence (2 >= 2)
Mar 16 12:51:15 node7 dovecot: IMAP(justin): fscking index file 
/var/indexes//j/ju/justin/.INBOX/dovecot.index
Mar 16 12:51:15 node7 dovecot: IMAP(justin): Unexpected transaction log 
desync with index /var/indexes//j/ju/justin/.INBOX/dovecot.index
Mar 16 12:51:15 node7 dovecot: IMAP(justin): Disconnected: Mailbox is in 
inconsistent state, please relogin.
Mar 16 12:51:15 node7 dovecot: IMAP(justin): file client.c: line 401 
(_client_input): assertion failed: (!client->handling_input)
Mar 16 12:51:15 node7 dovecot: IMAP(justin): Raw backtrace: imap 
[0x468dbc] -> imap [0x4686ac] -> imap [0x416971] -> imap [0x41363c] -> 
imap(cmd_idle+0x108) [0x413858] -> imap [0x416765] -> imap [0x41670a] -> 
imap(_client_input+0x91) [0x4168c1] -> imap(io_loop_handler_run+0x104) 
[0x46e874] -> imap(io_loop_run+0x1a) [0x46dc3a] -> imap(main+0x406) 
[0x41dfb6] -> /lib64/tls/libc.so.6(__libc_start_main+0xdb) 
[0x31c8a1c3fb] -> imap [0x411b3a]
Mar 16 12:51:15 node7 dovecot: child 31850 (imap) killed with signal 6

However, I think a more simple way to recreate the problem is to simply 
delete an existing maildir (with existing indexes) and send a message to 
it. This shows the behavior every time on my system. I'll attach a tar 
of all files in the index dir to this email though.
-------------- next part --------------
A non-text attachment was scrubbed...
Name: indexfiles.tar.gz
Type: application/x-gzip
Size: 6407 bytes
Desc: not available
Url : http://dovecot.org/pipermail/dovecot/attachments/20070316/3778b636/attachment-0001.bin