As I understand, Linux kernel logs to /proc/kmsg
file(mostly hardware-related messages) and /dev/log
socket? Anywhere else? Are other applications also able to send messages to /proc/kmsg
or /dev/log
? Last but not least, am I correct that it is the syslog daemon(rsyslog, syslog-ng) which checks messages from those two places and then distributes those to various files like /var/log/messages
or /var/log/kern.log
or even central syslog server?
linux – Understanding Logging in Linux
linux-kernelrsyslogsyslogsyslog-ng
Related Solutions
Not a direct solution but I would enable some debugging to see what's happening behind the scenes.
Idea #1 - Debugging logger
For starters when you run your logger
commands you can do them like so, echoing out messages to STDERR.
$ logger -s "hi"
saml: hi
Idea #2 - validate your configuration file
You can also try validating your rsyslog configuration file:
$ sudo rsyslogd -N6 | head -10
rsyslogd: version 7.2.6, config validation run (level 6), master config /etc/rsyslog.conf
rsyslogd: End of config validation run. Bye.
6921.173842409:7f8b11df2780: rsyslogd 7.2.6 startup, module path '', cwd:/root
6921.175241008:7f8b11df2780: caller requested object 'net', not found (iRet -3003)
6921.175261977:7f8b11df2780: Requested to load module 'lmnet'
6921.175272711:7f8b11df2780: loading module '/lib64/rsyslog/lmnet.so'
6921.175505384:7f8b11df2780: module lmnet of type 2 being loaded (keepType=0).
6921.175520208:7f8b11df2780: entry point 'isCompatibleWithFeature' not present in module
6921.175528413:7f8b11df2780: entry point 'setModCnf' not present in module
6921.175535294:7f8b11df2780: entry point 'getModCnfName' not present in module
6921.175541502:7f8b11df2780: entry point 'beginCnfLoad' not present in module
Idea #3 - Turn up rsyslogd debugging
Also I'd try enabling debugging of the rsyslogd
daemon for further insight.
$ sudo -i
$ export RSYSLOG_DEBUGLOG="/tmp/debuglog"
$ export RSYSLOG_DEBUG="Debug"
$ service rsyslog stop
$ rsyslogd -d | head -10
7160.005597645:7fae096a3780: rsyslogd 7.2.6 startup, module path '', cwd:/root
7160.005872662:7fae096a3780: caller requested object 'net', not found (iRet -3003)
7160.005895004:7fae096a3780: Requested to load module 'lmnet'
7160.005906331:7fae096a3780: loading module '/lib64/rsyslog/lmnet.so'
7160.006023505:7fae096a3780: module lmnet of type 2 being loaded (keepType=0).
7160.006030872:7fae096a3780: entry point 'isCompatibleWithFeature' not present in module
7160.006033780:7fae096a3780: entry point 'setModCnf' not present in module
7160.006036209:7fae096a3780: entry point 'getModCnfName' not present in module
7160.006038359:7fae096a3780: entry point 'beginCnfLoad' not present in module
...
...
7160.006063913:7fae096a3780: rsyslog runtime initialized, version 7.2.6, current users 1
7160.006102179:7fae096a3780: source file syslogd.c requested reference for module 'lmnet', reference count now 2
7160.006113657:7fae096a3780: GenerateLocalHostName uses 'greeneggs'
Confirming version info
$ rsyslogd -version
rsyslogd 7.2.6, compiled with:
FEATURE_REGEXP: Yes
FEATURE_LARGEFILE: No
GSSAPI Kerberos 5 support: Yes
FEATURE_DEBUG (debug build, slow code): No
32bit Atomic operations supported: Yes
64bit Atomic operations supported: Yes
Runtime Instrumentation (slow code): No
uuid support: Yes
See http://www.rsyslog.com for more information.
Confirmed bug and a workaround
The OP submitted this as a bug to Red Hat.
The bug was characterized as follows:
Sure enough when I set the host's own time the VM had the same wrong time as the host. That's when I noticed /var/log/messages was no longer being updated.
It turns out nothing other than restarting the rsyslog service itself logs to files at that point. If I do so this gets logged:
--- Apr 15 16:39:39 rhel7time-dev rsyslogd-3000: sd_journal_get_cursor() failed: 'Cannot assign requested address' Apr 15 16:39:39 rhel7time-dev rsyslogd: [origin software="rsyslogd" swVersion="7.4.2" x-pid="574" x-info="http://www.rsyslog.com"] exiting on signal 15. Apr 15 16:39:39 rhel7time-dev rsyslogd: [origin software="rsyslogd" swVersion="7.4.2" x-pid="2117" x-info="http://www.rsyslog.com"] start ---
Otherwise nothing is logged to file, including logger.
If I comment out $OmitLocalLogging on in rsyslog.conf then file logging resumes (notice that until that point I hadn't changed rsyslog.conf).
Logging through journal is unaffected by all this. journalctl -b shows logging, including anything sent by logger.
To which the one of the developers responded:
When this issue occurs, you can delete
/var/lib/rsyslog/imjournal.state
and restart the daemon as a workaround.rsyslog doesn't handle the date directly but only through the systemd API. I've checked the code in imjournal a while ago and this looks like an issue in systemd.
For reference, see: https://github.com/rsyslog/rsyslog/issues/43
It appears that systemd does not have a built-in means of forwarding messages to a syslog server. Red Hat's official recommendation is to use the imjournal
module to allow rsyslog to read the journald logs and forward these logs to a central logging server by setting the following in /etc/rsyslog.conf:
module(load="imjournal"
PersistStateInterval="number_of_messages"
StateFile="path"
ratelimit.interval="seconds"
ratelimit.burst="burst_number"
IgnorePreviousMessages="off/on")
They provide usage details for these options , noting
With number_of_messages, you can specify how often the journal data must be saved. This will happen each time the specified number of messages is reached.
Replace path with a path to the state file. This file tracks the journal entry that was the last one processed.
With seconds, you set the length of the rate limit interval. The number of messages processed during this interval can not exceed the value specified in burst_number. The default setting is 20,000 messages per 600 seconds. Rsyslog discards messages that come after the maximum burst within the time frame specified.
With IgnorePreviousMessages you can ignore messages that are currently in Journal and import only new messages, which is used when there is no state file specified. The default setting is off. Please note that if this setting is off and there is no state file, all messages in the Journal are processed, even if they were already processed in a previous rsyslog session.
Best Answer
Simplified, it goes more or less like this:
The kernel logs messages (using the
printk()
function) to a ring buffer in kernel space. These messages are made available to user-space applications in two ways: via the/proc/kmsg
file (provided that/proc
is mounted), and via thesys_syslog
syscall.There are two main applications that read (and, to some extent, can control) the kernel's ring buffer:
dmesg(1)
andklogd(8)
. The former is intended to be run on demand by users, to print the contents of the ring buffer. The latter is a daemon that reads the messages from/proc/kmsg
(or callssys_syslog
, if/proc
is not mounted) and sends them tosyslogd(8)
, or to the console. That covers the kernel side.In user space, there's
syslogd(8)
. This is a daemon that listens on a number of UNIX domain sockets (mainly/dev/log
, but others can be configured too), and optionally to the UDP port 514 for messages. It also receives messages fromklogd(8)
(syslogd(8)
doesn't care about/proc/kmsg
). It then writes these messages to some files in/log
, or to named pipes, or sends them to some remote hosts (via thesyslog
protocol, on UDP port 514), as configured in/etc/syslog.conf
.User-space applications normally use the
libc
functionsyslog(3)
to log messages.libc
sends these messages to the UNIX domain socket/dev/log
(where they are read bysyslogd(8)
), but if an application ischroot(2)
-ed the messages might end up being written to other sockets, f.i. to/var/named/dev/log
. It is, of course, essential for the applications sending these logs andsyslogd(8)
to agree on the location of these sockets. For these reasonsyslogd(8)
can be configured to listen to additional sockets aside from the standard/dev/log
.Finally, the
syslog
protocol is just a datagram protocol. Nothing stops an application from sending syslog datagrams to any UNIX domain socket (provided that its credentials allows it to open the socket), bypassing thesyslog(3)
function inlibc
completely. If the datagrams are correctly formattedsyslogd(8)
can use them as if the messages were sent throughsyslog(3)
.Of course, the above covers only the "classic" logging theory. Other daemons (such as
rsyslog
andsyslog-ng
, as you mention) can replace the plainsyslogd(8)
, and do all sorts of nifty things, like send messages to remote hosts via encrypted TCP connections, provide high resolution timestamps, and so on. And there's alsosystemd
, that is slowly phagocytosing the UNIX part of Linux.systemd
has its own logging mechanisms, but that story would have to be told by somebody else. :)Differences with the *BSD world:
On *BSD there is no
klogd(8)
, and/proc
either doesn't exist (on OpenBSD) or is mostly obsolete (on FreeBSD and NetBSD).syslogd(8)
reads kernel messages from the character device/dev/klog
, anddmesg(1)
uses/dev/kmem
to decode kernel names. Only OpenBSD has a/dev/log
. FreeBSD uses two UNIX domain sockets/var/run/log
andvar/rub/logpriv
instead, and NetBSD has a/var/run/log
.