dovecot - May 2014 - WG: on High Load using IMAPSYNC : Panic: file ostream-lzma.c: line 147: unreached. Dovecot 2.2.12 with zlib/XZ compression

when syncing Mailboxes with IMAPSYNC, using xz compression the dbox file 
gets corrupted.
the same configuration was working ok on low load with xz compression.

Dovecot Version 2.2.12
Linux Mint 16
EXT4 Filesystem

another dovecot user already reported the same problem on the mailinglist, 

using dsync. That user switched to bz2 compression what worked for him.

the answer was : 
> are you on latest patchlevel ?
> there are some dsync fixes since 2.2.12
but it is not a problem of dsync.
when looking at the code, we get here an unexpected returnvalue when 
flushing.

I propose it would be good practice to write some logging in the default 
switch cases, to see the unexpected returnvalues in the errorlog.

something like : 

ostream-lzma.c : 
-- Line 147 :   i_unreached();
++ Line 147 :   i_fatal("unexpected lzma errorcode when flushing :
%s",
ret);

after that modification the errorlog shows : 

May  6 14:03:05 vm-imap dovecot: imap(test): Fatal: lzma errorcode when 
flushing : (null)

maybe You can also investigate and let me know when fixed.

Here the log : 

May  5 14:53:10 vm-imap dovecot: imap(rrernboeck): Panic: file 
ostream-lzma.c: line 147: unreached
May  5 14:53:10 vm-imap dovecot: imap(rrernboeck): Error: Raw backtrace: 
/usr/local/lib/dovecot/libdovecot.so.0(+0x67450) [0x7ff99d8ce450] -> 
/usr/local/lib/dovecot/libdovecot.so.0(+0x6752e) [0x7ff99d8ce52e] -> 
/usr/local/lib/dovecot/libdovecot.so.0(i_fatal+0) [0x7ff99d88955e] -> 
/usr/local/lib/dovecot/lib20_zlib_plugin.so(+0x4f0a) [0x7ff99ce87f0a] -> 
/usr/local/lib/dovecot/libdovecot.so.0(o_stream_flush+0x3e) 
[0x7ff99d8e6dbe] -> 
/usr/local/lib/dovecot/libdovecot.so.0(o_stream_nflush+0xf) 
[0x7ff99d8e71df] -> 
/usr/local/lib/dovecot/libdovecot.so.0(o_stream_nfinish+0x9) 
[0x7ff99d8e7229] -> 
/usr/local/lib/dovecot/libdovecot-storage.so.0(dbox_save_end+0x29) 
[0x7ff99db7cfa9] -> 
/usr/local/lib/dovecot/libdovecot-storage.so.0(mdbox_save_finish+0x39) 
[0x7ff99db76619] -> 
/usr/local/lib/dovecot/libdovecot-storage.so.0(mailbox_save_finish+0x4d) 
[0x7ff99dbb6a4d] -> dovecot/imap [rrernboeck 127.0.0.1 APPEND]() 
[0x40be09] -> dovecot/imap [rrernboeck 127.0.0.1 
APPEND](command_exec+0x3c) [0x416cfc] -> dovecot/imap [rrernboeck 
127.0.0.1 APPEND]() [0x40b491] -> 
/usr/local/lib/dovecot/libdovecot.so.0(io_loop_call_io+0x27) 
[0x7ff99d8de527] -> 
/usr/local/lib/dovecot/libdovecot.so.0(io_loop_handler_run+0xd7) 
[0x7ff99d8df2b7] -> 
/usr/local/lib/dovecot/libdovecot.so.0(io_loop_run+0x38) [0x7ff99d8de0c8] 
-> /usr/local/lib/dovecot/libdovecot.so.0(master_service_run+0x13) 
[0x7ff99d88e753] -> dovecot/imap [rrernboeck 127.0.0.1 APPEND](main+0x2af) 

[0x40b06f] -> /lib/x86_64-linux-gnu/libc.so.6(__libc_start_main+0xf5) 
[0x7ff99d4c0de5] -> dovecot/imap [rrernboeck 127.0.0.1 APPEND]() 
[0x40b1cc]
May  5 14:53:10 vm-imap dovecot: imap(rrernboeck): Fatal: master: 
service(imap): child 47957 killed with signal 6 (core dumped)
May  5 14:53:10 vm-imap dovecot: imap(rrernboeck): Error: Corrupted dbox 
file /home/vmail/virtualmailboxes/rrernboeck/storage/m.1 (around 
offset=1302): msg header has bad magic value

On 05/06/2014 04:39 PM, Robert Nowotny wrote:
> I propose it would be good practice to write some logging in the default 
> switch cases, to see the unexpected returnvalues in the errorlog.
> 
> something like : 
> 
> ostream-lzma.c : 
> -- Line 147 :   i_unreached();
> ++ Line 147 :   i_fatal("unexpected lzma errorcode when flushing :
%s",
> ret);
> 
> after that modification the errorlog shows : 
> 
> May  6 14:03:05 vm-imap dovecot: imap(test): Fatal: lzma errorcode when 
> flushing : (null)
The code change should be i_fatal("unexpected lzma errorcode when flushing
: %d", ret);
since ret is an integer.

A logging change like that is a good idea and we have been meaning to do
something similar. It would help debugging, if you
could continue running it in your setup, where the error seems to occur quite
frequently. Also tell me if you figure out what
data or action triggers it.

br,
Teemu Huovila