Ubuntu

dovecot-deliver crashes (exits with status code 134) when message is passed to pipe backend

Asked by Ben Johnson on 2014-09-19

I first reported this issue on the Dovecot mailing list, but nobody there was able to help me identify the source of the problem (no less how to fix it). And that's a pretty sharp group! Here's the full thread:

http://<email address hidden>/msg58938.html

I will preface this by saying that this bug could very well be with dovecot-deliver and not the antispam plugin, specifically. I'm still trying to make that determination, definitively. Any assistance in that regard is much appreciated.

One aspect that I would like to point-out immediately is that the dovecot deliver manual at http://wiki2.dovecot.org/LDA#logging states very clearly, "If dovecot-lda fails to write to log files it exits with temporary failure." That's a curious note, because I believe that a "temporary failure" exit code is precisely what we're dealing with here.

Anyhow, without further ado...

On Ubuntu 12.04, I used this plug-in with great success, so when I upgraded to 14.04 (using dist-upgrade), I had hoped to be able to continue using it in exactly the same way.

I consulted the manpages for Ubuntu 12.04 LTS and 14.04 LTS and they are identical -- verbatim, right down to the last letter. As such, I assumed that my antispam-related configuration directives would not need to be changed.

However, on Ubuntu 14.04, when the "pipe script" that the antispam plugin calls executes dovecot-deliver (this is how I pass the ham or spam message to a dedicated training mailbox), dovecot-deliver exits with status code 134, every time. Dovecot seems not to log anything with regard to the segfault in its logs, despite my efforts to configure deliver to log any issues:

protocol lda {
..
  # remember to give proper permissions for these files as well
  log_path = /var/log/dovecot-lda-errors.log
  info_log_path = /var/log/dovecot-lda.log
}

These are the permissions I assigned to those two log files:

# ls -lah /var/log | grep "dovecot"
-rw-r--r-- 1 vmail vmail 0 Sep 19 14:21 dovecot-lda-errors.log
-rw-r--r-- 1 vmail vmail 0 Sep 19 14:21 dovecot-lda.log

When I restart dovecot with these LDA logging efforts in-place, I still don't see the log file sizes grow beyond zero bytes.

The exit code, 134, isn't mentioned at all in the documentation at http://wiki2.dovecot.org/LDA , either.

By adding the following to the top of my pipe script (thank you to Steffen Kaiser on the mailing list for the suggestion)

exec >> /tmp/trace 2>&1
set -vx

I've been able to capture the following output when the pipe script is called (pardon the wrapping); this is just the most relevant bit:

+ /usr/lib/dovecot/deliver -d <email address hidden> -m Training.SPAM
^A^H22212 prefix=lda:
^A^F22212 io_add(0x1) called twice fd=7, callback=0x7f020f5486f0 -> 0x7f020f4f7530
^A^D22212 Raw backtrace: /usr/lib/dovecot/libdovecot.so.0(+0x5e271) [0x7f020f536271] -> /usr/lib/dovecot/libdovecot.so.0(+0x5e34e) [0x7f020f53634e] -> /usr/lib/dovecot/libdovecot.so.0(i_fatal+0) [0x7f020f4f1a9e] -> /usr/lib/dovecot/libdovecot.so.0(ioloop_iolist_add+0x83) [0x7f020f546533] -> /usr/lib/dovecot/libdovecot.so.0(io_loop_handle_add+0x3b) [0x7f020f546cbb] -> /usr/lib/dovecot/libdovecot.so.0(io_add+0x9b) [0x7f020f5459fb] -> /usr/lib/dovecot/libdovecot.so.0(master_service_io_listeners_add+0x69) [0x7f020f4f6e49] -> /usr/lib/dovecot/libdovecot.so.0(master_service_init_finish+0xb0) [0x7f020f4f6f90] -> /usr/lib/dovecot/deliver(main+0x1cb) [0x7f020feea69b] -> /lib/x86_64-linux-gnu/libc.so.6(__libc_start_main+0xf5) [0x7f020f131ec5] -> /usr/lib/dovecot/deliver(+0x31de) [0x7f020feeb1de]
/usr/local/bin/sa-learn-pipe.sh: line 52: 22212 Aborted (core dumped) /usr/lib/dovecot/deliver -d "<email address hidden>" -m "Training.$mode"
+ echo 'Exit status was 134'

The steps I took to obtain a core-dump are as follows:

# ulimit -c unlimited
# ulimit -c
unlimited
# vim /etc/sysctl.d/20-coredump.conf

(added the following contents to the above new file and saved the file)

kernel.core_uses_pid = 1
kernel.core_pattern = /tmp/core-%e-%s-%u-%g-%p-%t
fs.suid_dumpable = 2

# sysctl -p
# service dovecot stop
# /usr/sbin/dovecot -F -c /etc/dovecot/dovecot.conf&
[1] 28150

At this point, when I drag a message from Inbox to Junk, a core-dump is created in /tmp. Here is the gdb output for the core-dump:

