Backtrace io_add(0x1) called twice fd= (was Exit status code 134; what is it, in the context of Dovecot Antispam plug-in?)

[Steffen Kaiser]

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

On Thu, 7 Aug 2014, Ben Johnson wrote:
> On 8/7/2014 11:14 AM, Steffen Kaiser wrote:
>> one idea: http://www.tldp.org/LDP/abs/html/exitcodes.html
>>
>> exit code 134 would be in bash's meaning (if this website is
>> correct all) some program died off signal 6. This would be Abort in
>> Linux.
>>
>> prepend your script with
>>
>> exec >> /tmp/trace 2>&1 set -vx
>>
>> that will dump anything visible into /tmp/trace
>>
>> - -- Steffen Kaiser
>
> Thank you for your continued assistance, Steffen.
>
> You seem to be exactly correct with the Abort signal.
>
> I prepended the values you suggested to the pipe script and here's the
> relevant output:
>
> + /usr/lib/dovecot/deliver -d sa-training at example.com -m Training.SPAM
> ^A^H5584 prefix=lda:
> ^A^F5584 io_add(0x1) called twice fd=7, callback=0x7f23489fb6f0 ->
> 0x7f23489aa530

Unfortunately the only spot found is:
http://dovecot.org/pipermail/dovecot/2012-May/135636.html

Is it the same fd=# always? Is it already open in your script?
You could check with lsof -p $$

However, you should check if Dovecot v2.2.13 already fixes the problem.

> ^A^D5584 Raw backtrace: /usr/lib/dovecot/libdovecot.so.0(+0x5e271)
> [0x7f23489e9271] -> /usr/lib/dovecot/libdovecot.so.0(+0x5e34e)
> [0x7f23489e934e] -> /usr/lib/dovecot/libdovecot.so.0(i_fatal+0)
> [0x7f23489a4a9e] ->
> /usr/lib/dovecot/libdovecot.so.0(ioloop_iolist_add+0x83)
> [0x7f23489f9533] ->
> /usr/lib/dovecot/libdovecot.so.0(io_loop_handle_add+0x3b)
> [0x7f23489f9cbb] -> /usr/lib/dovecot/libdovecot.so.0(io_add+0x9b)
> [0x7f23489f89fb] ->
> /usr/lib/dovecot/libdovecot.so.0(master_service_io_listeners_add+0x69)
> [0x7f23489a9e49] ->
> /usr/lib/dovecot/libdovecot.so.0(master_service_init_finish+0xb0)
> [0x7f23489a9f90] -> /usr/lib/dovecot/deliver(main+0x1cb)
> [0x7f234939269b] ->
> /lib/x86_64-linux-gnu/libc.so.6(__libc_start_main+0xf5)
> [0x7f23485e6ec5] -> /usr/lib/dovecot/deliver(+0x31de) [0x7f23493931de]
> /usr/local/bin/sa-learn-pipe.sh: line 52:  5584 Aborted
>  (core dumped) /usr/lib/dovecot/deliver -d "sa-training at example.com"
> -m "Training.$mode"
> + echo 'Exit status was 134'
>
> Does this tell us anything more?
>
> I don't see any indication that apparmor is at play, as there is no
> profile that should apply in this context (and there is nothing in the
> relevant log file):
>
> # service apparmor status
> apparmor module is loaded.
> 8 profiles are loaded.
> 8 profiles are in enforce mode.
>   /sbin/dhclient
>   /usr/bin/freshclam
>   /usr/lib/NetworkManager/nm-dhcp-client.action
>   /usr/lib/connman/scripts/dhclient-script
>   /usr/sbin/clamd
>   /usr/sbin/mysqld
>   /usr/sbin/ntpd
>   /usr/sbin/tcpdump
> 0 profiles are in complain mode.
> 4 processes have profiles defined.
> 4 processes are in enforce mode.
>   /usr/bin/freshclam (2015)
>   /usr/sbin/clamd (1897)
>   /usr/sbin/mysqld (1239)
>   /usr/sbin/ntpd (2472)
> 0 processes are in complain mode.
> 0 processes are unconfined but have a profile defined.
>
> I'll try to reproduce this on an identically-configured server. I
> wonder if it would be worth changing the version of Dovecot. But I
> hate to play whack-a-mole if a more systematic approach is to be had.
>
> Thanks again,
>
> -Ben
>

- -- 
Steffen Kaiser
-----BEGIN PGP SIGNATURE-----
Version: GnuPG v1.4.11 (GNU/Linux)

iQEVAwUBU+SMkXz1H7kL/d9rAQL7owf/UoNtkoN02JU/1ODYJCaccrpZFTaW1L98
hUPs40eAkh7XsCCe8ymBlG8PzTushkDlqW1EGY2JP3qr5wFV9ACG9ga1Z2oik7CE
R3ELjcB6z4D7j2gIHbSGeF+rAIwP2I8K4tVwd4bfVDm2nv+8fAC2OFo4osark1Z9
+3szhhwYIdlon3droAKkUarppXLX9AiYRHHrIpd3ITI55r1x3D6Ni8ClTmyIqKk2
fuKvrFCzU+OIkBegguLfHjhtU6iG4t6RWgb6X77YfnfNy4jHcbeHc9j0dKL4/bP8
Cy5ro1twUcqtC7qQY2kdI3Ka59+dGFhoewFczEsZ8cVOb+ivpv2MiQ==
=VORN
-----END PGP SIGNATURE-----