Dmesg and Linux kernel log

Revision as of 15:31, 24 June 2024 by Registered User
(diff) ← Older revision | Latest revision (diff) | Newer revision → (diff)
Applicable for STM32MP13x lines, STM32MP15x lines, STM32MP25x lines

1. Article purpose[edit source]

The purpose of this article is to provide information about the Linux® kernel log including configuration, and to detail usage of dmesg command.

2. Introduction[edit source]

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

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. See [1] for detail.

dmesg is a shell command on the kernel console, which also displays the content of the ring buffer, with filter or not (default).

3. printk function[edit source]

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");

See elinux.org[2] for reference. This information will be sent to the console, and also stored in a ring buffer.

You can also check to the printk-format.txt[3] document provided in the Linux kernel package to get detail about syntax and formatting.

4. Linux kernel ring buffer[edit source]

The Linux kernel also manages a ring buffer to store log and trace messages.

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

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
 Location:
   -> General setup
     -> Kernel log buffer size (16 => 64KB, 17 => 128KB)
  • Or modify kernel arguments[4] 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 (see dmesg).

5. Loglevels[edit source]

As reference, see elinux.org[5].

The log level is used by the kernel to determine the importance of a message and to decide whether it should be presented to the user immediately, by printing it to the current console.

For this, the kernel compares the log level of the message to the console_loglevel (a kernel variable) and if the priority is higher (i.e. a lower value) than the console_loglevel, the message will be printed to the current console. As example, if console_loglevel=5, all messages with log level 0 to 4 will be displayed.

Note that all messages with loglevel lower or equal to KERN_INFO level are stored in the ring buffer.

5.1. loglevels values[edit source]

"Loglevels table"
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_warning dev_warn
KERN_NOTICE "5" 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" Debug messages pr_debug, pr_devel if DEBUG is defined dev_dbg

Important: note that Higher priority message is loglevel 0

5.2. Set loglevel filter value for console[edit source]

5.2.1. Default values[edit source]

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

cat /proc/sys/kernel/printk
7       4           1       7
current default_msg minimum default_console

The first integer shows you the current console_loglevel; the second the default log level, see Use loglevel in the kernel source for log and trace.

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

5.2.2. Using kernel command-line[edit source]

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

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.

Note: The command-line is set in one of several extlinux configuration files located in the bootfs partition. The used configuration file path is dependent of the boot device and the board type. For simplicity, you can retrieve the file parsed at boot time from the console once U-Boot takes over the boot sequence. As example :

 Boot over mmc0!
 Saving Environment to MMC... Writing to redundant MMC(0)... OK
 switch to partitions #0, OK
 mmc0 is current device
 Scanning mmc 0:8...
 Found U-Boot script /boot.scr.uimg
 4187 bytes read in 7 ms (584 KiB/s)
 ## Executing script at c6100000
 Executing SCRIPT on target=mmc0
 FOUND /mmc0_extlinux/stm32mp135f-dk_extlinux.conf
 [...]
 Starting kernel ...

Two ways to add this loglevel command-line parameter (as example with stm32mp135f-dk_extlinux.conf):

  • If using SD card, this is possible to edit the file on host PC:
Insert SD card on host PC
Check for mounting boot partition (i.e. /media/$USER/bootfs)
Open the appropriate extlinux configuration file for edition
cd /media/$USER/bootfs/mmc0_extlinux/
gedit stm32mp135f-dk_extlinux.conf
Add loglevel=8 at the end of APPEND line
Save and insert SD card on the board
  • If using SD Card or eMMC, this is possible to edit the file directly on the board side:
When software is boot
Mount boot partition if not already done
mount /dev/mmcblk0p4 /boot
Update the kernel command line
cd /boot
cd mmc0_extlinux # (or mmc1_extlinux if booting from eMMC)
vi stm32mp135f-dk_extlinux.conf
Modify the extlinux configuration file to add loglevel=8 at the end of APPEND line
Save and reboot the board

5.2.3. Using sysfs in runtime[edit source]

To change your current console_loglevel simply write to this file:

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

or using dmesg command.

As example:

echo 8 > /proc/sys/kernel/printk         # Temporary increase loglevel to display messages up to loglevel 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.

5.2.4. Using menuconfig before compilation[edit source]

As values are defined first at compilation step, this is also possible to set them (CONFIG_CONSOLE_LOGLEVEL_DEFAULT and CONFIG_MESSAGE_LOGLEVEL_DEFAULT) using the Linux kernel Menuconfig tool (Menuconfig or how to configure kernel):

Symbol: CONSOLE_LOGLEVEL_DEFAULT [=7]
Location:
  -> Kernel hacking
    -> printk and dmesg options
      (7) Default console loglevel (1-15)

