dovecot - Aug 2016 - dovecot-lda core-dumps when antispam pipe script calls it

On 2016-08-19 12:17, ben at indietorrent.org wrote:
> Aha! Clearly, the vmail user cannot read from nor write to /tmp. (Why
> that is, I have no idea, as the /tmp directory's permissions certainly
> allow for both; maybe Dovecot implements this as a security measure.)
> 
> This prompted me to change all references to /tmp in the pipe script
> to ~/tmp, and create this directory:
> 
> $ whoami
> vmail
> $ mkdir ~/tmp && chmod 770 ~/tmp
> $ /bin/bash /usr/local/bin/sa-learn-pipe.sh --ham < 
> /var/vmail/gtube.txt
> 
> No errors this time (at least not on the console).
> 
> But I do get this in /var/log/mail.err:
> 
> Aug 19 12:04:24 example.com dovecot: lda(sa-training at example.com):
> Fatal: Can't open delivery mail as raw: Permission denied
> 
> I'm not sure how to interpret this message. Where is permission being
> denied? More importantly, what's the fix?
> 
> Thanks for any hints!
> 
> -Ben
Apologies for the rapid-fire replies here.

The strace output that I'm capturing in the pipe script pinpointed the 
problem:

open("/root/~/tmp/sendmail-msg-26272.txt", O_RDONLY) = -1 EACCES 
(Permission denied)

There seems to be some expansion occurring that assumes the root user, 
despite executing the pipe script as the vmail user, so I changed all 
references  to ~/tmp in the pipe script to /var/vmail/tmp and permission 
is no longer denied.

But, now dovecot-lda is core-dumping. Here is the strace output:

http://pastebin.com/RrKmFhzC

So, I'm back to where I was with this problem two years ago.

At that time, I gave-up, because I couldn't invest the time required to 
compile the latest versions of Dovecot and all plugins from scratch in 
an effort to prove that the bug exists in the latest source.

"Dovecot always logs a detailed error message if something goes wrong. 
If it doesn't, it's considered a bug and will be fixed." - 
http://wiki2.dovecot.org/Logging

I'm happy to help identify the root-cause, but I need some guidance 
here.

Thank you,

-Ben

-----BEGIN PGP SIGNED MESSAGE-----
Hash: SHA1

On Fri, 19 Aug 2016, ben at indietorrent.org wrote:
> On 2016-08-19 12:17, ben at indietorrent.org wrote:
>> Aha! Clearly, the vmail user cannot read from nor write to /tmp. (Why
>> that is, I have no idea, as the /tmp directory's permissions
certainly
Do you have SELinux active?
See almost at the end of
http://wiki2.dovecot.org/WhyDoesItNotWork?highlight=%28selinux%29
>> allow for both; maybe Dovecot implements this as a security measure.)
No. Dovecot does not implement anything like that.
Do you chroot ?
>> This prompted me to change all references to /tmp in the pipe script
>> to ~/tmp, and create this directory:
>> 
>> $ whoami
>> vmail
>> $ mkdir ~/tmp && chmod 770 ~/tmp
>> $ /bin/bash /usr/local/bin/sa-learn-pipe.sh --ham <
/var/vmail/gtube.txt
>> 
>> No errors this time (at least not on the console).
>> 
>> But I do get this in /var/log/mail.err:
>> 
>> Aug 19 12:04:24 example.com dovecot: lda(sa-training at example.com):
>> Fatal: Can't open delivery mail as raw: Permission denied
>> 
>> I'm not sure how to interpret this message. Where is permission
being
>> denied? More importantly, what's the fix?
>> 
>> Thanks for any hints!
>> 
>> -Ben
>
> Apologies for the rapid-fire replies here.
>
> The strace output that I'm capturing in the pipe script pinpointed the 
> problem:
>
> open("/root/~/tmp/sendmail-msg-26272.txt", O_RDONLY) = -1 EACCES
(Permission
> denied)
Er, '/root/~/tmp/' ??
> There seems to be some expansion occurring that assumes the root user, 
> despite executing the pipe script as the vmail user, so I changed all 
> references  to ~/tmp in the pipe script to /var/vmail/tmp and permission is
> no longer denied.
>
> But, now dovecot-lda is core-dumping. Here is the strace output:
>
> http://pastebin.com/RrKmFhzC
>
> So, I'm back to where I was with this problem two years ago.
>
> At that time, I gave-up, because I couldn't invest the time required to
> compile the latest versions of Dovecot and all plugins from scratch in an 
> effort to prove that the bug exists in the latest source.
>
> "Dovecot always logs a detailed error message if something goes wrong.
If it
> doesn't, it's considered a bug and will be fixed." - 
> http://wiki2.dovecot.org/Logging
>
> I'm happy to help identify the root-cause, but I need some guidance
here.
First: check the SELinux thing.
Second: Do you run in a chrooted environment?
Third: Enclose all your script with logging, e.g.:

