The Logging Mechanism in Linux

1. Overview

Log files provide a timeline of events for our Linux system and its applications. Logs are very helpful in troubleshooting to pinpoint issues by examining warning and error messages. Other uses of logs are to identify security incidents, diagnose performance issues, and for compliance and auditing.

In this tutorial, we’ll explore kernel space as well as user space logging. We’ll see how logs are collected and stored, and which daemons are used for that. Moreover, we’ll discuss the utilities to read the log files.

2. Kernel Space Logging

In Linux, the kernel utilizes a ring buffer to store log messages starting from the system boot process. This buffer is of fixed size, and once it gets full, new messages will overwrite older messages. All the messages from the kernel code are stored in this ring buffer through the printk() function. Later, messages from the kernel ring buffer are stored in log files on the system’s permanent storage. Kernel configuration option CONFIG_PRINTK enables kernel space logging through printk(). If it is not set, the kernel system calls return the ENOSYS error.

2.1. Kernel Log Levels

Like the printf() function in user space, kernel logging is done using the printk() (also called print kernel) function. Same as printf(), a string is used to define text accompanied by a variable set of arguments. The format of a printk function is:

int printk( const char ∗ fmt, ... );

However, unlike printf(), printk() messages can specify log levels to define the severity of the particular message. Depending on the log level, the kernel decides whether to show the message immediately on the console. The below table shows the available log levels and their usage:

The typical usage of printk() is:

printk(KERN_INFO "Message: %s\n", arg);

If we don’t provide any log level, then a default KERN_WARNING level is used, and log messages with KERN_WARNING and higher priorities will be logged.

2.2. Reading Kernel Ring Buffer

All the printk() messages are printed to the kernel ring buffer. As everything in Linux is a file, this ring buffer is also a character device file which we can find under the /dev directory named kmsg. The kmsg device is an abstraction for the kernel ring buffer to read and write to it. The dmesg Linux command is used to control or print the kernel ring buffer to the standard output on the console.

When we use the dmesg command, it interacts with the /dev/kmsg file to display the content of the kernel buffer. Root access is required to execute the dmesg command.

# dmesg
[ 0.000000] microcode: microcode updated early to revision 0x21, date = 2019-02-13
[ 0.000000] Initializing cgroup subsys cpuset
[ 0.000000] Initializing cgroup subsys cpu
[ 0.000000] Initializing cgroup subsys cpuacct
[ 0.000000] Linux version 3.10.0-1160.31.1.el7.x86_64 ([email protected]) (gcc version 4.8.5 20150623 (Red Hat 4.8.5-44) (GCC) ) #1 SMP Thu Jun 10 13:32:12 UTC 2021
[ 0.000000] Command line: BOOT_IMAGE=/vmlinuz-3.10.0-1160.31.1.el7.x86_64 root=/dev/mapper/centos-root ro crashkernel=auto rd.lvm.lv=centos/root rd.lvm.lv=centos/swap rhgb quiet LANG=en_US.UTF-8
[ 0.000000] e820: BIOS-provided physical RAM map:
[ 0.000000] BIOS-e820: [mem 0x0000000000000000-0x000000000009d7ff] usable
[ 0.000000] BIOS-e820: [mem 0x000000000009d800-0x000000000009ffff] reserved
[ 0.000000] BIOS-e820: [mem 0x00000000000e0000-0x00000000000fffff] reserved
...

3. User Space Logging

User space logging is based on the syslog protocol. Syslog is a message logging standard, and each log message is labeled with a syslog prefix that indicates facility and priority level.

When operating over a network, syslog follows a client-server architecture. Here, there are three main components of the syslog architecture, called originator, relay, and collector. An originator, also known as a syslog client, creates and sends messages over the network. A relay forwards messages over the network. Lastly, a collector, also known as a syslog server, receives and stores the messages.

In the case of a standalone Linux system, the machine itself acts as a syslog client-server: it generates logs, and logs are collected by rsyslog and stored on the filesystem.

3.1. Syslog Facilities

In our Linux system, many different programs may generate logs. Therefore, facilities are defined by the syslog protocol and determine where in the system or which program has originated a log message.

3.2. Syslog Priorities

Syslog priorities indicate the severity of the message. It ranges from 0 to 7, 0 being the most critical level.

4. Linux Log Files

Log files are controlled by a daemon. In older Linux distributions, syslogd was responsible for gathering logs. In recent distributions, it was replaced by the rsyslogd daemon. rsyslogd is an enhanced replacement for syslogd. It provides extended filtering, various configuration options, encryption-protected relaying of messages, input and output modules, and support for transportation via the TCP or UDP protocols. Moreover, rsyslog is backward compatible with syslogd.

Other than rsyslog, log files can also be managed by the journal daemon – systemd-journal (a component of systemd). The journald daemon captures syslog messages, kernel log messages, initial RAM disk, and early boot messages, as well as messages written to standard output and standard error output of all services, indexes them, and makes this available to the user.

The main difference between rsyslog and systemd-journal is that log files produced by journald are, by default, not persistent. Log files are stored only in memory or a small ring buffer in the /run/log/journal/ directory. However, rsyslog will persist logs into the log files available at /var/log.

