dovecot-pigeonhole running external script ends with signal 11
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@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@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@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@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
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@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@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@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@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
This seems to be a problem with SCRIPT, it seems to sigfault.
Aki
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=, alt= 220 johanna.johanna.tds Dovecot ready. Info: Connect from local lhlo frop 250-johanna.johanna.tds 250-8BITMIME 250-ENHANCEDSTATUSCODES 250 PIPELINING mail from:stephan@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/lmtp
I 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@entry=0x7fffffffd710, format=<optimized out>, format@entry=0x555555764938 "chroot(%s) failed: Bad address", ap=ap@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
On 04.01.2017 09:49, Tobi wrote:
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/lmtp I 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@entry=0x7fffffffd710, format=<optimized out>, format@entry=0x555555764938 "chroot(%s) failed: Bad address", ap=ap@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
Did you update both dovecot *and* pigeonhole when you last updated?
Aki
Hi Aki
yes I built dovecot and pigeonhole rpms in the same rpmbuild. pigeonhole rpm is based on 0.4.14 Do you think that the error might come from self building the rpms?
Regards
tobi
Am 04.01.2017 um 08:55 schrieb Aki Tuomi:
On 04.01.2017 09:49, Tobi wrote:
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/lmtp I 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@entry=0x7fffffffd710, format=<optimized out>, format@entry=0x555555764938 "chroot(%s) failed: Bad address", ap=ap@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
Did you update both dovecot *and* pigeonhole when you last updated?
Aki
Problem avoided by a quite ugly workaround :-) The script now is called by postfix as a transport. Works so far and the script never segfaults until now. Would still prefer the solution via dovecot sieve but for the moment the postfix solution is okay with me.
Cheers
tobi
----- Originale Nachricht ----- Von: Tobi tobster@brain-force.ch Gesendet: 04.01.17 - 09:37 An: dovecot@dovecot.org Betreff: Re: dovecot-pigeonhole running external script ends with signal 11
Hi Aki
yes I built dovecot and pigeonhole rpms in the same rpmbuild. pigeonhole rpm is based on 0.4.14 Do you think that the error might come from self building the rpms?
Regards
tobi
Am 04.01.2017 um 08:55 schrieb Aki Tuomi:
On 04.01.2017 09:49, Tobi wrote:
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/lmtp I 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@entry=0x7fffffffd710, format=<optimized out>, format@entry=0x555555764938 "chroot(%s) failed: Bad address", ap=ap@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
Did you update both dovecot *and* pigeonhole when you last updated?
Aki
Op 1/4/2017 om 9:37 AM schreef Tobi:
Hi Aki
yes I built dovecot and pigeonhole rpms in the same rpmbuild. pigeonhole rpm is based on 0.4.14 Do you think that the error might come from self building the rpms?
But what version of Pigeonhole are you actually using? Version 0.4.16 is released for Dovecot v2.2.26.
Also:
- Can you find out which process is getting the segfault? GDB shows the pid and you should lookup what process that is while GDB is still active.
- Isn't that GDB backtrace you provided deeper? It shows only two levels, but that makes no sense (i.e. main() is not listed).
Regards,
Stephan.
-----BEGIN PGP SIGNED MESSAGE----- Hash: SHA1
On Wed, 4 Jan 2017, Tobi wrote:
[New process 20844] Program received signal SIGSEGV, Segmentation fault. [Switching to process 20844] 0x00007ffff7203694 in _IO_vfprintf_internal (s=s@entry=0x7fffffffd710, format=<optimized out>, format@entry=0x555555764938 "chroot(%s) failed: Bad address", ap=ap@entry=0x7fffffffd970) at vfprintf.c:1635 1635 process_string_arg (((struct printf_spec *) NULL));
Does your script tries to chroot? Do you have LMTP or Dovecot configured to chroot? As Stephan asked, can you determine with process is spawned here?
The format string "chroot(%s) failed: Bad address" may stem from a Dovecot library.
Steffen Kaiser -----BEGIN PGP SIGNATURE----- Version: GnuPG v1
iQEVAwUBWG9Nxnz1H7kL/d9rAQJIrgf/Y6NvtcCa0HkOHogOJwC42a5NSpA5nqlP sdANI8onYt/JReJA9PzeIKXgCps92xj0d85LNAIVcS4HjKcnBJZLSuWCVg8ppyjy NQbW499DsPtW/sw4bjs4P/yUR5eLw8ERV5EOABwemTBQz03EuBVa4bm6vkses+sN X+C9WJ54bBtjH6fPljpTagwfijNgAnPbkr/EuthMOKzx5IS02Nr3ec0hgDdFGHPu 4slRViTuYSr1dx0MmsqdiEE6wDdZLagLuc6kpVWa5M04L7wrQIri4b6AECf5sFOZ YQaosywbBTZKGYMXGHwX09A3wa8Uei1WgXkRNh6NyVbdy+Ubp5Dahw== =ntGy -----END PGP SIGNATURE-----
participants (4)
-
Aki Tuomi
-
Steffen Kaiser
-
Stephan Bosch
-
Tobi