Mailing List Archive

slight kernel log format inconsistency between 3.16.2 and 3.18.0
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.

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

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).

I think that real solutions are numbers 1 and 3, with 3 probably having
the best arguments. However, I have to admit I do not like this option
very much at all.

A fourth option would be to add two new property replacer argument "add
<SP> at end if none is already there" and "drop first <SP> if there is
one". I could then modify the default templates to use the first one
with Tag and the later with MSG (instead of the regular ones). That
would be a good fix, probably my favorite, BUT it would also cause
format change, now in other messages. Plus, it is a little bit to code
and I prefer to do as few code changes to a stable as possible.

This issue has unfortunately been lurking ever since the beginning of
rsyslog (as it is rooted in rfc 3164) and I should probably have it
addressed earlier. But as you see: it is ugly... ;)

So question now: what do the list members think?

Feedback is highly appreciated.

Thanks,
Rainer
slight kernel log format inconsistency between 3.16.2 and 3.18.0 [ In reply to ]
> So question now: what do the list members think?

I think I may be partially re-stating #4 by saying this, but I think
the most pragmatic approach would be to implement strict RFC
compliance, then add non-default options to break that in one way or
another for backwards compatibility. Make it explicit (in the option
name and/or documentation) that by doing so they're breaking RFC 3164;
you could even request a courtesy contact to you or the list so you
could roughly track its use and thereby when you can drop it (if
ever).

Of course, that makes more code and more complexity; I'd also support
leaving people with inflexible/broken parsers out in the cold, but I'm
pretty heartless like that.
slight kernel log format inconsistency between 3.16.2 and 3.18.0 [ In reply to ]
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?
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.

> 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?

Imho, if there is no clear definition in the RFC, how the message
should be written, it's best to stay backwards compatible.


Cheers,
Michael


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