Following up to myself on this, I think I'm basically seeing a variation on this bug from 2.1.x:
http://www.dovecot.org/list/dovecot/2012-March/064211.html
To restate what happens:
- dovecot detects the size mismatch
- file is renamed to correct it
- the cache file is flagged as incorrect due to the size mismatch
- next read of the mailbox dovecot looks for the *old* filename
The workaround to set "maildir_broken_filename_sizes=yes" seems to work.
The cause of all this of course was Courier, as it was what generated all the mismatches in the first place, but it seems like this is in turn triggering a bug in Dovecot. It kind of seems like the file gets renamed but the index is never updated to reflect this?
I've got plenty of samples, here's what one looks like, always just a few bytes off:
-rw------- 1 vpopmail vchkpw 23731 Oct 4 16:11 cur/1380917460.26966.xena.bway.net,S=23666:2,S
Also, while that thread mentions gzipped, messages, these are not.
Charles
On Oct 10, 2013, at 2:25 PM, Charles Sprickman wrote:
Hello,
We recently moved from courier to dovecot, and I'm seeing a handful of errors that prevent people from retrieving email.
Below is a snippet of the log sequence I see when this happens:
Oct 10 13:44:24 mbox dovecot: imap(xxx@bway.net): Error: Cached message size smaller than expected (1759 < 1830) Oct 10 13:44:24 mbox dovecot: imap(xxx@bway.net): Error: Maildir filename has wrong S value, renamed the file from /home/vpopmail/domains/bway.net/1/xxx/Maildir/cur/1381381552.91972.xena.bway.net,S=1759:2,b to /home/vpopmail/domains/bway.net/1/xxx/Maildir/cur/1381381552.91972.xena.bway.net,S=1830:2,b Oct 10 13:44:24 mbox dovecot: imap(xxx@bway.net): Error: Corrupted index cache file /home/vpopmail/domains/bway.net/1/xxx/Maildir/dovecot.index.cache: Broken physical size for mail UID 447401 Oct 10 13:44:24 mbox dovecot: imap(xxx@bway.net): Error: read(/home/vpopmail/domains/bway.net/1/xxx/Maildir/cur/1381381552.91972.xena.bway.net,S=1759:2,b) failed: Invalid argument Oct 10 13:44:24 mbox dovecot: imap(xxx@bway.net): Disconnected: Internal error occurred. Refer to server log for more information. [2013-10-10 13:44:24] in=784 out=3017
Basically it looks like dovecot detects a mismatch in the file size vs. the file size embedded in the maildir filename, tries to fix it and then has issues reading the fixed file. Removing the file in question allows the user to retrieve email. The "invalid argument" error seems especially strange, as I'm able to view the file by hand with no problems.
Blowing away the indexes and letting them get recreated seems to not help at all.
This was an old vpopmail setup with both maildrop and vdelivermail doing the final delivery both now and prior to the migration to dovecot.
For a quick fix, is there a way to have dovecot ignore the error and present the rest of the mailbox?
Longer term fix, I'm not even sure where to start I've used dovecot elsewhere for quite some time (with maildirs) and I've never had an issue like this.
'doveconf -n' below...
Thanks,
Charles
Charles Sprickman NetEng/SysAdmin Bway.net - New York's Best Internet www.bway.net spork@bway.net - 212.655.9344
# 2.2.5: /usr/local/etc/dovecot/dovecot.conf # OS: FreeBSD 8.4-RELEASE-p1 amd64 auth_default_realm = bway.net auth_socket_path = /var/run/dovecot/auth-userdb auth_verbose = yes base_dir = /var/run/dovecot/ default_process_limit = 300 disable_plaintext_auth = no first_valid_uid = 89 instance_name = dovecot1 last_valid_uid = 90 listen = 127.0.0.1,216.220.96.26,216.220.96.25 login_greeting = Dovecot ready - bway.net. mail_plugins = " quota" mailbox_list_index = yes namespace inbox { hidden = no inbox = yes list = yes location = mailbox Drafts { special_use = \Drafts } mailbox Sent { special_use = \Sent } mailbox "Sent Messages" { special_use = \Sent } mailbox Spam { special_use = \Junk } mailbox Trash { special_use = \Trash } prefix = INBOX. separator = . subscriptions = yes type = private } passdb { args = /usr/local/etc/dovecot/dovecot-sql.conf.ext driver = sql } plugin { quota = maildir:User quota quota_rule = Inbox.Trash:storage=+100M quota_rule2 = Inbox.Spam:storage=+100M } pop3_client_workarounds = outlook-no-nuls oe-ns-eoh pop3_uidl_format = %v-%u protocols = imap pop3 ssl_cert = </usr/local/etc/ssl/bwaynet.pem ssl_key = </usr/local/etc/ssl/bwaynet.key userdb { args = /usr/local/etc/dovecot/dovecot-sql.conf.ext driver = sql } protocol imap { mail_max_userip_connections = 40 mail_plugins = " quota imap_quota" } protocol pop3 { mail_max_userip_connections = 20 }