GNU/Linux - Kernel Logging

The Logging Mechanism in Linux

日志文件提供了 Linux 系统及其应用程序的事件时间表。日志对故障排除很有帮助，可以通过检查警告和错误信息找出问题所在。日志的其他用途还包括识别安全事件、诊断性能问题以及合规性和审计。

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.

日志包括内核空间和用户空间两种。这里我们将介绍内核日志。

There are kernel space and user space logging. Here we are going to introduce the kernel logging.

Kernel Space Logging /  内核空间日志

Linux 内核可以打印日志和跟踪信息，这些信息默认存储在环形缓冲区中。

在 Linux 中，内核利用环形缓冲区存储从系统启动进程开始的日志信息。该缓冲区大小固定，一旦满了，新信息就会覆盖旧信息。内核代码的所有信息都通过 printk() 函数存储在这个环形缓冲区中。随后，内核环形缓冲区中的信息会存储到系统永久存储的日志文件中。内核配置选项 CONFIG_PRINTK 可以通过 printk() 启用内核空间日志。如果未设置该选项，内核系统调用将返回 ENOSYS 错误。

同样的信息也可以通过过滤后使用串行端口在 uart/console 上显示。这可以通过内核命令行中的 "console "参数来定义。

Linux kernel is able to print log and trace messages, which are by default stored in a ring buffer.

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.

The same messages can also be displayed, applying filter, on uart/console using serial port. This is defined in the kernel command-line, with the "console" parameter.

1 What is the kernel ring buffer

在启动过程中，控制台提供了大量有关系统启动初始阶段的重要信息。为了避免丢失早期信息，内核使用了所谓的环形缓冲区。该缓冲区存储内核代码中 printk() 函数生成的所有信息，包括启动信息。内核环形缓冲区中的信息会被读取并存储到永久存储的日志文件中，例如由 syslog 服务读取。

上述缓冲区是一个循环数据结构，大小固定，并被硬编码到内核中。用户可以通过 dmesg（diagnostic messages） 命令或 /var/log/boot.log 文件显示内核环形缓冲区中存储的数据。当环形缓冲区满时，新数据会覆盖旧数据。

During the boot process, the console provides a lot of important information about the initial phase of the system startup. To avoid loss of the early messages the kernel utilizes what is called a ring buffer. This buffer stores all messages, including boot messages, generated by the printk() function within the kernel code. The messages from the kernel ring buffer are then read and stored in log files on permanent storage, for example, by the syslog service.

The buffer mentioned above is a cyclic data structure which has a fixed size, and is hard-coded into the kernel. Users can display data stored in the kernel ring buffer through the dmesg command or the /var/log/boot.log file. When the ring buffer is full, the new data overwrites the old.

缓冲区的大小不能在运行时修改，默认值为 2^CONFIG_LOG_BUF_SHIFT 字节。

The size of the buffer cannot be modified in runtime, and its default size value is 2^CONFIG_LOG_BUF_SHIFT bytes.

要更改它，有 3 种可能的方法：

* 修改 defconfig 文件中的 CONFIG_LOG_BUF_SHIFT 值或使用配置片段文件：

To change it, there are 3 possibles ways:

* Modify CONFIG_LOG_BUF_SHIFT value in defconfig file or use the config fragment file:

In example for 64K : CONFIG_LOG_BUF_SHIFT=16

* 或使用 Linux 内核 menuconfig 更新

* or use the Linux kernel menuconfig update

Location:

   -> General setup

     -> Kernel log buffer size (16 => 64KB, 17 => 128KB)

* 或在内核命令行中修改内核参数（通过设备树中的 bootargs 值，或直接在 extlinux uboot 配置文件中）。

* Or modify kernel arguments in kernel command-line (via bootargs value in device tree, or directly in extlinux uboot config file)

bootargs = "root=/dev/mmcblk0p5 rootwait rw console=ttySTM0,115200 log_buf_len=65536";

This ring buffer can be displayed using dmesg command

2 printk function

要从内核代码中获取一些调试信息，最简单的方法就是使用内核中的 printf 等效函数--printk 函数及其派生函数--打印出各种信息。

The simplest way to get some debug information from the kernel code is by printing out various information with the kernel's equivalent of printf - the printk function and its derivatives.

printk("My Debugger is Printk\n");

这些信息将被发送到控制台，并存储在环形缓冲区中。

与用户空间的 printf() 函数一样，内核日志记录也是通过 printk() 函数（也称为 print kernel）完成的。与 printf() 函数一样，使用一个字符串来定义文本，并附带一组可变参数。printk 函数的格式如下:

This information will be sent to the console, and also stored in a ring buffer.

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

3 Role of printk on log-levels and kernel logging /  printk 对日志级别和内核日志记录的作用

与 printf() 不同，printk() 消息可以指定日志级别，以定义特定消息的严重性。内核会根据日志级别决定是否立即在控制台上显示消息。

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.

内核报告的每条信息都有一个日志级别，该级别定义了信息的重要性。正如 "什么是内核环形缓冲区 "一文所述，内核环形缓冲区收集所有日志级别的内核信息。kernel.printk 参数定义了将缓冲区中的哪些信息打印到控制台。

