Hi,
I found these in my logs:
Jan 5 15:58:56 mail dovecot: imap-login: Login: user=<xy at z.com>,
method=PLAIN, rip=1.2.3.4, lip=2.3.4.5, mpid=5852, TLS,
session=<K2oaPLd+885fWs6U>
Jan 5 15:58:56 mail dovecot: imap-login: Login: user=<xy at z.com>,
method=PLAIN, rip=1.2.3.4, lip=2.3.4.5, mpid=5854, TLS,
session=<uxAjPLd+ys5fWs6U>
Jan 5 15:58:56 mail dovecot: imap(<xy at z.com>): Error: Maildir
filename has wrong S value, renamed the file from /var/vmail/mailboxes/<xy at
z.com>/mail/Sent/cur/1537260554.M80670P8164.mail,S=17247,W=17549:2,Sab,Z to
/var/vmail/mailboxes/<xy at
z.com>/mail/Sent/cur/1537260554.M80670P8164.mail,S=4172:2,Sab,Z
Jan 5 15:58:56 mail dovecot: imap(<xy at z.com>): Error: Corrupted
index cache file /var/vmail/mailboxes/<xy at
z.com>/mail/Sent/dovecot.index.cache: Broken physical size for mail UID 99 in
mailbox Sent: read(zlib(/var/vmail/mailboxes/<xy at
z.com>/mail/Sent/cur/1537260554.M80670P8164.mail,S=17247,W=17549:2,Sab,Z))
failed: Cached message size larger than expected (17247 > 4268, box=Sent,
UID=99)
Jan 5 15:58:56 mail dovecot: imap(<xy at z.com>): Panic: file
istream.c: line 175 (i_stream_read): assertion failed: (old_size <=
_stream->pos - _stream->skip)
Jan 5 15:58:56 mail dovecot: imap(<xy at z.com>): Error: Raw
backtrace: /usr/lib/dovecot/libdovecot.so.0(+0x95e92) [0x7f5068d3ee92] ->
/usr/lib/dovecot/libdovecot.so.0(+0x95f8d) [0x7f5068d3ef8d] ->
/usr/lib/dovecot/libdovecot.so.0(i_fatal+0) [0x7f5068cd4a91] ->
/usr/lib/dovecot/libdovecot.so.0(i_stream_read+0x290) [0x7f5068d49f20] ->
/usr/lib/dovecot/libdovecot.so.0(i_stream_read_data+0x3d) [0x7f5068d4a72d] ->
/usr/lib/dovecot/libdovecot.so.0(message_parse_header_next+0x72)
[0x7f5068d25d12] -> /usr/lib/dovecot/libdovecot.so.0(+0x76fd1)
[0x7f5068d1ffd1] -> /usr/lib/dovecot/libdovecot.so.0(i_stream_read+0x53)
[0x7f5068d49ce3] -> /usr/lib/dovecot/libdovecot.so.0(i_stream_read_data+0x3d)
[0x7f5068d4a72d] ->
/usr/lib/dovecot/libdovecot.so.0(message_parse_header_next+0x72)
[0x7f5068d25d12] -> /usr/lib/dovecot/libdovecot.so.0(+0x76fd1)
[0x7f5068d1ffd1] -> /usr/lib/dovecot/libdovecot.so.0(i_stream_read+0x53)
[0x7f5068d49ce3] -> /usr/lib/dovecot/libdovecot.so.0(i_stream_read_data+0x3d)
[0x7f5068d4a72d] ->
/usr/lib/dovecot/libdovecot.so.0(message_get_header_size+0x74) [0x7f5068d29904]
-> /usr/lib/dovecot/libdovecot-storage.so.0(imap_msgpart_open+0x32f)
[0x7f50690b52ef] -> dovecot/imap(+0x1ebbc) [0x556dd2cd7bbc] ->
dovecot/imap(+0x1cfb6) [0x556dd2cd5fb6] -> dovecot/imap(imap_fetch_more+0x39)
[0x556dd2cd70e9] -> dovecot/imap(cmd_fetch+0x33b) [0x556dd2cc8d9b] ->
dovecot/imap(command_exec+0xa5) [0x556dd2cd4735] -> dovecot/imap(+0x199c2)
[0x556dd2cd29c2] -> dovecot/imap(+0x19a4c) [0x556dd2cd2a4c] ->
dovecot/imap(client_handle_input+0x1b5) [0x556dd2cd2e55] ->
dovecot/imap(client_input+0x86) [0x556dd2cd33c6] ->
/usr/lib/dovecot/libdovecot.so.0(io_loop_call_io+0x52) [0x7f5068d539f2] ->
/usr/lib/dovecot/libdovecot.so.0(io_loop_handler_run_internal+0x109)
[0x7f5068d55029] ->
/usr/lib/dovecot/libdovecot.so.0(io_loop_handler_run+0x3c) [0x7f5068d53a8c]
-> /usr/lib/dovecot/libdovecot.so.0(io_loop_run+0x38) [0x7f5068d53c38]
Jan 5 15:58:56 mail dovecot: imap(<xy at z.com>): Fatal: master:
service(imap): child 5852 killed with signal 6 (core dumps disabled)
# and again:
Jan 5 15:58:56 mail dovecot: imap(<xy at z.com>): Error: Maildir
filename has wrong S value, renamed the file from /var/vmail/mailboxes/<xy at
z.com>/mail/Sent/cur/1537260554.M80670P8164.mail,S=4172:2,Sab,Z to
/var/vmail/mailboxes/<xy at
z.com>/mail/Sent/cur/1537260554.M80670P8164.mail,S=4268:2,Sab,Z
Jan 5 15:58:56 mail dovecot: imap(<xy at z.com>): Error: Corrupted
index cache file /var/vmail/mailboxes/<xy at
z.com>/mail/Sent/dovecot.index.cache: Broken physical size for mail UID 254
in mailbox Sent: read(zlib(/var/vmail/mailboxes/<xy at
z.com>/mail/Sent/cur/1537260554.M80670P8164.mail,S=4172:2,Sab,Z)) failed:
Cached message size smaller than expected (4172 < 4268, box=Sent, UID=254)
Jan 5 15:58:56 mail dovecot: imap(<xy at z.com>): Panic: file
istream.c: line 212 (i_stream_read): assertion failed:
(!i_stream_is_buffer_invalid(_stream))
Jan 5 15:58:56 mail dovecot: imap(<xy at z.com>): Error: Raw
backtrace: /usr/lib/dovecot/libdovecot.so.0(+0x95e92) [0x7f1dd9f6be92] ->
/usr/lib/dovecot/libdovecot.so.0(+0x95f8d) [0x7f1dd9f6bf8d] ->
/usr/lib/dovecot/libdovecot.so.0(i_fatal+0) [0x7f1dd9f01a91] ->
/usr/lib/dovecot/libdovecot.so.0(i_stream_read+0x190) [0x7f1dd9f76e20] ->
/usr/lib/dovecot/libdovecot.so.0(i_stream_read_data+0x3d) [0x7f1dd9f7772d] ->
/usr/lib/dovecot/libdovecot.so.0(message_get_header_size+0x74) [0x7f1dd9f56904]
-> /usr/lib/dovecot/libdovecot-storage.so.0(index_mail_init_stream+0x388)
[0x7f1dda2a7538] -> /usr/lib/dovecot/libdovecot-storage.so.0(+0x66fc0)
[0x7f1dda25efc0] ->
/usr/lib/dovecot/libdovecot-storage.so.0(mail_get_stream_because+0x5d)
[0x7f1dda22ee1d] -> /usr/lib/dovecot/libdovecot-storage.so.0(+0x66d87)
[0x7f1dda25ed87] ->
/usr/lib/dovecot/libdovecot-storage.so.0(mail_get_virtual_size+0x33)
[0x7f1dda22ea83] -> dovecot/imap(+0x1eae3) [0x5595eb2dfae3] ->
dovecot/imap(+0x1cfb6) [0x5595eb2ddfb6] -> dovecot/imap(imap_fetch_more+0x39)
[0x5595eb2df0e9] -> dovecot/imap(cmd_fetch+0x33b) [0x5595eb2d0d9b] ->
dovecot/imap(command_exec+0xa5) [0x5595eb2dc735] -> dovecot/imap(+0x199c2)
[0x5595eb2da9c2] -> dovecot/imap(+0x19a4c) [0x5595eb2daa4c] ->
dovecot/imap(client_handle_input+0x1b5) [0x5595eb2dae55] ->
dovecot/imap(client_input+0x86) [0x5595eb2db3c6] ->
/usr/lib/dovecot/libdovecot.so.0(io_loop_call_io+0x52) [0x7f1dd9f809f2] ->
/usr/lib/dovecot/libdovecot.so.0(io_loop_handler_run_internal+0x109)
[0x7f1dd9f82029] ->
/usr/lib/dovecot/libdovecot.so.0(io_loop_handler_run+0x3c) [0x7f1dd9f80a8c]
-> /usr/lib/dovecot/libdovecot.so.0(io_loop_run+0x38) [0x7f1dd9f80c38] ->
/usr/lib/dovecot/libdovecot.so.0(master_service_run+0x13) [0x7f1dd9f07fd3] ->
dovecot/imap(main+0x328) [0x5595eb2cde68] ->
/lib/x86_64-linux-gnu/libc.so.6(__libc_start_main+0xf1) [0x7f1dd9b572e1] ->
dovecot/imap(_start+0x2a) [0x5595eb2cdfea]
Jan 5 15:58:56 mail dovecot: imap(<xy at z.com>): Fatal: master:
service(imap): child 5854 killed with signal 6 (core dumps disabled)
Trying to read them with zcat they turned out to be binary. I figured out they
might accidentally be compressed twice - they are.
How could this happen?
I used this script: dovecot-maildir-compress.sh
(https://gist.github.com/cviebrock/e37f80a3223dfee19051c936c5ebe509),
which appends an additional flag 'Z' after processing/conmpressong the
mail and only compresses those without the flag:
> find=$(find "$maildir" -type f -name "*,S=*"
-mtime +30 ! -name "*,*:2,*,*Z*" -printf "%f\n")
... > if echo $flags | grep
',';> then
> newname=$filename"Z"
> else
> newname=$filename",Z"
which is actually neat.
Now two possible things:
(1) I am not quite sure yet but my best guess is that moving messages from one
folder to another
(via mail client) the message looses it's 'Z' flag.
(2) compressing might have failed to rename but successfully compressed the file
and the another
consecutive run of the script compressed the file again.
How could I recursively
(a) check each maildir file if e.g. the output of(zcat $file | zcat) is
ASCII or !binary
(b) find all mails which are compressed - i.e. valid gzip - but miss the
'Z' flag ?
(c) find all mails that are valid gzip but dont contain ASCII if / dont
uncompress to mail ?
There are backups in place for all files I get a error for, but I want to
recursively fix the problem.
Any hint?
Thanks in advance!
-M
--
info at awib.it