# gdb /usr/lib/dovecot/deliver /tmp/core-deliver-6-5000-5000-29807-1411152222
GNU gdb (Ubuntu 7.7-0ubuntu3.1) 7.7
Copyright (C) 2014 Free Software Foundation, Inc.
License GPLv3+: GNU GPL version 3 or later <http://gnu.org/licenses/gpl.html>
This is free software: you are free to change and redistribute it.
There is NO WARRANTY, to the extent permitted by law. Type "show copying"
and "show warranty" for details.
This GDB was configured as "x86_64-linux-gnu".
Type "show configuration" for configuration details.
For bug reporting instructions, please see:
<http://www.gnu.org/software/gdb/bugs/>.
Find the GDB manual and other documentation resources online at:
<http://www.gnu.org/software/gdb/documentation/>.
For help, type "help".
Type "apropos word" to search for commands related to "word"...
Reading symbols from /usr/lib/dovecot/deliver...Reading symbols from /usr/lib/debug//usr/lib/dovecot/dovecot-lda...done.
done.

warning: core file may not match specified executable file.
[New LWP 29807]
Core was generated by `/usr/lib/dovecot/deliver -d <email address hidden> -m Training.HAM'.
Program terminated with signal SIGABRT, Aborted.
#0 0x00007fd083fb6bb9 in __GI_raise (sig=sig@entry=6) at ../nptl/sysdeps/unix/sysv/linux/raise.c:56
56 ../nptl/sysdeps/unix/sysv/linux/raise.c: No such file or directory.
(gdb)

Might anybody know how to interpret this? The research I've done indicates that the final breath, "No such file or directory," is the result of not having the source for the C library installed. Not too helpful, it seems.

The "bt full" output can be found at http://pastebin.com/qGyRtQSN . Nothing therein jumps-out at me, but I don't know exactly what I'm looking for, either.

My "lsb_release -a" output:

# lsb_release -a
No LSB modules are available.
Distributor ID: Ubuntu
Description: Ubuntu 14.04.1 LTS
Release: 14.04
Codename: trusty

My full "doveconf -n" output:

# doveconf -n
# 2.2.9: /etc/dovecot/dovecot.conf
# OS: Linux 3.13.0-34-generic x86_64 Ubuntu 14.04.1 LTS
auth_mechanisms = plain login
disable_plaintext_auth = no
listen = *,[::]
log_timestamp = "%Y-%m-%d %H:%M:%S "
mail_debug = yes
mail_privileged_group = vmail
managesieve_notify_capability = mailto
managesieve_sieve_capability = fileinto reject envelope encoded-character vacation subaddress comparator-i;ascii-numeric relational regex imap4flags copy include variables body enotify environment mailbox date ihave
passdb {
  args = /etc/dovecot/dovecot-sql.conf
  driver = sql
}
plugin {
  antispam_backend = pipe
  antispam_debug_target = syslog
  antispam_pipe_program = /bin/bash
  antispam_pipe_program_args = /usr/local/bin/sa-learn-pipe.sh
  antispam_pipe_program_notspam_arg = --ham
  antispam_pipe_program_spam_arg = --spam
  antispam_pipe_tmpdir = /tmp
  antispam_spam_pattern_ignorecase = SPAM;JUNK
  antispam_trash_pattern_ignorecase = trash;Deleted *
  antispam_verbose_debug = 1
  quota = dict:user::file:/var/vmail/%d/%n/.quotausage
  quota_rule2 = Trash:storage=+100M
  quota_rule3 = Junk:ignore
  quota_rule4 = INBOX:storage=+100M
  quota_warning = storage=100%% quota-reached 100 %u %d
  quota_warning2 = storage=95%% quota-warning 95 %u %d
  quota_warning3 = storage=80%% quota-warning 80 %u %d
  quota_warning4 = -storage=100%% quota-below below %u %d
  sieve = /var/vmail/%d/%n/.sieve
}
postmaster_address = <email address hidden>
protocols = imap pop3 sieve
service auth {
  unix_listener /var/spool/postfix/private/auth {
    group = postfix
    mode = 0660
    user = postfix
  }
  unix_listener auth-userdb {
    group = vmail
    mode = 0600
    user = vmail
  }
  user = root
}
service config {
  unix_listener config {
    group = vmail
    mode = 0600
    user = vmail
  }
}
service imap-login {
  client_limit = 1000
  process_limit = 500
}
service quota-below {
  executable = script /usr/local/bin/quota-below.sh
  unix_listener quota-below {
    group = vmail
    mode = 0666
    user = vmail
  }
  user = vmail
}
service quota-reached {
  executable = script /usr/local/bin/quota-reached.sh
  unix_listener quota-reached {
    group = vmail
    mode = 0666
    user = vmail
  }
  user = vmail
}
service quota-warning {
  executable = script /usr/local/bin/quota-warning.sh
  unix_listener quota-warning {
    group = vmail
    mode = 0666
    user = vmail
  }
  user = vmail
}
ssl_cert = </etc/postfix/smtpd.cert
ssl_key = </etc/postfix/smtpd.key
userdb {
  args = /etc/dovecot/dovecot-sql.conf
  driver = sql
}
protocol imap {
  mail_plugins = quota imap_quota antispam
}
protocol pop3 {
  mail_plugins = quota
  pop3_uidl_format = %08Xu%08Xv
}
protocol lda {
  info_log_path =
  log_path =
  mail_plugins = sieve quota
}