Each message the kernel reports has a log-level associated with it that defines the importance of the message. The kernel ring buffer, as described in What is the kernel ring buffer, collects kernel messages of all log-levels. It is the kernel.printk parameter that defines what messages from the buffer are printed to the console.

下表列出了可用的日志级别及其用途：

The below table shows the available log levels and their usage:

Name	String	Meaning	alias functions	dev alias function
KERN_EMERG	"0"	Emergency messages, system is about to crash or is unstable	pr_emerg	dev_emerg
KERN_ALERT	"1"	Something bad happened and action must be taken immediately	pr_alert	dev_alert
KERN_CRIT	"2"	A critical condition occurred like a serious hardware/software failure	pr_crit	dev_crit
KERN_ERR	"3"	An error condition, often used by drivers to indicate difficulties with the hardware	pr_err	dev_err
KERN_WARNING	"4"	A warning, meaning nothing serious by itself but might indicate problems	pr_warn	dev_warn
KERN_NOTICE	"5"	Kernel notice of a normal but significant condition. Nothing serious, but notably nevertheless. Often used to report security events.	pr_notice	dev_notice
KERN_INFO	"6"	Informational message e.g. startup information at driver initialization	pr_info	dev_info
KERN_DEBUG	"7"	Kernel debug-level messages.	pr_debug, pr_devel if DEBUG is defined	dev_dbg
KERN_DEFAULT		Default kernel logging level
KERN_CONT		Continuation of a log line	pr_cont

重要：请注意，较高优先级的报文日志级别为 0

Important: note that Higher priority message is loglevel 0

printk() 的典型用法是

The typical usage of printk() is:

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

要确定目标机上当前的 console_logle 级别，可以使用以下命令进行验证：

To determine your current console_loglevel on the target you can verifiy with the following command:

# sysctl kernel.printk

kernel.printk = 7       4       1       7

$ sudo sysctl kernel.printk=2

kernel.printk = 2

$ sudo sysctl kernel.printk

kernel.printk = 2    4    1    7

$ cat /proc/sys/kernel/printk

7       4           1       7

current default_msg minimum default_console

默认情况下，kernel.printk 包含上述四个值。

And by default, kernel.printk contains the above four values.

这是在编译时定义的：

This is defined at compilation:

- Current console loglevel via CONFIG_CONSOLE_LOGLEVEL_DEFAULT=7 (defined in file lib/Kconfig.debug)

- Default message loglevel via CONFIG_MESSAGE_LOGLEVEL_DEFAULT=4 (defined in file lib/Kconfig.debug)

- Minimum console loglevel via #define CONSOLE_LOGLEVEL_MIN 1 (defined in file include/linux/printk.h)

- Default console loglevel is equal to CONFIG_CONSOLE_LOGLEVEL_DEFAULT

printk 中的四个值分别表示：console_loglevel、default_message_oglelvel、minimum_console_loglevel 和 default_console_loglevel。

这些值影响 printk() 在打印或记录错误信息时的行为。有关不同日志级别的更多信息，请参阅 man 2 syslog。

The four values in printk denote: console_loglevel, default_message_loglevel, minimum_console_loglevel and default_console_loglevel respectively.

These values influence printk() behavior when printing or logging error messages. See man 2 syslog for more info on the different loglevels.

这四个值依次定义如下：

1. 控制台日志级别，定义打印到控制台的信息的最低优先级。

2. 默认日志级别，用于没有明确日志级别的信息。

3. 为控制台日志级别设置可能的最低日志级别配置。

4. 设置启动时控制台日志级别的默认值。

The four values define the following, in order:

1. Console log-level, defines the lowest priority of messages printed to the console.

2. Default log-level for messages without an explicit log-level attached to them.

3. Sets the lowest possible log-level configuration for the console log-level.

4. Sets default value for the console log-level at boot time.

* console_loglelevel：优先级高于此值的消息将被打印到控制台

* default_message_loglevel：没有明确优先级的消息将以该优先级打印

* minimum_console_loglevel：可设置的 console_loglevel 的最小（最高）值

* default_console_loglevel：控制台级别的默认值

* console_loglevel: messages with a higher priority than this will be printed to the console

* default_message_loglevel: messages without an explicit priority will be printed with this priority

* minimum_console_loglevel: minimum (highest) value to which console_loglevel can be set

* default_console_loglevel: default value for console_loglevel

如果想使用与 CONFIG_CONSOLE_LOGLEVEL_DEFAULT 指定值不同的值，也可以通过内核命令行参数设置控制台日志级别。

例如：

The console loglevel can be also set via a kernel command-line parameter if you want to use a different value than one specified by CONFIG_CONSOLE_LOGLEVEL_DEFAULT.

For example:

root=/dev/mmcblk0p5 rootwait rw console=ttySTM0,115200 loglevel=4

在这种情况下，控制台只会显示优先级高于 KERN_WARNING 的信息（即 < 4，KERN_EMERG 至 KERN_ERR ）。