#!/bin/bash
(
date
echo "$@"
id
id -a
echo environment
env
set
# check for chroot
echo stat /
stat /
echo /proc/1/mountinfo
awk '$5=="/" {print}' </proc/1/mountinfo
echo /proc/$$/mountinfo
awk '$5=="/" {print}' </proc/$$/mountinfo
# enable bash tracing
set -vx

... # old script
) >> /var/tmp/antispam.$$.log 2>&1

Make sure /var/tmp/antispam.$$.log is writeable, maybe create a new 
directory with owner vmail.
Make sure you have 2>&1 at the end. Your log misses all the error 
messages.
Also, you will now have a log file for each run of the script.

To check for chroot:
stat / should print inode 2, but any mountpoint has inode 2.
/proc/$$/mountinfo displays the physical information of a mount, if both 
differ, the current process is chrooted. "1" should be the init
process.

In your script:

for opt; do
         if [[ "$*" =~ .*ham.* ]]

This makes no sense, either use for loop and test "$opt" here, or do
not
use for, but use "$*"; .*ham.* should be quoted anyway.

cat<&0 >> /tmp/sendmail-msg-$$.txt
Well, if for any reason this file exists, ..
cat - >/tmp/sendmail-msg-$$.txt


/usr/lib/dovecot/deliver -d "sa-training at example.com" -m
"Training.$mode"
You've already scraped the message from stdin into a file, so add:
< /tmp/sendmail-msg-$$.txt

About the '-p' switch present in the strace-variant:
Please scan the mailing list for the status of it, IMHO, there had been 
lots of trouble in certain cases.

The strace variant should use -oLogfile.strace.$$.log in order to separate 
the output of the command and strace logging.

- -- 
Steffen Kaiser
-----BEGIN PGP SIGNATURE-----
Version: GnuPG v1

iQEVAwUBV7qnd3z1H7kL/d9rAQJXWQf9E/ucaEXMy10IE5f7JY3tbZVlROGrz+wk
5rA0/Xe/aFwgNvCzyTX+MV7BblHH//aDwlNs3L4P+bZatCjAVCmoDdQ/WDZ7wr51
mBq/vOjcullnzz8NHv2+gQgRCKhGGd8M+mVjGUlyK6jXEFjwAaivEnRA86AudZi4
ybK0CZKw+Pg+VzDcfGjvO4PHZWAxvbqktqVOUhQwEL/+A/CZ7FNSsBuuZug42TGK
tmghQmAKuwY96djSV/vFax8J8WyVnGKBVLpONP9iMllGkZ7MHGacpfm0MSgsIgPv
DTTdjdk1P6FIQ615rp6BRg0JKaTn7COC6YxMnuaNtlXJ2t/M5zoCNA==/xgA
-----END PGP SIGNATURE-----

On 19/08/16 17:35, ben at indietorrent.org wrote:
> So, I'm back to where I was with this problem two years ago.
Maybe this will help you.
I've been using antispam plugin in the same way you intend to do it for 
years now. (script modification date Feb 2014).

