[syslog-ng] 3.3.4 anyone else notice a memory leak
Balazs Scheidler
bazsi at balabit.hu
Sat Feb 25 08:43:02 CET 2012
On Fri, 2012-02-10 at 14:57 -0800, Evan Rempel wrote:
> Gergely Nagy wrote:
> > Evan Rempel <erempel at uvic.ca> writes:
> >
> >> I am fairly certain that there is a memory leak. How do I help track
> >> it down?
> >
> > Looking at your config, I don't recall any known problems in those
> > areas, but I'll try to reproduce the problem.
> >
> > Meanwhile, if you have time, running syslog-ng under valgrind would be
> > very, very useful. If you do that, please set the G_SLICE environment
> > variable to always-malloc, otherwise due to glib's allocator, the
> > results will be severley screwed and hardly usable.
> >
>
> Yup, I can reproduce it. The output of valgrind does not appear to
> show the leak. If I run syslog-ng and do NOT send any data to it (it processes no
> log lines) the output of valgrind is the same as if it processes 100,000 log lines,
> however, when I "dump" 100,000 log lines
>
>
> % wc /home1l/erempel/log
> 107590 1233928 18956930 /home1l/erempel/log
>
>
> into the pipe (cat /home1l/erempel/log > pipe) the memory footprint of syslog-ng
> grows by 3MB, every time I dump in the log lines.
I've tried to reproduce it locally, but without success. Two patches in
addition to 3.3.4, but neither seems to be related.
$ cat etc/syslog-ng-leak.conf
@version: 3.3
#
# UVic syslog-ng configuration
options {
log_fifo_size(100000);
use_fqdn(yes);
keep_hostname(yes);
chain_hostnames(yes);
time_reap(60);
time_reopen(5);
flush_lines(1000);
flush_timeout(1000);
};
source local { pipe("logloglog" log_iw_size(90000) log_fetch_limit(500) flags(no-parse)); };
source int { internal(); };
destination localsyslog { tcp("localhost" port(1514) localip(localhost) log_fifo_size(50000) template("<$PRI>$S_DATE syslogstats@$HOST syslogstats: $MSGONLY\n") template_escape(no) ); };
destination syslog_stats { program("/bin/cat > /dev/null" template("$MESSAGE\n") template_escape(no) ); };
log { source(local); destination(syslog_stats); flags(flow-control); };
log { source(int); destination(localsyslog); };
The tcp destination wasn't working, but if I understand it doesn't matter in your usecase.
$ wc pattern1
109290 643018 5927136 pattern1
$ ps axuw | grep syslog-ng
bazsi 23689 10.3 0.1 68016 4260 pts/0 S+ 06:42 0:02 sbin/syslog-ng -Fef etc/syslog-ng-leak.conf
bazsi 23741 0.0 0.0 12048 892 pts/1 S+ 06:42 0:00 grep syslog-ng
bazsi at bzorp:~/.zwa/install/syslog-ng-ose-3.3$ cat pattern pattern pattern pattern1 > logloglog
bazsi at bzorp:~/.zwa/install/syslog-ng-ose-3.3$ ps axuw | grep syslog-ng
bazsi 23689 10.8 0.1 68020 4264 pts/0 S+ 06:42 0:03 sbin/syslog-ng -Fef etc/syslog-ng-leak.conf
bazsi 23748 0.0 0.0 12048 888 pts/1 S+ 06:42 0:00 grep syslog-ng
>
>
> I have attached the config file and two valgrind outputs.
>
>
> plain text document attachment (valgrind-syslog-ng.txt)
> [root at catamount ~]# G_SLICE=always-malloc
> [root at catamount ~]# export G_SLICE
> [root at catamount ~]# /usr/bin/valgrind /usr/local/sbin/syslog-ng --cfgfile=/usr/local/etc/syslog-ng/syslog-ng.erempel.conf --persist-file=/var/local/syslog-ng.erempel.persist --pidfile=/var/run/syslog-ng.erempel.pid --foreground
> ==19346== Memcheck, a memory error detector
> ==19346== Copyright (C) 2002-2010, and GNU GPL'd, by Julian Seward et al.
> ==19346== Using Valgrind-3.6.0 and LibVEX; rerun with -h for copyright info
> ==19346== Command: /usr/local/sbin/syslog-ng --cfgfile=/usr/local/etc/syslog-ng/syslog-ng.erempel.conf --persist-file=/var/local/syslog-ng.erempel.persist --pidfile=/var/run/syslog-ng.erempel.pid --foreground
> ==19346==
> syslog-ng: Error setting file number limit; limit='4096'; error='Operation not permitted'
> ==19346== Syscall param epoll_ctl(event) points to uninitialised byte(s)
> ==19346== at 0x64F3ECA: epoll_ctl (in /lib64/libc-2.12.so)
> ==19346== by 0x4E7F8FF: iv_epoll_pollable (iv_method_epoll.c:153)
> ==19346== by 0x4E6356B: log_writer_start_watches (logwriter.c:426)
> ==19346== by 0x4E62CFD: log_writer_reopen (logwriter.c:1229)
> ==19346== by 0x6DC25FD: afprogram_dd_reopen (afprog.c:280)
> ==19346== by 0x4E5096A: log_dest_group_init (logpipe.h:239)
> ==19346== by 0x4E4C166: log_center_init (logpipe.h:239)
> ==19346== by 0x4E4D3EF: cfg_init (cfg.c:255)
> ==19346== by 0x4E664BC: main_loop_init (mainloop.c:481)
> ==19346== by 0x401584: main (in /usr/local/sbin/syslog-ng)
> ==19346== Address 0x7ff000128 is on thread 1's stack
> ==19346==
> ^C==19346== Invalid read of size 8
> ==19346== at 0x4E51A81: log_dest_driver_deinit_method (driver.c:172)
> ==19346== by 0x6DC284C: afprogram_dd_deinit (afprog.c:344)
> ==19346== by 0x4E50CAC: log_dest_group_deinit (logpipe.h:254)
> ==19346== by 0x4E4C575: log_center_deinit (logpipe.h:254)
> ==19346== by 0x4E659EF: main_loop_exit_finish (mainloop.c:585)
> ==19346== by 0x4E80EE8: iv_run_timers (iv_timer.c:345)
> ==19346== by 0x4E7F417: iv_main (iv_main.c:252)
> ==19346== by 0x4E6570D: main_loop_run (mainloop.c:731)
> ==19346== by 0x4015B0: main (in /usr/local/sbin/syslog-ng)
> ==19346== Address 0x684a928 is 8 bytes inside a block of size 24 free'd
> ==19346== at 0x4C2695D: free (vg_replace_malloc.c:366)
> ==19346== by 0x590EFDF: g_list_remove (in /lib64/libglib-2.0.so.0.2200.5)
> ==19346== by 0x4E51A5F: log_dest_driver_deinit_method (driver.h:190)
> ==19346== by 0x6DC284C: afprogram_dd_deinit (afprog.c:344)
> ==19346== by 0x4E50CAC: log_dest_group_deinit (logpipe.h:254)
> ==19346== by 0x4E4C575: log_center_deinit (logpipe.h:254)
> ==19346== by 0x4E659EF: main_loop_exit_finish (mainloop.c:585)
> ==19346== by 0x4E80EE8: iv_run_timers (iv_timer.c:345)
> ==19346== by 0x4E7F417: iv_main (iv_main.c:252)
> ==19346== by 0x4E6570D: main_loop_run (mainloop.c:731)
> ==19346== by 0x4015B0: main (in /usr/local/sbin/syslog-ng)
> ==19346==
> ==19346== Invalid read of size 8
> ==19346== at 0x4E51A81: log_dest_driver_deinit_method (driver.c:172)
> ==19346== by 0x6FD07DA: afsocket_dd_deinit (afsocket.c:1221)
> ==19346== by 0x4E50CAC: log_dest_group_deinit (logpipe.h:254)
> ==19346== by 0x4E4C575: log_center_deinit (logpipe.h:254)
> ==19346== by 0x4E659EF: main_loop_exit_finish (mainloop.c:585)
> ==19346== by 0x4E80EE8: iv_run_timers (iv_timer.c:345)
> ==19346== by 0x4E7F417: iv_main (iv_main.c:252)
> ==19346== by 0x4E6570D: main_loop_run (mainloop.c:731)
> ==19346== by 0x4015B0: main (in /usr/local/sbin/syslog-ng)
> ==19346== Address 0x684f358 is 8 bytes inside a block of size 24 free'd
> ==19346== at 0x4C2695D: free (vg_replace_malloc.c:366)
> ==19346== by 0x590EFDF: g_list_remove (in /lib64/libglib-2.0.so.0.2200.5)
> ==19346== by 0x4E51A5F: log_dest_driver_deinit_method (driver.h:190)
> ==19346== by 0x6FD07DA: afsocket_dd_deinit (afsocket.c:1221)
> ==19346== by 0x4E50CAC: log_dest_group_deinit (logpipe.h:254)
> ==19346== by 0x4E4C575: log_center_deinit (logpipe.h:254)
> ==19346== by 0x4E659EF: main_loop_exit_finish (mainloop.c:585)
> ==19346== by 0x4E80EE8: iv_run_timers (iv_timer.c:345)
> ==19346== by 0x4E7F417: iv_main (iv_main.c:252)
> ==19346== by 0x4E6570D: main_loop_run (mainloop.c:731)
> ==19346== by 0x4015B0: main (in /usr/local/sbin/syslog-ng)
> ==19346==
> ==19346==
> ==19346== HEAP SUMMARY:
> ==19346== in use at exit: 169,334 bytes in 3,407 blocks
> ==19346== total heap usage: 226,539 allocs, 223,132 frees, 178,250,594 bytes allocated
> ==19346==
> ==19346== LEAK SUMMARY:
> ==19346== definitely lost: 197 bytes in 2 blocks
> ==19346== indirectly lost: 1,823 bytes in 22 blocks
> ==19346== possibly lost: 0 bytes in 0 blocks
> ==19346== still reachable: 167,314 bytes in 3,383 blocks
> ==19346== suppressed: 0 bytes in 0 blocks
> ==19346== Rerun with --leak-check=full to see details of leaked memory
> ==19346==
> ==19346== For counts of detected and suppressed errors, rerun with: -v
> ==19346== Use --track-origins=yes to see where uninitialised values come from
> ==19346== ERROR SUMMARY: 4 errors from 3 contexts (suppressed: 66 from 9)
>
> plain text document attachment (valgrind-syslog-ng-leak-check.txt)
> [root at catamount ~]# /usr/bin/valgrind --leak-check=full /usr/local/sbin/syslog-ng --cfgfile=/usr/local/etc/syslog-ng/syslog-ng.erempel.conf --persist-file=/var/local/syslog-ng.erempel.persist --pidfile=/var/run/syslog-ng.erempel.pid --foreground
> ==19487== Memcheck, a memory error detector
> ==19487== Copyright (C) 2002-2010, and GNU GPL'd, by Julian Seward et al.
> ==19487== Using Valgrind-3.6.0 and LibVEX; rerun with -h for copyright info
> ==19487== Command: /usr/local/sbin/syslog-ng --cfgfile=/usr/local/etc/syslog-ng/syslog-ng.erempel.conf --persist-file=/var/local/syslog-ng.erempel.persist --pidfile=/var/run/syslog-ng.erempel.pid --foreground
> ==19487==
> syslog-ng: Error setting file number limit; limit='4096'; error='Operation not permitted'
> ==19487== Syscall param epoll_ctl(event) points to uninitialised byte(s)
> ==19487== at 0x64F3ECA: epoll_ctl (in /lib64/libc-2.12.so)
> ==19487== by 0x4E7F8FF: iv_epoll_pollable (iv_method_epoll.c:153)
> ==19487== by 0x4E6356B: log_writer_start_watches (logwriter.c:426)
> ==19487== by 0x4E62CFD: log_writer_reopen (logwriter.c:1229)
> ==19487== by 0x6DC25FD: afprogram_dd_reopen (afprog.c:280)
> ==19487== by 0x4E5096A: log_dest_group_init (logpipe.h:239)
> ==19487== by 0x4E4C166: log_center_init (logpipe.h:239)
> ==19487== by 0x4E4D3EF: cfg_init (cfg.c:255)
> ==19487== by 0x4E664BC: main_loop_init (mainloop.c:481)
> ==19487== by 0x401584: main (in /usr/local/sbin/syslog-ng)
> ==19487== Address 0x7ff000128 is on thread 1's stack
> ==19487==
> ^C==19487== Invalid read of size 8
> ==19487== at 0x4E51A81: log_dest_driver_deinit_method (driver.c:172)
> ==19487== by 0x6DC284C: afprogram_dd_deinit (afprog.c:344)
> ==19487== by 0x4E50CAC: log_dest_group_deinit (logpipe.h:254)
> ==19487== by 0x4E4C575: log_center_deinit (logpipe.h:254)
> ==19487== by 0x4E659EF: main_loop_exit_finish (mainloop.c:585)
> ==19487== by 0x4E80EE8: iv_run_timers (iv_timer.c:345)
> ==19487== by 0x4E7F417: iv_main (iv_main.c:252)
> ==19487== by 0x4E6570D: main_loop_run (mainloop.c:731)
> ==19487== by 0x4015B0: main (in /usr/local/sbin/syslog-ng)
> ==19487== Address 0x684a928 is 8 bytes inside a block of size 24 free'd
> ==19487== at 0x4C2695D: free (vg_replace_malloc.c:366)
> ==19487== by 0x590EFDF: g_list_remove (in /lib64/libglib-2.0.so.0.2200.5)
> ==19487== by 0x4E51A5F: log_dest_driver_deinit_method (driver.h:190)
> ==19487== by 0x6DC284C: afprogram_dd_deinit (afprog.c:344)
> ==19487== by 0x4E50CAC: log_dest_group_deinit (logpipe.h:254)
> ==19487== by 0x4E4C575: log_center_deinit (logpipe.h:254)
> ==19487== by 0x4E659EF: main_loop_exit_finish (mainloop.c:585)
> ==19487== by 0x4E80EE8: iv_run_timers (iv_timer.c:345)
> ==19487== by 0x4E7F417: iv_main (iv_main.c:252)
> ==19487== by 0x4E6570D: main_loop_run (mainloop.c:731)
> ==19487== by 0x4015B0: main (in /usr/local/sbin/syslog-ng)
> ==19487==
> ==19487== Invalid read of size 8
> ==19487== at 0x4E51A81: log_dest_driver_deinit_method (driver.c:172)
> ==19487== by 0x6FD07DA: afsocket_dd_deinit (afsocket.c:1221)
> ==19487== by 0x4E50CAC: log_dest_group_deinit (logpipe.h:254)
> ==19487== by 0x4E4C575: log_center_deinit (logpipe.h:254)
> ==19487== by 0x4E659EF: main_loop_exit_finish (mainloop.c:585)
> ==19487== by 0x4E80EE8: iv_run_timers (iv_timer.c:345)
> ==19487== by 0x4E7F417: iv_main (iv_main.c:252)
> ==19487== by 0x4E6570D: main_loop_run (mainloop.c:731)
> ==19487== by 0x4015B0: main (in /usr/local/sbin/syslog-ng)
> ==19487== Address 0x684f358 is 8 bytes inside a block of size 24 free'd
> ==19487== at 0x4C2695D: free (vg_replace_malloc.c:366)
> ==19487== by 0x590EFDF: g_list_remove (in /lib64/libglib-2.0.so.0.2200.5)
> ==19487== by 0x4E51A5F: log_dest_driver_deinit_method (driver.h:190)
> ==19487== by 0x6FD07DA: afsocket_dd_deinit (afsocket.c:1221)
> ==19487== by 0x4E50CAC: log_dest_group_deinit (logpipe.h:254)
> ==19487== by 0x4E4C575: log_center_deinit (logpipe.h:254)
> ==19487== by 0x4E659EF: main_loop_exit_finish (mainloop.c:585)
> ==19487== by 0x4E80EE8: iv_run_timers (iv_timer.c:345)
> ==19487== by 0x4E7F417: iv_main (iv_main.c:252)
> ==19487== by 0x4E6570D: main_loop_run (mainloop.c:731)
> ==19487== by 0x4015B0: main (in /usr/local/sbin/syslog-ng)
> ==19487==
> ==19487==
> ==19487== HEAP SUMMARY:
> ==19487== in use at exit: 169,334 bytes in 3,407 blocks
> ==19487== total heap usage: 226,539 allocs, 223,132 frees, 178,250,594 bytes allocated
> ==19487==
> ==19487== 13 bytes in 1 blocks are definitely lost in loss record 11 of 604
> ==19487== at 0x4C26FDE: malloc (vg_replace_malloc.c:236)
> ==19487== by 0x59197D2: g_malloc (in /lib64/libglib-2.0.so.0.2200.5)
> ==19487== by 0x5930FCD: g_strdup (in /lib64/libglib-2.0.so.0.2200.5)
> ==19487== by 0x4E6E999: log_tags_init (tags.c:162)
> ==19487== by 0x4E4B721: app_startup (apphook.c:120)
> ==19487== by 0x4E663AE: main_loop_init (mainloop.c:663)
> ==19487== by 0x401584: main (in /usr/local/sbin/syslog-ng)
> ==19487==
> ==19487== 2,007 (184 direct, 1,823 indirect) bytes in 1 blocks are definitely lost in loss record 589 of 604
> ==19487== at 0x4C26FDE: malloc (vg_replace_malloc.c:236)
> ==19487== by 0x59197D2: g_malloc (in /lib64/libglib-2.0.so.0.2200.5)
> ==19487== by 0x4E544AF: g_process_set_argv_space (gprocess.c:500)
> ==19487== by 0x40148C: main (in /usr/local/sbin/syslog-ng)
> ==19487==
> ==19487== LEAK SUMMARY:
> ==19487== definitely lost: 197 bytes in 2 blocks
> ==19487== indirectly lost: 1,823 bytes in 22 blocks
> ==19487== possibly lost: 0 bytes in 0 blocks
> ==19487== still reachable: 167,314 bytes in 3,383 blocks
> ==19487== suppressed: 0 bytes in 0 blocks
> ==19487== Reachable blocks (those to which a pointer was found) are not shown.
> ==19487== To see them, rerun with: --leak-check=full --show-reachable=yes
> ==19487==
> ==19487== For counts of detected and suppressed errors, rerun with: -v
> ==19487== Use --track-origins=yes to see where uninitialised values come from
> ==19487== ERROR SUMMARY: 6 errors from 5 contexts (suppressed: 66 from 9)
>
> plain text document attachment (syslog-ng.conf)
> @version: 3.3
>
> options {
> log_fifo_size(1000000); # must be at least the biggest value of any log_is_size
> use_fqdn(yes);
> keep_hostname(yes);
> chain_hostnames(yes);
> time_reap(60);
> time_reopen(5);
> flush_lines(1000);
> flush_timeout(1000);
> };
>
>
> source test { pipe("/var/log/syslog.pipes/test" log_fetch_limit(50) log_iw_size(10000) flags(no-parse) ); };
> source int { internal(); };
>
>
> template t_standardfile { template("$S_ISODATE $FULLHOST $FACILITY.$LEVEL $MSGHDR][$PROGRAM][$MESSAGE\n"); template_escape(no); };
>
> destination localsyslog { tcp("localhost" port(1514) localip(catamount.comp.uvic.ca) log_fifo_size(5000) template("<$PRI>$S_ISODATE test@$HOST flexfilter_alert: $MSGONLY\n") template_escape(no) ); };
> destination flexfilter { program("/usr/local/sbin/flexfilter /home1l/erempel/alert/fullsyslog.xml" template("$MESSAGE\n") template_escape(no) ); };
> destination flexfilter2 { program("/bin/cat > /dev/null" template("$MESSAGE\n") template_escape(no) ); };
>
> log { source(test); destination(flexfilter); flags(flow-control); };
> log { source(int); destination(localsyslog); };
>
>
> ______________________________________________________________________________
> Member info: https://lists.balabit.hu/mailman/listinfo/syslog-ng
> Documentation: http://www.balabit.com/support/documentation/?product=syslog-ng
> FAQ: http://www.balabit.com/wiki/syslog-ng-faq
>
--
Bazsi
More information about the syslog-ng
mailing list