Hi,
I'm running a dovecot 2.2.26 (self compiled) on a Centos 7.
I have a sieve script which should run an external script (in filter
mode) that encrypts the mail using the users pub key.
I configured 90-plugin.conf as follows
plugin {
sieve_plugins = sieve_extprograms
sieve_extensions = +vnd.dovecot.filter
sieve_filter_bin_dir = /etc/dovecot/sieve-filters
sieve_filter_exec_timeout = 10000
}
The script is named SCRIPT and is called in my sieve script
require "vnd.dovecot.filter";
if blabla {
filter "SCRIPT" ["me at example.com"];
}
the script returns the encrypted mail.
I can call this SCRIPT without any error manually on the console as
dovecot user (vmail).
Also sieve-test "says" that the script called sucessfully
su vmail
sieve-test -e -t - -Tlevel=commands -r me at example.com -l
/home/vmail/example.com/me/.Maildir
/home/vmail/example.com/me/.dovecot.sieve /tmp/test.mail
...
23: filter action
23: execute program `SCRIPT'
23: executed program successfully
23: changed message
...
info:
msgid=<B5OEuIEvrCZzcoJ7A6fCF-ka2Nwz-Ze2UCO840Panvw.w7zr1vruaJMbDBwK63natps3v__yOgbhHy3ntACTU0s
at redacted>:
stored mail into mailbox 'INBOX'.
sieve-test(vmail): Info: final result: success
and I get the encrpted message in my mailbox.
Just when it's called upon delivery via lmtp the script ends with signal 11
Jan 3 15:59:48 mbox2 dovecot: lmtp(me at example.com): Error: program
`/etc/dovecot/sieve-filters/SCRIPT' terminated abnormally, signal 11
And in ~/.dovecot.sieve.log I can find the following
.dovecot: line 23: error: filter action: failed to execute to program
`SCRIPT': refer to server log for more information. [2017-01-03 15:59:48].
I have no idea why the manual call runs perfect and the call from sieve
file ends up in this error.
Does anyone have an idea how I could narrow down the source of this
error? Or even better how to fix it? :-)
Thanks for any answer
tobi
Aki Tuomi
2017-Jan-03 19:32 UTC
dovecot-pigeonhole running external script ends with signal 11
On 01/03/2017 05:28 PM, Tobi wrote:> Hi, > > I'm running a dovecot 2.2.26 (self compiled) on a Centos 7. > I have a sieve script which should run an external script (in filter > mode) that encrypts the mail using the users pub key. > > I configured 90-plugin.conf as follows > > plugin { > sieve_plugins = sieve_extprograms > sieve_extensions = +vnd.dovecot.filter > sieve_filter_bin_dir = /etc/dovecot/sieve-filters > sieve_filter_exec_timeout = 10000 > } > > The script is named SCRIPT and is called in my sieve script > > require "vnd.dovecot.filter"; > if blabla { > filter "SCRIPT" ["me at example.com"]; > } > > the script returns the encrypted mail. > > I can call this SCRIPT without any error manually on the console as > dovecot user (vmail). > Also sieve-test "says" that the script called sucessfully > > su vmail > sieve-test -e -t - -Tlevel=commands -r me at example.com -l > /home/vmail/example.com/me/.Maildir > /home/vmail/example.com/me/.dovecot.sieve /tmp/test.mail > ... > 23: filter action > 23: execute program `SCRIPT' > 23: executed program successfully > 23: changed message > ... > info: > msgid=<B5OEuIEvrCZzcoJ7A6fCF-ka2Nwz-Ze2UCO840Panvw.w7zr1vruaJMbDBwK63natps3v__yOgbhHy3ntACTU0s at redacted>: > stored mail into mailbox 'INBOX'. > sieve-test(vmail): Info: final result: success > > and I get the encrpted message in my mailbox. > > Just when it's called upon delivery via lmtp the script ends with signal 11 > > Jan 3 15:59:48 mbox2 dovecot: lmtp(me at example.com): Error: program > `/etc/dovecot/sieve-filters/SCRIPT' terminated abnormally, signal 11 > > And in ~/.dovecot.sieve.log I can find the following > > .dovecot: line 23: error: filter action: failed to execute to program > `SCRIPT': refer to server log for more information. [2017-01-03 15:59:48]. > > I have no idea why the manual call runs perfect and the call from sieve > file ends up in this error. > Does anyone have an idea how I could narrow down the source of this > error? Or even better how to fix it? :-) > > Thanks for any answer > > tobiThis seems to be a problem with SCRIPT, it seems to sigfault. Aki
Stephan Bosch
2017-Jan-03 20:12 UTC
dovecot-pigeonhole running external script ends with signal 11
Op 1/3/2017 om 4:28 PM schreef Tobi:> I have no idea why the manual call runs perfect and the call from sieve > file ends up in this error. > Does anyone have an idea how I could narrow down the source of this > error? Or even better how to fix it? :-)In the most likely scenario, there is some sort of bug in one of the programs your script invokes or even the shell running the script. Still, it is possible that Dovecot is causing this in the brief moment after the child process is forked and before actual script is executed. Since you're using LMTP, you could try to run the lmtp service from command line in GDB. In essence, this looks as follows (you will need to run this as the mail user, e.g. vmail, or you can run it as root): $ gdb --args /usr/lib/dovecot/lmtp <verbose GDB output/> Reading symbols from /usr/lib/dovecot/lmtp...done. (gdb) set follow-fork-mode child (gdb) r Starting program: /usr/lib/dovecot/lmtp process 63910 is executing new program: /usr/bin/doveconf process 63910 is executing new program: /usr/lib/dovecot/lmtp Debug: none: root=, index=, indexpvt=, control=, inbox=, alt220 johanna.johanna.tds Dovecot ready. Info: Connect from local lhlo frop 250-johanna.johanna.tds 250-8BITMIME 250-ENHANCEDSTATUSCODES 250 PIPELINING mail from:<stephan at rename-it.nl> 250 2.1.0 OK rcpt to:<user> 250 2.1.5 OK data 354 OK <message> . After the message is submitted, it should segfault. GDB will tell you where this happened. If it happens in Dovecot somewhere, you should obtain a back trace using `bt full`. If some other software is involved, those developers would also likely need that back trace to find the underlying problem. Regards, Stephan.
Hi Stephan Am 03.01.2017 um 21:12 schrieb Stephan Bosch:> Since you're using LMTP, you could try to run the lmtp service from > command line in GDB. In essence, this looks as follows (you will need to > run this as the mail user, e.g. vmail, or you can run it as root): > > $ gdb --args /usr/lib/dovecot/lmtpI did so and it seems that libc.so.6 throws the error as I get the following result (as root): [New process 14843] Program received signal SIGSEGV, Segmentation fault. [Switching to process 14843] 0x00007ffff7241b71 in __strlen_sse2 () from /lib64/libc.so.6 bt full does not give me more than this #0 0x00007ffff7241b71 in __strlen_sse2 () from /lib64/libc.so.6 No symbol table info available. Cannot access memory at address 0x7fffffffd848 Then I installed debuginfo for glibc via debuginfo-install glibc-2.17-157.el7_3.1.x86_64 and get Program received signal SIGSEGV, Segmentation fault. [Switching to process 18099] __strlen_sse2 () at ../sysdeps/x86_64/strlen.S:31 31 movdqu (%rdi), %xmm1 So this is an issue for glibc developpers? Just wonder why this error does not occur if I call the script directly on cli or if I use sieve-test program. It seems only to occur if the script called from dovecot To compare I tried gdb as well as user vmail and get more detailed information [New process 20844] Program received signal SIGSEGV, Segmentation fault. [Switching to process 20844] 0x00007ffff7203694 in _IO_vfprintf_internal (s=s at entry=0x7fffffffd710, format=<optimized out>, format at entry=0x555555764938 "chroot(%s) failed: Bad address", ap=ap at entry=0x7fffffffd970) at vfprintf.c:1635 1635 process_string_arg (((struct printf_spec *) NULL)); bt full does return much more in this case. I attached that output as bt_full.txt to this mail (maybe it can be of help) Thanks for your help tobi -------------- next part -------------- #0 0x00007ffff7203694 in _IO_vfprintf_internal (s=s at entry=0x7fffffffd710, format=<optimized out>, format at entry=0x555555764938 <Address 0x555555764938 out of bounds>, ap=ap at entry=0x7fffffffd970) at vfprintf.c:1635 len = <optimized out> string_malloced = <optimized out> step0_jumps = <error reading variable step0_jumps (Cannot access memory at address 0x7ffff7331d00)> space = <error reading variable space (Cannot access memory at address 0x7fffffffd1c0)> is_short = <error reading variable is_short (Cannot access memory at address 0x7fffffffd1a0)> use_outdigits = <error reading variable use_outdigits (Cannot access memory at address 0x7fffffffd198)> step1_jumps = <error reading variable step1_jumps (Cannot access memory at address 0x7ffff7331c80)> group = <error reading variable group (Cannot access memory at address 0x7fffffffd190)> prec = <error reading variable prec (Cannot access memory at address 0x7fffffffd1d8)> step2_jumps = <error reading variable step2_jumps (Cannot access memory at address 0x7ffff7331c00)> string = <optimized out> left = <error reading variable left (Cannot access memory at address 0x7fffffffd1c8)> is_long_double = <error reading variable is_long_double (Cannot access memory at address 0x7fffffffd19c)> width = <error reading variable width (Cannot access memory at address 0x7fffffffd1e0)> step3a_jumps = <error reading variable step3a_jumps (Cannot access memory at address 0x7ffff7331b80)> alt = <error reading variable alt (Cannot access memory at address 0x7fffffffd1e8)> showsign = <error reading variable showsign (Cannot access memory at address 0x7fffffffd1b8)> is_long = <error reading variable is_long (Cannot access memory at address 0x7fffffffd1d0)> is_char = <error reading variable is_char (Cannot access memory at address 0x7fffffffd188)> pad = <error reading variable pad (Cannot access memory at address 0x7fffffffd1b0)> step3b_jumps = <error reading variable step3b_jumps (Cannot access memory at address 0x7ffff7331a80)> step4_jumps = <error reading variable step4_jumps (Cannot access memory at address 0x7ffff7331b00)> is_negative = <optimized out> number = <optimized out> base = <optimized out> the_arg = <error reading variable the_arg (Cannot access memory at address 0x7fffffffd270)> spec = <error reading variable spec (Cannot access memory at address 0x7fffffffd200)> _buffer = <error reading variable _buffer (Cannot access memory at address 0x7fffffffd2c0)> _avail = <optimized out> thousands_sep = <error reading variable thousands_sep (Cannot access memory at address 0x7fffffffd1f0)> grouping = <error reading variable grouping (Cannot access memory at address 0x7fffffffd1f8)> done = <error reading variable done (Cannot access memory at address 0x7fffffffd238)> f = <error reading variable f (Cannot access memory at address 0x7fffffffd240)> lead_str_end = <optimized out> end_of_spec = <optimized out> work_buffer = <error reading variable work_buffer (Cannot access memory at address 0x7fffffffd2e0)> workstart = 0x0 workend = <optimized out> ap_save = <error reading variable ap_save (Cannot access memory at address 0x7fffffffd2a0)> nspecs_done = <error reading variable nspecs_done (Cannot access memory at address 0x7fffffffd208)> save_errno = <optimized out> readonly_format = <error reading variable readonly_format (Cannot access memory at address 0x7fffffffd1ec)> args_malloced = <error reading variable args_malloced (Cannot access memory at address 0x7fffffffd220)> specs = <optimized out> specs_malloced = <error reading variable specs_malloced (Cannot access memory at address 0x7fffffffd20f)> jump_table = <error reading variable jump_table (Cannot access memory at address 0x7ffff7331d80)> #1 0x00007ffff72c78d5 in ___vsnprintf_chk (s=0x555555764855 <Address 0x555555764855 out of bounds>, s at entry=<error reading variable: Cannot access memory at address 0x7fffffffd878>, maxlen=<optimized out>, flags=1, slen=<optimized out>, format=0x555555764938 <Address 0x555555764938 out of bounds>, args=0x7fffffffd970) at vsnprintf_chk.c:63 sf = <error reading variable sf (Cannot access memory at address 0x7fffffffd710)> ret = <optimized out>