I've noticed that maildir IMAP COPY commands can generate invalid dovecot.index entries when all seven of the following are true:
- The zlib plugin is enabled;
- The zlib_save/zlib_save_level options are NOT enabled;
- The source message being copied is compressed;
- The mail_log plugin is logging "copy" events;
- The mail_log_fields setting includes at least one message header;
- The destination mailbox folder has an index file that is recording the logged headers;
- The source mailbox folder does NOT have an index file recording the logged headers.
In this situation, copying a message results in an index entry in the destination that has all the headers blank, like this:
RECORD: seq=5, uid=182415, flags=0x08 (Seen)
- ext 1 modseq : 3 (0300000000000000)
- ext 2 cache : 2352 (30090000)
- cache offset=2352 size=120, prev_offset = 0
- hdr.FROM:
- hdr.MESSAGE-ID:
- hdr.SUBJECT:
- hdr.DATE:
- hdr.BCC:
- hdr.CC:
- hdr.CONTENT-TYPE:
- hdr.IN-REPLY-TO:
- hdr.NEWSGROUPS:
- hdr.PRIORITY:
- hdr.REFERENCES:
- hdr.REPLY-TO:
- hdr.TO:
- hdr.X-PRIORITY:
For these copies, the mail_log plugin records blank header data in the log, too, like this (despite the message having a valid message-ID, from, and subject):
Oct 29 21:11:42 wheezy dovecot: imap[31763]: user=1@example.com ip=192.168.0.4 session=RV/MmUojyADAqAAE copy from INBOX.Saved: box=INBOX.Trash, uid=182412, msgid=, size=1357, vsize=1392, from=, subject=, flags=(\Seen)
I've found this occurs in at least Dovecot 2.1.7, 2.2.13, and 2.2.18 (all packaged Debian versions).
Changing any of the seven things I mentioned above fixes it. I've tried to find the code that causes this, but not yet been successful. My theory is that when the mail_log plugin calls mail_get_first_header(), and there's no index header record to read it from, it looks at the real message on disk. Perhaps it somehow operates on a compressed copy of the message although it expects uncompressed plaintext, so it doesn't find any of the headers. The "missing" headers then get cached to the destination index file as a side-effect.
The copied maildir message itself is fine, by the way. It's an identical, still-compressed copy of the original message. And deleting the destination "dovecot.index*" files that contain the bad data causes Dovecot to rebuild the index with the correct header data.
It's unusual to use the zlib plugin without the zlib_save/zlib_save_level options enabled, of course. That's probably why (as far as I can tell) there have been no reports of this before. I noticed it only because I was testing a small amount of manual mail compression before deploying it for all mail.
Here's the "doveconf -n" of a system in the "has the problem" state:
# 2.2.18: /etc/dovecot/dovecot.conf # Pigeonhole version 0.4.8 (0c4ae064f307+) # OS: Linux 3.2.0-4-686-pae i686 Debian stretch/sid auth_mechanisms = plain login auth_username_format = auth_verbose = yes auth_verbose_passwords = sha1 default_vsz_limit = 1 G disable_plaintext_auth = no lda_mailbox_autosubscribe = yes listen = * log_timestamp = "%Y-%m-%d %H:%M:%S " login_log_format_elements = user=<%u> pid=[%{mail_pid}] method=%m rip=%r lip=%l %c mail_fsync = never mail_location = maildir:~/ mail_log_prefix = "%s[%{pid}]: user=<%u> ip=%{rip} session=%{session} " mail_max_userip_connections = 100 mail_plugins = mail_log notify zlib managesieve_notify_capability = mailto managesieve_sieve_capability = fileinto envelope encoded-character vacation subaddress comparator-i;ascii-numeric relational regex imap4flags copy include variables body enotify environment mailbox date index ihave duplicate spamtest spamtestplus namespace { inbox = yes location = prefix = INBOX. separator = . type = private } namespace { hidden = yes inbox = no list = no location = prefix = separator = . type = private } passdb { args = /etc/dovecot/dovecot.users driver = passwd-file } plugin { fts = lucene fts_lucene = whitespace_chars=@. mail_log_events = copy delete undelete expunge mailbox_delete mailbox_rename flag_change save mailbox_create mail_log_fields = vsize size flags box uid box msgid size flags vsize from subject sieve = %h/mailbox.sieve sieve_after = %h/../../domain-after.sieve sieve_before = %h/../../domain-before.sieve sieve_dir = %h/sieve sieve_extensions = -reject +spamtest +spamtestplus sieve_global_dir = %h/../../sieve-global-include-scripts sieve_spamtest_max_value = 7 sieve_spamtest_status_header = X-Spam-Level sieve_spamtest_status_type = strlen } protocols = pop3 imap lmtp sieve service auth { unix_listener /var/spool/postfix/private/auth { group = postfix mode = 0660 user = postfix } } service imap-login { process_min_avail = 8 service_count = 0 } service imap { process_limit = 2000 } service lmtp { unix_listener /var/spool/postfix/private/dovecot-lmtp { group = postfix mode = 0660 user = postfix } } service pop3-login { process_min_avail = 8 service_count = 0 } service pop3 { process_limit = 2000 } ssl = no userdb { args = /etc/dovecot/dovecot.users driver = passwd-file } verbose_proctitle = yes protocol imap { imap_client_workarounds = delay-newmail imap_logout_format = %i bytes in, %o bytes out } protocol pop3 { pop3_client_workarounds = outlook-no-nuls oe-ns-eoh pop3_logout_format = ; %i bytes in, %o bytes out, %t top (%p bytes), %r retr (%b bytes), %d of %m deleted, mailbox size %s bytes pop3_uidl_format = UID%u-%v } protocol lda { mail_fsync = optimized mail_plugins = mail_log notify zlib sieve } protocol lmtp { mail_fsync = optimized mail_plugins = mail_log notify zlib sieve }
-- Robert L Mathews, Tiger Technologies, http://www.tigertech.net/