mail_filter and mail_filter_out broken somewhere between 2.2.27 and 2.3.4, problem still exists in git

Michael Fincham michael at hotplate.co.nz
Thu Sep 5 05:29:31 EEST 2019


Hi Dovecot folks,

I recently reported this bug in Debian (https://bugs.debian.org/cgi-bin/bugreport.cgi?bug=939442) after a stretch -> buster upgrade, however since I can reproduce it using the latest 2.4 from git I thought perhaps I ought to take it straight upstream.

Here's the text I provided Debian about the issue, and below that I've included a syslog snip showing the same issue in a fresh build of git master as well.

mail_filter_out seems to fully panic (backtrace below), whereas mail_filter is just behaving oddly.

Thanks :)

*****************************

Package: dovecot-core
Version: 2.3.4.1-5+deb10u1
Severity: important

Hi Dovecot maintainers,

After upgrading from the latest stretch version of dovecot-core
(2.2.27-3+deb9u5) to buster (2.3.4.1-5+deb10u1) the "mail filter"
interface seems to have broken. This problem is also present in the sid
version (2.3.7.2-1).

Mail filter is used to run the content of messages being stored or
retrieved through an arbitrary process. The interface used for the
external process is described here:
https://wiki.dovecot.org/Plugins/MailFilter

It is expected that the process will be called with the arguments
specified in the configuration then supplied a message body on stdin,
however since upgrading it seems that the arguments are not being
correctly passed, instead being all jammed in to $1 and separated by
tabs, rather than expanded in to argv. Even stranger the first few
lines of the body of the message appear in argv rather than in stdin...

These reproduction steps were carried out on a fresh install of Debian
Buster with the "dovecot-core" package installed initially from stretch
then upgraded to the buster version, however this behaviour has also
been observed on stretch systems after upgrading to buster.

To reproduce, drop this minimalised config in
to /etc/dovecot/conf.d/repro.conf:

# Minimal maildir setup for LDA
first_valid_uid = 0
mail_location = maildir:~/Maildir
userdb {
  driver = static
  args = allow_all_users=yes uid=mail gid=mail home=/tmp/%u
}

# Mail filter configuration
mail_plugins = $mail_plugins mail_filter

plugin {
  mail_filter = mail-filter read %u
  mail_filter_out = mail-filter write %u
}

service mail-filter {
 executable = script /usr/local/bin/mail-filter.sh
 user = dovecot
 unix_listener mail-filter {
   mode = 0666
 }
}

And create the example script in /usr/local/bin/mail-filter.sh with
executable permissions:

#!/bin/bash

echo "arguments were: $@" 1>&2
tempfile=$(mktemp)
cat > "${tempfile}"
cat "${tempfile}"
rm "${tempfile}"

This script simply logs the arguments it recieves, writes stdin to a
file then retrieves it again from the file.

Here's a sample session of me using dovecot-lda to pass a message
through this script, then retrieve it again with doveadm:

root at scratch-b6fd8bdd:~# /usr/lib/dovecot/dovecot-lda -d fincham at scratch-b6fd8bdd -f 'Test <scratch-b6fd8bdd>' < /root/test.eml 
root at scratch-b6fd8bdd:~# doveadm fetch -u 'fincham at scratch-b6fd8bdd' hdr subject Test
hdr:
To: Test <fincham at scratch-b6fd8bdd>
From: Test <fincham at scratch-b6fd8bdd>
Subject: This is the test e-mail

root at scratch-b6fd8bdd:~# tail /var/log/syslog | grep mail-filter
Sep  5 00:07:48 scratch-b6fd8bdd dovecot: mail-filter: Error: arguments were: write fincham at scratch-b6fd8bdd
Sep  5 00:07:50 scratch-b6fd8bdd dovecot: mail-filter: Error: arguments were: read fincham at scratch-b6fd8bdd

However after upgrading dovecot to the buster version this process no
longer works, and the logged argv of the example script is very strange:

root at scratch-b6fd8bdd:~# apt dist-upgrade
Reading package lists... Done
Building dependency tree       
Reading state information... Done
Calculating upgrade... Done
The following NEW packages will be installed:
  liblua5.3-0 libsodium23 ssl-cert
The following packages will be upgraded:
  dovecot-core
[...]