All the Maildirs on my system are under /var/vmail/%d/%u/ and chmod'ed 
as vmail:vmail user. This is the script that is working for sure. You 
can test it by changinf the output path, but anyway it has been with me 
since dovecot 1.x as far as I remember, no problems at all!

#!/bin/bash

T=`date +%s%N`
cat<&0 >> /var/vmail/learn/$1/$T-$$.txt
exit 0

Good luck!

Karol

-- 
Karol Augustin
karol at augustin.pl
http://karolaugustin.pl/
+353 85 775 5312

On 2016-08-22 03:19, Steffen Kaiser wrote:
> -----BEGIN PGP SIGNED MESSAGE-----
> Hash: SHA1
> 
> On Fri, 19 Aug 2016, ben at indietorrent.org wrote:
>> On 2016-08-19 12:17, ben at indietorrent.org wrote:
>>> Aha! Clearly, the vmail user cannot read from nor write to /tmp.
(Why
>>> that is, I have no idea, as the /tmp directory's permissions 
>>> certainly
Thank you very much for taking the time to investigate my use-case and 
help me work through this, Steffen. I really appreciate it.
> 
> Do you have SELinux active?
> See almost at the end of
> http://wiki2.dovecot.org/WhyDoesItNotWork?highlight=%28selinux%29
> 
No.

# apparmor_status
The program 'apparmor_status' is currently not installed. You can 
install it by typing:
apt install apparmor

# sestatus
The program 'sestatus' is currently not installed. You can install it by
typing:
apt install policycoreutils
>>> allow for both; maybe Dovecot implements this as a security
measure.)
> 
> No. Dovecot does not implement anything like that.
> Do you chroot ?
> 
No. Certainly not intentionally, anyway.
>> The strace output that I'm capturing in the pipe script pinpointed
the
>> problem:
>> 
>> open("/root/~/tmp/sendmail-msg-26272.txt", O_RDONLY) = -1
EACCES
>> (Permission denied)
> 
> Er, '/root/~/tmp/' ??
> 
I know. It's weird. Presumably, Bash is responsible for this
"unusual"
expansion. The raw script source has ~/tmp, so why would Bash prepend it 
with "/root/", especially when the script is executed as the
"vmail"
user? Perhaps it's academic at this point, because I've changed all 
paths to be absolute and they are now resolved correctly.
> 
> First: check the SELinux thing.
> Second: Do you run in a chrooted environment?
> Third: Enclose all your script with logging, e.g.:
> 
> #!/bin/bash
> (
> date
> echo "$@"
> id
> id -a
> echo environment
> env
> set
> # check for chroot
> echo stat /
> stat /
> echo /proc/1/mountinfo
> awk '$5=="/" {print}' </proc/1/mountinfo
> echo /proc/$$/mountinfo
> awk '$5=="/" {print}' </proc/$$/mountinfo
> # enable bash tracing
> set -vx
> 
> ... # old script
> ) >> /var/tmp/antispam.$$.log 2>&1
> 
> Make sure /var/tmp/antispam.$$.log is writeable, maybe create a new
> directory with owner vmail.
> Make sure you have 2>&1 at the end. Your log misses all the error 
> messages.
> Also, you will now have a log file for each run of the script.
> 
> To check for chroot:
> stat / should print inode 2, but any mountpoint has inode 2.
> /proc/$$/mountinfo displays the physical information of a mount, if
> both differ, the current process is chrooted. "1" should be the
init
> process.
> 
> In your script:
> 
> for opt; do
>         if [[ "$*" =~ .*ham.* ]]
> 
> This makes no sense, either use for loop and test "$opt" here, or
do
> not use for, but use "$*"; .*ham.* should be quoted anyway.
Nice catch. I am by no means a Bash wizard, and I cobbled this together 
3-4 years ago. I have no idea what I was thinking at the time.