In that case only messages with a higher priority than KERN_WARNING (means < 4, KERN_EMERG to KERN_ERR ) will be displayed on the console.

3.1 Using sysfs in runtime /  在运行时使用 sysfs

要更改当前的 console_logle 级别，只需写入该文件即可：

To change your current console_loglevel simply write to this file:

$ echo <loglevel> > /proc/sys/kernel/printk

或使用dmesg命令参数里指定level。

or using dmesg command.

例如：

As example:

$ echo 8 > /proc/sys/kernel/printk         # Temporary increase loglevel to display messages up to loglevel 8

在这种情况下，所有内核信息都会显示在控制台上，因为所有优先级高于 8（日志级别较低）的信息都会显示。

请注意，重启后，该配置将被重置。

In that case, every kernel messages will appear on your console, as all priority higher than 8 (lower loglevel values) will be displayed.

Note that after reboot, this configuration is reset.

3.2 Using menuconfig before compilation /  在编译前使用 menuconfig

由于值是在编译时首先定义的，因此也可以使用 Linux 内核 Menuconfig 工具设置 CONFIG_MESSAGE_LOGLEVEL_DEFAULT）。

As values are defined first at compilation step, this is also possible to set CONFIG_MESSAGE_LOGLEVEL_DEFAULT) using the Linux kernel Menuconfig tool.

Symbol: MESSAGE_LOGLEVEL_DEFAULT [=4]

Location:

  -> Kernel hacking

    -> printk and dmesg options

      (4) Default message log level (1-7)

Symbol: MESSAGE_LOGLEVEL_DEFAULT [=4]                                                                                                                                                                   │  

  │ Type  : integer                                                                                                                                                                                     │  

  │ Range : [1 7]                                                                                                                                                                                       │  

  │ Prompt: Default message log level (1-7)                                                                                                                                                             │  

  │   Location:                                                                                                                                                                                         │  

  │     -> Kernel hacking                                                                                                                                                                               │  

  │ (1)   -> printk and dmesg options                                                                                                                                                                   │  

  │   Defined at lib/Kconfig.debug:18    

3.3 Using dedicated functions /  使用专用函数

在上面的日志级别表中，有一些别名函数 pr_ 和 dev_。

定义这些函数的目的是为了替换其中的 printk + loglevel 信息，以简化语法。

In the loglevels table above, there are some alias functions pr_ and dev_.

These functions are defined to replace printk + loglevel info inside, in order to simplify syntax.

pr_err("something went wrong, return code: %d\n",ret);

dev_ 函数多了一个参数，可提供更多有关当前设备或驱动程序的信息，信息就来自于这些设备或驱动程序。

dev_ functions are taken one more parameter to provide more information about current device or driver where message is coming from.

4 Reading Kernel Ring Buffer

所有 printk() 消息都会打印到内核环形缓冲区中。由于 Linux 中的所有东西都是文件，因此这个环形缓冲区也是一个字符设备文件，我们可以在 /dev 目录下找到它，名为 kmsg。kmsg 设备是内核环形缓冲区读写的抽象设备。dmesg Linux 命令用于控制内核环形缓冲区或将其打印到控制台的标准输出上。

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.

4.1 dmesg command / diagnostic message

使用 dmesg 命令可以显示内核环形缓冲区。它将在控制台上显示环形缓冲区的所有内容。

使用 dmesg 命令时，它会与 /dev/kmsg 文件交互，显示内核缓冲区的内容。执行 dmesg 命令需要 root 访问权限。

The Kernel ring buffer can be displayed using dmesg command. It will display on the console all the content of the ring buffer.

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 (mockbuild@kbuilder.bsys.centos.org) (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

...

可以按照日志级别过滤信息：

It is possible to filter messages following the loglevels:

dmesg -n <loglevel>

在这种情况下，只有值小于（不等于）console_loglevel 的信息才会被打印。

这里，<loglevel> 可以是数值，也可以是字符串：

In that case, only messages with a value lower (not lower equal) than the console_loglevel will be printed.

Here, <loglevel> can be a numeric value, but also a string:

Supported log levels (priorities):

  emerg (0)

  alert (1)

   crit (2)

    err (3)

   warn (4)

notice (5)

   info (6)

  debug (7)

As example:

dmesg -n 8         # Temporary change loglevel to display messages up to debug level

or

dmesg -n debug

在这种情况下，所有内核信息都会显示在控制台上，因为所有优先级高于 8（日志级别较低）的信息都会显示出来。

In that case, every kernel messages will appear on your console, as all priority higher than 8 (lower loglevel values) will be displayed.

可以清除 dmesg 缓冲区：

It is possible to clear the dmesg buffer:

dmesg -c        # Display the full content of dmesg ring buffer, and then clear it

dmesg -C        # Clear the dmesg ring buffer

参考：

1, StackOverflow

linux - Description of kernel.printk values - Unix & Linux Stack Exchange

2，Baeldung

https://www.baeldung.com/linux/logging-mechanism

3, Redhat

Chapter 13. Getting started with kernel logging | Red Hat Product Documentation

4, ST

Dmesg and Linux kernel log - stm32mpu