[syslog-ng] rewrite problem

micah anderson micah at riseup.net
Mon May 2 20:57:51 CEST 2011


On Mon, 02 May 2011 19:58:17 +0200, Balazs Scheidler <bazsi at 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 at 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 at 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.3-3%2Bb1&stamp=1302672422
> 
> 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 at 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:
> 
> http://wiki.debian.org/HowToGetABacktrace

Sure, I will do this soon and get back to you.

micah
-------------- next part --------------
A non-text attachment was scrubbed...
Name: not available
Type: application/pgp-signature
Size: 835 bytes
Desc: not available
Url : http://lists.balabit.hu/pipermail/syslog-ng/attachments/20110502/8316c775/attachment-0001.pgp 


More information about the syslog-ng mailing list