I removed the "for" loop, leaving only the regex check, and it seems
to
work as intended. (FWIW, if I add quotes around the test expression, 
e.g., ".*ham.*", a match is never found and the check fails.)
> cat<&0 >> /tmp/sendmail-msg-$$.txt
> Well, if for any reason this file exists, ..
> cat - >/tmp/sendmail-msg-$$.txt
> 
> 
> /usr/lib/dovecot/deliver -d "sa-training at example.com" -m 
> "Training.$mode"
> You've already scraped the message from stdin into a file, so add:
> < /tmp/sendmail-msg-$$.txt
Yes, but I uncomment that line only for debugging purposes. Normally, I 
do not take the interim step of saving the message contents to disk, in 
which case I want dovecot-lda to read from stdin.
> About the '-p' switch present in the strace-variant:
> Please scan the mailing list for the status of it, IMHO, there had
> been lots of trouble in certain cases.
> 
> The strace variant should use -oLogfile.strace.$$.log in order to
> separate the output of the command and strace logging.
> 
> - -- Steffen Kaiser
Good to know; I have made that adjustment, too.

Bash issues aside, I've taken a step back and attempted to make the 
reproducible test-case as simple as possible, whittling-down the script 
to only the following, and dovecot-lda still segfaults:

http://pastebin.com/zXzBDcvG

I've added a couple of things to Dovecot's configuration, but they
don't
make any difference:

# Required for "vmail" user to be able to call dovecot-lda/deliver.
# See: http://wiki.dovecot.org/LDA ("Logging" section)
service config {
   unix_listener config {
     mode = 0600
     user = vmail
     group = vmail
   }
}

protocol lda {
   # Enable logging for dovecot-lda.
   info_log_path = /var/log/dovecot-lda.log
   log_path = /var/log/dovecot-lda-errors.log
   mail_plugins = sieve quota
}

Yet, nothing is logged to either of these files when the pipe script is 
called.

The permissions on these files look reasonable to me:

-rw-rw----   1 vmail  vmail              0 Aug 23 12:02 
dovecot-lda-errors.log
-rw-rw----   1 vmail  vmail              0 Aug 23 12:01 dovecot-lda.log

Here is my current "doveconf -n" output:

http://pastebin.com/hCgpA009

At this point, this seems obvious, but the problem is definitely with 
using dovecot-lda to send the mail.

If I simply write the contents of the spam/ham message to disk in the 
pipe script, it works fine. But that approach feels "hackish" to me,
as
it doesn't account for sieve, quota, etc. And I want the delivery to be 
logged.

Again, this works fine:

# su vmail
$ /usr/lib/dovecot/deliver -d "sa-training at example.org" -m 
"Training.HAM" -p /var/vmail/gtube.txt

Here's the output from the logging that we added:

http://pastebin.com/rz2f4S4G

Does anything jump-out?

Thanks again for all your help with this!

--Ben
> -----BEGIN PGP SIGNATURE-----
> Version: GnuPG v1
> 
> iQEVAwUBV7qnd3z1H7kL/d9rAQJXWQf9E/ucaEXMy10IE5f7JY3tbZVlROGrz+wk
> 5rA0/Xe/aFwgNvCzyTX+MV7BblHH//aDwlNs3L4P+bZatCjAVCmoDdQ/WDZ7wr51
> mBq/vOjcullnzz8NHv2+gQgRCKhGGd8M+mVjGUlyK6jXEFjwAaivEnRA86AudZi4
> ybK0CZKw+Pg+VzDcfGjvO4PHZWAxvbqktqVOUhQwEL/+A/CZ7FNSsBuuZug42TGK
> tmghQmAKuwY96djSV/vFax8J8WyVnGKBVLpONP9iMllGkZ7MHGacpfm0MSgsIgPv
> DTTdjdk1P6FIQ615rp6BRg0JKaTn7COC6YxMnuaNtlXJ2t/M5zoCNA=> =/xgA
> -----END PGP SIGNATURE-----