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

[Balazs Scheidler]

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?

Alternatively, causing syslog-ng to drop core and investigating it with
gdb could help a lot.

start syslog-ng with --enable-core, reproduce the segfault and then:

gdb /usr/local/sbin/syslog-ng /var/run/syslog-ng/core
(gdb) bt full

syslog-ng should be compiled with debug symbols (configure
--enable-debug) for maximum usefulness.

-- 
Bazsi