On Mon, 02 May 2011 19:58:17 +0200, Balazs Scheidler <bazsi@balabit.hu> wrote:
On Mon, 2011-05-02 at 12:01 -0400, micah anderson wrote:
On Mon, 02 May 2011 17:41:41 +0200, Balazs Scheidler <bazsi@balabit.hu> wrote:
On Sun, 2011-05-01 at 12:43 -0400, micah anderson wrote:
On Sat, 30 Apr 2011 22:17:36 +0200, Balazs Scheidler <bazsi@balabit.hu> wrote:
On Tue, 2011-04-26 at 14:51 -0400, Micah Anderson wrote:
Hi,
I've been trying to use the rewrite functionality using 3.1.3, but I am having some problems:
1. when having a rewrite setup, I can denial of service syslog-ng :(
if I do this:
rewrite r_ip { subst("([[:digit:]]{1,3}\.){3}[[:digit:]]{1,3}", "\[REDACTED\]", value("MESSAGE"), type("pcre"), flags("global")); };
filter f_mail { facility(mail) and not facility(local1) and not program("^postfix/"); }; destination df_mail { file("/var/log/mail.log"); };
log { source(s_src); filter(f_mail); rewrite(r_ip); destination(df_mail); flags(final); };
and then I do:
$ logger -p mail.info hi
syslog-ng starts going crazy, it eats 100% of the CPU and the memory. If you are lucky, the OOM killer kicks in and stops it before your system goes down.
I originally thought that this was due to a bad regexp I had, but the above regexp works fine for normal mail syslog messages. However, in the process of trying to make a better rewrite rule, I found that I've created ones where normal mail messages do this too.
Hmm... well, it is still probably a regexp problem, but it'd probably make sense to validate it.
It could be a regexp problem, although I have not found it yet. Validating would be better than having the system brought down by syslog-ng, which doesn't look so good :)
Hmm.. reading the code again, there's indeed a loop when "global" replacements are made. However an infinite loop is only possible, when the match has a zero length.
That seems like a problem, because the log message I send, if I understand it correctly, has no match.
Can you please give me a log sample that causes syslog-ng to spin? I couldn't reproduce it with a simplistic sample.
Well the above works flawlessly for me. This is the bare-minimum syslog-ng.conf that causes this:
@version: 3.1
source s_src { unix-dgram("/dev/log"); internal(); file("/proc/kmsg" program_override("kernel")); };
rewrite r_ip { subst("([[:digit:]]{1,3}\.){3}[[:digit:]]{1,3}", "\[REDACTED\]", value("MESSAGE"), type("pcre"), flags("global")); };
filter f_mail { facility(mail); };
destination df_mail { file("/var/log/mail.log"); };
log { source(s_src); filter(f_mail); rewrite(r_ip); destination(df_mail); flags(final); };
Then restart syslog-ng, and then do this (even as a regular user):
$ logger -p mail.info hi
you might want to be ready to kill the syslog-ng process, because if you wait too long, then things will become very slow as you start to swap and then you have to just hope the OOM killer makes the right choice.
Thanks for the detailed testcase. I've tried to reproduce the problem, but couldn't, with both 3.2 and 3.1. Which OS are you running syslog-ng on? PCRE version? Did you compile it on your own?
This is 3.1.3 on Debian sid, I did not compile it on my own. The package depends on libpcre3 (>= 8.10) and build-depends on libpcre3-dev which also depends on libpcrecpp0. Looking at its build logs, it was built against 8.12-3 (-3 is the debian revision).
If you would like to look at the build log, this is it:
https://buildd.debian.org/status/fetch.php?pkg=syslog-ng&arch=amd64&ver=3.1....
I run Ubuntu maverick, which still ships 3.1.2, but I've downloaded the package from the Debian archive, and it still doesn't reproduce the problem:
$ dpkg -l syslog-ng ii syslog-ng 3.1.3-3 Next generation logging daemon
Interesting... what architecture are you using? I'm using amd64, I dont know if that matters, but I figure I should mention it.
$ ldd /usr/sbin/syslog-ng linux-vdso.so.1 => (0x00007fff49b3a000) librt.so.1 => /lib/librt.so.1 (0x00007f2803ea6000) libnsl.so.1 => /lib/libnsl.so.1 (0x00007f2803c8c000) libgthread-2.0.so.0 => /usr/lib/libgthread-2.0.so.0 (0x00007f2803a86000) libglib-2.0.so.0 => /lib/libglib-2.0.so.0 (0x00007f28037a4000) libevtlog.so.0 => /usr/lib/libevtlog.so.0 (0x00007f280359f000) libssl.so.0.9.8 => /lib/libssl.so.0.9.8 (0x00007f280334c000) libcrypto.so.0.9.8 => /lib/libcrypto.so.0.9.8 (0x00007f2802fc0000) libz.so.1 => /lib/libz.so.1 (0x00007f2802da8000) libnet.so.1 => /usr/lib/libnet.so.1 (0x00007f2802b8e000) libwrap.so.0 => /lib/libwrap.so.0 (0x00007f2802983000) libdbi.so.0 => /usr/lib/libdbi.so.0 (0x00007f2802775000) libcap.so.2 => /lib/libcap.so.2 (0x00007f280256f000) libpcre.so.3 => /lib/libpcre.so.3 (0x00007f280233e000) libpthread.so.0 => /lib/libpthread.so.0 (0x00007f2802121000) libc.so.6 => /lib/libc.so.6 (0x00007f2801d9d000) /lib64/ld-linux-x86-64.so.2 (0x00007f28040d1000) libdl.so.2 => /lib/libdl.so.2 (0x00007f2801b99000) libm.so.6 => /lib/libm.so.6 (0x00007f2801915000) libattr.so.1 => /lib/libattr.so.1 (0x00007f2801710000)
Mine: $ ldd /usr/sbin/syslog-ng linux-vdso.so.1 => (0x00007fff3e7ff000) librt.so.1 => /lib/librt.so.1 (0x00007f9715f2e000) libnsl.so.1 => /lib/libnsl.so.1 (0x00007f9715d16000) libgthread-2.0.so.0 => /usr/lib/libgthread-2.0.so.0 (0x00007f9715b11000) libglib-2.0.so.0 => /lib/libglib-2.0.so.0 (0x00007f9715820000) libevtlog.so.0 => /usr/lib/libevtlog.so.0 (0x00007f971561c000) libssl.so.1.0.0 => /usr/lib/libssl.so.1.0.0 (0x00007f97153c9000) libcrypto.so.1.0.0 => /usr/lib/libcrypto.so.1.0.0 (0x00007f9715001000) libz.so.1 => /usr/lib/libz.so.1 (0x00007f9714dea000) libnet.so.1 => /usr/lib/libnet.so.1 (0x00007f9714bd1000) libwrap.so.0 => /lib/libwrap.so.0 (0x00007f97149c8000) libdbi.so.0 => /usr/lib/libdbi.so.0 (0x00007f97147ba000) libcap.so.2 => /lib/libcap.so.2 (0x00007f97145b5000) libpcre.so.3 => /lib/libpcre.so.3 (0x00007f971437a000) libpthread.so.0 => /lib/libpthread.so.0 (0x00007f971415e000) libc.so.6 => /lib/libc.so.6 (0x00007f9713dfb000) /lib64/ld-linux-x86-64.so.2 (0x00007f971615c000) libdl.so.2 => /lib/libdl.so.2 (0x00007f9713bf7000) libm.so.6 => /lib/libm.so.6 (0x00007f9713974000) libattr.so.1 => /lib/libattr.so.1 (0x00007f9713770000) basically the same, with the exception of the addresses and the libssl/libcrypto versions (I have newer) and the location of them (and libz), seems they are in /lib on your system, but /usr/lib on mine.
$ dpkg -l libpcre3 ii libpcre3 8.02-1 Perl 5 Compatible Regular Expression Library - runtime files
Yeah, mine is newer: ii libpcre3 8.12-3 Perl 5 Compatible Regular Expression Library - runtime files
$ /usr/sbin/syslog-ng -V syslog-ng 3.1.3 Installer-Version: 3.1.3 Revision: ssh+git://bazsi@git.balabit//var/scm/git/syslog-ng/syslog-ng-ose--mainline--3.1#master#def34661b08109f8148904b860457d5747c425b3 Compile-Date: Feb 1 2011 19:11:59 Enable-Threads: on Enable-Debug: off Enable-GProf: off Enable-Memtrace: off Enable-Sun-STREAMS: off Enable-Sun-Door: off Enable-IPv6: on Enable-Spoof-Source: on Enable-TCP-Wrapper: on Enable-SSL: on Enable-SQL: on Enable-Linux-Caps: on Enable-Pcre: on
Pretty much the same here, with the exception of the compile date: $ /usr/sbin/syslog-ng -V syslog-ng 3.1.3 Installer-Version: 3.1.3 Revision: ssh+git://bazsi@git.balabit//var/scm/git/syslog-ng/syslog-ng-ose--mainline--3.1#master#def34661b08109f8148904b860457d5747c425b3 Compile-Date: Apr 13 2011 05:26:38 Enable-Threads: on Enable-Debug: off Enable-GProf: off Enable-Memtrace: off Enable-Sun-STREAMS: off Enable-Sun-Door: off Enable-IPv6: on Enable-Spoof-Source: on Enable-TCP-Wrapper: on Enable-SSL: on Enable-SQL: on Enable-Linux-Caps: on Enable-Pcre: on
$ /usr/sbin/syslog-ng -Fedvf etc/syslog-ng-rewrite.conf syslog-ng: Error setting file number limit; limit='4096'; error='Operation not permitted' syslog-ng: Error setting capabilities, capability management disabled; error='Operation not permitted' syslog-ng: Error creating pid file; file='/var/lib/syslog-ng/syslog-ng.pid', error='Permission denied' Running application hooks; hook='1' Running application hooks; hook='3' syslog-ng starting up; version='3.1.3' Error opening control socket, bind() failed; socket='/var/lib/syslog-ng/syslog-ng.ctl', error='Address already in use (98)' Syslog connection accepted; fd='6', client='AF_UNIX(anonymous)', local='AF_UNIX(log)' Incoming log entry; line='<22>May 2 19:46:33 bazsi: hi' Filter rule evaluation begins; filter_rule='f_mail' Filter node evaluation result; filter_result='match', filter_type='facility' Filter rule evaluation result; filter_result='match', filter_rule='f_mail' Rewrite expression evaluation result; value='MESSAGE', new_value='hi' Initializing destination file writer; template='mail.log', filename='mail.log' EOF occurred while reading; fd='6' Syslog connection closed; fd='6', client='AF_UNIX(anonymous)', local='AF_UNIX(log)' Closing log transport fd; fd='6'
No ill behaviour. The only changes I did to your config was to use a local unix-stream socket instead of /dev/log & /proc/kmsg.
Here is what I get when I run it: root@algae:/tmp# /usr/sbin/syslog-ng -Fedvf /etc/syslog-ng/syslog-ng.conf Running application hooks; hook='1' Running application hooks; hook='3' syslog-ng starting up; version='3.1.3' Incoming log entry; line='<22>May 2 14:55:58 logger: hi' Filter rule evaluation begins; filter_rule='f_mail' Filter node evaluation result; filter_result='match', filter_type='facility' Filter rule evaluation result; filter_result='match', filter_rule='f_mail' Error while matching regexp; error_code='-24' Error while matching regexp; error_code='-24' Error while matching regexp; error_code='-24' Error while matching regexp; error_code='-24' Error while matching regexp; error_code='-24' Error while matching regexp; error_code='-24' Error while matching regexp; error_code='-24' Error while matching regexp; error_code='-24' Error while matching regexp; error_code='-24' Error while matching regexp; error_code='-24' Error while matching regexp; error_code='-24' Error while matching regexp; error_code='-24' Error while matching regexp; error_code='-24' Error while matching regexp; error_code='-24' Error while matching regexp; error_code='-24' Error while matching regexp; error_code='-24' Error while matching regexp; error_code='-24' Error while matching regexp; error_code='-24' Error while matching regexp; error_code='-24' Error while matching regexp; error_code='-24' Error while matching regexp; error_code='-24' Error while matching regexp; error_code='-24' Error while matching regexp; error_code='-24' I have to kill -9 the process for it to stop, otherwise it repeats that Error while mathcing regexp; error_code '-24' until infinity.
Can you install the debugging symbols for syslog-ng (I'm not sure, but Ubuntu has dbgsym packages, I'm not sure about Debian though), so it'd be nice if you could attach to the runaway syslog-ng process (even before it runs away) and produce a backtrace where it is spinning.
Just stop the program using Ctrl-C at the gdb prompt and use bt, some more details on how to do that can be found here:
Sure, I will do this soon and get back to you. micah