Hi,
I run a fairly large Dovecot Installation (around 100k mailboxes) on
several servers.
gzip compression is on.
Every once in a while I get the dreaded "cache corruption" messages in
the log:
Error: Corrupted record in index cache file
/[redacted]/Maildir/dovecot.index.cache: UID 3868: Broken physical size
in mailbox INBOX:
read(zlib(/[redacted]/Maildir/cur/1674129792.M797543P21755.node2,S=8099,W=8276:2,))
failed: Cached message size smaller than expected (2877 < 8099,
box=INBOX, UID=3868)
Error: Corrupted record in index cache file
/[redacted]/Maildir/dovecot.index.cache: UID 3875: Broken physical size
in mailbox INBOX:
read(zlib(/[redacted]/Maildir/cur/1674212201.M985809P29112.node2,S=13907,W=14121:2,))
failed: Cached message size smaller than expected (5533 < 8192,
box=INBOX, UID=3875)
The first entry shows 2877 (size on disk) vs. 8099 (real size unzipped,
also in the filename: S=8099).
The second entry shows 5533 (size on disk) vs. 8192 - this is not
correct in any way. Size on disk is 13907 as noted in the filename.
Both mails were delivered trough LMTP and retrieved by the POP3 service.
Anyone with an idea what might be happening here? I've read all
available info in the doc and in the previous discussions / bug reports,
but nothing seems to match my case. And where does that 8192 come from -
it looks suspicious?
Version is 2.3.7.2 (Ubuntu 20.04)
doveconf -n excerpt:
protocol lmtp {
? mail_plugins = " old_stats mail_log notify zlib sieve quota"
}
protocol imap {
? mail_max_userip_connections = 50
? mail_plugins = " old_stats mail_log notify zlib imap_old_stats quota
imap_quota imap_sieve"
}
protocol pop3 {
? mail_max_userip_connections = 50
? mail_plugins = " old_stats mail_log notify zlib"
}
Tim
I would like to add some more observations: I hav another mailbox with one mail's size being saved wrong in the cache file: doveadm dump: RECORD: seq=40, uid=1202, flags=0x00 ?- ext 5 cache???? :?????? 8504 (38210000) ?- ext 6 vsize???? :???? 145625 (d9380200) ?????????????????? : vsize???????? = 5166845802713 ?????????????????? : highest_uid?? = 0 ?????????????????? : message_count = 8716 ?- cache offset=8504 size=212, prev_offset = 0 ??? - hdr.From: 42: From: [redacted] ??? - hdr.Message-ID: 45: Message-ID:? [redacted] ??? - hdr.Subject: 44: Subject:? [redacted] ??? - flags: (20000000) RECORD: seq=41, uid=1203, flags=0x00 ?- ext 5 cache???? :?????? 8716 (0c220000) ?- ext 6 vsize???? :???? 105141 (b59a0100) ?????????????????? : vsize???????? = 105141 ?????????????????? : highest_uid?? = 0 ?????????????????? : message_count = 0 ?- cache offset=8716 size=280, prev_offset = 0 ??? - hdr.From: 104: From:? [redacted] ??? - hdr.Message-ID: 108: Message-ID:? [redacted] ??? - hdr.Subject: 105: Subject:? [redacted] ??? - flags: (20000000) The message with seq=40 is the mail dovecot complains about: Error: Corrupted record in index cache file /[redacted]/Maildir/dovecot.index.cache: UID 1202: Broken physical size in mailbox INBOX: read(zlib(/[redacted]/Maildir/new/1675176154.M829333P14495.node2,S=232816,W=236045)) failed: Cached message size smaller than expected (145082 < 146788, box=INBOX, UID=1202) Size on disk is 145082 Size after decompression is 232816 (as expected) Message with seq=41 is correct with both vsize in cache and decompressed size being equal. Before the POP3 access that produced the error both mails were only ever touched by the dovecot lmtp delivery process. Am 01.02.23 um 14:13 schrieb Tim Evers:> Hi, > > I run a fairly large Dovecot Installation (around 100k mailboxes) on > several servers. > > gzip compression is on. > > Every once in a while I get the dreaded "cache corruption" messages in > the log: > > Error: Corrupted record in index cache file > /[redacted]/Maildir/dovecot.index.cache: UID 3868: Broken physical > size in mailbox INBOX: > read(zlib(/[redacted]/Maildir/cur/1674129792.M797543P21755.node2,S=8099,W=8276:2,)) > failed: Cached message size smaller than expected (2877 < 8099, > box=INBOX, UID=3868) > > Error: Corrupted record in index cache file > /[redacted]/Maildir/dovecot.index.cache: UID 3875: Broken physical > size in mailbox INBOX: > read(zlib(/[redacted]/Maildir/cur/1674212201.M985809P29112.node2,S=13907,W=14121:2,)) > failed: Cached message size smaller than expected (5533 < 8192, > box=INBOX, UID=3875) > > The first entry shows 2877 (size on disk) vs. 8099 (real size > unzipped, also in the filename: S=8099). > > The second entry shows 5533 (size on disk) vs. 8192 - this is not > correct in any way. Size on disk is 13907 as noted in the filename. > > Both mails were delivered trough LMTP and retrieved by the POP3 service. > > Anyone with an idea what might be happening here? I've read all > available info in the doc and in the previous discussions / bug > reports, but nothing seems to match my case. And where does that 8192 > come from - it looks suspicious? > > Version is 2.3.7.2 (Ubuntu 20.04) > > doveconf -n excerpt: > > protocol lmtp { > ? mail_plugins = " old_stats mail_log notify zlib sieve quota" > } > protocol imap { > ? mail_max_userip_connections = 50 > ? mail_plugins = " old_stats mail_log notify zlib imap_old_stats quota > imap_quota imap_sieve" > } > protocol pop3 { > ? mail_max_userip_connections = 50 > ? mail_plugins = " old_stats mail_log notify zlib" > } > > Tim >
On 2023-02-01, Tim Evers <te-ml-ext at artfiles.de> wrote:> I run a fairly large Dovecot Installation (around 100k mailboxes) on > several servers. > > gzip compression is on. > > Every once in a while I get the dreaded "cache corruption" messages in > the log: > > Error: Corrupted record in index cache file > /[redacted]/Maildir/dovecot.index.cache: UID 3868: Broken physical size > in mailbox INBOX: > read(zlib(/[redacted]/Maildir/cur/1674129792.M797543P21755.node2,S=8099,W=8276:2,)) > failed: Cached message size smaller than expected (2877 < 8099, > box=INBOX, UID=3868) > > Error: Corrupted record in index cache file > /[redacted]/Maildir/dovecot.index.cache: UID 3875: Broken physical size > in mailbox INBOX: > read(zlib(/[redacted]/Maildir/cur/1674212201.M985809P29112.node2,S=13907,W=14121:2,)) > failed: Cached message size smaller than expected (5533 < 8192, > box=INBOX, UID=3875) > > The first entry shows 2877 (size on disk) vs. 8099 (real size unzipped, > also in the filename: S=8099). > > The second entry shows 5533 (size on disk) vs. 8192 - this is not > correct in any way. Size on disk is 13907 as noted in the filename. > > Both mails were delivered trough LMTP and retrieved by the POP3 service. > > Anyone with an idea what might be happening here? I've read all > available info in the doc and in the previous discussions / bug reports, > but nothing seems to match my case. And where does that 8192 come from - > it looks suspicious? > > Version is 2.3.7.2 (Ubuntu 20.04)2.3.7.2 is rather old now. There were definitely fixes regarding compression around the 2.3.10-2.3.12 timeframe or thereabouts (I forget all the details but it took a release or two before some remaining issues were sorted out after changes in the area). I'd be looking to get it updated to a current version first.