[systemd-devel] systemd-logger and external syslog daemon

[Lennart Poettering]

On Fri, 11.03.11 08:03, Michael Biebl (mbiebl at gmail.com) wrote:

> 
> 2011/2/26 Andrey Borzenkov <arvidjaar at mail.ru>:
> > On Wed, Feb 23, 2011 at 10:48 AM, Mike Kazantsev <mk.fraggod at gmail.com> wrote:
> >>
> >> I've recently deployed systemd on a machine that uses some syslog
> >> monitoring software and the software went nuts because messages from
> >> systemd logger were inconsistent with other logging - they all look
> >> like this:
> >>
> >>  kernel.warning kernel[-]: process[pid]: message contents
> >>
> >
> > I confirm this at least for one special case - redirecting service
> > output to syslog. Here is how it looks like:
> >
> > Mar  1 06:35:53 localhost kernel: crond[847]: Starting crond: [  OK  ]^M[  OK  ]
> > Mar  1 06:35:53 localhost kernel: atd[850]: Starting atd: [  OK  ]
> 
> For me the log messages actually look slightly different, as I also
> get the kernel timestamp and I also noticed a different problem:
> 
> Mar 11 07:56:27 pluto kernel: imklog 5.7.8, log source = /proc/kmsg started.
> Mar 11 07:56:27 pluto rsyslogd: [origin software="rsyslogd"
> swVersion="5.7.8" x-pid="25093" x-info="http://www.rsyslog.com"] start
> Mar 11 07:56:27 pluto kernel: [ 5913.491848] michael[24089]: foo
> Mar 11 07:56:27 pluto kernel: [ 5918.029738] michael[24911]: bar
> Mar 11 07:56:27 pluto kernel: [ 5921.140864] michael[25078]: baz
> 
> As you can see, when rsyslog starts up and flushes the kmsg queue, the
> log messages all have the same timestamp (Mar 11 07:56:27) and they
> come after the rsyslog startup message, although they were logged
> before the  rsyslog start.
> Lennart argues, that this should be handles within the syslogd (in
> this case rsyslog 5.7.8), which should use the kernel time stamp to
> compute the correct time when the log message occured.

Yeah, it would be very good if rsyslog was able to parse the "[ 5921.140864]" 
style kernel timestamps if they are set and translate them via
CLOCK_MONOTONIC/uptime back to normal wallclock timestamps which would
then be used as message timestamps like any other.

Lennart

-- 
Lennart Poettering - Red Hat, Inc.