[syslog-ng] syslog-ng 3.3.1 dying after SIGHUP

[Patrick H.]

Sent: Sat Oct 22 2011 23:54:23 GMT-0600 (MDT)
From: Balazs Scheidler <bazsi at balabit.hu>
To: Syslog-ng users' and developers' mailing list 
<syslog-ng at lists.balabit.hu>
Subject: Re: [syslog-ng] syslog-ng 3.3.1 dying after SIGHUP
> On Mon, 2011-10-17 at 11:37 -0600, Patrick H. wrote:
>> Sent: Mon Oct 17 2011 11:33:16 GMT-0600 (MDT)
>> From: Patrick H.<syslogng at feystorm.net>
>> To: syslog-ng at lists.balabit.hu
>> Subject: [syslog-ng] syslog-ng 3.3.1 dying after SIGHUP
>>> Is anyone else having issues with syslog-ng 3.3 dying when it gets a
>>> sighup?
>>>
>>> When the syslog-ng monitor process gets a HUP, it seems to die
>>> immediately, as if there were no signal handler. Strace shows
>>> absolutely nothing between getting the signal, and it exiting.
>>> When the actual syslog-ng worker process gets a HUP, it does a bunch
>>> of stuff, and then segfaults. It looks like it segfaults immediately
>>> after closing /var/log/syslog
>>>
>>> 4362  17:28:44.964645 stat("/var/log", {st_mode=S_IFDIR|0755,
>>> st_size=4096, ...}) = 0
>>> 4362  17:28:44.964729 stat("/var/log/syslog", {st_mode=S_IFREG|0644,
>>> st_size=3905, ...}) = 0
>>> 4362  17:28:44.964813 open("/var/log/syslog", O_WRONLY|O_CREAT|
>>> O_NOCTTY|O_NONBLOCK, 0644) = 26
>>> 4362  17:28:44.964879 fcntl(26, F_GETFD) = 0
>>> 4362  17:28:44.964936 fcntl(26, F_SETFD, FD_CLOEXEC) = 0
>>> 4362  17:28:44.964993 capget(0x19980330, 0, {CAP_DAC_OVERRIDE|
>>> CAP_SYS_ADMIN, CAP_CHOWN|CAP_DAC_OVERRIDE|CAP_DAC_READ_SEARCH|
>>> CAP_FOWNER|CAP_NET_BIND_SERVICE|CAP_NET_BROADCAST|CAP_NET_RAW|
>>> CAP_SYS_ADMIN, 0}) = 0
>>> 4362  17:28:44.965082 capset(0x19980330, 0, {CAP_CHOWN|
>>> CAP_DAC_OVERRIDE|CAP_SYS_ADMIN, CAP_CHOWN|CAP_DAC_OVERRIDE|
>>> CAP_DAC_READ_SEARCH|CAP_FOWNER|CAP_NET_BIND_SERVICE|
>>> CAP_NET_BROADCAST|CAP_NET_RAW|CAP_SYS_ADMIN, 0}) = 0
>>> 4362  17:28:44.965148 capget(0x19980330, 0, {CAP_CHOWN|
>>> CAP_DAC_OVERRIDE|CAP_SYS_ADMIN, CAP_CHOWN|CAP_DAC_OVERRIDE|
>>> CAP_DAC_READ_SEARCH|CAP_FOWNER|CAP_NET_BIND_SERVICE|
>>> CAP_NET_BROADCAST|CAP_NET_RAW|CAP_SYS_ADMIN, 0}) = 0
>>> 4362  17:28:44.965213 capset(0x19980330, 0, {CAP_CHOWN|
>>> CAP_DAC_OVERRIDE|CAP_FOWNER|CAP_SYS_ADMIN, CAP_CHOWN|
>>> CAP_DAC_OVERRIDE|CAP_DAC_READ_SEARCH|CAP_FOWNER|
>>> CAP_NET_BIND_SERVICE|CAP_NET_BROADCAST|CAP_NET_RAW|CAP_SYS_ADMIN,
>>> 0}) = 0
>>> 4362  17:28:44.965279 fchown(26, 0, 4294967295) = 0
>>> 4362  17:28:44.965344 fchown(26, 4294967295, 0) = 0
>>> 4362  17:28:44.965404 fchmod(26, 0644)  = 0
>>> 4362  17:28:44.965464 capset(0x19980330, 0, {CAP_SYS_ADMIN,
>>> CAP_CHOWN|CAP_DAC_OVERRIDE|CAP_DAC_READ_SEARCH|CAP_FOWNER|
>>> CAP_NET_BIND_SERVICE|CAP_NET_BROADCAST|CAP_NET_RAW|CAP_SYS_ADMIN,
>>> 0}) = 0
>>> 4362  17:28:44.965532 close(21)         = 0
>>> 4362  17:28:44.966122 --- SIGSEGV (Segmentation fault) @ 0 (0) ---
>>>
>> Oh, file descriptor 21 is /var/log/syslog, and was open already before
>> I sent the SIGHUP. Then it opened /var/log/syslog again as descriptor
>> 26. So maybe this is screwing it up somehow, opening the handle twice.
>>>
>>> I'm going to try and track this down further, but was wondering if
>>> anyone else was seeing this behavior.
>>> Running this on RHEL5
> Is this always reproducible? If that is can you please send me the
> configuration file, so that I can reproduce this too?
>
Yes, always reproducible. But I found the more precise cause and filed 
it under bug 139 <https://bugzilla.balabit.com/show_bug.cgi?id=139>.
-------------- next part --------------
An HTML attachment was scrubbed...
URL: http://lists.balabit.hu/pipermail/syslog-ng/attachments/20111023/a485ae07/attachment.htm