Mailing List Archive

rsyslog segfaults was: rsyslog 1.19.5 released
Patrick,

thanks for this report, it is useful. Unfortunately, I had hoped that an
assertion failed, which was obviously not the case. I have looked at the
code in question, but the root cause seems to be different. It looks
like the code that actually aborted was "just" affected by something
that happened earlier (the earlier code destroyed the list, which was
then detected in cvthname() processing).

The assert on discard was a bug in the debug code. I have fixed that in
the current CVS (I do not yet want to release a version because of this
minor thing - if you like, you can pull it from anon CVS).

We have some other things under review. In the mean time, I am asking
myself if the problem may be related to a threading issue. Rsyslog can
be compiled in single-threading mode. You can do that by:

./configure --disable-pthreads [--enable-debug (if you like)]

There is a drawback, though: as message processing and reception is no
longer de-coupled, messages in bursts are more likely to be lost. Also,
TCP messages sent to an unresponsive server may be lost, as the priority
is on reception (there is code that discards messages that block
rsyslgogd). However, sysklogd always works in that mode, so I think it
is worth giving a try. It would be very helpful to know if the problem
persists in single threading mode - or not.

Thanks,
Rainer

On Mon, 2007-09-10 at 15:17 +0200, Patrick von der Hagen wrote:
> Am Montag, den 10.09.2007, 14:38 +0200 schrieb Patrick von der Hagen:
> [...]
> > It's been running for several minutes now...
> Now I captured the "real" crash.
>
> First, my config:
> $AllowedSender UDP, 1.2.3.0/24
> $AllowedSender TCP, 1.2.3.0/24
> $template clamavFile,"/home/local/log/%$YEAR%/%$MONTH%/%$DAY%/%HOSTNAME
> %/clamav"
> $template eximFile,"/home/local/log/%$YEAR%/%$MONTH%/%$DAY%/%HOSTNAME
> %/exim"
> $template avFile,"/home/local/log/%$YEAR%/%$MONTH%/%$DAY%/%HOSTNAME%/av"
> *.* /home/local/log/all
> !rsyslogd
> :programname, contains, "rsyslogd" /home/local/log/rsyslogd
> !spamd
> mail.* /home/local/log/mail
> !clamd
> local5.* ?clamavFile
> !exim
> *.* ?eximFile
> :msg, contains, "malware detected" ?avFile
>
>
> Here the output of "rsyslog -r514 -d"
> Successful select, descriptor count = 1, Activity on: 1084229952:
> -1431504256: 8
> Called fprintlog, logging to builtin-file1084229952: (eximFile)
> Filter: check for property 'msg' (value ' 2007-09-10 14:56:03
> 1IUio2-00054R-EA H=X (Y) [1.2.3.4] Warning: X-Spam-Status: yes,
> hits=13.9, size=32842') contains 'malware detected': FALSE
> 1084229952: singleWorker: queue EMPTY, waiting for next message.
> -1431504256: Message from inetd socket: #8, host: mailin3
> -1431504256: Message length: 200, File descriptor: 8.
> -1431504256: logmsg: mail.info<22>, flags 2, from 'mailin3', msg
> exim[18550]: 2007-09-10 14:56:03 H=(a.b.c.d) [2.3.4.5] F=<x at y.z.1.b>
> temporarily rejected RCPT <localpart at domain>: greylisted.
> -1431504256: Message has legacy syslog format.
> -1431504256: HOSTNAME contains invalid characters, assuming it to be a
> TAG.
> -1431504256: EnqueueMsg signaled condition (0)
> -1431504256: 1084229952: Listening on UDP syslogd socket 7 (IPv6/port
> 514).
> -1431504256: Lone worker is running...
> 1084229952: Called fprintlog, logging to builtin-file
> (/home/local/log/all)
> Listening on UDP syslogd socket 8 (IPv4/port 514).
> -1431504256: ----------------------------------------
> -1431504256: Calling select, active file descriptors (max 8): 3 7 8
> 1084229952: programname filter 'rsyslogd' does not match 'exim'
> 1084229952: programname filter 'spamd' does not match 'exim'
> 1084229952: programname filter 'clamd' does not match 'exim'
> 1084229952: Called fprintlog, logging to builtin-file (eximFile)
> Filter: check for property 'msg' (value ' 2007-09-10 14:56:03 H=(domain)
> [1.2.3.4] F=<sender at domainA> temporarily rejected RCPT
> <recipient at domainB>: greylisted.') contains 'malware detected': FALSE
> 1084229952: singleWorker: queue EMPTY, waiting for next message.
> -1431504256:
> Successful select, descriptor count = 1, Activity on: 8
> *** glibc detected *** /opt/rsyslog/sbin/rsyslogd: corrupted
> double-linked list: 0x00002aaaac001230 ***
> ======= Backtrace: =========
> /lib64/libc.so.6[0x362766cb43]
> /lib64/libc.so.6[0x362766eea2]
> /lib64/libc.so.6(__libc_malloc+0x7d)[0x36276706dd]
> /lib64/libc.so.6[0x362765eb4a]
> /lib64/libnss_files.so.2[0x2aaaaaad445a]
> /lib64/libnss_files.so.2(_nss_files_gethostbyaddr_r
> +0x57)[0x2aaaaaad4b47]
> /lib64/libc.so.6(gethostbyaddr_r+0xf2)[0x36276e2b42]
> /lib64/libc.so.6(getnameinfo+0x3ad)[0x36276eb07d]
> /opt/rsyslog/sbin/rsyslogd(cvthname+0x154)[0x410e64]
> /opt/rsyslog/sbin/rsyslogd[0x40bec9]
> /opt/rsyslog/sbin/rsyslogd(main+0x630)[0x40c990]
> /lib64/libc.so.6(__libc_start_main+0xf4)[0x362761d8a4]
> /opt/rsyslog/sbin/rsyslogd[0x405899]
> ======= Memory map: ========
> 00400000-00424000 r-xp 00000000 08:03
> 688189 /opt/rsyslog/sbin/rsyslogd
> 00624000-00626000 rw-p 00024000 08:03
> 688189 /opt/rsyslog/sbin/rsyslogd
> 1c204000-1c249000 rw-p 1c204000 00:00 0
> 40000000-40001000 ---p 40000000 00:00 0
> 40001000-40a01000 rw-p 40001000 00:00 0
> 3627200000-362721a000 r-xp 00000000 08:03
> 4260124 /lib64/ld-2.5.so
> 3627419000-362741a000 r--p 00019000 08:03
> 4260124 /lib64/ld-2.5.so
> 362741a000-362741b000 rw-p 0001a000 08:03
> 4260124 /lib64/ld-2.5.so
> 3627600000-3627744000 r-xp 00000000 08:03
> 4260125 /lib64/libc-2.5.so
> 3627744000-3627944000 ---p 00144000 08:03
> 4260125 /lib64/libc-2.5.so
> 3627944000-3627948000 r--p 00144000 08:03
> 4260125 /lib64/libc-2.5.so
> 3627948000-3627949000 rw-p 00148000 08:03
> 4260125 /lib64/libc-2.5.so
> 3627949000-362794e000 rw-p 3627949000 00:00 0
> 3627e00000-3627e02000 r-xp 00000000 08:03
> 4260128 /lib64/libdl-2.5.so
> 3627e02000-3628002000 ---p 00002000 08:03
> 4260128 /lib64/libdl-2.5.so
> 3628002000-3628003000 r--p 00002000 08:03
> 4260128 /lib64/libdl-2.5.so
> 3628003000-3628004000 rw-p 00003000 08:03
> 4260128 /lib64/libdl-2.5.so
> 3628200000-3628215000 r-xp 00000000 08:03
> 4260022 /lib64/libpthread-2.5.so
> 3628215000-3628414000 ---p 00015000 08:03
> 4260022 /lib64/libpthread-2.5.so
> 3628414000-3628415000 r--p 00014000 08:03
> 4260022 /lib64/libpthread-2.5.so
> 3628415000-3628416000 rw-p 00015000 08:03
> 4260022 /lib64/libpthread-2.5.so
> 3628416000-362841a000 rw-p 3628416000 00:00 0
> 3628600000-3628614000 r-xp 00000000 08:03
> 4547586 /usr/lib64/libz.so.1.2.3
> 3628614000-3628813000 ---p 00014000 08:03
> 4547586 /usr/lib64/libz.so.1.2.3
> 3628813000-3628814000 rw-p 00013000 08:03
> 4547586 /usr/lib64/libz.so.1.2.3
> 362d200000-362d207000 r-xp 00000000 08:03
> 4260133 /lib64/librt-2.5.so
> 362d207000-362d407000 ---p 00007000 08:03
> 4260133 /lib64/librt-2.5.so
> 362d407000-362d408000 r--p 00007000 08:03
> 4260133 /lib64/librt-2.5.so
> 362d408000-362d409000 rw-p 00008000 08:03
> 4260133 /lib64/librt-2.5.so
> 362ee00000-362ee11000 r-xp 00000000 08:03
> 4260134 /lib64/libresolv-2.5.so
> 362ee11000-362f011000 ---p 00011000 08:03
> 4260134 /lib64/libresolv-2.5.so
> 362f011000-362f012000 r--p 00011000 08:03
> 4260134 /lib64/libresolv-2.5.so
> 362f012000-362f013000 rw-p 00012000 08:03
> 4260134 /lib64/libresolv-2.5.so
> 362f013000-362f015000 rw-p 362f013000 00:00 0
> 3815400000-381540d000 r-xp 00000000 08:03
> 4259862 /lib64/libgcc_s-4.1.1-20070105.so.1
> 381540d000-381560c000 ---p 0000d000 08:03
> 4259862 /lib64/libgcc_s-4.1.1-20070105.so.1
> 381560c000-381560d000 rw-p 0000c000 08:03
> 4259862 /libAborted
>
>
>