root at scratch-b6fd8bdd:~# /usr/lib/dovecot/dovecot-lda -d fincham at scratch-b6fd8bdd -f scratch-b6fd8bdd < /root/test.eml 
Aborted
root at scratch-b6fd8bdd:~# doveadm fetch -u 'fincham at scratch-b6fd8bdd' hdr subject Test
hdr:
Hello!
doveadm(fincham at scratch-b6fd8bdd): Error: Mailbox INBOX: UID=1: read() failed: Cached message size larger than expected (115 > 7, box=INBOX, UID=1) (read reason=mail stream)
doveadm(fincham at scratch-b6fd8bdd): Error: Corrupted record in index cache file /tmp/fincham at scratch-b6fd8bdd/Maildir/dovecot.index.cache: UID 1: Broken physical size in mailbox INBOX: read() failed: Cached message size larger than expected (115 > 7, box=INBOX, UID=1)
doveadm(fincham at scratch-b6fd8bdd): Error: read() failed: Cached message size larger than expected (115 > 7, box=INBOX, UID=1)
doveadm(fincham at scratch-b6fd8bdd): Error: fetch(hdr) failed for box=INBOX uid=1: read() failed: Cached message size larger than expected (115 > 7, box=INBOX, UID=1)
root at scratch-b6fd8bdd:~# tail /var/log/syslog | grep mail-filter
Sep  5 00:07:48 scratch-b6fd8bdd dovecot: mail-filter: Error: arguments were: write fincham at scratch-b6fd8bdd
Sep  5 00:07:50 scratch-b6fd8bdd dovecot: mail-filter: Error: arguments were: read fincham at scratch-b6fd8bdd
Sep  5 00:12:11 scratch-b6fd8bdd dovecot: mail-filter: Error: arguments were: write#011fincham at scratch-b6fd8bdd#011 To: Test <fincham at scratch-b6fd8bdd> From: Test <fincham at scratch-b6fd8bdd> Subject: This is the test e-mail
Sep  5 00:12:14 scratch-b6fd8bdd dovecot: mail-filter: Error: arguments were: read#011fincham at scratch-b6fd8bdd#011 To: Test <fincham at scratch-b6fd8bdd> From: Test <fincham at scratch-b6fd8bdd> Subject: This is the test e-mail

-- Package-specific info:

dovecot configuration
---------------------
# 2.3.4.1 (f79e8e7e4): /etc/dovecot/dovecot.conf
# Pigeonhole version 0.5.4 ()
# OS: Linux 4.19.0-5-cloud-amd64 x86_64 Debian 10.0
# Hostname: scratch-b6fd8bdd
first_valid_uid = 0
mail_location = maildir:~/Maildir
mail_plugins = " mail_filter"
mail_privileged_group = mail
namespace inbox {
  inbox = yes
  location =
  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 =
}
passdb {
  driver = pam
}
plugin {
  mail_filter = mail-filter read %u
  mail_filter_out = mail-filter write %u
}
service mail-filter {
  executable = script /usr/local/bin/mail-filter.sh
  unix_listener mail-filter {
    mode = 0666
  }
  user = dovecot
}
ssl = no
userdb {
  driver = passwd
}
userdb {
  args = allow_all_users=yes uid=mail gid=mail home=/tmp/%u
  driver = static
}

-- System Information:
Debian Release: 10.0
  APT prefers stable-updates
  APT policy: (500, 'stable-updates'), (500, 'stable')
Architecture: amd64 (x86_64)

Kernel: Linux 4.19.0-5-cloud-amd64 (SMP w/2 CPU cores)
Locale: LANG=en_US.UTF-8, LC_CTYPE=en_US.UTF-8 (charmap=UTF-8), LANGUAGE=en_US.UTF-8 (charmap=UTF-8)
Shell: /bin/sh linked to /usr/bin/dash
Init: systemd (via /run/systemd/system)
LSM: AppArmor: enabled

Versions of packages dovecot-core depends on:
ii  adduser              3.118
ii  libapparmor1         2.13.2-10
ii  libbz2-1.0           1.0.6-9.1
ii  libc6                2.28-10
ii  libexttextcat-2.0-0  3.4.5-1
ii  libicu63             63.1-6
ii  liblua5.3-0          5.3.3-1.1
ii  liblz4-1             1.8.3-1
ii  liblzma5             5.2.4-1
ii  libpam-runtime       1.3.1-5
ii  libpam0g             1.3.1-5
ii  libsodium23          1.0.17-1
ii  libssl1.1            1.1.1c-1
ii  libstemmer0d         0+svn585-1+b2
ii  libwrap0             7.6.q-28
ii  lsb-base             10.2019051400
ii  openssl              1.1.1c-1
ii  ssl-cert             1.0.39
ii  ucf                  3.0038+nmu1
ii  zlib1g               1:1.2.11.dfsg-1

