Michael Fincham
2019-Sep-05  02:29 UTC
mail_filter and mail_filter_out broken somewhere between 2.2.27 and 2.3.4, problem still exists in git
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]
Aki Tuomi
2019-Sep-05  05:57 UTC
mail_filter and mail_filter_out broken somewhere between 2.2.27 and 2.3.4, problem still exists in git
On 5.9.2019 5.29, Michael Fincham via dovecot wrote:> 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 :)Hi! Thank you for reporting this bug, we are tracking it internally as DOP-1408. Aki
Michael Fincham
2020-Jan-29  06:58 UTC
mail_filter and mail_filter_out broken somewhere between 2.2.27 and 2.3.4, problem still exists in git
Hi Aki, other devs, On Thu, 5 Sep 2019 08:57:30 +0300, Aki Tuomi via dovecot wrote:> Thank you for reporting this bug, we are tracking it internally as DOP-1408.Did a fix for this ever happen? Not urgent, just want to make sure I didn't miss anything. Cheers, -- Michael -------------- next part -------------- A non-text attachment was scrubbed... Name: not available Type: application/pgp-signature Size: 488 bytes Desc: not available URL: <https://dovecot.org/pipermail/dovecot/attachments/20200129/b954ddca/attachment.sig>
Reasonably Related Threads
- mail_filter and mail_filter_out broken somewhere between 2.2.27 and 2.3.4, problem still exists in git
- mail_filter and mail_filter_out broken somewhere between 2.2.27 and 2.3.4, problem still exists in git
- mail_filter plugin: failed: EOF without input
- mail_filter plugin: failed: EOF without input
- mail-filter plugin v2.2 - corrupts IMAP indexes?