On Fri, 2012-02-10 at 14:57 -0800, Evan Rempel wrote:
Gergely Nagy wrote:
Evan Rempel <erempel@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@bzorp:~/.zwa/install/syslog-ng-ose-3.3$ cat pattern pattern pattern pattern1 > logloglog bazsi@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@catamount ~]# G_SLICE=always-malloc [root@catamount ~]# export G_SLICE [root@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@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