dovecot-core recommends no packages.

Versions of packages dovecot-core suggests:
pn  dovecot-gssapi        <none>
pn  dovecot-imapd         <none>
pn  dovecot-ldap          <none>
pn  dovecot-lmtpd         <none>
pn  dovecot-lucene        <none>
pn  dovecot-managesieved  <none>
pn  dovecot-mysql         <none>
pn  dovecot-pgsql         <none>
pn  dovecot-pop3d         <none>
pn  dovecot-sieve         <none>
pn  dovecot-solr          <none>
pn  dovecot-sqlite        <none>
pn  dovecot-submissiond   <none>
ii  ntp                   1:4.2.8p12+dfsg-4

Versions of packages dovecot-core is related to:
ii  dovecot-core [dovecot-common]  1:2.3.4.1-5+deb10u1
pn  dovecot-dev                    <none>
pn  dovecot-gssapi                 <none>
pn  dovecot-imapd                  <none>
pn  dovecot-ldap                   <none>
pn  dovecot-lmtpd                  <none>
pn  dovecot-managesieved           <none>
pn  dovecot-mysql                  <none>
pn  dovecot-pgsql                  <none>
pn  dovecot-pop3d                  <none>
pn  dovecot-sieve                  <none>
pn  dovecot-sqlite                 <none>

-- no debconf information

*****************************

And here it is on 2.4 from git:

Sep  5 02:18:10 scratch-b6fd8bdd dovecot: master: Dovecot v2.4.devel () starting up for imap, pop3, lmtp
Sep  5 02:18:10 scratch-b6fd8bdd systemd[1]: Started LSB: Dovecot init script.
Sep  5 02:18:12 scratch-b6fd8bdd dovecot: mail-filter: Error: arguments were: write#011fincham at scratch-b6fd8bdd#011 To: Test <fincham at scratch-b6fd8bdd> From: Test <fincham at scratch-b6fd8bdd> Subject: This is the test e-mail
Sep  5 02:18:12 scratch-b6fd8bdd dovecot: lda(fincham at scratch-b6fd8bdd)<4213><94f8BWRwcF11EAAA/w3Ckw>: Panic: file ostream.c: line 201 (o_stream_flush): assertion failed: (stream->stream_errno != 0)
Sep  5 02:18:12 scratch-b6fd8bdd dovecot: lda(fincham at scratch-b6fd8bdd)<4213><94f8BWRwcF11EAAA/w3Ckw>: Error: Raw backtrace: /usr/lib/dovecot/libdovecot.so.0(+0xef5fb) [0x7f85ed0715fb] -> /usr/lib/dovecot/libdovecot.so.0(+0xef661) [0x7f85ed071661] -> /usr/lib/dovecot/libdovecot.so.0(+0x4e808) [0x7f85ecfd0808] -> /usr/lib/dovecot/libdovecot.so.0(+0x52ec1) [0x7f85ecfd4ec1] -> /usr/lib/dovecot/libdovecot-storage.so.0(maildir_save_finish+0x96) [0x7f85ed1b24d6] -> /usr/lib/dovecot/libdovecot-lda.so.0(+0x4395) [0x7f85ed294395] -> /usr/lib/dovecot/libdovecot-storage.so.0(mailbox_save_finish+0x82) [0x7f85ed189e52] -> /usr/lib/dovecot/libdovecot-storage.so.0(mail_storage_copy+0xd9) [0x7f85ed17c409] -> /usr/lib/dovecot/libdovecot-storage.so.0(maildir_copy+0x52) [0x7f85ed1aea02] -> /usr/lib/dovecot/libdovecot-lda.so.0(+0x4221) [0x7f85ed294221] -> /usr/lib/dovecot/libdovecot-storage.so.0(+0x5c1bc) [0x7f85ed18a1bc] -> /usr/lib/dovecot/libdovecot-lda.so.0(mail_deliver_save+0x1b0) [0x7f85ed295390] 
 -> /usr/lib/dovecot/libdovecot-lda.so.0(mail_deliver+0x2f6) [0x7f85ed295ad6] -> /usr/libexec/dovecot/dovecot-lda(main+0x81b) [0x560cba869f4b] -> /lib/x86_64-linux-gnu/libc.so.6(__libc_start_main+0xeb) [0x7f85ecdde09b] -> /usr/libexec/dovecot/dovecot-lda(_start+0x2a) [0x560cba86a65a]



More information about the dovecot mailing list