[syslog-ng] [Bug 125] New: [systemd] refuses stop request from systemctl on socket activated start

[bugzilla at bugzilla.balabit.com]

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 at balabit.hu
        ReportedBy: d at 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.