Index corruption in 2.2.18
We are using dbox with lz4 compression and dovecot-lda + sieve for delivery.
Mail recieved: Mar 16 06:27:55 mail2 dovecot: lda(svs@example.com): sieve: msgid=20160316032754.4C89D2C4@rdbms.oldstable.office.example.com: stored mail into mailbox 'INBOX'
Around 08:14:00 user start his thunderbird with local filters. He found one mail without headers.
Around that time user do repair folder in thunderbird: Mar 16 10:14:44 mail2 dovecot: imap(svs@example.com): Error: read(/mail/boxes/example.com/svs/storage/m.139) failed: Cached message size larger than expected (1572 > 980, box=Logs/Backup, UID=9763, cached Message-Id=20160316032754.4C89D2C4@rdbms.oldstable.office.example.com) Mar 16 10:14:44 mail2 dovecot: imap(svs@example.com): Error: Corrupted index cache file /mail/boxes/example.com/svs/mailboxes/Logs/Backup/dbox-Mails/dovecot.index.cache: Broken physical size for mail UID 9763 Mar 16 10:14:44 mail2 dovecot: imap(svs@example.com): Error: read(/mail/boxes/example.com/svs/storage/m.139) failed: Cached message size larger than expected (1572 > 980, box=Logs/Backup, UID=9763, cached Message-Id=20160316032754.4C89D2C4@rdbms.oldstable.office.example.com) (FETCH BODY[] for mailbox Logs/Backup UID 9763) Mar 16 10:14:44 mail2 dovecot: imap(svs@example.com): Disconnected: FETCH read() failed in=14812 out=1077049 Mar 16 10:14:45 mail2 dovecot: imap(svs@example.com): Error: read(/mail/boxes/example.com/svs/storage/m.139): FETCH BODY[] for mailbox Logs/Backup UID 9763 got too little data: 1008 vs 1613 Mar 16 10:14:45 mail2 dovecot: imap(svs@example.com): Error: Corrupted index cache file /mail/boxes/example.com/svs/mailboxes/Logs/Backup/dbox-Mails/dovecot.index.cache: Broken virtual size for mail UID 9763 Mar 16 10:14:45 mail2 dovecot: imap(svs@example.com): Disconnected: FETCH failed in=837 out=641651
And still in a same state: Mar 16 11:42:51 mail2 dovecot: imap(svs@example.com): Error: read(/mail/boxes/example.com/svs/storage/m.139): FETCH BODY[] for mailbox Logs/Backup UID 9763 got too little data: 1008 vs 1613 Mar 16 11:42:51 mail2 dovecot: imap(svs@example.com): Error: Corrupted index cache file /mail/boxes/example.com/svs/mailboxes/Logs/Backup/dbox-Mails/dovecot.index.cache: Broken virtual size for mail UID 9763 Mar 16 11:42:51 mail2 dovecot: imap(svs@example.com): Disconnected: FETCH failed in=12462 out=984043
In thunderbird we see raw lz4 data.
I have today backup (duplicate mail on exim to per day mbox). So I can restore that message, but I found older problems in other mailboxes and I can't restore it due to tapes rotation
I see a lot of fixes in 2.2.19? Was it fixed after 2.2.18?
-- Anton Chevychalov
On 16 Mar 2016, at 20:09, Anton Chevychalov ac@stacksoft.ru wrote:
We are using dbox with lz4 compression and dovecot-lda + sieve for delivery.
Mail recieved: Mar 16 06:27:55 mail2 dovecot: lda(svs@example.com): sieve: msgid=20160316032754.4C89D2C4@rdbms.oldstable.office.example.com: stored mail into mailbox 'INBOX'
Around 08:14:00 user start his thunderbird with local filters. He found one mail without headers.
Around that time user do repair folder in thunderbird: Mar 16 10:14:44 mail2 dovecot: imap(svs@example.com): Error: read(/mail/boxes/example.com/svs/storage/m.139) failed: Cached message size larger than expected (1572 > 980, box=Logs/Backup, UID=9763, cached Message-Id=20160316032754.4C89D2C4@rdbms.oldstable.office.example.com) Mar 16 10:14:44 mail2 dovecot: imap(svs@example.com): Error: Corrupted index cache file /mail/boxes/example.com/svs/mailboxes/Logs/Backup/dbox-Mails/dovecot.index.cache: Broken physical size for mail UID 9763 Mar 16 10:14:44 mail2 dovecot: imap(svs@example.com): Error: read(/mail/boxes/example.com/svs/storage/m.139) failed: Cached message size larger than expected (1572 > 980, box=Logs/Backup, UID=9763, cached Message-Id=20160316032754.4C89D2C4@rdbms.oldstable.office.example.com) (FETCH BODY[] for mailbox Logs/Backup UID 9763) Mar 16 10:14:44 mail2 dovecot: imap(svs@example.com): Disconnected: FETCH read() failed in=14812 out=1077049 Mar 16 10:14:45 mail2 dovecot: imap(svs@example.com): Error: read(/mail/boxes/example.com/svs/storage/m.139): FETCH BODY[] for mailbox Logs/Backup UID 9763 got too little data: 1008 vs 1613 Mar 16 10:14:45 mail2 dovecot: imap(svs@example.com): Error: Corrupted index cache file /mail/boxes/example.com/svs/mailboxes/Logs/Backup/dbox-Mails/dovecot.index.cache: Broken virtual size for mail UID 9763 Mar 16 10:14:45 mail2 dovecot: imap(svs@example.com): Disconnected: FETCH failed in=837 out=641651
And still in a same state: Mar 16 11:42:51 mail2 dovecot: imap(svs@example.com): Error: read(/mail/boxes/example.com/svs/storage/m.139): FETCH BODY[] for mailbox Logs/Backup UID 9763 got too little data: 1008 vs 1613 Mar 16 11:42:51 mail2 dovecot: imap(svs@example.com): Error: Corrupted index cache file /mail/boxes/example.com/svs/mailboxes/Logs/Backup/dbox-Mails/dovecot.index.cache: Broken virtual size for mail UID 9763 Mar 16 11:42:51 mail2 dovecot: imap(svs@example.com): Disconnected: FETCH failed in=12462 out=984043
In thunderbird we see raw lz4 data.
I have today backup (duplicate mail on exim to per day mbox). So I can restore that message, but I found older problems in other mailboxes and I can't restore it due to tapes rotation
I see a lot of fixes in 2.2.19? Was it fixed after 2.2.18?
Probably this: https://github.com/dovecot/core/commit/879dfd4da1a9a379936b8d51c1e00c3bd7787...
The mails aren't actually corrupted. Dovecot just didn't detect LZ4 compressed mails correctly always. v2.2.22 should help.
Yep, 2.2.22 fix the problem.
Thank you.
-- Anton
On Wed, 16 Mar 2016 21:26:02 +1100 Timo Sirainen tss@iki.fi wrote:
On 16 Mar 2016, at 20:09, Anton Chevychalov ac@stacksoft.ru wrote:
We are using dbox with lz4 compression and dovecot-lda + sieve for delivery.
Mail recieved: Mar 16 06:27:55 mail2 dovecot: lda(svs@example.com): sieve: msgid=20160316032754.4C89D2C4@rdbms.oldstable.office.example.com: stored mail into mailbox 'INBOX'
Around 08:14:00 user start his thunderbird with local filters. He found one mail without headers.
Around that time user do repair folder in thunderbird: Mar 16 10:14:44 mail2 dovecot: imap(svs@example.com): Error: read(/mail/boxes/example.com/svs/storage/m.139) failed: Cached message size larger than expected (1572 > 980, box=Logs/Backup, UID=9763, cached Message-Id=20160316032754.4C89D2C4@rdbms.oldstable.office.example.com) Mar 16 10:14:44 mail2 dovecot: imap(svs@example.com): Error: Corrupted index cache file /mail/boxes/example.com/svs/mailboxes/Logs/Backup/dbox-Mails/dovecot.index.cache: Broken physical size for mail UID 9763 Mar 16 10:14:44 mail2 dovecot: imap(svs@example.com): Error: read(/mail/boxes/example.com/svs/storage/m.139) failed: Cached message size larger than expected (1572 > 980, box=Logs/Backup, UID=9763, cached Message-Id=20160316032754.4C89D2C4@rdbms.oldstable.office.example.com) (FETCH BODY[] for mailbox Logs/Backup UID 9763) Mar 16 10:14:44 mail2 dovecot: imap(svs@example.com): Disconnected: FETCH read() failed in=14812 out=1077049 Mar 16 10:14:45 mail2 dovecot: imap(svs@example.com): Error: read(/mail/boxes/example.com/svs/storage/m.139): FETCH BODY[] for mailbox Logs/Backup UID 9763 got too little data: 1008 vs 1613 Mar 16 10:14:45 mail2 dovecot: imap(svs@example.com): Error: Corrupted index cache file /mail/boxes/example.com/svs/mailboxes/Logs/Backup/dbox-Mails/dovecot.index.cache: Broken virtual size for mail UID 9763 Mar 16 10:14:45 mail2 dovecot: imap(svs@example.com): Disconnected: FETCH failed in=837 out=641651
And still in a same state: Mar 16 11:42:51 mail2 dovecot: imap(svs@example.com): Error: read(/mail/boxes/example.com/svs/storage/m.139): FETCH BODY[] for mailbox Logs/Backup UID 9763 got too little data: 1008 vs 1613 Mar 16 11:42:51 mail2 dovecot: imap(svs@example.com): Error: Corrupted index cache file /mail/boxes/example.com/svs/mailboxes/Logs/Backup/dbox-Mails/dovecot.index.cache: Broken virtual size for mail UID 9763 Mar 16 11:42:51 mail2 dovecot: imap(svs@example.com): Disconnected: FETCH failed in=12462 out=984043
In thunderbird we see raw lz4 data.
I have today backup (duplicate mail on exim to per day mbox). So I can restore that message, but I found older problems in other mailboxes and I can't restore it due to tapes rotation
I see a lot of fixes in 2.2.19? Was it fixed after 2.2.18?
Probably this: https://github.com/dovecot/core/commit/879dfd4da1a9a379936b8d51c1e00c3bd7787...
The mails aren't actually corrupted. Dovecot just didn't detect LZ4 compressed mails correctly always. v2.2.22 should help.
participants (3)
-
Anton Chevychalov
-
Anton Cheyvhchalov
-
Timo Sirainen