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 at rp-auth-test.com): Error: Cached
message size smaller than expected (615 < 971)
Sep 19 20:34:25 imap01 dovecot: imap(grain at rp-auth-test.com): Error:
Corrupted index cache file /mail/index01/434/860/grain at
rp-auth-test.com/.Bup/dovecot.index.cache: Broken physical size for mail UID 0
Sep 19 20:34:25 imap01 dovecot: imap(grain at 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 at rp-auth-test.com/.Bup/
Detected file type: index
-- INDEX: /mail/index01/434/860/grain at 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 at
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
}