Hi.

Dovecot 2.2, with the zlib plugin, I think we're getting bad index entries on IMAP COPY.

On copying a message to an empty folder, in the dovecot error log I see:

Sep 19 20:34:25 imap01 dovecot: imap(grain@rp-auth-test.com): Error: Cached message size smaller than expected (615 < 971) Sep 19 20:34:25 imap01 dovecot: imap(grain@rp-auth-test.com): Error: Corrupted index cache file /mail/index01/434/860/grain@rp-auth-test.com/.Bup/dovecot.index.cache: Broken physical size for mail UID 0 Sep 19 20:34:25 imap01 dovecot: imap(grain@rp-auth-test.com): Error: read() failed: Invalid argument (uid=0)

(Note this happens from the copy operation, not a subsequent access. Also note the UID is always 0).

The filename for the message is: -rw------- 2862 mail mail 615 Aug 29 15:38 1379622865.M228140P11548.imap01,S=971,W=988:2,S

S= size looks correct:

$ zcat 1379622865.M228140P11548.imap01\,S\=971\,W\=988\:2\,S |wc 17 51 971

doveadm dump says: $ sudo -u mail doveadm -c /he/dovecot/conf/dovecot.conf dump /mail/index01/434/860/grain@rp-auth-test.com/.Bup/ Detected file type: index -- INDEX: /mail/index01/434/860/grain@rp-auth-test.com/.Bup//dovecot.index version .................. = 7.3 base header size ......... = 120 header size .............. = 208 record size .............. = 12 compat flags ............. = 1 index id ................. = 1379605150 (2013-09-19 15:39:10) flags .................... = 0 uid validity ............. = 1377629137 (2013-08-27 18:45:37) next uid ................. = 14309 messages count ........... = 1 seen messages count ...... = 1 deleted messages count ... = 0 first recent uid ......... = 14308 first unseen uid lowwater = 14309 first deleted uid lowwater = 14308 log file seq ............. = 6 log file tail offset ..... = 204 log file head offset ..... = 204 day stamp ................ = 1379548800 (2013-09-19 00:00:00) day first uid[0] ......... = 1 day first uid[1] ......... = 0 day first uid[2] ......... = 0 day first uid[3] ......... = 0 day first uid[4] ......... = 0 day first uid[5] ......... = 0 day first uid[6] ......... = 0 day first uid[7] ......... = 0 -- Extension 0 -- name ........ = maildir hdr_size .... = 36 reset_id .... = 0 record_offset = 0 record_size . = 0 record_align = 0 header

• new_check_time .... = 2013-09-19 20:34:10
• new_mtime ......... = 2013-09-19 20:08:51
• new_mtime_nsecs ... = 792530000
• cur_check_time .... = 2013-09-19 20:35:38
• cur_mtime ......... = 2013-09-19 20:35:38
• cur_mtime_nsecs.... = 227710000
• uidlist_mtime ..... = 2013-09-19 20:35:38
• uidlist_mtime_nsecs = 254613000
• uidlist_size ...... = 1025178 -- Extension 1 -- name ........ = cache hdr_size .... = 0 reset_id .... = 1379605174 record_offset = 8 record_size . = 4 record_align = 4 -- Keywords --

-- CACHE: /mail/index01/434/860/grain@rp-auth-test.com/.Bup//dovecot.index.cache major version ........ = 1 minor version ........ = 1 indexid .............. = 1379605150 (2013-09-19 15:39:10) file_seq ............. = 1379605174 (2013-09-19 15:39:34) (24 compressions) continued_record_count = 0 record_count ......... = 0 used_file_size (old) . = 108 deleted_record_count . = 0 field_header_offset .. = 32 (0x88808080 nontranslated) -- Cache fields -- # Name Type Size Dec Last used 0: flags bit 4 tmp 2013-09-19 20:07 1: hdr.Message-ID hdr - tmp 2013-09-19 20:07 2: hdr.X-HE-Tag hdr - tmp 2013-09-19 20:07

-- RECORDS: 1 RECORD: seq=1, uid=14308, flags=0x08 (Seen)

• ext 3 cache : 0 (00000000)

$ sudo -u mail dovecot -c /he/dovecot/conf/dovecot.conf -n # 2.2.4.3 (12e60e803a54+): /he/dovecot/conf/dovecot.conf # OS: Linux 3.4.46-dom0-2.0.0 x86_64 Debian 7.0 debug_log_path = syslog disable_plaintext_auth = no first_valid_uid = 8 info_log_path = syslog lock_method = dotlock log_path = /var/run/dovecot/log-fifo log_timestamp = mail_fsync = always mail_gid = mail mail_nfs_index = yes mail_nfs_storage = yes mail_plugins = zlib quota tc_mail_log notify tc_proc stats mail_uid = mail maildir_very_dirty_syncs = yes mmap_disable = yes namespace inbox { inbox = yes location = prefix = } passdb { args = host=localhost port=1143 username=%L{user}::%L{service}::%L{rip}::%L{session} driver = imap } plugin { mail_log_events = delete undelete expunge copy mailbox_delete mailbox_rename flag_change append mail_log_fields = uid box msgid flags hetag memcached_servers = 10.5.47.223,10.5.47.222 quota = dict:User quota::proxy:/var/run/auth_proxy_dovecot/quotasocket:quota stats_command_min_time = 1 mins stats_domain_min_time = 12 hours stats_ip_min_time = 12 hours stats_memory_limit = 16 M stats_refresh = 30 secs stats_session_min_time = 15 mins stats_track_cmds = yes stats_user_min_time = 1 hours zlib_save = gz zlib_save_level = 6 } protocols = imap pop3 service anvil { unix_listener anvil-auth-penalty { mode = 00 } } service imap-login { inet_listener imap { address = 0 } inet_listener imaps { port = 0 } process_limit = 29 process_min_avail = 14 service_count = 0 } service imap-postlogin { executable = script-login -d /he/dovecot/utils/post_login.sh } service imap { executable = imap imap-postlogin process_limit = 1270 vsz_limit = 0 } service pop3-login { inet_listener pop3 { address = 0 } inet_listener pop3s { port = 0 } process_limit = 29 process_min_avail = 14 service_count = 0 } service pop3-postlogin { executable = script-login -d /he/dovecot/utils/post_login.sh } service pop3 { executable = pop3 pop3-postlogin process_limit = 206 vsz_limit = 512 M } service stats { fifo_listener stats-mail { mode = 0600 user = mail } } ssl = no userdb { args = /he/dovecot/conf/dovecot-tc-dict-auth.conf driver = dict } verbose_proctitle = yes protocol imap { mail_plugins = zlib quota tc_mail_log notify tc_proc stats imap_stats imap_quota }