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) --- I'm going to try and track this down further, but was wondering if anyone else was seeing this behavior. Running this on RHEL5
Sent: Mon Oct 17 2011 11:33:16 GMT-0600 (MDT) From: Patrick H. <syslogng@feystorm.net> To: syslog-ng@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
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@feystorm.net> To: syslog-ng@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
Sent: Sat Oct 22 2011 23:54:23 GMT-0600 (MDT) From: Balazs Scheidler <bazsi@balabit.hu> To: Syslog-ng users' and developers' mailing list <syslog-ng@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@feystorm.net> To: syslog-ng@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>.
participants (2)
-
Balazs Scheidler
-
Patrick H.