Red Hat Bugzilla – Bug 1113215
rsyslogd logs kernel messages under the facility 'user' instead of 'kern'
Last modified: 2016-05-16 09:06:21 EDT
Description of problem: When logging kernel messages rsyslogd appears to consider them to be in facility user. It logs them not under whatever was configured for 'kern.*' but under whatever was configured for 'user.*', and when forwarding them to another machine via at least UDP it identifies them as facility 'user' messages (verified both on the other machine and by tcpdump of UDP traffic from a CentOS 7 preliminary test machine). I don't think that the kernel is at fault here, as 'dmesg -f kern' shows all the kernel messages while 'dmesg -f user' shows nothing. In addition, using 'logger' to talk directly to rsyslogd also has the same results. Version-Release number of selected component (if applicable): rsyslog-7.4.7-6.el7.x86_64 kernel-3.10.0-123.4.2.el7.x86_64 How reproducible: Always. Steps to Reproduce: Create an /etc/rsyslog.d/test.conf that contains: kern.* /var/log/test-kern user.* /var/log/test-user Reboot your test machine. Observe that kernel boot messages show up in /var/log/test-user and don't show up in /var/log/test-kern. Also: logger -p kern.info "This is a test" Observe that this message again appeared in /var/log/test-user. Additional info: According to reports from rigeld2 on the #rhel IRC channel, this bug is not present in an earlier rsyslog package from RHEL 7 beta; they did not see the bug in rsyslog-7.4.2-4.el7.x86_64 but did after they updated to the release rsyslog RPM. Also observed and reported in/against CentOS, as https://bugs.centos.org/view.php?id=7197 I have reproduced this on an official RHEL 7 install with the latest updates.
(In reply to Chris Siebenmann from comment #0) > Description of problem: > When logging kernel messages rsyslogd appears to consider them to be > in facility user. It logs them not under whatever was configured for > 'kern.*' but under whatever was configured for 'user.*', Hello Chris, I think rsyslog is not at fault here, but rather systed/journald. rsyslog merely takes the logs from the journal, not /dev/log. You can list the journald logs with more details using: journalct -o json -f If you now repeat your test by logging messages with different facilities, in the output of the command above, you can see a property named "SYSLOG_FACILITY". If journald labels the messages with the 'user' facility, rsyslog simply takes them as such. If you can confirm that the issue is not on rsyslog's side, switch the bug to the systemd component, please. > Additional info: > > According to reports from rigeld2 on the #rhel IRC channel, this bug > is not present in an earlier rsyslog package from RHEL 7 beta; they > did not see the bug in rsyslog-7.4.2-4.el7.x86_64 but did after they > updated to the release rsyslog RPM. It might be of interest to compare the versions of systemd.
Okay, I don't know to interpret what I'm seeing in journalctl here so I'm going to put it here. However, based on other evidence I don't think that systemd is at fault here. What I see for 'journalctl -o json --no-tail' and then looking for both kernel and 'logger -p kern.info message' results, I get: * real kernel messages have "_TRANSPORT" : "kernel", "SYSLOG_IDENTIFIER" : "kernel", "PRIORITY" : "6"; this is for a boot time message of 'XFS (dm-0): Ending clean mount'. They do not have a 'SYSLOG_FACILITY' setting. * logger messages have: "_TRANSPORT" : "syslog", "SYSLOG_FACILITY" : "1", "SYSLOG_IDENTIFIER" : "root". On my Fedora 20 machine, 'journalctl -o json' reports that real kernel messages are (to pick one boot time message) "_TRANSPORT" : "kernel", "SYSLOG_IDENTIFIER" : "kernel", "PRIORITY" : "6" (and no SYSLOG_FACILITY setting). They do get logged correctly by the Fedora 20 rsyslogd, which is rsyslog-7.4.8-1.fc20.1.x86_64. These fields are identical to what the RHEL 7 systemd journal is showing. The systemd on my RHEL 7 test machine is systemd-208-11.el7.x86_64. Fedora 20 has systemd-208-19.fc20.x86_64.
(In reply to Chris Siebenmann from comment #3) > Okay, I don't know to interpret what I'm seeing in journalctl here so > I'm going to put it here. However, based on other evidence I don't think > that systemd is at fault here. Thanks for the data. I still think this is an issue in systemd, let me try to explain why. > What I see for 'journalctl -o json --no-tail' and then looking for > both kernel and 'logger -p kern.info message' results, I get: > > * real kernel messages have "_TRANSPORT" : "kernel", > "SYSLOG_IDENTIFIER" : "kernel", "PRIORITY" : "6"; this is for a boot > time message of 'XFS (dm-0): Ending clean mount'. They do not have > a 'SYSLOG_FACILITY' setting. > > * logger messages have: "_TRANSPORT" : "syslog", "SYSLOG_FACILITY" : "1", > "SYSLOG_IDENTIFIER" : "root". The missing 'SYSLOG_FACILITY' field is the crux of the issue. As per systemd.journal-fields(7), these fields should be supplied to be able to filter messages according to syslog priority. The imjournal plugin, that parses the messages from systemd, relies on these fields to be present. If they are not, default facility value is used. There is no guesswork involved. It's not possible for all messages to have SYSLOG_FACILITY provided by the log source; not all logs come in through /dev/log. But the journald should be able to emulate it at least in the case of kernel messages. It actually does so already - for the syslog socket it provides: the messages journald forwards to /run/systemd/journal/syslog have a correct kernel facility. Therefore I think the missing SYSLOG_FACILITY field is a bug. > On my Fedora 20 machine, 'journalctl -o json' reports that real kernel > messages are (to pick one boot time message) "_TRANSPORT" : "kernel", > "SYSLOG_IDENTIFIER" : "kernel", "PRIORITY" : "6" (and no SYSLOG_FACILITY > setting). They do get logged correctly by the Fedora 20 rsyslogd, which > is rsyslog-7.4.8-1.fc20.1.x86_64. Actually they don't. There is a bug in the configuration on F20. The message excerpt above gets logged to /var/log/messsages, you can check. The messages that you see as having 'kern' facility are coming through the imklog plugin which is turned on by default by mistake. Thus there are duplicate kernel messages; one copy from imjournal and the other from imklog. The ones from imklog go nowhere by default. > These fields are identical to what the > RHEL 7 systemd journal is showing. Yes, they are. The difference is the bug in configuration.
You're right about the situation on Fedora 20. I have a syslog destination configured with (among other things) 'kern.!*' and it gets kernel log messages. I was fooled by the extra copy showing up in my /var/log/kern file that I have just for kern.* messages. So I guess that this is a systemd bug instead of an rsyslog bug. I'll switch the component to systemd as you requested.
(In reply to Chris Siebenmann from comment #5) > So I guess that this is a systemd bug instead of an rsyslog bug. I'll > switch the component to systemd as you requested. Thanks. I'll reset the contact for the bug.
Created attachment 920973 [details] Fix syslog facility for kernel logs
http://10.3.11.34/msekleta/systemd-rhel/commit/74f419223c04026d03495a20a49f30a9cb443b09 -> POST
Amended commit message. http://10.3.11.34/msekleta/systemd-rhel/commit/7f85c4184fc45c3dd2c76b4867ab252c3530f84d
Note that the original reproducer is wrong, as `logger` cannot use the 'kern' facility. It gets converted to 'user' silently, without any error/warning and without mention in the docs (manpage) that it works this was - I've filed a new bug 1184558 for util-linux about this.
(In reply to Karel Volný from comment #15) s/this was/this way/ sorry for the typo and I forgot to mention that I've tested the fix on real kernel messages which are processed correctly with the new systemd-journald version
Since the problem described in this bug report should be resolved in a recent advisory, it has been closed with a resolution of ERRATA. For information on the advisory, and where to find the updated files, follow the link below. If the solution does not work for you, open a new bug report. https://rhn.redhat.com/errata/RHBA-2015-0509.html