Robert L Mathews
2015-Oct-30 22:06 UTC
IMAP COPY creates invalid index data with zlib and mail_log plugins enabled but zlib_save off
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 at 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/
Robert L Mathews
2015-Nov-02 20:12 UTC
IMAP COPY creates invalid index data with zlib and mail_log plugins enabled but zlib_save off
On 10/30/15 3:06 PM, Robert L Mathews wrote:> I've noticed that maildir IMAP COPY commands can generate invalid > dovecot.index entries when all seven of the following are true:As a followup to my own post, I believe I've tracked this problem down to this code at lines 119-124 of /src/plugins/zlib/zlib-plugin.c: /* don't uncompress input when we are reading a mail that we're just in the middle of saving, and we didn't do the compression ourself. in such situation we're probably checking if the user-given input looks compressed */ if (_mail->saving && zuser->save_handler == NULL) return zmail->super.istream_opened(_mail, stream); When these lines are removed, the problem no longer happens. I'm guessing that an IMAP COPY with the seven circumstances I mentioned matches "we are reading a mail that we're just in the middle of saving, and we didn't do the compression ourself". But the mail apparently does need decompressing in this situation. It seems odd for the code to not simply decompress the mail in all cases. But I'm not sure what other code relies on this check, so I have no idea whether removing these lines might cause problems. -- Robert L Mathews, Tiger Technologies, http://www.tigertech.net/
Timo Sirainen
2015-Nov-27 12:59 UTC
IMAP COPY creates invalid index data with zlib and mail_log plugins enabled but zlib_save off
> On 02 Nov 2015, at 22:12, Robert L Mathews <lists at tigertech.com> wrote: > > On 10/30/15 3:06 PM, Robert L Mathews wrote: > >> I've noticed that maildir IMAP COPY commands can generate invalid >> dovecot.index entries when all seven of the following are true: > > As a followup to my own post, I believe I've tracked this problem down > to this code at lines 119-124 of /src/plugins/zlib/zlib-plugin.c: > > /* don't uncompress input when we are reading a mail that we're just > in the middle of saving, and we didn't do the compression ourself. > in such situation we're probably checking if the user-given input > looks compressed */ > if (_mail->saving && zuser->save_handler == NULL) > return zmail->super.istream_opened(_mail, stream); > > When these lines are removed, the problem no longer happens. > > I'm guessing that an IMAP COPY with the seven circumstances I mentioned > matches "we are reading a mail that we're just in the middle of saving, > and we didn't do the compression ourself". But the mail apparently does > need decompressing in this situation. > > It seems odd for the code to not simply decompress the mail in all > cases. But I'm not sure what other code relies on this check, so I have > no idea whether removing these lines might cause problems.The check is there to make sure that people can't try to exploit bugs in compression libraries by uploading something that Dovecot attempts to decompress later on. So if the input looks compressed it's simply rejected. (If zlib_save is enabled this isn't a problem, because the compressed-looking input is compressed again.) Fixed: http://hg.dovecot.org/dovecot-2.2/rev/574c1e5b3d90