[syslog-ng] Possible memleak in 3.3 HEAD

[Balazs Scheidler]

On Mon, 2011-10-31 at 12:17 +0100, Jakub Jankowski wrote:
> On Mon, 31 Oct 2011 10:32:28 +0100, Balazs Scheidler wrote:
> > On Tue, 2011-10-18 at 23:15 +0200, Jakub Jankowski wrote:
> > > On Fri, 14 Oct 2011 01:39:28 +0200, Jakub Jankowski wrote:
> > > > On Thu, 13 Oct 2011 15:32:27 +0200, Balazs Scheidler wrote:
> > > > 
> > > > Since upgrading to 3.3.1, there is a strange behaviour of my system: if
> > > > I reload syslog-ng, it spits out *tons* of similar messages:
> > > > Internal error, duplicate configuration elements refer to the same
> > > > persistent config; name='dd_queue(d_mesg,d_mesg#0)'
> [...]
> > > Ok, at least I managed to get valgrind output from SIGHUP processing. It's
> > > avaliable at http://toxcorp.com/stuff/syslog-ng-leak/s3.3.1-head-HUP.log
> > > This is for 3.3.1 with recent SIGHUP-leak-related patches applied.
> > > 
> > > ==13436== LEAK SUMMARY:
> > > ==13436==    definitely lost: 83,795 bytes in 1,698 blocks
> > > ==13436==    indirectly lost: 1,012 bytes in 21 blocks
> > > ==13436==      possibly lost: 13,153 bytes in 108 blocks
> > > ==13436==    still reachable: 80,050 bytes in 3,278 blocks
> > > ==13436==         suppressed: 0 bytes in 0 blocks
> > > 
> > > But still I don't get why all of the sudden, "duplicate configuration
> > > elements" are logged on SIGHUP, but:
> > > - not on start
> > > - not if SIGHUP was received prior to any remote message
> > 
> > Using your problem description I think I've found the issues that caused
> > the leaks for you. The issue is a bit more involved than I like it at
> > this stage (having released a stable version already), but anyway better
> > late than never.
> > 
> > The fix is a series of 5 patches (available on "master" branch):
> [...] 
> > Without these, file destinations would keep their queues around when
> > reaped via time-reap(). Also the duplicate config elements should be
> > fixed.
> > 
> > Any feedback is appreciated.
> 
> Thanks for your support. I've built current HEAD (using 3.3.1 tarball 
> and applying git diff v3.3.1..master, because Gergely's automated dist
> tarball scripts did not have a chance to built what I need yet) 
> and then ran my tests. 
> 
> My findings:
> 
> 1. The "duplicate configuration elements" on HUP are gone indeed. Thanks.
> 2. There are still some leaks; one of which is definitely triggered by HUP.
> Full valgrind output files are available as:
> http://toxcorp.com/stuff/syslog-ng-leak/s3.3.1-60b5967-HUP.log
> http://toxcorp.com/stuff/syslog-ng-leak/s3.3.1-60b5967-noHUP.log
> Those are produced by using exactly the same input data, sent using: 
> $ loggen --loop-reading --read-file access.random --active-connections 5 \
>   --number 10000 --interval 600 --syslog-proto 10.20.10.2 515
> to syslog-ng running under valgrind on 10.20.10.2.
> 
> access.random is a ~700k lines of apache access logs, with (prepended)
> virtualhost name replaced with some random data. 
> If its any help, I could send you (off-list, due to privacy concerns) this
> source file along with my complete syslog-ng.conf.
> 
> I hope that 3.3.2 will be The BugFreeiest Release of them all :-)
> 
> 

Thanks for the detailed diagnosis, there was indeed a leak which can
multiply on reload for each open (at the time of the reload),
macro-based destination file.

commit 9e7f9258b03c58701be40d40f9708bb3a9c56625
Author: Balazs Scheidler <bazsi at balabit.hu>
Date:   Mon Oct 31 22:14:05 2011 +0100

    log_writer_set_options: fixed a memory leak
    
    log_writer_set_options() will be called possibly multiple times on the same
    instance, but the code didn't check if stats_id or stats_instance were
    already set. If they were, their old value was forgotten, thus leaked.
    
    Reported-By: Jakub Jankowski <shasta at toxcorp.com>
    Signed-off-by: Balazs Scheidler <bazsi at balabit.hu>


-- 
Bazsi