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 <l...@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