5. Monitoring a Log File

The systemd-journal logs are stored as binary files in the /run/log/journal directory. We can inspect these logs using the journalctl command:

$ journalctl
-- Logs begin at Fri 2016-07-15 13:47:49 IST, end at Mon 2030-08-26 16:23:33 IST. --
Jul 15 13:47:49 linux-d2jt systemd-journal[464]: Runtime journal is using 4.5M (max allowed 36.3M, trying
Jul 15 13:47:49 linux-d2jt systemd-journal[464]: Runtime journal is using 4.5M (max allowed 36.3M, trying
Jul 15 13:47:49 linux-d2jt kernel: Initializing cgroup subsys cpuset
Jul 15 13:47:49 linux-d2jt kernel: Initializing cgroup subsys cpu
Jul 15 13:47:49 linux-d2jt kernel: Initializing cgroup subsys cpuacct
Jul 15 13:47:49 linux-d2jt kernel: Linux version 3.16.6-2-desktop (geeko@buildhost) (gcc version 4.8.3 20
Jul 15 13:47:49 linux-d2jt kernel: Command line: BOOT_IMAGE=/boot/vmlinuz-3.16.6-2-desktop root=UUID=05fa
Jul 15 13:47:49 linux-d2jt kernel: Disabled fast string operations
Jul 15 13:47:49 linux-d2jt kernel: e820: BIOS-provided physical RAM map:
Jul 15 13:47:49 linux-d2jt kernel: BIOS-e820: [mem 0x0000000000000000-0x000000000009ebff] usable
...

To view the latest entries, we can use -r (reverse option):

$ journalctl -r
-- Logs begin at Fri 2016-07-15 13:47:49 IST, end at Mon 2030-08-26 16:23:33 IST. --
Aug 26 16:23:33 linux-d2jt wickedd[1198]: route ipv4 0.0.0.0/0 via 172.16.38.2 dev eno16777736 type unica
Aug 26 16:23:33 linux-d2jt wickedd[1198]: eno16777736: Notified neighbours about IP address 172.16.38.137
Aug 26 16:23:33 linux-d2jt wickedd[1198]: eno16777736: address 172.16.38.137 covered by a dhcp lease
Aug 26 16:23:33 linux-d2jt wickedd-dhcp4[1195]: eno16777736: Committed DHCPv4 lease with address 172.16.3
Aug 26 16:23:15 linux-d2jt PackageKit[4249]: uid 1000 obtained auth
Aug 26 16:23:15 linux-d2jt PackageKit[4249]: uid 1000 is trying to obtain org.freedesktop.packagekit.syst
Aug 26 16:23:15 linux-d2jt dbus[1087]: [system] Successfully activated service 'org.freedesktop.PackageKi
Aug 26 16:23:15 linux-d2jt PackageKit[4249]: daemon start
...

Moreover, to view logs for the specific service, we can use the -u option with the service name:

$ journalctl -u bluetooth.service 
-- Logs begin at Fri 2016-07-15 13:47:49 IST, end at Mon 2030-08-26 16:23:33 IST. --
Jul 15 13:48:37 linux-d2jt bluetoothd[2335]: Bluetooth daemon 5.23
Jul 15 13:48:38 linux-d2jt bluetoothd[2335]: Starting SDP server
Jul 15 13:48:38 linux-d2jt bluetoothd[2335]: Bluetooth management interface 1.6 initialized
Jul 15 15:00:47 linux-d2jt bluetoothd[2335]: Terminating
Jul 15 15:00:47 linux-d2jt bluetoothd[2335]: Stopping SDP server
Jul 15 15:00:47 linux-d2jt bluetoothd[2335]: Exit
...

Most Linux log files are located under the /var/log directory and subdirectories:

$ ls /var/log
alternatives.log  btmp     journal  ntp README        wpa_supplicant.log  
apparmor          cups     kdm.log  pbl.log           samba               
audit             faillog  krb5     pk_backend_zypp   snapper.log         
boot.log          hp       lastlog  pk_backend_zypp-1 tuned Xorg.0.log.old

There are a couple of commands we can use to view log files. For instance, less, more, cat, tail, etc. The tail command is more popular, which prints the last 10 lines of a file to standard output. Using the tail command with the -f option prints logs as the file grows:

$ tail -f boot.log
[ OK ] Reached target Login Prompts.
Starting /etc/init.d/after.local Compatibility...
[ OK ] Started /etc/init.d/after.local Compatibility.
Starting X Display Manager...
[ OK ] Started Login Service.
Starting Locale Service...
[ OK ] Started Locale Service.
[ OK ] Started Authorization Manager.
[ OK ] Started Modem Manager.
[ OK ] Started X Display Manager.
...

6. Conclusion

In this article, we saw how kernel messages are logged with the printk() function to the kernel ring buffer and how to inspect them. We also explored user space logging with the syslog protocol. Then, we discussed rsyslogd and systemd-journal daemons, which control logs. Lastly, we learned how we can read log files generated by them using different commands.