[syslog-ng] Repeated log messages?

[John Morrissey]

Recently, we've noticed a few machines are filling up their log filesystems
with duplicate log entries. At first, I thought this behavior was caused by
running out of disk space (i.e., the machine runs out of disk and syslog-ng
does some sort of buffering, and as disk space oscellates between a few
hundred bytes available and completely full, syslog-ng is writing this
buffered log data out to disk but never removing the log entries from its
buffer), but I can't reliably reproduce it.

I also noticed that sometimes this would happen when the remote syslog sub
was unavailable, but I can't reliably reproduce this behavior by blocking
UDP syslog traffic directed at the remote syslog hub. I'd also wonder how
syslog-ng would know that UDP syslog traffic is being dropped, unless the
nature of the traffic block is such that an ICMP message (host/port
unreachable, etc.) is returned to the sending host.

I've poked and prodded at syslog-ng, attempting to reliably reproduce this
behavior, but haven't been able to. I'm not sure if either of these two
events (out of disk space, loss of network access to the syslog hub) are
simple coincidences or actually cause/contribute to the behavior.

The odd part is that the duplicate log entries seem to be logged forever,
such as if syslog-ng was in an infinite loop. Additionally, each duplicate
log entry has an additional space each time it's duplicated. For example:

Original log entries:
Feb 12 06:28:12 rdr01 su[21942]: Successful su for nobody by root
Feb 12 06:28:12 rdr01 su[21942]: + ??? root:nobody

First round of duplicates, with a single trailing space:
Feb 12 06:28:12 localhost su[21942]: Successful su for nobody by root 
Feb 12 06:28:12 localhost su[21942]: + ??? root:nobody 

Second round of duplicates, with two trailing spaces:
Feb 12 06:28:12 localhost su[21942]: Successful su for nobody by root  
Feb 12 06:28:12 localhost su[21942]: + ??? root:nobody  

Third round of duplicates, with three trailing spaces:
Feb 12 06:28:12 localhost su[21942]: Successful su for nobody by root   
Feb 12 06:28:12 localhost su[21942]: + ??? root:nobody   

[and so on]

This is with syslog-ng 2.0.0-1etch1.

john
-- 
John Morrissey          _o            /\         ----  __o
jwm at horde.net        _-< \_          /  \       ----  <  \,
www.horde.net/    __(_)/_(_)________/    \_______(_) /_(_)__