On 05/08/2014 11:59 AM, Alexander 'Leo' Bergolth wrote:
On 05/08/2014 11:44 AM, Charles Marcus wrote:
On 5/7/2014 4:38 PM, Alexander 'Leo' Bergolth <leo@strike.wu.ac.at> wrote:
I am getting "Cached message size smaller than expected" errors since dovecot-2.1.x.
I tried dovecot 2.2.7, 2.2.10 and 2.2.12. All of them produce tha same errors. ("Cached message size smaller than expected", sometimes followed by "read... Invalid argument".)
This really drives me to despair! :-( Timo please help!
I also tried dovecot-2.2.13 and even downgraded to dovecot-2.1.17 now. (Did a doveadm -v force-resync -u $user "*" for all users after changing versions.) I can also see somehow similar problems on another box that uses (the rather old) dovecot 2.1.1.
I tried to add dotlock to mbox_write_locks since according to the source, the LDA (maildrop) seems to try dotlock before fcntl. I also changed fcntl to dotlock for locking index files. (lock_method = dotlock) The only processes that access a users mailboxes are dovecot (imap and pop) and maildrop (LDA).
The only non-standard setup I can identify is that I am using an imap-postlogin script that dynamically adds some additional namespaces via environment variables for some users that have access to shared mailboxes. But I doubt wether this can have an influence on the index.cache errors.
I'd greatly appreciate your help!
Thanks, --leo
maillogs,dovecot config and additional information can be found at: http://leo.kloburg.at/tmp/dovecot-index/
2.2.13 Errors: -------------------- 8< -------------------- May 19 05:51:15 samba dovecot: imap(USER1): Error: Cached message size smaller than expected (75357 < 75358) May 19 05:51:15 samba dovecot: imap(USER1): Error: Corrupted index cache file /home/USER1/mail/.imap/INBOX/dovecot.index.cache: Broken physical size for mail UID 70929 May 19 05:51:15 samba dovecot: imap(USER1): Error: copy: i_stream_read() failed: Invalid argument May 19 05:51:15 samba dovecot: imap(USER1): Error: mail parser: read(/var/mail/USER1, box=Trash) failed: Invalid argument May 19 07:23:59 samba dovecot: imap(USER2): Error: Cached message size smaller than expected (75357 < 75358) May 19 07:23:59 samba dovecot: imap(USER2): Error: Corrupted index cache file /home/USER2/mail/.imap/INBOX/dovecot.index.cache: Broken physical size for mail UID 18322 May 19 07:23:59 samba dovecot: imap(USER2): Error: read(/var/mail/USER2) failed: Cached message size smaller than expected (75357 < 75358) (FETCH BODY[] for mailbox INBOX UID 18322) May 19 07:48:11 samba dovecot: imap(USER3): Error: Cached message size smaller than expected (13510 < 13511) May 19 07:48:11 samba dovecot: imap(USER3): Error: Corrupted index cache file /home/USER3/mail/.imap/INBOX/dovecot.index.cache: Broken physical size for mail UID 952 May 19 07:48:11 samba dovecot: imap(USER3): Error: read(/var/mail/USER3) failed: Cached message size smaller than expected (13510 < 13511) (FETCH BODY[2] for mailbox INBOX UID 952) May 19 07:58:45 samba dovecot: imap(USER4): Error: Cached message size smaller than expected (1892192 < 1892193) May 19 07:58:45 samba dovecot: imap(USER4): Error: Corrupted index cache file /home/USER4/mail/.imap/INBOX/dovecot.index.cache: Broken physical size for mail UID 20561 May 19 07:58:45 samba dovecot: imap(USER4): Error: copy: i_stream_read() failed: Invalid argument May 19 07:58:45 samba dovecot: imap(USER4): Error: mail parser: read(/var/mail/USER4, box=Stab) failed: Invalid argument May 19 08:58:44 samba dovecot: imap(USER1): Error: Cached message size smaller than expected (185239 < 185240) May 19 08:58:44 samba dovecot: imap(USER1): Error: Corrupted index cache file /home/USER1/mail/.imap/INBOX/dovecot.index.cache: Broken physical size for mail UID 70934 May 19 08:58:44 samba dovecot: imap(USER1): Error: read(/var/mail/USER1) failed: Cached message size smaller than expected (185239 < 185240) (FETCH BODY[] for mailbox INBOX UID 70934) May 19 09:00:00 samba dovecot: imap(USER2): Error: Cached message size smaller than expected (185239 < 185240) May 19 09:00:00 samba dovecot: imap(USER2): Error: Corrupted index cache file /home/USER2/mail/.imap/INBOX/dovecot.index.cache: Broken physical size for mail UID 18324 May 19 09:00:00 samba dovecot: imap(USER2): Error: copy: i_stream_read() failed: Invalid argument May 19 09:00:00 samba dovecot: imap(USER2): Error: mail parser: read(/var/mail/USER2, box=Trash) failed: Invalid argument May 19 09:56:47 samba dovecot: imap(USER1): Error: Cached message size smaller than expected (1829385 < 1829386) May 19 09:56:47 samba dovecot: imap(USER1): Error: Corrupted index cache file /home/USER1/mail/.imap/INBOX/dovecot.index.cache: Broken physical size for mail UID 70938 May 19 09:56:47 samba dovecot: imap(USER1): Error: copy: i_stream_read() failed: Invalid argument May 19 09:56:47 samba dovecot: imap(USER1): Error: mail parser: read(/var/mail/USER1, box=Trash) failed: Invalid argument May 19 10:11:48 samba dovecot: imap(USER5): Error: Cached message size smaller than expected (75357 < 75358) May 19 10:11:48 samba dovecot: imap(USER5): Error: Corrupted index cache file /home/USER5/mail/.imap/INBOX/dovecot.index.cache: Broken physical size for mail UID 24136 May 19 10:11:48 samba dovecot: imap(USER5): Error: read(/var/mail/USER5) failed: Cached message size smaller than expected (75357 < 75358) (FETCH BODY[] for mailbox INBOX UID 24136) -------------------- 8< --------------------
2.1.17 Errors: -------------------- 8< -------------------- May 22 12:36:29 samba dovecot: imap(USER1): Error: Cached message size smaller than expected (63266 < 63267) May 22 12:36:29 samba dovecot: imap(USER1): Error: Corrupted index cache file /home/USER1/mail/.imap/INBOX/dovecot.index.cache: Broken physical size for mail UID 71075 May 22 12:38:01 samba dovecot: imap(USER2): Error: Cached message size smaller than expected (221845 < 221846) May 22 12:38:01 samba dovecot: imap(USER2): Error: Corrupted index cache file /home/USER2/mail/.imap/INBOX/dovecot.index.cache: Broken physical size for mail UID 2871 May 22 12:38:01 samba dovecot: imap(USER2): Error: read(/var/mail/USER2) failed: Input/output error (FETCH for mailbox INBOX UID 2871) May 22 12:38:02 samba dovecot: imap(USER2): Error: Cached message size smaller than expected (221845 < 221846) May 22 12:38:02 samba dovecot: imap(USER2): Error: Corrupted index cache file /home/USER2/mail/.imap/INBOX/dovecot.index.cache: Broken physical size for mail UID 2871 May 22 12:56:02 samba dovecot: imap(USER3): Error: Cached message size smaller than expected (57091 < 57092) May 22 12:56:02 samba dovecot: imap(USER3): Error: Corrupted index cache file /home/USER3/mail/.imap/INBOX/dovecot.index.cache: Broken physical size for mail UID 18358 May 22 12:56:02 samba dovecot: imap(USER3): Error: read(/var/mail/USER3) failed: Input/output error (FETCH for mailbox INBOX UID 18358) May 22 12:56:11 samba dovecot: imap(USER3): Error: Cached message size smaller than expected (57091 < 57092) May 22 12:56:11 samba dovecot: imap(USER3): Error: Corrupted index cache file /home/USER3/mail/.imap/INBOX/dovecot.index.cache: Broken physical size for mail UID 18358 May 22 12:56:11 samba dovecot: imap(USER3): Error: read(/var/mail/USER3) failed: Input/output error (FETCH for mailbox INBOX UID 18358) May 22 13:21:26 samba dovecot: imap(USER4): Error: Cached message size smaller than expected (57091 < 57092) May 22 13:21:26 samba dovecot: imap(USER4): Error: Corrupted index cache file /home/USER4/mail/.imap/INBOX/dovecot.index.cache: Broken physical size for mail UID 11275 May 22 13:21:26 samba dovecot: imap(USER4): Error: read(/var/mail/USER4) failed: Input/output error (FETCH for mailbox INBOX UID 11275) May 22 14:03:02 samba dovecot: imap(USER5): Error: Cached message size smaller than expected (16034 < 16035) May 22 14:03:02 samba dovecot: imap(USER5): Error: Corrupted index cache file /home/USER5/mail/.imap/INBOX/dovecot.index.cache: Broken physical size for mail UID 11394 May 22 14:03:02 samba dovecot: imap(USER5): Error: read(/var/mail/USER5) failed: Input/output error (uid=11394) May 22 14:35:49 samba dovecot: imap(USER6): Error: Cached message size smaller than expected (10925 < 10926) May 22 14:35:49 samba dovecot: imap(USER6): Error: Corrupted index cache file /home/USER6/mail/.imap/INBOX/dovecot.index.cache: Broken physical size for mail UID 23149 May 22 14:43:08 samba dovecot: imap(USER1): Error: Cached message size smaller than expected (616708 < 616709) May 22 14:43:08 samba dovecot: imap(USER1): Error: Corrupted index cache file /home/USER1/mail/.imap/INBOX/dovecot.index.cache: Broken physical size for mail UID 71078 May 22 14:43:08 samba dovecot: imap(USER1): Error: read(/var/mail/USER1) failed: Input/output error (FETCH for mailbox INBOX UID 71078) May 22 14:51:52 samba dovecot: imap(USER5): Error: Cached message size smaller than expected (10924 < 10925) May 22 14:51:52 samba dovecot: imap(USER5): Error: Corrupted index cache file /home/USER5/mail/.imap/INBOX/dovecot.index.cache: Broken physical size for mail UID 11499 May 22 14:51:52 samba dovecot: imap(USER5): Error: read(/var/mail/USER5) failed: Input/output error (uid=11499) -------------------- 8< --------------------
2.1.1 on another box: -------------------- 8< -------------------- Mar 4 20:32:44 strike dovecot: imap(USER1): Error: Log synchronization error at seq=1,offset=2656 for /home/USER1/mail/.imap/Drafts/dovecot.index: Extension header update points outside header size Mar 4 20:32:44 strike dovecot: imap(USER1): Error: Log synchronization error at seq=1,offset=2744 for /home/USER1/mail/.imap/Drafts/dovecot.index: Extension header update points outside header size Mar 4 20:32:44 strike dovecot: imap(USER1): Error: Log synchronization error at seq=1,offset=2832 for /home/USER1/mail/.imap/Drafts/dovecot.index: Extension header update points outside header size Mar 10 07:27:00 strike dovecot: imap(USER2): Error: Cached message size larger than expected (10369 > 10337) Mar 10 07:27:00 strike dovecot: imap(USER2): Error: Corrupted index cache file /home/USER2/mail/.imap/Sent/dovecot.index.cache: Broken physical size for mail UID 606 Mar 10 07:27:00 strike dovecot: imap(USER2): Error: read(/home/USER2/mail/Sent) failed: Input/output error (FETCH for mailbox Sent UID 606) Mar 11 10:45:21 strike dovecot: imap(USER3): Error: Cached message size larger than expected (1066719 > 1065140) Mar 11 10:45:21 strike dovecot: imap(USER3): Error: Corrupted index cache file /home/USER3/mail/.imap/Drafts/dovecot.index.cache: Broken physical size for mail UID 458 Mar 11 10:45:21 strike dovecot: imap(USER3): Error: Cached message size larger than expected (1066719 > 1065140) Mar 11 10:45:21 strike dovecot: imap(USER3): Error: Corrupted index cache file /home/USER3/mail/.imap/Drafts/dovecot.index.cache: Broken physical size for mail UID 458 Mar 11 10:45:21 strike dovecot: imap(USER3): Error: copy: i_stream_read() failed: Input/output error Mar 17 19:47:29 strike dovecot: imap(USER4): Error: Cached message size larger than expected (4093 > 3364) Mar 17 19:47:29 strike dovecot: imap(USER4): Error: Corrupted index cache file /home/USER4/mail/.imap/Drafts/dovecot.index.cache: Broken physical size for mail UID 20089 Mar 17 19:47:29 strike dovecot: imap(USER4): Error: Cached message size larger than expected (4093 > 3364) Mar 17 19:47:29 strike dovecot: imap(USER4): Error: Corrupted index cache file /home/USER4/mail/.imap/Drafts/dovecot.index.cache: Broken physical size for mail UID 20089 Mar 17 19:47:29 strike dovecot: imap(USER4): Error: copy: i_stream_read() failed: Input/output error Apr 2 18:06:39 strike dovecot: imap(USER5): Error: Log synchronization error at seq=1,offset=30176 for /home/USER5/mail/.imap/virus/dovecot.index: Extension header update points outside header size Apr 16 18:49:26 strike dovecot: imap(USER4): Error: FETCH [] for mailbox Drafts UID 20428 got too little data: 9936 vs 10490 Apr 16 18:49:26 strike dovecot: imap(USER4): Error: Corrupted index cache file /home/USER4/mail/.imap/Drafts/dovecot.index.cache: Broken virtual size for mail UID 20428 Apr 28 16:04:56 strike dovecot: imap(USER6): Error: Log synchronization error at seq=1,offset=3900 for /home/USER6/mail/.imap/Berni/dovecot.index: Extension header update points outside header size Apr 28 16:04:56 strike dovecot: imap(USER6): Error: Log synchronization error at seq=1,offset=3988 for /home/USER6/mail/.imap/Berni/dovecot.index: Extension header update points outside header size Apr 28 16:04:56 strike dovecot: imap(USER6): Error: Log synchronization error at seq=1,offset=4076 for /home/USER6/mail/.imap/Berni/dovecot.index: Extension header update points outside header size Apr 28 16:04:59 strike dovecot: imap(USER6): Error: Log synchronization error at seq=1,offset=4164 for /home/USER6/mail/.imap/Berni/dovecot.index: Extension header update points outside header size Apr 28 16:05:34 strike dovecot: imap(USER6): Error: Log synchronization error at seq=1,offset=4340 for /home/USER6/mail/.imap/Berni/dovecot.index: Extension header update points outside header size May 12 13:34:52 strike dovecot: imap(USER4): Error: Log synchronization error at seq=2,offset=240 for /home/USER4/mail/.imap/Junk/dovecot.index: Extension header update points outside header size May 12 21:59:29 strike dovecot: imap(USER5): Error: Log synchronization error at seq=1,offset=30264 for /home/USER5/mail/.imap/virus/dovecot.index: Extension header update points outside header size -------------------- 8< --------------------
-------------------- 8< -------------------- # 2.2.12: /etc/dovecot/dovecot.conf # OS: Linux 2.6.32-431.3.1.el6.x86_64 x86_64 CentOS release 6.5 (Final) auth_mechanisms = plain login auth_verbose = yes default_vsz_limit = 512 M first_valid_uid = 100 imap_client_workarounds = tb-extra-mailbox-sep login_trusted_networks = 172.23.60.0/24 mail_location = mbox:~/mail:INBOX=/var/mail/%u mail_plugins = " mail_log notify" mail_privileged_group = mail managesieve_notify_capability = mailto managesieve_sieve_capability = fileinto reject envelope encoded-character vacation subaddress comparator-i;ascii-numeric relational regex imap4flags copy include variables body enotify environment mailbox date ihave mbox_write_locks = fcntl namespace inbox { inbox = yes location = mbox:~/mail:INBOX=/var/mail/%u mailbox Drafts { special_use = \Drafts } mailbox Junk { special_use = \Junk } mailbox Sent { special_use = \Sent } mailbox "Sent Messages" { special_use = \Sent } mailbox Trash { special_use = \Trash } prefix = separator = / type = private } passdb { driver = pam } plugin { mail_log_events = delete undelete expunge copy mailbox_delete mailbox_rename mail_log_fields = uid box msgid size } protocols = imap pop3 service auth { unix_listener /var/spool/postfix/private/auth { group = postfix mode = 0666 user = postfix } } service imap-postlogin { executable = script-login -d /usr/local/sbin/dovecot-post-login.pl } service imap { executable = imap imap-postlogin } ssl = required ssl_cert = </etc/pki/dovecot/certs/dovecot.pem ssl_key = </etc/pki/dovecot/private/dovecot.pem userdb { driver = passwd } -------------------- 8< --------------------
--
e-mail ::: Leo.Bergolth (at) wu.ac.at
fax ::: +43-1-31336-906050
location ::: IT-Services | Vienna University of Economics | Austria