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@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@toxcorp.com> Signed-off-by: Balazs Scheidler <bazsi@balabit.hu> -- Bazsi