Symbol: MESSAGE_LOGLEVEL_DEFAULT [=4]
Location:
  -> Kernel hacking
    -> printk and dmesg options
      (4) Default message log level (1-7)

5.3. Use loglevel in kernel source for log and trace[edit source]

5.3.1. Using printk[edit source]

A loglevel information can be added in the printk function call, with the following syntax.

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

When not present, default loglevel value is given by CONFIG_MESSAGE_LOGLEVEL_DEFAULT (usually "4"=KERN_WARNING)

5.3.2. Using dedicated functions[edit source]

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_ functions are taken one more parameter to provide more information about current device or driver where message is coming from.

  • Example for pr_info
pr_info("%s%s%s at %s (irq = %d, base_baud = %d) is a %s\n",
        port->dev ? dev_name(port->dev) : "",
        port->dev ? ": " : "",
        port->name,
        address, port->irq, port->uartclk / 16, uart_type(port));

will display information below:

[ 0.919488] 40010000.serial: ttySTM0 at MMIO 0x40010000 (irq = 41, base_baud = 6046875) is a stm32-usart
  • Example for dev_info
dev_info(&pdev->dev, "interrupt mode used for rx (no dma)\n");

will display information below, including device reference automatically:

[    1.046700] stm32-usart 40010000.serial: interrupt mode used for rx (no dma)

6. earlycon for STM32 Arm® Cortex® MPUs More info.png[edit source]

earlycon is a Linux kernel debug feature useful to get traces for kernel issues which happen before the normal console is initialized.

It is available on for both STM32MP1 series (AArch processors type - 32 bits) and STM32MP2 series (AArch64 processors type - 64 bits).

6.1. Linux kernel configuration[edit source]

Linux kernel config SERIAL_EARLY_CON is enable by default:

Symbol: SERIAL_EARLYCON [=y]
Type    : bool
Defined at drivers/tty/serial/Kconfig:9
      Depends on: TTY [=y] && HAS_IOMEM [=y] && SERIAL_CORE [=y]
Selected by [y]:
      ...
      - SERIAL_STM32_CONSOLE [=y] && TTY [=y] && HAS_IOMEM [=y] && SERIAL_STM32 [=y]
      ...
Selected by [n]:
      ...

6.2. Serial port configuration[edit source]

The serial port configuration is done via the stdout-path setting from the devide tree source file.

6.3. Linux kernel boot command configuration[edit source]

The Linux kernel boot command must contain the command-line parameter earlycon (for details, refer to kernel-parameter documentation).

For instance, the kernel bootargs can be modified in the following ways:

  • Mount a boot partition from the Linux kernel console, and then update the extlinux configuration file using the vi editor (see man page[6], or introduction page[7] ).
For example:
mount /dev/mmcblk0p8 /boot
vi /boot/mmc0_extlinux/stm32mp135f-dk_extlinux.conf

or

To mount partitions (mmc 0:microSD card / mmc 1: eMMC):

- Press any key to stop at U-Boot execution when booting the board.
...
Hit any key to stop autoboot:  0
STM32MP>
- Then
STM32MP> ums 0 mmc 0
- Check for the boot partition mounted on your host PC (/media/$USER/bootfs)
- Edit the extlinux configuration file corresponding to your setup (as example: /media/$USER/bootfs/mmc0_extlinux/stm32mp135f-dk_extlinux.conf)
  • Update the kernel command line by adding the earlycon parameter:
root=PARTUUID=e91c4e10-16e6-4c0e-bd0e-77becf4a3582 rootwait rw earlycon console=ttySTM0,115200

Save and quit file update, and then reboot the board.

Warning white.png Warning
In some cases, to avoid clocking issue during debug with earlycon, which cause the console display to stop, we recommend to also add ignore_clk_unused in kernel command line

6.4. Get trace[edit source]

Earlycon traces are pushed automatically to the serial console defined as seen previously, and also added to the kernel ring log buffer.

7. dmesg command[edit source]

As reference, see man page[8].

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

  • It is possible to filter messages following the loglevels:
dmesg -n <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 
In that case, every kernel messages will appear on your console, as all priority higher than 8 (lower loglevel values) will be displayed.
  • 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

8. /var/log/messages file system entry[edit source]

An other way to display the content of the Linux kernel log is to look at the content of the file /var/log/messages.

It contains general system activity messages from the start-up. It also provides useful information about origin of the message, and log level.

9. Dynamic debug message[edit source]

These messages are using the loglevel 7 (KERN_DEBUG).

Refer to How to use the kernel dynamic debug article.

10. References[edit source]