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

[Michael Biebl]

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.

Rainer, can you share any insight on this matter?

Cheers,
Michael




-- 
Why is it that all of the instruments seeking intelligent life in the
universe are pointed away from Earth?