[syslog-ng] rewrite problem

Balazs Scheidler bazsi at balabit.hu
Tue May 3 20:59:31 CEST 2011


Hi Micah,

I've successfully reproduced the problem with PCRE 8.12, the workaround
I've sent earlier only prevented the loop, a newer patch this time also
makes pcre replacements to work again, even when using pcre 8.12.

Thanks for the great problem description.

This was indeed a bug in syslog-ng, but is only triggered by a newer
pcre version.

I've commited this patch to 3.2, but because you are using 3.1, I've
backported it into 3.1 as well.

I'm planning 3.2.4 in the very near future, however the release for
another maintenance for 3.1.x is questionable. I'd thus recommend you to
apply this patch or perhaps upgrade to latest GIT head, that only
contains a small number of patches compared to the latest release
(3.1.4).


commit 35de55e53dd653c50c8da5daf41a99ab22e7e8aa
Author: Balazs Scheidler <bazsi at balabit.hu>
Date:   Tue May 3 20:54:53 2011 +0200

    pcre: fixed a potential resource hogging infinite loop when an error occurs
    
    Any kind of PCRE error case would cause an infinite loop, when the
    "global" flag is present and pcre returns an error code.
    
    The reported problem is that with PCRE 8.12 we indeed get such an error
    while doing a global replace.
    
    This patch also reworks the way PCRE based replacements are made, that code
    was hairy, and I just hope this one is one bit less so. One performance
    related change also made it that improves the speed pcre replacements,
    which previously zeroed out a 3k array unconditionally in every invocation.
    
    Also added some additional testcases to be sure I didn't break anything.
    
    Reported-By: Micah Anderson <micah at riseup.net>
    Signed-off-by: Balazs Scheidler <bazsi at balabit.hu>


On Mon, 2011-05-02 at 14:57 -0400, micah anderson wrote:
> 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

-- 
Bazsi




More information about the syslog-ng mailing list