[Bug 125] New: [systemd] refuses stop request from systemctl on socket activated start
https://bugzilla.balabit.com/show_bug.cgi?id=125 Summary: [systemd] refuses stop request from systemctl on socket activated start Product: syslog-ng Version: 3.2.x Platform: PC OS/Version: Linux Status: NEW Severity: major Priority: unspecified Component: syslog-ng AssignedTo: bazsi@balabit.hu ReportedBy: d@falconindy.com Type of the Report: bug Estimated Hours: 0.0 I'm seeing some unexpected behavior from syslog-ng when it's started by way of systemd's socket activation. The visible issue is that the process is ignoring a stop request from systemctl will will lead to systemd issuing a kill -9. An strace of the syslog-ng process when the signal is sent is as follows: 0x6e9ed0, 8192, 0, 0x7fff35fe0360, 0x7fff35fe03ec) = ? ERESTARTSYS (To be restarted) --- {si_signo=SIGTERM, si_code=SI_USER, si_pid=1, si_uid=0, si_value={int=1, ptr=0x1}} (Terminated) --- --- {si_signo=SIGCONT, si_code=SI_USER, si_pid=1, si_uid=0, si_value={int=1, ptr=0x1}} (Continued) --- rt_sigreturn(0xf) = -1 EINTR (Interrupted system call) recvfrom(3, And eventually: +++ killed by SIGKILL +++ It seems to ignore the SIGTERM. It does continue to receive messages and log them (checked via logger(1)). After the daemon is SIGKILL'ed, if I start it and then try to stop, it ends normally: ) = ? ERESTART_RESTARTBLOCK (To be restarted) --- {si_signo=SIGTERM, si_code=SI_USER, si_pid=1, si_uid=0, si_value={int=1, ptr=0x1}} (Terminated) --- --- {si_signo=SIGCONT, si_code=SI_USER, si_pid=1, si_uid=0, si_value={int=1, ptr=0x1}} (Continued) --- rt_sigreturn(0xf) = -1 EINTR (Interrupted system call) gettimeofday({1308428877, 84197}, NULL) = 0 gettimeofday({1308428877, 84385}, NULL) = 0 close(6) = 0 gettimeofday({1308428877, 84763}, NULL) = 0 poll([{fd=3, events=POLLIN}, {fd=5, events=POLLIN}, {fd=6, events=POLLIN}], 3, 0) = 1 ([{fd=6, revents=POLLNVAL}]) gettimeofday({1308428877, 85143}, NULL) = 0 gettimeofday({1308428877, 85332}, NULL) = 0 lseek(7, 0, SEEK_END) = 3013 write(7, "Jun 18 16:27:57 kweemoo syslog-n"..., 87) = 87 lseek(8, 0, SEEK_END) = 175609 write(8, "Jun 18 16:27:57 kweemoo syslog-n"..., 87) = 87 gettimeofday({1308428877, 86379}, NULL) = 0 poll([{fd=3, events=POLLIN}, {fd=5, events=POLLIN}, {fd=6, events=POLLIN}], 3, 0) = 1 ([{fd=6, revents=POLLNVAL}]) gettimeofday({1308428877, 86757}, NULL) = 0 gettimeofday({1308428877, 86946}, NULL) = 0 lseek(7, 0, SEEK_END) = 3100 write(7, "Jun 18 16:27:57 kweemoo syslog-n"..., 81) = 81 lseek(8, 0, SEEK_END) = 175696 write(8, "Jun 18 16:27:57 kweemoo syslog-n"..., 81) = 81 close(3) = 0 close(5) = 0 close(7) = 0 close(8) = 0 unlink("/var/run/syslog-ng.pid") = 0 exit_group(0) = ? If if disable the syslog-ng.service from automatically starting at boot and start it manually, it appears to behave properly. The service file I use is: ------------------- [Unit] Description=System Logger Daemon [Service] Sockets=syslog.socket ExecStartPre=/bin/systemctl stop systemd-kmsg-syslogd.service ExecStart=/usr/sbin/syslog-ng -F [Install] WantedBy=multi-user.target ------------------- Additional Info: * version: 3.2.4 * build options: --prefix=/usr --sysconfdir=/etc/syslog-ng --libexecdir=/usr/lib --localstatedir=/var/lib/syslog-ng --enable-tcp-wrapper --with-pidfile-dir=/var/run --disable-spoof-source --enable-systemd * Distro: Arch Linux * Kernel: 2.6.39.1 -- Configure bugmail: https://bugzilla.balabit.com/userprefs.cgi?tab=email ------- You are receiving this mail because: ------- You are watching all bug changes.
https://bugzilla.balabit.com/show_bug.cgi?id=125 Gergely Nagy <algernon@balabit.hu> changed: What |Removed |Added ---------------------------------------------------------------------------- CC| |algernon@balabit.hu --- Comment #1 from Gergely Nagy <algernon@balabit.hu> 2011-06-18 23:10:20 --- Thanks for the report! I have a vague idea what causes this - as soon as I managed to get a systemd-enabled system to boot in KVM, I'll test my theory. If all goes well, I'll have a patch ready in a couple of days. -- Configure bugmail: https://bugzilla.balabit.com/userprefs.cgi?tab=email ------- You are receiving this mail because: ------- You are watching all bug changes.
https://bugzilla.balabit.com/show_bug.cgi?id=125 --- Comment #2 from Balazs Scheidler <bazsi@balabit.hu> 2011-06-24 13:45:34 --- Hi, my systemd fu is not complete (having just installed F15 in a virtualbox environment), but after some fiddling, syslog-ng seems to cope with systemd just fine. I've used this syslog-ng.service file (not the same as the example in the source tarball): [Unit] Description=syslog-ng [Service] ExecStartPre=/bin/systemctl stop systemd-kmsg-syslogd.service ExecStart=/usr/local/sbin/syslog-ng -F -dv ExecReload=/bin/kill -HUP $MAINPID Sockets=syslog.socket Then, I've changed syslog.socket to activate syslog-ng, instead of systemd-kmsg-syslogd.service, by setting: Service=syslog-ng.service Once having done that, and rebooting the system, syslog-ng was properly activated whenever logger sent messages to /dev/log: # ps axwu | grep syslog-ng root 1586 0.0 0.2 43464 2124 ? Ss 12:08 0:00 /usr/local/sbin/syslog-ng -F -dv root 1615 0.0 0.1 108608 840 pts/2 S+ 12:12 0:00 grep --color=auto syslog-ng [root@f15 ~]# systemctl stop syslog-ng.service [root@f15 ~]# ps axwu | grep syslog-ng root 1620 0.0 0.1 108608 840 pts/2 S+ 12:12 0:00 grep --color=auto syslog-ng [root@f15 ~]# logger foobar [root@f15 ~]# ps axwu | grep syslog-ng root 1624 3.0 0.2 43464 2124 ? Ss 12:13 0:00 /usr/local/sbin/syslog-ng -F -dv root 1630 0.0 0.1 108608 836 pts/2 S+ 12:13 0:00 grep --color=auto syslog-ng [root@f15 ~]# tail -1 /var/log/messages Jun 22 12:13:04 f15 bazsi: foobar [root@f15 ~]# systemctl stop syslog-ng.service [root@f15 ~]# ps axwu | grep syslog-ng root 1637 0.0 0.1 108608 836 pts/2 S+ 12:13 0:00 grep --color=auto syslog-ng [root@f15 ~]# exit SIGTERM is indeed caught by syslog-ng, in order to properly execute exit strategies. One difference is that you were using 3.2, whereas I was using the latest git tree (post 3.3.0beta1) Let me retest with 3.2.x -- Configure bugmail: https://bugzilla.balabit.com/userprefs.cgi?tab=email ------- You are receiving this mail because: ------- You are watching all bug changes.
https://bugzilla.balabit.com/show_bug.cgi?id=125 Balazs Scheidler <bazsi@balabit.hu> changed: What |Removed |Added ---------------------------------------------------------------------------- Resolution| |FIXED Status|NEW |RESOLVED --- Comment #3 from Balazs Scheidler <bazsi@balabit.hu> 2011-06-24 14:22:32 --- Indeed, it was a problem in syslog-ng, and is fixed by this patch. It only affects syslog-ng if it is really socket activated, which it isn't on Fedora 15. I'm not sure about other Linux distributions though. commit 2f214c4f87d944aa28d53e331a67b1fd88d9840f Author: Balazs Scheidler <bazsi@balabit.hu> Date: Wed Jun 22 12:50:53 2011 +0200 systemd: make sure the acquired fd is in non-blocking mode The fd acquired from systemd is in blocking mode, and syslog-ng didn't explicitly set it to non-blocking, causing syslog-ng to stall. This patch changes that, explicitly enables O_NONBLOCK and O_CLOEXEC on systemd acquired fds. Reported-By: Enrico Scholz <enrico.scholz@informatik.tu-chemnitz.de> Signed-off-by: Balazs Scheidler <bazsi@balabit.hu> -- Configure bugmail: https://bugzilla.balabit.com/userprefs.cgi?tab=email ------- You are receiving this mail because: ------- You are watching all bug changes.
participants (1)
-
bugzilla＠bugzilla.balabit.com