[syslog-ng] trailing spaces on udp messages (now with
NULLs!)
Paul Krizak
paul.krizak at amd.com
Fri Jan 19 18:08:16 CET 2007
I have confirmed that this problem was introduced between 2.0rc1 (no
extraneous NULLs) and 2.0rc2 (broken). I'll now start diffing the
releases to see if I can figure out what broke it.
Paul Krizak 5900 E. Ben White Blvd. MS 625
Advanced Micro Devices Austin, TX 78741
Linux/Unix Systems Engineering Phone: (512) 602-8775
Silicon Design Division Cell: (512) 791-0686
Paul Krizak wrote:
> OK I just confirmed that rolling back to syslog-ng-1.9.9 and
> eventlog-0.2.2 corrects this. I will work on locating the revision that
> introduced this problem.
>
> Paul Krizak 5900 E. Ben White Blvd. MS 625
> Advanced Micro Devices Austin, TX 78741
> Linux/Unix Systems Engineering Phone: (512) 602-8775
> Silicon Design Division Cell: (512) 791-0686
>
>
> Paul Krizak wrote:
>> I think that I may be seeing this same thing, though I'm unsure
>> because of the very strange hoops I must go through to reproduce my
>> problem. In my case, I'm getting NULL characters at the end of some
>> messages, particularly those left in the /dev/log buffer (I
>> think...keep reading for an explanation).
>>
>> Here's how I reproduce, using syslog-ng-2.0.1 stable. I've attached
>> my syslog-ng.conf.
>>
>> 1. On a fresh install of RHEL3 U8 (it also happens in RHEL4 U4), stop
>> the syslog service twice:
>>
>> [skaven at byleth ~]$ sudo service syslog stop
>> Shutting down kernel logger: [ OK ]
>> Shutting down system logger: [ OK ]
>> [skaven at byleth ~]$ sudo service syslog stop
>> Shutting down kernel logger: [FAILED]
>> Shutting down system logger: [FAILED]
>>
>> Now start up syslog-ng using the config file provided, and the
>> following messages will appear in /tmp/messages.log:
>>
>> 2007 Jan 18 18:52:22 byleth syslog.notice syslog-ng[15245]: syslog-ng
>> starting up; version='2.0.1'
>> 2007 Jan 18 18:52:24 byleth local7.notice syslog: syslogd shutdown
>> succeeded ^@
>> 2007 Jan 18 18:52:24 byleth auth.warning sudo: skaven : TTY=pts/4 ;
>> PWD=/home/skaven ; USER=root ; COMMAND=/sbin/service syslog stop ^@
>> 2007 Jan 18 18:52:24 byleth local7.notice syslog: klogd shutdown
>> failed ^@
>> 2007 Jan 18 18:52:24 byleth local7.notice syslog: syslogd shutdown
>> failed ^@
>>
>> The ^@ are the NULL characters.
>>
>> So it appears that any syslog message generated after syslogd has gone
>> down (the syslogd shutdown message generated by initlog, the sudo
>> message, the klogd message, and the extra syslogd shutdown messages
>> from the second shutdown) are stored in some sort of buffer. When
>> syslog-ng fires up, /dev/log dumps these messages, and they for some
>> reason contain NULLs at the end.
>>
>> Totally and completely bizarre. Any ideas?
>>
>> Paul Krizak 5900 E. Ben White Blvd. MS 625
>> Advanced Micro Devices Austin, TX 78741
>> Linux/Unix Systems Engineering Phone: (512) 602-8775
>> Silicon Design Division Cell: (512) 791-0686
>>
>>
>> Johan Fischer wrote:
>>> Hi List,
>>>
>>> I'm using syslog-ng-2.0.1 on RHEL4 (centos4 actually) but I
>>> reproduced the same
>>> problem on debian unstable using the debian package (currently 2.0.0).
>>>
>>> The clients are using sysklogd 1.4.1-20
>>>
>>> It seems that all my lines logs from udp() have one trailing space.
>>> The internal
>>> logs and /dev/log don't have that space so I'm currently assuming
>>> either the
>>> sender (sysklogd) or the receiver (udp module of syslog-ng) is not
>>> filtering
>>> that space.
>>>
>>> This also seem to happen with the internal() source.
>>>
>>> A wireshark of the packet will show this:
>>> Syslog message: USER.NOTICE: jfischer: blahklfdsfd\n
>>>
>>> I can see a \n at the end of the line but no space. I don't know what
>>> to think
>>> of this yet.
>>>
>>> I attached the configuration used (stripped as much), and the logs
>>> created.
>>>
>>> This problem is affecting mostly logwatch which do from time to time
>>> strict
>>> regex on the end of the string that I cannot match because of this
>>> trailing space.
>>>
>>> Cheers.
>>> J.
>>>
>>>
>>>
>>>
>>> ------------------------------------------------------------------------
>>>
>>> Jan 17 12:45:01 clamp CRON[8797]: (pam_unix) session opened for user
>>> root by (uid=0)
>>> Jan 17 12:45:01 clamp CRON[8799]: (pam_unix) session opened for user
>>> root by (uid=0)
>>> Jan 17 12:45:01 clamp CRON[8801]: (pam_unix) session opened for user
>>> jfischer by (uid=0)
>>> Jan 17 12:45:01 clamp /USR/SBIN/CRON[8798]: (root) CMD ([ -x
>>> /usr/lib/sysstat/sa1 ] && { [ -r "$DEFAULT" ] && . "$DEFAULT" ; [
>>> "$ENABLED" = "true" ] && exec /usr/lib/sysstat/sa1 $SA1_OPTIONS 1 1 ; })
>>> Jan 17 12:45:01 clamp /USR/SBIN/CRON[8800]: (root) CMD (if [ -x
>>> /usr/bin/mrtg ] && [ -r /etc/mrtg.cfg ]; then env LANG=C
>>> /usr/bin/mrtg /etc/mrtg.cfg >> /var/log/mrtg/mrtg.log 2>&1; fi)
>>> Jan 17 12:45:01 clamp /USR/SBIN/CRON[8802]: (jfischer) CMD
>>> (/home/jfischer/bin/chg_background >/dev/null)
>>> Jan 17 12:45:01 clamp CRON[8801]: (pam_unix) session closed for user
>>> jfischer
>>> Jan 17 12:45:01 clamp CRON[8797]: (pam_unix) session closed for user
>>> root
>>> Jan 17 12:45:02 clamp CRON[8799]: (pam_unix) session closed for user
>>> root
>>> Jan 17 12:45:09 clamp sensord: Sensor alarm: Chip w83627hf-isa-0290:
>>> VCore 1: +0.00 V (min = +1.14 V, max = +1.55 V) [ALARM]
>>> Jan 17 12:45:09 clamp sensord: Sensor alarm: Chip w83627hf-isa-0290:
>>> VCore 2: +0.00 V (min = +1.14 V, max = +1.55 V) [ALARM]
>>> Jan 17 12:45:09 clamp sensord: Sensor alarm: Chip w83627hf-isa-0290:
>>> +3.3V: +0.00 V (min = +2.82 V, max = +3.79 V) [ALARM]
>>> Jan 17 12:45:09 clamp sensord: Sensor alarm: Chip w83627hf-isa-0290:
>>> +5V: +5.03 V (min = +4.01 V, max = +1.10 V) [ALARM]
>>> Jan 17 12:45:09 clamp sensord: Sensor alarm: Chip w83627hf-isa-0290:
>>> +12V: +0.00 V (min = +14.29 V, max = +11.31 V) [ALARM]
>>> Jan 17 12:45:09 clamp sensord: Sensor alarm: Chip w83627hf-isa-0290:
>>> -12V: -14.91 V (min = -4.55 V, max = -10.39 V) [ALARM]
>>> Jan 17 12:45:09 clamp sensord: Sensor alarm: Chip w83627hf-isa-0290:
>>> -5V: -7.71 V (min = -3.39 V, max = +5.00 V) [ALARM]
>>> Jan 17 12:45:09 clamp sensord: Sensor alarm: Chip w83627hf-isa-0290:
>>> V5SB: +5.59 V (min = +2.93 V, max = +2.53 V) [ALARM]
>>> Jan 17 12:45:09 clamp sensord: Sensor alarm: Chip w83627hf-isa-0290:
>>> VBat: +0.00 V (min = +2.99 V, max = +1.84 V) [ALARM]
>>> Jan 17 12:45:09 clamp sensord: Sensor alarm: Chip w83627hf-isa-0290:
>>> fan1: 0 RPM (min = 2812 RPM, div = 2) [ALARM]
>>> Jan 17 12:45:09 clamp sensord: Sensor alarm: Chip w83627hf-isa-0290:
>>> fan2: 0 RPM (min = 3183 RPM, div = 2) [ALARM]
>>> Jan 17 12:45:09 clamp sensord: Sensor alarm: Chip w83627hf-isa-0290:
>>> fan3: 0 RPM (min = 25000 RPM, div = 2) [ALARM]
>>> Jan 17 12:45:44 clamp fetchmail[2500]: awakened at Wed 17 Jan 2007
>>> 12:45:44 EST
>>> Jan 17 12:45:44 clamp fetchmail[2500]: Server CommonName mismatch:
>>> localhost.localdomain != pop.cmcrc.com
>>> Jan 17 12:45:44 clamp fetchmail[2500]: Server certificate
>>> verification error: self signed certificate
>>> Jan 17 12:45:44 clamp fetchmail[2500]: sleeping at Wed 17 Jan 2007
>>> 12:45:44 EST for 300 seconds
>>>
>>>
>>> ------------------------------------------------------------------------
>>>
>>> Jan 17 12:45:01 192.168.15.19 CRON[2871]: (pam_unix) session opened
>>> for user root by (uid=0) Jan 17 12:45:01 192.168.15.19
>>> /USR/SBIN/CRON[2872]: (root) CMD ([ -x /usr/lib/sysstat/sa1 ] && { [
>>> -r "$DEFAULT" ] && . "$DEFAULT" ; [ "$ENABLED" = "true" ] && exec
>>> /usr/lib/sysstat/sa1 $SA1_OPTIONS 1 1 ; }) Jan 17 12:45:01
>>> 192.168.15.19 CRON[2871]: (pam_unix) session closed for user root Jan
>>> 17 12:45:59 192.168.15.19 sshd[3586]: Accepted password for jfischer
>>> from 192.168.15.17 port 49664 ssh2 Jan 17 12:45:59 192.168.15.19
>>> sshd[3606]: (pam_unix) session opened for user jfischer by (uid=0)
>>>
>>> ------------------------------------------------------------------------
>>>
>>> options {
>>> chain_hostnames(0);
>>> time_reopen(10);
>>> time_reap(360);
>>> log_fifo_size(2048);
>>> create_dirs(yes);
>>> group(adm);
>>> perm(0640);
>>> dir_perm(0755);
>>> use_dns(no);
>>> stats_freq(0);
>>> };
>>>
>>> source s_internal {
>>> internal();
>>> };
>>>
>>> source s_local {
>>> unix-stream("/dev/log");
>>> file("/proc/kmsg" log_prefix("kernel: "));
>>> };
>>>
>>> source s_remote {
>>> udp();
>>> tcp();
>>> };
>>>
>>> destination df_internal { file("/var/log/test/internal.log"); };
>>> destination df_local { file("/var/log/test/local.log"); };
>>> destination df_remote { file("/var/log/test/remote.log"); };
>>>
>>> log { source(s_internal); destination(df_internal); };
>>> log { source(s_local); destination(df_local); };
>>> log { source(s_remote); destination(df_remote); };
>>>
>>>
>>>
>>> ------------------------------------------------------------------------
>>>
>>> Jan 17 12:44:30 clamp syslog-ng[8783]: syslog-ng starting up;
>>> version='2.0.0'
>>>
>>> ------------------------------------------------------------------------
>>>
>>> _______________________________________________
>>> syslog-ng maillist - syslog-ng at lists.balabit.hu
>>> https://lists.balabit.hu/mailman/listinfo/syslog-ng
>>> Frequently asked questions at http://www.campin.net/syslog-ng/faq.html
>>>
>>
>> ------------------------------------------------------------------------
>>
>> #options {
>> # sync(0); # The number of lines buffered
>> before written to file: we want immediate output to our destinations
>> # mark_freq(300); # The number of seconds between two
>> MARK lines.
>> # stats_freq(60); # The number of seconds between two
>> STATS. (number of dropped messages)
>> # log_fifo_size(10000); # The number of lines fitting to the
>> output queue: we want to be able to handle a flood
>> # chain_hostnames(no); # Enable or disable the chained
>> hostname format.
>> # keep_hostname(no); # Enable or disable hostname
>> rewriting. We rewrite hostnames because our systems send all their
>> names as IPs.
>> # owner("root"); # group("root");
>> # perm(0644);
>> # create_dirs(yes);
>> # dir_owner("root");
>> # dir_group("root");
>> # dir_perm(0755);
>> # use_dns(yes) ; # Enable or disable DNS usage.
>> **syslog-ng blocks on DNS queries**
>> # dns_cache(yes); # Enable or disable DNS cache usage.
>> (not implemented)
>> # dns_cache_size(10000); # Number of hostnames in the DNS
>> cache: lets try to keep all hosts in the cache (not implemented)
>> # dns_cache_expire(3600); # Number of seconds while a
>> successful lookup is cached: 1 hr seems reasonable (not implemented)
>> # dns_cache_expire_failed(30); # Number of seconds while a failed
>> lookup is cached: 30 seconds seems reasonable (not implemented)
>> # use_fqdn(no); # Add Fully Qualified Domain Name
>> instead of short hostname.
>> #};
>>
>> # Local syslog
>> source s_internal_syslog {
>> unix-dgram("/dev/log");
>> file("/proc/kmsg" log_prefix("kernel:"));
>> };
>>
>> # Sylog-ng's internal log
>> source s_syslog-ng {
>> internal();
>> };
>>
>> # This template reformats incoming messages for use in human-readable
>> logfiles
>> template t_human_readable {
>> template("$R_FULLDATE $HOST $FACILITY.$PRIORITY $MESSAGE\n");
>> template-escape(no);
>> };
>>
>> # The big monolithic syslog file
>> destination d_big_messages {
>> file (
>> "/tmp/messages.log"
>> template(t_human_readable)
>> owner("root")
>> group("root")
>> perm(0644)
>> );
>> };
>>
>> # log local syslog stuff to /var/log/messages
>> log {
>> source(s_internal_syslog);
>> source(s_syslog-ng);
>> destination(d_big_messages);
>> };
>>
>>
>>
>> ------------------------------------------------------------------------
>>
>> _______________________________________________
>> syslog-ng maillist - syslog-ng at lists.balabit.hu
>> https://lists.balabit.hu/mailman/listinfo/syslog-ng
>> Frequently asked questions at http://www.campin.net/syslog-ng/faq.html
>>
>
>
> _______________________________________________
> syslog-ng maillist - syslog-ng at lists.balabit.hu
> https://lists.balabit.hu/mailman/listinfo/syslog-ng
> Frequently asked questions at http://www.campin.net/syslog-ng/faq.html
>
>
More information about the syslog-ng
mailing list