Linux Kernel Logging Concepts

Introduction

The Linux kernel log is one of the most important diagnostic tools in Linux development and system troubleshooting. Understanding the kernel log is therefore essential. Before exploring how the kernel logging mechanism works, it is important to understand its core component, which is the printk() function.

PrintK()

printk() is the Linux kernel’s printing function, it is similar to the user-space printf() function, but not fully compatible with it. For example, The printk() doesn't support floating-point formats such as (%f,%e,%g) because floating-point operations are generally avoided in kernel code. At the same time, printk() provides several kernel-specific format specifiers, like extended %p forms to %pS and %pe, for printing information such as symbol names and error-pointer values. For more information about the format specifiers supported by printk(), see the Linux kernel documentation.

Messages produced by printk() are written to the kernel ring buffer, commonly referred to as the kernel log. This kernel log can be viewed and managed using the dmesg command.

Examples:

$ dmesg                    # Display all messages from the kernel ring buffer
$ dmesg | tail -1          # Display the most recent kernel log message
$ dmesg | head -2          # Display the first two kernel log messages
$ dmesg | grep 'xyz'       # Display kernel log messages containing "xyz"

Priority of kernel log messages

The Linux kernel provides a useful logging priority mechanism based on levels. These log levels allow us to control the priority of messages produced by printk(). There are eight kernel log levels (0 to 7), where a lower number indicates a higher priority. These log levels are defined as C macros in the kern_levels.h In most cases, the default printk() log level is set to 4, corresponding to the warning level. Please note that if no log level is specified in printk(), the message is automatically assigned the default log level.

Example of assigning a log level (INFO) to a message. Note that there is no comma between the log level and the log message.

printk(KERN_INFO"Info Message...\n"); 

Kernel Log Levels and Console Output

Every kernel message is stored in the kernel ring buffer. To determine whether a message should also appear on the console, its log level is compared with the current console log level. The message is printed to the console only when its log-level value is lower than the console log level.

                  printk() message
                         |
                         v
           Stored in the kernel ring buffer
                         |
                         v
       Is message log level < console log level?
                    /             \
                  Yes             No
                   |               |
                   v               v
        Printed to the        Not printed to the
        console               console, but still
                              available through dmesg

For example, when the console log level is set to 7:

Message levels 0-6  -> Printed to the console
Message level 7     -> Kept in the kernel ring buffer only

The initial console log level is configured through the CONFIG_CONSOLE_LOGLEVEL_DEFAULT kernel configuration option and is commonly set to 7. It can be modified through the kernel menuconfig interface or changed at runtime through /proc/sys/kernel/printk.

$ cat /proc/sys/kernel/printk        # Display the printk log-level settings
$ echo 4 > /proc/sys/kernel/printk   # Set the console log level to 4

The output of cat normally contains four values:

console_loglevel | default_message_loglevel | minimum_console_loglevel | default_console_loglevel

The pr_*() Logging Macros

Instead of calling printk() with an explicit log-level macro, the kernel provides pr_*() for the different log levels. For example, pr_info("xyz") is equivalent to printk(KERN_INFO"xyz"). These wrappers make logging statements shorter and easier to read.

For example:

pr_info("Module loaded successfully\n");
pr_warn("A warning occurred\n");
pr_err("An error occurred\n");

Conclusion

Every log message is stored in the kernel ring buffer. Its log level determines whether the message is printed immediately to the console or kept in the kernel log for later inspection using the dmesg command. As discussed earlier, the Linux kernel also provides ready-to-use macros for the different log levels, So, there is no need to manually specify the log level each time we need to print a log message.

Understanding this logging mechanism also makes it easier to understand the Zephyr RTOS logging system, since both use similar concepts such as log levels, priorities, and predefined logging macros.

Sources

• Linux kernel source code
• Message logging with printk() — Linux kernel documentation
• printk() format specifiers — Linux kernel documentation
• printk() versus printf() — GeeksforGeeks