We are using dbox with lz4 compression and dovecot-lda + sieve for delivery. Mail recieved: Mar 16 06:27:55 mail2 dovecot: lda(svs at example.com): sieve: msgid=<20160316032754.4C89D2C4 at 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 at 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 at rdbms.oldstable.office.example.com>) Mar 16 10:14:44 mail2 dovecot: imap(svs at 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 at 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 at rdbms.oldstable.office.example.com>) (FETCH BODY[] for mailbox Logs/Backup UID 9763) Mar 16 10:14:44 mail2 dovecot: imap(svs at example.com): Disconnected: FETCH read() failed in=14812 out=1077049 Mar 16 10:14:45 mail2 dovecot: imap(svs at 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 at 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 at example.com): Disconnected: FETCH failed in=837 out=641651 And still in a same state: Mar 16 11:42:51 mail2 dovecot: imap(svs at 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 at 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 at 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 at 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 at example.com): sieve: msgid=<20160316032754.4C89D2C4 at 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 at 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 at rdbms.oldstable.office.example.com>) > Mar 16 10:14:44 mail2 dovecot: imap(svs at 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 at 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 at rdbms.oldstable.office.example.com>) (FETCH BODY[] for mailbox Logs/Backup UID 9763) > Mar 16 10:14:44 mail2 dovecot: imap(svs at example.com): Disconnected: FETCH read() failed in=14812 out=1077049 > Mar 16 10:14:45 mail2 dovecot: imap(svs at 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 at 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 at example.com): Disconnected: > FETCH failed in=837 out=641651 > > And still in a same state: > Mar 16 11:42:51 mail2 dovecot: imap(svs at 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 at 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 at 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/879dfd4da1a9a379936b8d51c1e00c3bd77873b4 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 at iki.fi> wrote:> On 16 Mar 2016, at 20:09, Anton Chevychalov <ac at 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 at example.com): sieve: msgid=<20160316032754.4C89D2C4 at 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 at 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 at rdbms.oldstable.office.example.com>) > > Mar 16 10:14:44 mail2 dovecot: imap(svs at 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 at 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 at rdbms.oldstable.office.example.com>) (FETCH BODY[] for mailbox Logs/Backup UID 9763) > > Mar 16 10:14:44 mail2 dovecot: imap(svs at example.com): Disconnected: FETCH read() failed in=14812 out=1077049 > > Mar 16 10:14:45 mail2 dovecot: imap(svs at 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 at 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 at example.com): Disconnected: > > FETCH failed in=837 out=641651 > > > > And still in a same state: > > Mar 16 11:42:51 mail2 dovecot: imap(svs at 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 at 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 at 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/879dfd4da1a9a379936b8d51c1e00c3bd77873b4 > > The mails aren't actually corrupted. Dovecot just didn't detect LZ4 compressed mails correctly always. v2.2.22 should help.