[syslog-ng] syslog-ng 3.0.1 dies on reload with program() destination

[Balazs Scheidler]

On Wed, 2009-04-15 at 11:46 +0200, Jan Rekorajski wrote:
> On Tue, 14 Apr 2009, Balazs Scheidler wrote:
> 
> > On Mon, 2009-03-30 at 22:54 +0200, Jan Rekorajski wrote:
> > > Sorry for possible double post, I sent the first from wrong email.
> > > 
> > > Hi,
> > > Syslog-ng 3.0.1 dies on reload (kill -HUP pid) when config file contains
> > > log { destination { program() } }  directive set. 100% repeatable.
> > > 
> > > Here are the relevant config lines:
> > > 
> > > destination d_sshguard  { program("/usr/sbin/sshguard -a 6"); };
> > > # A desperate experiment
> > > #destination d_sshguard  { program("read"); };
> > > 
> > > log { source(s_sys); filter(f_authpriv);        destination(d_sshguard); };
> > > 
> > > 
> > > From what I managed to find with strace/ltrace, syslog-ng kills the
> > > program, does not clear some data structures and then falls face down
> > > with sigsegv/term/ill trying to restart/reattach(?) to the program.
> > > 
> > > The exact same configuration works perfectly with version 2.0.10.
> > > 
> > 
> > Hm... I've just tried to reproduce this problem with current 3.0 HEAD
> > and also 3.0.1, but without success.
> > 
> > Can you show me a backtrace of the failing program? You can do it using:
> > 
> > gdb syslog-ng core
> > (gdb) bt
> 
> I can't get it to dump core unfortunately, all I get is:
> 
> # syslog-ng -f /etc/syslog-ng/syslog-ng.conf
> 
> Apr 15 11:25:25 sith syslog-ng[26571]: syslog-ng starting up; version='3.0.1'
> Apr 15 11:25:25 sith sshguard[26576]: Started successfully [(a,p,s)=(6, 420, 1200)], now ready to scan.
> 
> # kill -HUP 26571
> 
> Apr 15 11:25:33 sith sshguard[26576]: Got exit signal, flushing blocked addresses and exiting...
> Apr 15 11:25:33 sith sshguard[26576]: Run command "/usr/sbin/iptables -F sshguard ; /usr/sbin/ip6tables -F sshguard": exited 1.
> Apr 15 11:25:33 sith syslog-ng[26571]: WARNING: Your configuration uses a newly introduced reserved word as identifier, please use a different name; keyword='syslog', filename='/etc/syslog-ng/syslog-ng.conf', line='77'
> Apr 15 11:25:33 sith syslog-ng[26571]: Configuration reload request received, reloading configuration;
> Apr 15 11:25:33 sith sshguard[26585]: Started successfully [(a,p,s)=(6, 420, 1200)], now ready to scan.
> Apr 15 11:25:33 sith syslog-ng[26571]: Termination requested via signal, terminating;
> Apr 15 11:25:33 sith sshguard[26585]: Got exit signal, flushing blocked addresses and exiting...
> Apr 15 11:25:33 sith syslog-ng[26571]: syslog-ng shutting down; version='3.0.1'

Hm.. syslog-ng seems to exit normally here, not because it crashed but
because it received either SIGINT or SIGTERM.

The question what process sends it a SIGINT or SIGTERM signal? You could
confirm this by running syslog-ng under strace and check whether it gets
a SIGTERM somewhere.

Since signals might be delivered to process groups, it might be possible
that sshguard kill its whole process group and that signal is also
delivered to syslog-ng. But this is only a hypothesis.

-- 
Bazsi