Mailing List Archive

slight kernel log format inconsistencybetween 3.16.2and 3.18.0
FYI: I have now taken action against the format problem. I think the
changelog entries tells it all:

- added a new property replacer option "sp-if-no-1st-sp" to cover
a problem with RFC 3164 based interpretation of tag separation. While
it is a generic approach, it fixes a format problem introduced in
3.18.0, where kernel messages no longer had a space after the tag.
This is done by a modification of the default templates.
Please note that this may affect some messages where there
intentionally
is no space between the tag and the first character of the message
content. If so, this needs to be worked around via a specific
template. However, we consider this scenario to be quite remote and,
even if it exists, it is not expected that it will actually cause
problems with log parsers (instead, we assume the new default template
behavior may fix previous problems with log parsers due to the
missing space).

It is not a perfect solution, but I hope a pragmatic and good-enough
one. Other than format issues, I had also some performance concerns.
What I have now implemented affects performance very little. Most
importantly, it enables us to stay away from copying large strings in
memory just to prepend a space.

If some has a concern, please voice it. This patch will be part of
3.21.0 (as it looks to be released today) and, if no hard objection is
received, 3.18.1.

Thanks,
Rainer

> -----Original Message-----
> From: rsyslog-bounces at lists.adiscon.com [mailto:rsyslog-
> bounces at lists.adiscon.com] On Behalf Of Rainer Gerhards
> Sent: Tuesday, July 15, 2008 4:10 PM
> To: rsyslog-users
> Subject: Re: [rsyslog] slight kernel log format inconsistencybetween
> 3.16.2and 3.18.0
>
> Michael,
>
> I have reviewed some of the code in question. It looks like a bug.
It's
> actually not a klog driver issue, the PRI parsing is done at an upper
> klog layer and thus should work for linux as well. I would like to
> generate a version with some additional instrumentation. Could you run
> it and report the results back (maybe via private mail to keep the
list
> free of noise).
>
> Rainer
>
> > -----Original Message-----
> > From: rsyslog-bounces at lists.adiscon.com [mailto:rsyslog-
> > bounces at lists.adiscon.com] On Behalf Of Rainer Gerhards
> > Sent: Tuesday, July 15, 2008 3:04 PM
> > To: rsyslog-users
> > Subject: Re: [rsyslog] slight kernel log format inconsistency
between
> > 3.16.2and 3.18.0
> >
> > On Tue, 2008-07-15 at 14:54 +0200, Michael Biebl wrote:
> > > 2008/7/14 Rainer Gerhards <rgerhards at hq.adiscon.com>:
> > > > Hi all,
> > > >
> > > > Michael Biebl noticed a small inconsistency in kernel log
format:
> > > >
> > > > 3.16.x (and before):
> > > > Jul 11 17:33:28 pluto kernel: [14177.432349]
> > ADDRCONF(NETDEV_CHANGE):
> > > > wlan0: link becomes ready
> > > > Jul 11 17:53:17 pluto kernel: Kernel logging (proc) stopped.
> > > > <upgrade auf 3.18.0>
> > > >
> > > > 3.18.0:
> > > > Jul 11 17:53:17 pluto kernel:imklog 3.18.0, log source =
> /proc/kmsg
> > > > started.
> > > > Jul 11 17:55:56 pluto kernel:Kernel logging (proc) stopped.
> > >
> > > another example:
> > > Jul 15 13:43:42 pluto kernel:<6>[47539.265140] eth0: link down
> > > See the <6> after the kernel: tag. It's also new.
> > > Is this some kind of log level, set by the kernel?
> >
> > This does not look correct. Under FreeBSD, it is typical to have a
> PRI
> > inside kernel messages. But for linux kernels I tested with, I did
> not
> > see it and (I think) so I did not support it. But if you see it on
> > Debian, it seems to happen. A cure is to use the same logic that is
> > used
> > for BSD.
> >
> > > I have never seen, that other syslogger (like syslog-ng, sysklogd
> set
> > this).
> > >
> > > >
> > > > As you can see, there is a space <SP> after kernel: in the pre-
> > 3.18.0
> > > > messages. This also brings us down to a general inconsistency:
> > > >
> > > > Unfortunately, RFC 3164 defines the <SP> after TAG not as a
> > delimiter
> > > > but as part of the CONTENT of the message. This leads to some
> > > > inconsistency in practice. Depending on who generated the
> message,
> > there
> > > > may be a space after the TAG or not. If it is, that space must
be
> > > > submitted as part of the message itself.
> > > >
> > > > In versions up to 3.16.x, kernel log messages were generated by
> old
> > > > code, which did not know about tag and simply generated a non-
> > structured
> > > > message. With 3.17.x and above, the klog code is rewritten and
> > correctly
> > > > fills in all properties. This leads to the "missing" space,
> because
> > the
> > > > space is neither part of the tag nor part of the message.
> > > >
> > > > I have now three options:
> > > >
> > > > 1. leave as is (without a space)
> > > > In that case, some log parsers may run into troubles
> > >
> > > This was a rather vague concern of mine. I don't actually know, if
> > > other software is affected by this change.
> >
> > I share this concern, but also have no additional information. I
> wanted
> > to point out the options. I have to admit I am still undecided. But
> > that
> > nobody violently objected so far makes this look like it is not so
> > important...
> >
> > >
> > > > 2. add a <SP> at the end of the TAG
> > > > That will probably lead to even more confusion, as matches
> against
> > TAG
> > > > would need to include that space.
> > > >
> > > > 3. add a <SP> in front of each kernel message
> > > > This comes close to the previous mode, but is "a bit" clumpsy
and
> > > > hackish. It will also make all database tables etc have messages
> > > > starting with <SP>. Similar as 2, MSG matching rules are
affected
> > (but I
> > > > consider this less severe, as matches inside the MSG are usually
> > driven
> > > > by searches and not absolute positions).
> > >
> > > Just curious: For other log messages, that are not generated by
the
> > > kernel, you have a space after the programname: tag, e.g.
> > > Jul 15 13:43:50 pluto dhclient: DHCPACK from 192.168.2.1
> > >
> > > Is the space after dhclient: part of the message or part of the
> > > :programname tag?
> >
> > In our private communication, I thought it is part of TAG. But that
> is
> > wrong. It actually is part of MSG - at least for legacy/RFC3164
> syslog.
> >
> > For the new IETF syslog RFC series (syslog-protocol, -tls et al) it
> is
> > well-defined and part of neither. There, it is a delimiter (as one
> > would
> > expect). I you use rsyslog only with syslog-protocol messages (and
> the
> > syslog-protocol templates), this is more or less no issue. But who
> does
> > today...? ;)
> >
> > The real problem is that legacy syslog has many different
> > interpretations and we break one or the other in either way...
> >
> > >
> > > Imho, if there is no clear definition in the RFC, how the message
> > > should be written, it's best to stay backwards compatible.
> >
> > Is that a vote for option 3, stick a space in front of each kernel
> > message? ;)
> >
> > >
> > >
> > > Cheers,
> > > Michael
> > >
> > >
> >
> > _______________________________________________
> > rsyslog mailing list
> > http://lists.adiscon.net/mailman/listinfo/rsyslog
> _______________________________________________
> rsyslog mailing list
> http://lists.adiscon.net/mailman/listinfo/rsyslog