dovecot - Dec 2013 - Size detection/replair does not work with zlib

Hi!

Usually dovecot auto detects or repairs the size of a maildir
message.  So I can place a message named "foo" in the cur directory
and dovecot uses it.

Now I tried the same with a zlib compressed message but here dovecot
doesn't recognize/repair the size of the message.

When I access this folder via IMAP the connection is diconnected and
in dovecot logs I see the following error messages:

Error: Cached message size smaller than expected (805 < 2666)
Error: Corrupted index cache file /somedir/dovecot.index.cache: Broken physical
size for mail UID 23
Error: read() failed: Input/output error (FETCH for mailbox INBOX UID 23)
Disconnected: Internal error occurred. Refer to server log for more information.
[2013-12-12 10:54:18] in=321 out=1977

As you can see in the first line, dovecot does know the compressed
size of the file (805) as well as the uncompressed size (2666), but it
isn't able to repair its index for this.

If I modify the setup a little with a standard file naming but with a
wrong file size in S-flag (compressed size instead of uncompressed
size), the log entries become stranger:

Error: Cached message size smaller than expected (805 < 2666)
Error: Maildir filename has wrong S value, renamed the file from
/somedir/cur/1386772057.M152553P9709.host,S=805:2, to
/somedir/cur/1386772057.M152553P9709.host,S=805:2,

So here dovecot detects the wrong S value, but instead of fixing it by
using the uncompressed size, it renames to the same file name as
before...

All the above was tested with dovecot 2.1.17.
We did a short cross test with 2.2.9 which gives somewhat different
error messages, but also isn't able to detect/repair the
(uncompressed) file size:

Error: Cached message size smaller than expected (805 < 2666)
Error: Corrupted index cache file /somedir/dovecot.index.cache: Broken physical
size for mail UID 23
Error: read(zlib(/somedir/cur/foo)) failed: Invalid argument

We also noticed that on both dovecot versions after trying to access
the above file, dovecot.index.cache is always deleted and not
rebuild...

Is all this intended behavior?  It sounds different to the standard
behavior of dovecot, that repairs broken folders if possible...

Ciao
Roland

Sorry for the top post, but this is a quick one.

While I wasn't using compressed mailboxes, I ran into a similar bug, and I
can't help but wonder if there's some commonality here.  There was no
resolution (can't find a bug tracker to add the issue to), but have a look:

http://thr3ads.net/dovecot/2013/10/2693193-cached-message-size-errors  (note:
gmane seems down, hence the oddball archive service)

Charles

On Dec 12, 2013, at 6:47 AM, Roland Rosenfeld wrote:
> Hi!
> 
> Usually dovecot auto detects or repairs the size of a maildir
> message.  So I can place a message named "foo" in the cur
directory
> and dovecot uses it.
> 
> Now I tried the same with a zlib compressed message but here dovecot
> doesn't recognize/repair the size of the message.
> 
> When I access this folder via IMAP the connection is diconnected and
> in dovecot logs I see the following error messages:
> 
> Error: Cached message size smaller than expected (805 < 2666)
> Error: Corrupted index cache file /somedir/dovecot.index.cache: Broken
physical size for mail UID 23
> Error: read() failed: Input/output error (FETCH for mailbox INBOX UID 23)
> Disconnected: Internal error occurred. Refer to server log for more
information. [2013-12-12 10:54:18] in=321 out=1977
> 
> As you can see in the first line, dovecot does know the compressed
> size of the file (805) as well as the uncompressed size (2666), but it
> isn't able to repair its index for this.
> 
> If I modify the setup a little with a standard file naming but with a
> wrong file size in S-flag (compressed size instead of uncompressed
> size), the log entries become stranger:
> 
> Error: Cached message size smaller than expected (805 < 2666)
> Error: Maildir filename has wrong S value, renamed the file from
/somedir/cur/1386772057.M152553P9709.host,S=805:2, to
/somedir/cur/1386772057.M152553P9709.host,S=805:2,
> 
> So here dovecot detects the wrong S value, but instead of fixing it by
> using the uncompressed size, it renames to the same file name as
> before...
> 
> All the above was tested with dovecot 2.1.17.
> We did a short cross test with 2.2.9 which gives somewhat different
> error messages, but also isn't able to detect/repair the
> (uncompressed) file size:
> 
> Error: Cached message size smaller than expected (805 < 2666)
> Error: Corrupted index cache file /somedir/dovecot.index.cache: Broken
physical size for mail UID 23
> Error: read(zlib(/somedir/cur/foo)) failed: Invalid argument
> 
> We also noticed that on both dovecot versions after trying to access
> the above file, dovecot.index.cache is always deleted and not
> rebuild...
> 
> Is all this intended behavior?  It sounds different to the standard
> behavior of dovecot, that repairs broken folders if possible...
> 
> Ciao
> Roland

On 2013-12-12 12:47, Roland Rosenfeld wrote:
> Hi!
>
> Usually dovecot auto detects or repairs the size of a maildir
> message.  So I can place a message named "foo" in the cur
directory
> and dovecot uses it.
>
> Now I tried the same with a zlib compressed message but here dovecot
> doesn't recognize/repair the size of the message.
>
> When I access this folder via IMAP the connection is diconnected and
> in dovecot logs I see the following error messages:
[..]
> Error: Cached message size smaller than expected (805 < 2666)
> Error: Maildir filename has wrong S value, renamed the file from
> /somedir/cur/1386772057.M152553P9709.host,S=805:2, to
> /somedir/cur/1386772057.M152553P9709.host,S=805:2,
>
> So here dovecot detects the wrong S value, but instead of fixing it 
> by
> using the uncompressed size, it renames to the same file name as
> before...
I observed exactly the same issue ever since I enabled the zlib
plugin on our IMAP server, running dovecot 2.1.7.

For what it's worth, I wrote a small shell script which, given a
Maildir directory, looks for all files for which the S= value doesn't
match the effective file size (i.e. for zlib-compressed files,
the S= value should match the *uncompressed* file size, for
plain files the S= value should match the physical file sie). The
script the attempts to print appropriate 'mv' commands for renaming
the files as needed. Maybe it helps, I attached it to this mail.


-- 
Frerich Raabe - raabe at froglogic.com
www.froglogic.com - Multi-Platform GUI Testing
-------------- next part --------------
An embedded and charset-unspecified text was scrubbed...
Name: fixup-compressed-maildir.sh
URL:
<http://dovecot.org/pipermail/dovecot/attachments/20131212/02b83265/attachment.pl>