Use ramoops for logging under Linux
Unfortunately, an embedded system is not free of crashes. To analyze and log such crashes it is useful to have a file system where we can store such information between reboots. One interface which is meant to do that is pstore and its current single implementation ramoops. Ramoops can store log messages inside a reserved memory area in RAM. The nice thing about RAM is, that it should almost always be available when the CPU is still running. Flash memory on the other hand could not be available because e.g. the eMMC or NAND flash driver crashed. Further, by using RAM instead of flash memory we can write faster and don't fill our persistent memory. The disadvantage of storing information in RAM is that the information will not survive a power cycle.
For this article an Apalis iMX8QM from Toradex was used with Reference Multimedia Image 5.1.0.
Ramoops
The ramoops driver allows us to store kernel oopses, the kernel console output and user messages in a reserved memory region inside RAM. In normal hardware designs RAM will not power off when we just do a reboot and therefore the data will survive a restart. By defining a reserved memory region the kernel will not touch this memory area and therefore not overwrite data stored there. We have to find a free memory region in RAM which we can use. For this we read /proc/iommem on the device.
root@apalis-imx8:~$ cat /proc/iomem
....
80200000-83ffffff : System RAM
80280000-8161ffff : Kernel code
81620000-8188ffff : reserved
81890000-81a85fff : Kernel data
86400000-87ffffff : System RAM
90000000-901fffff : System RAM
90500000-91ffffff : System RAM
94c00000-94ffffff : System RAM
95400000-ffffffff : System RAM
96000000-d1ffffff : reserved
f9603000-fd62afff : reserved
880000000-8ffffffff : System RAM
8fae00000-8fb5fffff : reserved
8fb7fe000-8ff5fffff : reserved
8ff6db000-8ff73afff : reserved
8ff73b000-8ff73bfff : reserved
8ff73c000-8ff7cbfff : reserved
8ff7ce000-8ff7cefff : reserved
8ff7cf000-8ff7d3fff : reserved
8ff7d4000-8ff7d4fff : reserved
8ff7d5000-8ffffffff : reservedWe see that there are other memory regions marked as reserved. This regions are used e.g. for interprocessor communication. We just need to choose a region which is not used already. Let us pick an area of 1MB right at the start of the second RAM bank at 0x880000000. We now need to add that region to reserved-memory inside the device tree. Let us do that step by step.
Enable Ramoops
We first checkout the kernel.
build@machine:~$ git clone -b toradex_5.4-2.1.x-imx git://git.toradex.com/linux-toradex.git
build@machine:~$ cd linux-toradexWe modify the file arch/arm64/boot/dts/freescale/imx8qm-apalis-v1.1-eval.dts as follows:
// SPDX-License-Identifier: GPL-2.0+ OR X11
/*
* Copyright 2020 Toradex
*/
/dts-v1/;
#include "imx8qm-apalis-v1.1.dtsi"
#include "imx8-apalis-eval.dtsi"
/ {
model = "Toradex Apalis iMX8QM V1.1 on Apalis Evaluation Board";
compatible = "toradex,apalis-imx8-v1.1-eval",
"toradex,apalis-imx8-eval",
"toradex,apalis-imx8",
"fsl,imx8qm";
reserved-memory {
#address-cells = <2>;
#size-cells = <2>;
ranges;
ramoops@880000000 {
#address-cells = <2>;
#size-cells = <2>;
compatible = "ramoops";
reg = <0x00000008 0x80000000 0x0 0x100000>; // 1MB at 0x880000000
record-size = <0x10000>; // 64kB per record
console-size = <0x10000>; // 64kB for console output
pmsg-size = <0x1000>; // 4kB for user messages
};
};
};This reserves 1MB for logging. The ramoops driver can use 64kB per record to store klog messages when the kernel panics (record-size). It can store up to 64 kB per record to store the console output from the kernel (console-size) and up to 4kB per record for user messages (pmsg-size).
Now we build the device tree and deploy it to the module:
build@machine:~/linux-toradex$ export ARCH=arm64
build@machine:~/linux-toradex$ export CROSS_COMPILE=aarch64-linux-gnu-
build@machine:~/linux-toradex$ export LOCALVERSION="+git.a2f08dfd79ae"
build@machine:~/linux-toradex$ make imx_v8_defconfig
build@machine:~/linux-toradex$ make freescale/imx8qm-apalis-v1.1-eval.dtb
build@machine:~/linux-toradex$ scp arch/arm64/freescale/imx8qm-apalis-v1.1-eval.dtb root@<device IP>:/boot/We have to make sure that the configuration for pstore and ramoops are enabled in our kernel configuration. If they are not enabled we have to enable the missing modules and recompile the kernel. The iMX8 kernel from Toradex in this BSP has them enabled already:
root@apalis-imx8:~$ zcat /proc/config.gz |grep PSTORE
CONFIG_PSTORE=y
CONFIG_PSTORE_DEFLATE_COMPRESS=y
# CONFIG_PSTORE_LZO_COMPRESS is not set
# CONFIG_PSTORE_LZ4_COMPRESS is not set
# CONFIG_PSTORE_LZ4HC_COMPRESS is not set
# CONFIG_PSTORE_842_COMPRESS is not set
# CONFIG_PSTORE_ZSTD_COMPRESS is not set
CONFIG_PSTORE_COMPRESS=y
CONFIG_PSTORE_DEFLATE_COMPRESS_DEFAULT=y
CONFIG_PSTORE_COMPRESS_DEFAULT="deflate"
CONFIG_PSTORE_CONSOLE=y
CONFIG_PSTORE_PMSG=y
CONFIG_PSTORE_RAM=yThis are the configs which are required to make ramoops work.
Console log
Now that we have deployed the device tree and are sure that ramoops is enabled we reboot the module and check if we can mount pstore.
root@apalis-imx8:~$ mount -t pstore pstore /mntIf we check the directory we will see that it is empty. The reason is that we didn't reboot yet with ramoops enabled in the device tree and therefore don't have any messages available. Let us reboot once more and mount pstore again. We now see that there is a file /mnt/console-ramoops-0 available:
root@apalis-imx8:~$ cat /mnt/console-ramoops-0
[ 0.000000] Booting Linux on physical CPU 0x0000000000 [0x410fd034]
[ 0.000000] Linux version 5.4.77-5.1.0-devel+git.a2f08dfd79ae (eichest@eichest-laptop) (gcc version 10.2.0 (Ubuntu 10.2.0-8ubuntu1)) #19 SMP PREEMPT Tue Apr 6 17:18:18 CEST 2021
[ 0.000000] Machine model: Toradex Apalis iMX8QM V1.1 on Apalis Evaluation Board
[ 0.000000] efi: Getting EFI parameters from FDT:
[ 0.000000] efi: UEFI not found.
[ 0.000000] Reserved memory: created CMA memory pool at 0x0000000096000000, size 960 MiB
[ 0.000000] OF: reserved mem: initialized node linux,cma, compatible id shared-dma-pool
[ 0.000000] Reserved memory: created DMA memory pool at 0x0000000090400000, size 1 MiB
[ 0.000000] OF: reserved mem: initialized node vdevbuffer, compatible id shared-dma-pool
[ 0.000000] NUMA: No NUMA configuration found
...This is the console output of the kernel from the last boot (before we did a reboot).
Kernel Panic
Let us now generate a kernel panic and see if we gain some more information:
# Set reboot after panic timeout to 1s
root@apalis-imx8:~$ echo 1 > /proc/sys/kernel/panic
# Trigger panic via sysrq
root@apalis-imx8:~$ echo c > /proc/sysrq-trigger
[ 220.778364] sysrq: Trigger a crash
[ 220.781796] Kernel panic - not syncing: sysrq triggered crash
[ 220.787565] CPU: 1 PID: 778 Comm: sh Tainted: G O 5.4.77-5.1.0-devel+git.a2f08dfd79ae #19
[ 220.797060] Hardware name: Toradex Apalis iMX8QM V1.1 on Apalis Evaluation Board (DT)
[ 220.804894] Call trace:
[ 220.807357] dump_backtrace+0x0/0x140
[ 220.811031] show_stack+0x14/0x20
[ 220.814361] dump_stack+0xb4/0x11c
[ 220.817773] panic+0x15c/0x328
[ 220.820846] sysrq_handle_crash+0x18/0x20
[ 220.824862] __handle_sysrq+0x88/0x180
[ 220.828623] write_sysrq_trigger+0x8c/0xb0
[ 220.832732] proc_reg_write+0x6c/0xbc
[ 220.836396] __vfs_write+0x18/0x40
[ 220.839802] vfs_write+0xdc/0x1c4
[ 220.843118] ksys_write+0x68/0xfc
[ 220.846439] __arm64_sys_write+0x18/0x20
[ 220.850368] el0_svc_common.constprop.0+0x68/0x160
[ 220.855160] el0_svc_handler+0x20/0x80
[ 220.858915] el0_svc+0x8/0x208
[ 220.861975] SMP: stopping secondary CPUs
[ 220.865901] Kernel Offset: disabled
[ 220.869389] CPU features: 0x0002,2100600c
[ 220.873401] Memory Limit: none
[ 220.878761] Rebooting in 1 seconds..We find another file in the pstore directory:
root@apalis-imx8:~$ mount -t pstore pstore /mnt
root@apalis-imx8:~$ cat /mnt/dmesg-ramoops-0
Panic#1 Part1
<6>[ 0.000000] Booting Linux on physical CPU 0x0000000000 [0x410fd034]
<5>[ 0.000000] Linux version 5.4.77-5.1.0-devel+git.a2f08dfd79ae (eichest@eichest-laptop) (gcc version 10.2.0 (Ubuntu 10.2.0-8ubuntu1)) #19 SMP PREEMPT Tue Apr 6 17:18:18 CEST 2021
<6>[ 0.000000] Machine model: Toradex Apalis iMX8QM V1.1 on Apalis Evaluation Board
...
<6>[ 64.111102] sysrq: Trigger a crash
<0>[ 64.114539] Kernel panic - not syncing: sysrq triggered crash
<4>[ 64.120303] CPU: 1 PID: 705 Comm: sh Tainted: G O 5.4.77-5.1.0-devel+git.a2f08dfd79ae #19
<4>[ 64.129797] Hardware name: Toradex Apalis iMX8QM V1.1 on Apalis Evaluation Board (DT)
<4>[ 64.137635] Call trace:
<4>[ 64.140095] dump_backtrace+0x0/0x140
<4>[ 64.143772] show_stack+0x14/0x20
<4>[ 64.147099] dump_stack+0xb4/0x11c
<4>[ 64.150513] panic+0x15c/0x328
<4>[ 64.153582] sysrq_handle_crash+0x18/0x20
<4>[ 64.157600] __handle_sysrq+0x88/0x180
<4>[ 64.161361] write_sysrq_trigger+0x8c/0xb0
<4>[ 64.165473] proc_reg_write+0x6c/0xbc
<4>[ 64.169148] __vfs_write+0x18/0x40
<4>[ 64.172557] vfs_write+0xdc/0x1c4
<4>[ 64.175879] ksys_write+0x68/0xfc
<4>[ 64.179204] __arm64_sys_write+0x18/0x20
<4>[ 64.183137] el0_svc_common.constprop.0+0x68/0x160
<4>[ 64.187936] el0_svc_handler+0x20/0x80
<4>[ 64.191698] el0_svc+0x8/0x208
<2>[ 64.194768] SMP: stopping secondary CPUs
<0>[ 64.198703] Kernel Offset: disabled
<0>[ 64.202199] CPU features: 0x0002,2100600c
<0>[ 64.206209] Memory Limit: noneCompared to the console log this one also stores the log level. Furthermore, this file provides the full dmesg log while the console might only contain a limited amount of log messages depending on the console log level. Finally, the dmesg-ramoops-0 file only appears after a kernel panic and not after a normal reboot.
User messages
One last feature ramoops provides is to store user messages which will survive a reboot. For example if we install an update and then do a reboot we could write "update" to /dev/pmsg0:
root@apalis-imx8:~$ echo update > /dev/pmsg0
root@apalis-imx8:~$ rebootAfter the reboot we can read what we have stored before:
root@apalis-imx8:~$ mount -t pstore pstore /mnt
root@apalis-imx8:~$ cat /mnt/pmsg-ramoops-0
updateThis feature is useful if we need to pass information to the next boot cycle. However, keep in mind that if a power off would happen in between this information would be lost.
Where to use ramoops
The main use case for using ramoops is to keep logs between reboots after a kernel panic occurred. This allows us to understand why the system was crashing and send the log to a server for further analysis.
Another use case where ramoops can be used is to keep the console log and additional user data between reboots. This might be useful if we have a read only file system or don't want to waste read write cycles on NAND-Flash. However, the disadvantage is that the data will not survive a power cycle.
One last thing we can think of is to use ramoops to find out why a system was rebooting. This is actually where I first started to read about it. If we have a remote device and want to know why it was rebooting so that we can act accordingly we need something to store such information. As an example we could store reboot to /dev/pmsg0 after we run the reboot command and then read /mnt/pmsg-ramoops-0 after each boot. If the file contains reboot, we know that the user did a system reboot, if it is not there at all it probably means the system started because of a power cycle. We could even go further by checking for dmesg-ramoops-0. If the file is there the device crashed. This means we can differentiate between this three reboot reasons:
- reboot
- power cycle
- kernel panic
This information can be helpful when we get customer feedback. If a customer complains that the device is constantly resetting and we see it does that because of a kernel panic, we might have a bug. If the device is restarting because of a power cycle, the power supply could be defect.
In the next article I will write about a driver that directly provides information about the reset reason without having to analyse the pstore files. Furthermore it will also be able to detect when a watchdog was triggered. This driver is a bit more complex to implement, but has the advantage that it can be customized more.