[syslog-ng] trailing spaces on udp messages (now with
NULLs!)
Paul Krizak
paul.krizak at amd.com
Fri Jan 19 01:55:56 CET 2007
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
>
-------------- next part --------------
#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);
};
More information about the syslog-ng
mailing list