中文 EN

4.4.7. Log 系统介绍

4.4.7.1. Linux log 系统简介

Linux 的日志系统主要可以分为三个主要部分：

  1. 日志缓冲区：日志缓冲区（log buffer）是日志系统的核心组件。

  2. 日志写入：通过 printk、printk_deferred、devkmsg_write、dev_printk_emit 等接口将日志写入日志缓冲区。

  3. 日志提取：通过注册的控制台（console）、/dev/kmsg 以及 syslogd 来提取日志信息。

这三个部分可以描述为下图：

log_system

log buffer

在 Linux 系统中，日志缓冲区（log buffer）是内核用来临时存储日志消息的环形区域。它的主要作用是提供一个快速的日志消息收集机制，允许内核在不影响系统性能的情况下记录重要的信息。

log buffer 作为一个静态全局变量定义，它受 __LOG_BUF_LEN 的大小控制：

// kernel/printk.c
#define __LOG_BUF_LEN (1 << CONFIG_LOG_BUF_SHIFT)     // 即 2 的 CONFIG_LOG_BUF_SHIFT 次幂
static char __log_buf[__LOG_BUF_LEN] __aligned(LOG_ALIGN);

而 __LOG_BUF_LEN 受 CONFIG_LOG_BUF_SHIFT 影响，CONFIG_LOG_BUF_SHIFT 在 kernel config 中设置大小：

log_buf_size

可以看到，当前系统设置的 CONFIG_LOG_BUF_SHIFT 大小是17，所以 log buffer 的大小就是 2^17B（128KB）。若需修改 log buffer 大小，只需在 menuconfig 中修改 CONFIG_LOG_BUF_SHIFT，然后重新编译内核镜像即可。

需要注意，在当前系统的内核版本中（Linux V6.1.83） log buffer 的范围是 4KB ~ 32MB （CONFIG_LOG_BUF_SHIFT 的范围是12~25）：

# init/Kconfig
config LOG_BUF_SHIFT
	int "Kernel log buffer size (16 => 64KB, 17 => 128KB)"
	range 12 25
	default 17
	depends on PRINTK
	help
	  Select the minimal kernel log buffer size as a power of 2.
	  The final size is affected by LOG_CPU_MAX_BUF_SHIFT config
	  parameter, see below. Any higher size also might be forced
	  by "log_buf_len" boot parameter.

	  Examples:
		     17 => 128 KB
		     16 => 64 KB
		     15 => 32 KB
		     14 => 16 KB
		     13 =>  8 KB
		     12 =>  4 KB

log 写入接口

printk 函数

printk 是 Linux 内核中用于输出日志信息的核心函数，它与用户空间的 printf 类似，但用于内核空间。printk 是内核调试、日志记录和信息报告的重要工具。它能够将调试信息、错误消息等输出到内核日志缓冲区，然后由系统的日志守护进程（如 dmesg）将这些信息展示给用户。

1） printk 基本概述

printk 是 Linux 内核提供的一个用于输出日志信息的函数，其原型如下：

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

  • fmt：格式化字符串，类似于 printf 的格式化字符串。

  • 后续的参数：与格式化字符串相对应的数据。

printk 的行为与 printf 相似，但是输出的结果被保存在内核日志缓冲区中，而不是标准输出。

2）printk 的日志级别

printk 支持多种日志级别，帮助开发人员根据重要性、严重性和用途区分不同的日志消息。日志级别由内核的日志系统定义，并且可以影响信息的显示方式以及是否被保存。常用的日志级别如下：

  • KERN_EMERG (0)：紧急事件消息，通常用于系统崩溃或严重错误。这些消息会立即打印，并可能触发系统重启。

  • KERN_ALERT (1)：警报消息，表示需要立即处理的严重系统问题。

  • KERN_CRIT (2)：严重错误消息，通常用于严重的硬件或软件操作失败。

  • KERN_ERR (3)：错误消息，表示需要进一步调试或处理的系统错误，驱动程序常用此级别报告硬件错误。

  • KERN_WARNING (4)：警告消息，表示可能存在但通常不会导致系统崩溃的问题。

  • KERN_NOTICE (5)：通知消息，表示正在执行的重要操作，但不属于错误或警告，常用于安全相关提示。

  • KERN_INFO (6)：提示信息，表示正常的操作或状态变更，例如驱动程序启动时打印的硬件信息。

  • KERN_DEBUG (7)：调试信息，用于开发过程中输出详细的调试信息。

示例：

printk(KERN_INFO "Device initialized successfully.\n");
printk(KERN_ERR "Failed to allocate memory for device.\n");
printk(KERN_DEBUG "Debugging device register read.\n");

如不指定 log level，默认 loglevel 是 default_message_loglevel，默认为 4，也就是只会显示 KERN_WARNING 级别及以上的日志：

// kernel/include/linux/printk.h
#define default_message_loglevel (console_printk[1])
/* printk's without a loglevel use this.. */
#define MESSAGE_LOGLEVEL_DEFAULT CONFIG_MESSAGE_LOGLEVEL_DEFAULT

// kernel/kernel/printk/printk.c
int console_printk[4] = {
	CONSOLE_LOGLEVEL_DEFAULT,	/* console_loglevel */
	MESSAGE_LOGLEVEL_DEFAULT,	/* default_message_loglevel */
	CONSOLE_LOGLEVEL_MIN,		/* minimum_console_loglevel */
	CONSOLE_LOGLEVEL_DEFAULT,	/* default_console_loglevel */
};

default_message_loglevel 的值实际就是 MESSAGE_LOGLEVEL_DEFAULT ，而 MESSAGE_LOGLEVEL_DEFAULT 是在 kernel config 中设置的：

default_message_loglevel

MESSAGE_LOGLEVEL_DEFAULT 的取值范围是 1~7：

# lib/Kconfig.debug
config MESSAGE_LOGLEVEL_DEFAULT
	int "Default message log level (1-7)"
	range 1 7
	default "4"
	help
	  Default log level for printk statements with no specified priority.

	  This was hard-coded to KERN_WARNING since at least 2.6.10 but folks
	  that are auditing their logs closely may want to set it to a lower
	  priority.

	  Note: This does not affect what message level gets printed on the console
	  by default. To change that, use loglevel=<x> in the kernel bootargs,
	  or pick a different CONSOLE_LOGLEVEL_DEFAULT configuration value.

3）printk 的线程安全

printk 函数在多核系统中是线程安全的。这意味着多个内核线程可以同时调用 printk，并且内核会保证日志信息不会混乱。

但是，printk 的输出会使用一个全局的日志锁（logbuf_lock）来同步访问日志缓冲区。这个锁确保多个日志消息不会互相干扰，但同时也可能在高频率日志输出时带来一定的性能开销，特别是在系统负载较高时。所以，我们在开发过程中可以选择使用更为精细化、灵活和可控的日志接口，而不是在驱动中直接使用 printk。

4）动态调试

内核允许动态启用调试输出（printk 的调试信息），通过修改 /sys/kernel/debug/dynamic_debug/control 文件来控制哪些模块或文件的调试信息被启用。例如，可以启用某个驱动程序的调试输出：

echo "file drivers/net/* +p" > /sys/kernel/debug/dynamic_debug/control

这会启用 drivers/net/ 目录下所有源文件的调试信息输出。

要关闭相应的调试信息打印，可以向 dynamic_debug/control 文件写入关闭控制指令 -p。示例如下：

echo "file drivers/net/* -p" > /sys/kernel/debug/dynamic_debug/control

5）printk 的限制

有时，日志信息的频繁输出可能会导致系统性能问题，尤其是当同一个错误或警告反复发生时。为了避免这种情况，内核提供了以下两种机制：

  • printk_once：确保某个日志只打印一次，无论函数被调用多少次。这适用于只需要打印一次的错误信息。

    printk_once("This error message will be printed only once.\n");

  • printk_ratelimited：限制日志输出的频率。默认情况下，内核每 5 秒最多打印 10 次相同的错误信息。这对于那些重复触发的错误非常有用，能够减少日志的冗余输出。

    printk_ratelimited("Resource usage high, please check.\n");

驱动中常用的日志接口

内核提供了一些专门用于设备驱动的日志接口，这些接口基于设备结构体（struct device）进行设计，能够将日志与设备实例关联，从而方便追踪设备的行为。

在驱动开发中常用的日志接口有：

dev_err、dev_warn、dev_info、dev_dbg

这四个接口主要用于设备相关的日志输出，它们依赖于 struct device 结构体，因此需要在驱动代码中使用 dev（设备结构）指针，下面分别说明这四个接口：

  • dev_err

    • dev_err(dev, fmt, ...) 用于打印错误信息，通常在设备操作失败或者发生严重错误时使用。此函数会将错误信息输出到系统日志中，供开发人员进行问题排查。

    • 示例： dev_err(dev, "Failed to initialize device: %d\n", ret);

  • dev_warn

    • dev_warn(dev, fmt, ...) 用于打印警告信息，适用于非致命的错误或异常情形，提示系统存在潜在问题但不影响设备的继续运行。

    • 示例： dev_warn(dev, "Device is running low on resources\n");

  • dev_info

    • dev_info(dev, fmt, ...) 用于打印常规信息或状态报告。适用于设备初始化、状态变更等较为普通的日志输出。

    • 示例： dev_info(dev, "Device initialized successfully\n");

  • dev_dbg

    • dev_dbg(dev, fmt, ...) 用于打印调试信息，适合开发和调试阶段使用，提供详细的设备操作信息。注意，dev_dbg 一般默认会被禁用，因此它仅在调试模式下有效。

    • 示例： dev_dbg(dev, "Reading register value: 0x%X\n", value);

上述接口有下面几个优点：

  • 关联性强：这些接口与设备结构体 dev 绑定，能够清晰地记录哪个设备发生了什么事件，方便调试和排查问题。

  • 日志级别区分明确：根据不同的日志级别（错误、警告、信息、调试），可以有效地控制日志的详细程度。

  • 便于扩展与维护：使用这些设备相关的接口，可以保证日志格式的一致性，增强代码的可维护性。

无设备结构时使用的接口

在某些情况下，日志输出可能并不依赖于特定的设备结构，例如在内核模块的其他部分或更通用的代码中。这时，可以使用 pr_* 系列接口，比如：pr_err、pr_warn、pr_info、pr_debug。

  • pr_err(fmt, ...)：用于输出错误信息。

    示例：

    pr_err("Memory allocation failed\n");

  • pr_warn(fmt, ...)：用于输出警告信息。

    示例：

    pr_warn("The configuration value is set to the default\n");

  • pr_info(fmt, ...)：用于输出普通信息。

    示例：

    pr_info("Kernel module loaded successfully\n");

  • pr_debug(fmt, ...)：用于输出调试信息，适合开发阶段。

    示例：

    pr_debug("Debugging internal state: %d\n", state);

pr_debug 和 dev_dbg 等调试输出默认情况下是关闭的，以避免在生产环境中产生过多的日志信息。在开发和调试过程中，可以通过动态调试功能打开这些日志。

echo "file drivers/mmc/host/* +p" > /sys/kernel/debug/dynamic_debug/control

应用程序 log 接口

  1. 推荐使用 ALOG 的接口，对应的打印级别有 ALOGV、 ALOGD、 ALOGI、 ALOGW、 ALOGE、 ALOGV_TAG、 ALOGD_TAG、 ALOGI_TAG、 ALOGW_TAG、 ALOGE_TAG、 ALOGF_TAG。

  2. 使用 ALOG* 接口时，各个模块在输出 Log 时，可以通过定义 LOG_TAG 宏来打印自身模块名， logcat 支持使用 tag 筛选日志。其可通过 Makefile 传入，如： DLOG_TAG=camera；或者在代码开头声明。

  3. 使用 ALOG*_TAG 接口时，各个模块在输出 Log 时，可以通过第一个参数来打印自身模块名， logcat 支持使用 tag 筛选日志。

  4. log 系统支持 1 个 2MB 的 log_main 缓冲区， 1 个 256KB 的 log_radio、 log_system 和 log_event 和缓冲区，建议使用 log_main 缓冲区。

    • 当 bufID 是 LOG_ID_RADIO 时，日志保存到 log_radio 缓冲区， bufID 是 LOG_ID_SYSTEM 时，日志保存到 log_system 缓冲区，默认则是 log_main 缓冲区。

代码示例：

完整代码可在 hbre/liblog/log_test.cpp 文件中查看

#define LOG_TAG "alog_test"

#include <stdio.h>
#include <logging.h>

int main(int argc, char *argv[])
{
printf("\n  logcat test !!!!!!!!!!!!!!!\n");

if (argc == 2 && 0 == strcmp(argv[1], "--test")) {
  logprint_run_tests();
  exit(0);
}

if (argc == 2 && 0 == strcmp(argv[1], "--help")) {
  android::show_help(argv[0]);
  exit(0);
}

printf("\n LogV LogD test start!!! \n");

ALOGV("**************************ALOGV test start***************************");
ALOGV("**************************1***************************");
ALOGV("**************************2***************************");
ALOGV("**************************3***************************");
ALOGV("**************************4***************************");
ALOGV("**************************5***************************");
ALOGV("**************************ALOGV test  end ***************************");

ALOGD("**************************ALOGV test start***************************");
ALOGD("**************************1***************************");
ALOGD("**************************2***************************");
ALOGD("**************************3***************************");
ALOGD("**************************4***************************");
ALOGD("**************************5***************************");
ALOGD("**************************ALOGV test  end ***************************");

RLOGV("**************************RLOGV test log_radio start***************************");
RLOGD("**************************1*****************************************************");
RLOGE("**************************RLOGV test log_radio end******************************");

SLOGV("**************************SLOGV test log_system start***************************");
SLOGD("**************************2*****************************************************");
SLOGE("**************************RLOGV test log_system end**************************** *");
printf("\n LogV LogD write test success!!! \n");

return 0;
}

测试结果：

# ./logtest

不设置过滤：
# logcat
logcat test start !!!
--------- beginning of /dev/log_main
V/alog_test(21590): *ALOG test start*
D/alog_test(21590): ********1********
I/alog_test(21590): ********2********
W/alog_test(21590): ********3********
E/alog_test(21590): ********4********
V/tag     (21590): ********1********
D/tag     (21590): ********1********
I/tag     (21590): ********2********
W/tag     (21590): ********3********
E/tag     (21590): ********4********
F/tag     (21590): ********1********
V/alog_test(21590): *ALOG test end***

设置过滤 -s *:F
# logcat -s *:F
logcat test start !!!
--------- beginning of /dev/log_main
F/tag     (21590): ********1********

设置过滤 -s *:E
# logcat -s *:E
logcat test start !!!
--------- beginning of /dev/log_main
E/alog_test(21590): ********4********
E/tag     (21590): ********4********
F/tag     (21590): ********1********

设置过滤 -s tag:E
# logcat -s tag:E
logcat test start !!!
--------- beginning of /dev/log_main
E/tag     (21590): ********4********
F/tag     (21590): ********1********

切换缓存区为 log_radio:

logcat test start !!!
--------- beginning of /dev/log_radio
V/        ( 1319): **************************RLOGV test log_radio start***************************
D/        ( 1319): **************************1*****************************************************
E/        ( 1319): **************************RLOGV test log_radio end******************************

切换缓存区为 log_system:

  logcat test start !!!
--------- beginning of /dev/log_system

V/        ( 1319): **************************SLOGV test log_system start***************************
D/        ( 1319): **************************2*****************************************************
E/        ( 1319): **************************RLOGV test log_system end**************************** *

logcat 命令格式如下：

参数 描述
1 -b <buffer> 加载一个可使用的日志缓冲区供查看，比如 event 和 radio，默认值是 main
2 -c 清除缓冲区中的全部日志并退出（清除完后可以使用 -g 查看缓冲区）
3 -d 将缓冲区的 log 转存到屏幕中然后退出
4 -f <filename> 将 log 输出到指定的文件中<文件名>，默认为标准输出（stdout）
5 -g 打印日志缓冲区的大小并退出
6 -n <count> 设置日志的最大数目 <count>，默认值是4，需要和 -r 选项一起使用
7 -r <kbytes> 每输出 <kbytes> 时轮替日志文件，默认值是16，需要和 -f 选项一起使用
8 -s 设置过滤器
9 -v <format> 设置输出格式的日志消息，默认是短暂的格式

log 提取

在 Linux 系统中，日志输出的途径有多种，其中包括通过 console、/dev/kmsg 和 syslogd 提取日志。以下将详细介绍这三种主要的日志提取方式。

Console（控制台）

console 是指连接到系统的终端设备，通常用于输出内核日志信息和系统消息。在 Linux 系统中，控制台是最基础的日志输出方式之一，尤其是在没有图形界面的情况下。

一般常用的 console 有 uart、net、pstore，但是需要注意 uart 的 write 函数是受限于串口波特率的，过低的波特率（比如 115200），打印一行 log 是会导致几毫秒的关中断，如果串口打印大量 log，会导致 CPU 一直在关中断状态，其它进程很难抢到调度机会，会导致系统时序异常、softlockup 等问题。而且大量日志在串口打印的速度也很慢，需要快速打印日志的场景，建议使用 net console（即，使用 ssh 窗口）。

控制台输出的特点：

  • 实时显示：控制台输出是直接显示在终端上的，通常用于用户交互式的系统诊断。

  • 内核消息：通过 printk() 等函数输出的内核日志信息会被发送到控制台。控制台显示的日志包括启动过程中的内核日志、硬件信息、错误信息等。

  • 多控制台支持：Linux 支持多个虚拟控制台（如 /dev/tty1 到 /dev/tty6）。用户可以在这些虚拟终端中查看日志信息，或者通过 dmesg 命令查看内核环形缓冲区中的日志。

  • 控制台日志级别：内核允许用户设置不同的日志级别来控制哪些信息输出到控制台。可以通过内核启动参数或者运行时修改 console_loglevel 变量来配置输出的详细程度。

控制台的配置与使用：

在控制台中可以使用 dmesg 命令查看内核缓冲区中的日志，并根据需要设置控制台输出的日志级别。

先查看系统使用的日志等级信息：

root@buildroot:~# cat /proc/sys/kernel/printk
6       4       1       6

这四个数字依次对应 console_loglevel、default_message_loglevel、minimum_console_loglevel 以及 default_console_loglevel。

  • console_loglevel：控制台使用的日志级别；

  • default_message_loglevel：调用 printk() 未指定日志级别时使用的日志级别；

  • minimum_console_loglevel：允许设置的控制台日志级别（console_loglevel）最小值；

  • default_console_loglevel：系统启动时使用的日志级别。

通常情况下，为了加速系统启动，系统的启动信息会非常少。比如 default_console_loglevel 和 console_loglevel 为 4 的情况下，只能显示 err、crit、alert 和 emerg 等调式信息，所以，在内核模块的调式时需要调整日志显示级别。

在控制台中，一般常用下面两种方式调整控制台输出日志的详细程度：

1） 修改 proc/sys/kernel/printk

echo "8" > /proc/sys/kernel/printk

上述命令将控制台的日志级别设置为 8，显示所有级别的日志。这里需要注意，控制台只会显示大于所设置等级的信息，所以，想要显示 debug 信息，console_loglevel 应设置为大于 7的值。另外，这种修改方式系统重启后会失效。

2）dmesg 命令修改

dmesg 是一个用于显示和控制内核缓冲区（kernel ring buffer）内容的用户空间命令。它能够显示自系统启动以来的内核消息（日志信息），包括内核启动信息、驱动加载、硬件检测、文件系统挂载、设备驱动的状态等。

dmesg -n <value> 和 echo x > proc/sys/kernel/printk 能够达到同样的效果。同样，系统重启后会失效。

dmesg -n 7

dmesg 命令格式如下：

选项 描述
-C, --clear 清空内核环形缓冲区
-c, --read-clear 读取并清空所有消息
-D, --console-off 禁用控制台打印消息
-E, --console-on 启用控制台打印消息
-F, --file <file> 使用指定的文件而非内核日志缓冲区
-f, --facility <list> 限制输出到定义的设施列表
-H, --human 显示为人类可读的输出格式
-J, --json 使用 JSON 输出格式
-k, --kernel 显示内核消息
-L, --color[=<when>] 启用消息着色（auto、always 或 never），默认启用颜色
-l, --level <list> 限制输出到定义的日志级别
-n, --console-level <level> 设置打印到控制台的消息级别
-P, --nopager 不将输出通过分页程序传递
-p, --force-prefix 强制在每行多行消息上输出时间戳
-r, --raw 打印原始消息缓冲区内容
--noescape 不转义不可打印字符
-S, --syslog 强制使用 syslog(2) 而非 /dev/kmsg
-s, --buffer-size <size> 设置查询内核环形缓冲区的缓冲区大小
-u, --userspace 显示用户空间消息
-w, --follow 等待新消息
-W, --follow-new 等待并仅打印新消息
-x, --decode 解码设施和级别为可读字符串
-d, --show-delta 显示打印消息之间的时间差
-e, --reltime 显示本地时间和时间差的可读格式
-T, --ctime 显示人类可读的时间戳（可能不准确）
-t, --notime 不显示任何时间戳
--time-format <format> 使用指定的格式显示时间戳：[delta
--since <time> 显示自指定时间以来的日志
--until <time> 显示直到指定时间的日志
-h, --help 显示帮助信息
-V, --version 显示版本信息

支持的日志设施：

设施 描述
kern 内核消息
user 随机用户级消息
mail 邮件系统
daemon 系统守护进程
auth 安全/授权消息
syslog syslogd 生成的内部消息
lpr 打印机子系统
news 网络新闻子系统

支持的日志级别（优先级）：

级别 描述
emerg 系统不可用
alert 必须立即采取行动
crit 严重条件
err 错误条件
warn 警告条件
notice 正常但重要的条件
info 信息性消息
debug 调试级别消息

/dev/kmsg

/dev/kmsg 是 Linux 中的一个虚拟设备文件，提供了一个接口来读取内核日志。它的主要作用是允许用户空间的进程直接从内核日志读取消息以及向内核日志发送消息。

/dev/kmsg 的使用方式：

  • 查看内核日志： 可以通过 cat 命令查看 /dev/kmsg 中的日志：

    sudo cat /dev/kmsg

    该命令将输出内核日志的内容，包括通过 printk() 打印的所有日志信息。cat /dev/kmsg 和 dmesg -w 的执行效果相似，它们都用于实时显示内核日志。

  • 写入内核日志： 可以使用 echo 命令将消息写入内核日志。例如：

    echo "Custom log message from user space" | sudo tee /dev/kmsg
dmesg | tail -n 5

许多日志收集工具（如 rsyslog 或 systemd-journald）会定期读取 /dev/kmsg 文件来提取内核日志并将其存储在日志文件中或转发到远程服务器。

注意，与 dmesg 不同， 第一次执行 sudo cat /proc/kmsg 打印到目前位置的所有内核信息，再次执行 sudo cat /proc/kmsg 时，则不会打印再次之前打印过的信息。

syslogd

syslogd（System Log Daemon）是一个用于管理和记录系统日志的守护进程。在 Unix 和 Linux 系统中，syslogd 是一个核心组件，它负责收集、存储、转发系统日志消息，并将这些日志消息传送到文件、远程服务器或其他地方。系统日志通常包含操作系统、应用程序、设备驱动程序以及其他软件生成的各种信息，如错误、警告、调试信息等。

syslogd 的历史可以追溯到 1980 年代早期，是 Unix 系统中一个核心且重要的组件，下面是 syslogd 发展的简要历史概述：

  • 1980年代初：syslog 出现，作为 Unix 系统日志的基础，syslogd 守护进程负责处理日志。

  • 1983年：syslog 被引入到 BSD 4.2 Unix 系统中，成为标准化的日志管理工具。

  • 1990年代：syslogd 在 Unix 和 Linux 系统中得到广泛应用，并开始支持远程日志转发。

  • 2000年代：rsyslog 作为 syslogd 的增强版本，提供了更多功能，如高性能、日志加密、数据库集成等。

  • 2010年代：systemd 作为现代 Linux 系统的核心组件，逐步取代了传统的 syslogd，引入了 systemd-journald，但依然兼容传统的 syslog 协议。

syslogd 配置说明：

内核中， /etc/syslog-startup.conf 文件配置了 syslogd 进程以及其子服务，该文件内容如下：

# This configuration file is used by the busybox syslog init script,
# /etc/init.d/syslog[.busybox] to set syslog configuration at start time.

DESTINATION=file                        # log destinations (buffer file remote)
LOGFILE=/userdata/log/kernel/message     # where to log (file)
REMOTE=loghost:514                      # where to log (syslog remote)
REDUCE=no                               # reduce-size logging
DROPDUPLICATES=no                       # whether to drop duplicate log entries
BUFFERSIZE=64                           # size of circular buffer [kByte]
FOREGROUND=no                           # run in foreground (don't use!)
#LOGLEVEL=5                             # local log level (between 1 and 8)

下面是对每个配置项的详细解析：

  • DESTINATION=file

    • 含义：定义日志的目标地点，可以是 file（日志文件）、buffer（环形缓冲区）或 remote（远程 syslog 服务器）。

    • 解释：此配置项设置了日志记录的目标为文件。这意味着日志将被写入指定的文件，而不是仅存在内存缓冲区或通过网络发送到远程服务器。

  • LOGFILE=/userdata/log/kernel/message

    • 含义：指定日志文件的路径。

    • 解释：这个配置项设置了日志文件的存储路径为 /userdata/log/kernel/message。系统将在此文件中存储日志信息。如果 DESTINATION 配置为 file，则该文件是实际的日志输出文件。

  • REMOTE=loghost:514

    • 含义：指定远程 syslog 服务器的地址和端口。

    • 解释：如果选择 DESTINATION=remote，则日志将被发送到指定的远程主机。在这里，日志将被发送到 loghost 主机的 514 端口（默认的 syslog 端口）。此项配置可能用于将日志信息转发到集中管理的远程日志服务器。

  • REDUCE=no

    • 含义：是否减少日志的大小。

    • 解释：这个选项决定是否进行日志压缩或其他方式减少日志的大小。设置为 no 表示不压缩日志，日志将按原样存储。

  • DROPDUPLICATES=no

    • 含义：是否丢弃重复的日志条目。

    • 解释：该选项控制是否在日志中丢弃重复的条目。no 表示不丢弃重复条目，因此日志中可能包含相同的日志消息多次。

  • BUFFERSIZE=64

    • 含义：环形缓冲区的大小（以 KB 为单位）。

    • 解释：指定用于存储日志的环形缓冲区的大小，这里设置为 64KB。环形缓冲区是一个有限大小的缓冲区，用于临时存储日志数据，缓冲区满时会覆盖最旧的日志条目。

  • FOREGROUND=no

    • 含义：是否在前台运行 syslog。

    • 解释：设置为 no 表示 syslog 将在后台运行，而不是在前台运行。通常情况下，后台运行服务不会阻塞终端，而前台运行服务则会占用终端并输出日志。

  • #LOGLEVEL=5

    • 含义：设置本地日志级别（1 到 8），和 printk 的日志级别一致。

    • 解释：这一行被注释掉了，因此没有被启用。LOGLEVEL 配置项允许设置本地日志的详细级别，数值从 1 到 8，数字越大，日志输出越详细。通常，级别 5 表示“警告”级别的日志，显示重要的警告和错误信息。

/etc/syslog-startup.conf 最终会被 /etc/init.d/S91syslogd 脚本解析后用来设置日志记录的行为。

syslogd 日志格式说明：

配置好 /etc/syslog-startup.conf 并运行了 syslogd 或 klogd 后，一般所有 log 的信息也会追加到 /userdata/log/kernel/message 中。 下面是其中的一些日志内容：

root@buildroot:~# cat /userdata/log/kernel/message
Jan  1 00:00:04 buildroot kern.debug kernel: [    0.140925] dr-power-domain 31030000.power-controller: Looking up bpu-supply from device tree
Jan  1 00:00:04 buildroot kern.info kernel: [    0.141973] horizon-aon-pinctrl 31040000.aon_iomuxc: Initialized D-Robotics pinctrl driver
Jan  1 00:00:04 buildroot kern.err kernel: [    0.144257] (NULL device *): no horizon,gpio-banks in node /soc/disp_apb/disp_iomuxc@3e0a0054
……
Jan  1 00:51:52 buildroot user.notice ptp4l: [3112.607] selected local clock 8ea1d5.fffe.4ca67d as best master
Jan  1 00:51:55 buildroot kern.debug kernel: [ 3115.366849] sdhci-dwcmshc 35040000.sdhci: dwcmshc_runtime_resume
Jan  1 00:51:55 buildroot kern.debug kernel: [ 3115.366971] sdhci-dwcmshc 35040000.sdhci: Get fixed-drv-type: 2

/userdata/log/kernel/message 文件中的日志条目的组成格式如下：

<timestamp> <hostname> <level> <label>: [duration] <message>

以下面日志为例详细说明日志格式：

Jan  1 00:51:52 buildroot user.notice ptp4l: [3112.607] selected local clock 8ea1d5.fffe.4ca67d as best master

  • timestamp (时间戳)：Jan 1 00:51:52，日志消息的记录时间，通常包括月份（MMM）、日期（dd）和时间（hh:mm:ss）。

  • hostname (主机名)：buildroot，产生该日志消息的主机名。

  • level (日志级别)：user.notice，表示日志消息的级别，这里表示这是一条来自用户的 notice 级别信息。

  • label (标签)：ptp4l，表示产生该日志的进程、服务或系统组件的名称，这里表示消息来自 PTP 时间同步守护进程。

  • duration (持续时间)：[3112.607]，它表示在系统启动后持续的第 3112.607 秒打印的该日志。

  • message (消息内容)：selected local clock 8ea1d5.fffe.4ca67d as best master，日志消息的具体内容。

有关 syslogd 的更加详细信息可以在官方文档中获取。

4.4.7.2. log 目录结构

log 分区

本平台中日志系统分区如下：

log 类型 存储位置 单个 log 大小 是否压缩 内容
基础系统 log kernel /userdata/log/kernel 2M 否 内核 log 信息
pstore /userdata/log/pstore 最大3M 否 内核 crash 的 log 信息
coredump /userdata/log/coredump 未限制 否 应用 crash 的 log 信息
remoteproc /userdata/log/dsp 2M 否 DSP 输出的 log 信息
uboot /userdata/log/uboot 4KB 否 uboot 输出的 log 信息
reset /userdata/log/reset_reason.txt 1M 否 记录每次系统重启原因
/userdata/log/reset_count.txt 4KB 否 记录当前系统重启次数
ALOG 系统 ALOG /userdata/log/usr 2M 否 应用日志

log 分区内容说明

  1. Kernel log

    • 内核 log：通过 klogd 和 syslogd 转存到 /userdata/log/kernel 目录下

    • pstore log：当内核 crash 重启时，移动 /sys/fs/pstore 目录日志到 /userdata/log/pstore 目录下，记录系统 panic 前后的内核日志

  2. 启动原因 log

    • reset-reason.txt 信息介绍

      • COLD_BOOT: 掉电上电

      • UBOOT_RESET: uboot 下中的重启

      • PANIC：发生了 panic

      • WATCHDOG: 触发了 watchdog

      • REBOOT_CMD: kernel 下的 reboot 命令

    • reset_count.txt：当前系统重启次数

  3. remoteproc log

    • dsp：ADSP 输出的 log 信息

  4. ALOG 系统

    • 使用 ALOG 的接口打印的 log 信息

    • 应用软件推荐使用 ALOG 接口

  5. 应用 crash log

    • coredump：储存进程运行时在突然崩溃的那一刻的一个内存快照，会把进程此刻内存、寄存器状态、运行堆栈等信息转储保存在该目录文件中

4.4.7.3. log 管理

log 进程

log 进程信息说明

  • 板端 log 进程运行信息

    # ps -aux | grep log
root       817  0.0  0.2   3852  2764 ?        S    00:00   0:00 /bin/bash /usr/bin/hobot-log start
root       826  0.0  0.0   3008   332 ?        S    00:00   0:02 /sbin/syslogd -n -O /userdata/log/kernel/message -s 2048 -b 99
root       892  0.0  0.0   2724   332 ?        S    00:00   0:00 /usr/hobot/bin/hrut_remoteproc_log -b dsp -f /userdata/log/dsp/message -r 2048 -n 50
root       896  0.0  0.1   5088  1756 ?        S    00:00   0:00 /usr/hobot/bin/logcat -v time -f /userdata/log/usr/message -r2048 -n 100
root       900  0.0  0.0   3008   308 ?        S    00:00   0:01 /sbin/klogd -n

  • kernel： klogd+syslogd

    • 获取内核记录的消息，将消息数据转存成文件。

  • usr： ALOG（libalog.so）+logcat

    • 通过 ALOG 接口向 log buffer 写入 log 信息，logcat 从 log buffer 中提取数据到文件中。

  • remoteproc_log：hrut_remoteproc_log 进程

    • log 记录：通过 remoteproc 节点获取 ADSP 的 log 信息，将其写入文件中。

    • log 管控：根据输入参数中的 log 文件大小和数量限制去管控 log 的存储空间。

  • 日志管理：hobot-log

    • log 记录：记录 reset，pstore，uboot 的 log 信息。

    • log 管理：定期将原始 log 文件转存成固定格式文件，管控各个分区目录的存储空间，超过固定容量会进行删除，删除时间比较早产生的文件。

log 进程启动顺序说明

挂载完所有分区后，系统会索引 /etc/init.d/ 目录中 log 相应的脚本，并按规定好的顺序启动相应这些脚本，具体如下：

S90log_daemon
S91syslogd
S92hobot_log_start
S92klogd

执行顺序如下:

|- etc/init.d/S90log_daemon
        |- /usr/bin/hobot-log first //转储上次启动的日志信息
                |- record_reset_count(shell function)
                |- system_config(shell function)
                |- wait_for_timesync(shell function)
                |- record_reset_reason(shell function)
                |- set_pstore(shell function)
                |- set_uboot(shell function)
                |- check_first_log(shell function)
        |- /usr/bin/hobot-log
                |- check_log(shell function, major cycle)

|- /etc/init.d/S91syslogd
        |- /sbin/syslogd -n $SYSLOG_ARGS

|- /etc/init.d/S92hobot_log_start
        |- /usr/bin/hrut_remoteproc_log -b dsp
        |- logcat -v time

|- /etc/init.d/S92klogd
        |- /sbin/klogd -n $KLOGD_ARGS

log 管理方式

log 的文件生成和目录空间管控主要是由 /usr/bin/hobot-log 脚本去管理的。

hobot-log 脚本简介

hobot-log 脚本的功能是管理和归档多种日志文件，它会定期检查日志文件的大小和数量，并根据配置进行文件循环保存，它还可以处理不同日志源（如内核日志、用户空间日志、uboot、pstore 等），并在需要时备份日志到指定目录。

  • log 生成:

    • 系统每次启动时去转存 log，log 文件命名格式如下

      • X5_Uboot-count-time.Log：当系统启动时，将 uboot log 转存到 /userdata/log/uboot/archive 目录下

      • X5_Pstore-count-time（文件夹）：当系统启动时，如果检测到上次系统是异常重启，则创建该格式文件夹，并将对应的异常 log 信息记录到该文件夹下

    • 系统运行过程中每10分钟去转存 log，文件转存到各个模块的 archive 目录下，log 文件命名格式如下：

      • X5_Kernel-count-time_<inode>.Log

      • X5_Usr-count-time_<inode>.Log

      • X5_Bl31-count-time_<inode>.Log

      • X5_Dsp0-count-time_<inode>.Log

      • X5_Dsp1-count-time_<inode>.Log

      • X5_Mcore-count-time_<inode>.Log

    • log 文件命名格式解析示例： 以 /userdata/log/kernel/archive 目录中的日志文件 X5_Kernel-0003-2022_05_01_08_01_00_131599.Log 为例进行说明。

      • 命名说明：[board]_[module]-[count]-[time]_<inode>.Log

        • board: X5

        • module: Kernel, Usr, Dsp, Uboot, Pstore。首字母大写

        • count: 4位数字，0000到9999，示例中代表第3次重启

        • time：如2022_05_01_08_01_00

        • inode：如131599。正常情况下没有，只有当出现同一时间转存多个文件命名存在重合时，加入 inode 节点来做区分

  • 容量管控：

    • 一开始划分不同的 log 目录空间容量，每10分钟针对指定的目录容量去检索空间，如果容量超过，将会按照文件生成时间排序，删除产生时间比较早的文件

    • hobot-log

      管理着 usr、kernel、remoteproc_log、pstore、uboot 的空间，对应的数量限制由内部参数设定。 其中，每个类型日志文件大小说明见 log 分区，usr、kernel、pstore、uboot 日志文件系统默认的数量限制为100个，dsp 日志文件系统默认的数量限制为50个。 hobot-log 脚本中相关内容定义如下：

      ROTATESIZE=2048 #KB
ROTATEGENS_KER=100
ROTATEGENS_USR=100
ROTATEGENS_REMOTE=50
ROTATEGENS_CHIP=50
ROTATEGENS_ALL=$((${ROTATEGENS_REMOTE} + ${ROTATEGENS_KER} + ${ROTATEGENS_USR} + ${ROTATEGENS_CHIP}))
ROTATESIZE_BYTES=$((${ROTATESIZE} * 1024))
PSTORE_LOGMAX=100

      通过这样的配置可以实现日志轮换，当日志文件达到一定大小（当前设定值为 2048KB）时，系统会将当前的日志文件重命名，并创建一个新的日志文件来继续记录新的日志消息。并且限制了保存的总文件数量，在达到设置的文件数量上限会根据时间戳顺序删除最早日志，这样可以防止日志文件无限增长，占用过多的磁盘空间。

    • hrut_remoteproc_log:

      log 的大小和数量也是由进程自身管理的，对应的参数配置是 hobot-log 中去设置的

用户定制 log 系统

  • 日志命名修改

    • 在 hobot-log 中修改，具体的修改功能逻辑是 check_log 函数实现的

      • $1：log 产生的原始目录

      • $2：log 根据原始文件去转存的目录

      • $3：log 文件命名的前缀

      • $4：log 文件命名的后缀

      • $5：log 文件的限制的最大数量

        #$1 origin log dir
#$2 save log dir
#$3 filename prefix
#$4 filename suffix
#$5 maximum log count
function check_log()
{
    local origin_dir="$1"
    local save_dir="$2"
    local prefix="$3"
    local suffix="$4"
    local log_cnt_max="$5"
    local save_log_dir max_file_size file_name time_type_name file_repeat file_inod

        check_log 函数的目的是检查日志目录中是否有符合特定规则的日志文件，并根据设定的日志轮换策略处理这些日志文件。

    • 具体使用范例

      在 start 函数中描述新增的日志文件，使用 check_log 第3,4,5个参数来去定义 log 的文件命名格式以及限制 log 的文件数量

      function start() {
    LOG_EXE_FLAG=1
    record_reset_count

    while true; do
        check_log ${KER_ORI_LOG_DIR}   ${KER_SAVE_LOG_DIR}   "${SOC}_Kernel-${RESET_COUNT}-" ".Log" ${ROTATEGENS_KER}
        check_log ${USR_ORI_LOG_DIR}   ${USR_SAVE_LOG_DIR}   "${SOC}_Usr-${RESET_COUNT}-"    ".Log" ${ROTATEGENS_USR}
        check_log ${DSP0_ORI_LOG_DIR}  ${DSP0_SAVE_LOG_DIR}  "${SOC}_Dsp-${RESET_COUNT}-"   ".Log" ${ROTATEGENS_REMOTE}
        check_log ${BL31_ORI_LOG_DIR}  ${BL31_SAVE_LOG_DIR}  "${SOC}_Bl31-${RESET_COUNT}-"   ".Log" ${ROTATEGENS_REMOTE}
        check_log ${CHIP_ORI_LOG_DIR}  ${CHIP_SAVE_LOG_DIR}  "${SOC}_Chip-${RESET_COUNT}-"   ".Log" ${ROTATEGENS_CHIP}
        check_log_cnt_with_keyword ${CORE_DUMP_LOG_DIR} "adsp" 20
        check_log_dir_size ${CORE_DUMP_LOG_DIR} ${CORE_DUMP_LOG_DIR_SIZE}

        sleep 600
    done
}

      每个 check_log 的参数说明：

      • 源目录和保存目录：每个调用都有两个目录参数，分别代表原始日志文件的存放位置和目标日志保存的位置。例如，KER_ORI_LOG_DIR 表示内核日志的原始目录，KER_SAVE_LOG_DIR 表示保存的目标目录。

      • 日志文件名模板："${SOC}_Kernel-${RESET_COUNT}-" ".Log" 是日志文件名的前缀（SOC 和 RESET_COUNT 是变量，通常表示系统信息和重启次数）。这将生成一个唯一的日志文件名。

      • 旋转次数（例如 ROTATEGENS_KER）：该参数控制日志文件的旋转次数或数量限制，用于控制日志文件的大小或备份数量。不同的日志目录会有不同的旋转设置。

      另外，最后的 sleep 600，每次循环结束后，start() 函数会等待600秒（即10分钟）。这意味着每10分钟执行一次上述的日志检查和管理操作。

  • log 进程的裁剪

    • 可以通过控制 init.d 中 log 启动脚本，增删 log 进程启动。

    • 推荐有新的开发功能加入时，也通过 init.d 中的 S92hobot_log_start shell 脚本中集成。

  • log 回读

    • log-service demo 会针对 log 的分区目录每隔一段时间进行文件上传，此过程不去压缩 log。

pstore

pstore（Persistent Store）是 Linux 内核提供的一种机制，旨在将关键的错误信息（如内核崩溃日志、崩溃时的内存快照等）保存到持久存储中（如闪存中），即使在系统重启后，这些信息仍然可以被访问和分析。这有利于调试和分析 Linux 系统中的硬件故障、内核崩溃、或者严重系统错误。

pstore 具有以下特点：

  1. 持久化存储：pstore 可以将重要的内核调试信息（如 Oops 信息、内核崩溃日志等）保存到持久存储设备中，这样即使系统重启后，依然可以获取到崩溃时的信息。

  2. 多种存储介质支持：pstore 支持多种存储介质，例如，内存（通过内存的某些区域）、闪存（如 eMMC、NAND 闪存等）、以及其他内存设备（如 SPI Flash、NVRAM）。

  3. 内核崩溃信息记录：当内核发生崩溃时，pstore 可以将崩溃的堆栈信息、寄存器状态、内核错误信息等保存下来，供后续调试分析。

  4. 支持多种崩溃场景：pstore 不仅支持内核崩溃（Oops），还可以用于记录其它类型的错误信息，如内存泄漏、硬件错误等。

pstore 的机制

pstore 本质上是一个文件系统，它被挂载在 /sys/fs/pstore 目录下：

root@buildroot:~# cat /proc/mounts |grep "^pstore"
pstore /sys/fs/pstore pstore rw,relatime 0 0

当系统 panic 时，日志就会保存到 /sys/fs/pstore 目录中：

root@buildroot:/sys/fs/pstore# ls
console-ramoops-0  dmesg-ramoops-0  sched-ramoops-0

  • console-ramoops-0 ：该文件通常存储系统崩溃时控制台输出的日志（例如内核 panic 信息、错误消息、调试信息等）。

  • dmesg-ramoops-0：该文件通常存储内核启动后的日志信息，包括硬件检测、驱动加载、系统启动期间发生的错误或警告等。

  • sched-ramoops-0：该文件通常存储的是调度器（scheduler）相关的日志信息，记录内核调度器在崩溃时的状态。

配置 pstore

在板端系统中预留了 256KB 的空间用来保存 Ramoops 日志，相关描述在设备树文件中：

# kernel/arch/arm64/boot/dts/hobot/x5-memory.dtsi
ramoops@A4080000 {
    compatible = "ramoops";
    reg = <0x0 0xA4080000 0x0 0x00040000>;
    console-size = <0x8000>;
    pmg-size = <0x8000>;
    ftrace-size = <0x8000>;
    sched-size  = <0x8000>;
    record-size = <0x4000>;
    ecc-size = <0x0>;
};

  • ramoops@A4080000 { ... }

    • 这是一个设备节点，定义了一个名为 ramoops 的设备，节点的地址是 A4080000。这个节点表明系统有一个 ramoops 设备，它位于物理内存地址 0xA4080000 处。

  • compatible = "ramoops";

    • 这行定义了设备与 ramoops 驱动的兼容性。这里，它表明该设备使用 ramoops 驱动，ramoops 是一种用于保存内核崩溃信息（如控制台输出、调度信息等）的机制。

  • reg = <0x0 0xA4080000 0x0 0x00040000>;

    • 这是设备的地址和大小配置，格式为 <base address size>。 - 0x0：表示地址空间的起始地址（通常为 0，表示物理地址）。 - 0xA4080000：表示设备的起始物理地址，这里为 0xA4080000。 - 0x0：表示偏移量（通常为 0）。 - 0x00040000：表示设备的内存区域大小，这里是 0x00040000，即 256 KB。

    • 这表示设备 ramoops 的内存区域从 0xA4080000 地址开始，占用 256 KB 大小。

  • console-size = <0x8000>;

    • 这行配置了控制台日志缓冲区的大小。console-size 指定了保存内核控制台日志的内存区域大小，单位为字节。

    • 0x8000：表示 32 KB 的大小。意味着 ramoops 将为控制台日志分配 32 KB 的内存空间。

  • pmg-size = <0x8000>;

    • pmg-size 指定了保存内核 panic 信息的内存区域大小。

    • 0x8000：表示 32 KB 大小。意味着 ramoops 将为内核 panic 信息分配 32 KB 的内存空间。

  • ftrace-size = <0x8000>;

    • ftrace-size 配置了 ftrace（内核的追踪功能）日志的缓冲区大小。

    • 0x8000：表示 32 KB 大小。意味着 ramoops 将为内核的 ftrace 追踪日志分配 32 KB 的内存空间。

  • sched-size = <0x8000>;

    • sched-size 配置了内核调度器日志的缓冲区大小。

    • 0x8000：表示 32 KB 大小。意味着 ramoops 将为内核调度器相关的信息（如任务调度日志）分配 32 KB 的内存空间。

  • record-size = <0x4000>;

    • record-size 配置了记录日志的内存区域大小。

    • 0x4000：表示 16 KB 大小。意味着 ramoops 将为记录崩溃信息的日志区域分配 16 KB 的内存空间。

  • ecc-size = <0x0>;

    • ecc-size 配置了 ECC（错误更正码）日志的区域大小。

    • 0x0：表示没有为 ECC 分配内存。也就是说，在此配置中没有为 ECC 错误记录预留内存区域。

要启用 pstore 功能，需要在内核配置中启用相关选项（默认开启）：

pstore

注意，这里配置 pstore 日志保存位置是 RAM 上，所以在系统 panic 后的那次自动重启才能在 /sys/fs/pstore 里看到相应日志，一旦掉电重启后，/sys/fs/pstore 里的文件便会清空：

<*>     Log panic/oops to a RAM buffer

掉电重启后需要去转存目录 /userdata/log/pstore/ 里查看最新的一份日志。

在启用了 pstore 支持后，对应的驱动便会加载，在系统启动日志中可以看到相关内容：

root@buildroot:~# dmesg | grep "ramoops"
[    0.114818] printk: console [ramoops-1] enabled
[    0.114822] pstore: Registered ramoops as persistent store backend
[    0.114827] ramoops: using 0x40000@0xa4080000, ecc: 0

pstore 日志的转存

在板端系统中，hobot-log 脚本会将 /sys/fs/pstore 里的日志文件转存到 /userdata/log/pstore/ 目录下，具体实现是依赖 set_pstore 函数：

#pstore log information
PSTORE_FS=$(cat /proc/mounts |grep "^pstore" |awk '{print $2}')
PSTORE_LOG=${LOG_SOURCE_DIR}/pstore
PSTORE_LOGMAX=100

function set_pstore()
{
	if [ -n "${PSTORE_FS}" ] && [ ! -e ${PSTORE_LOG}/disable ]; then
		if [ "$(ls -A ${PSTORE_FS})" == "" ];then
			return 0
		fi

		local UBOOTCMD=$(cat /proc/cmdline| sed 's/ /\n/g' | grep -i hobotboot.reason)
		local BOOTREASON=$(echo ${UBOOTCMD#*=})
		if [ "${BOOTREASON}" == "COLD_BOOT" ] || [ "${BOOTREASON}" == "UBOOT_RESET" ] || [ "${BOOTREASON}" == "WATCHDOG" ] || [ "${BOOTREASON}" == "REBOOT_CMD" ]; then
			return 0
		fi

		local pstore_log_date=$(date +%Y_%m_%d_%H_%M_%S)
		local pstore_log_dir="${PSTORE_LOG}/${SOC}_Pstore-${RESET_COUNT_NOW}-${pstore_log_date}"
		mkdir -p ${pstore_log_dir}
		output "pstore log to ${pstore_log_dir}"
		cp ${PSTORE_FS}/* ${pstore_log_dir}/
		/usr/hobot/bin/hrut_sched_log_parse ${PSTORE_FS}/sched-ramoops-0 > ${pstore_log_dir}/sched-ramoops-0
		change_file_time ${pstore_log_dir}

		local pstore_log_cnt=$(ls -l ${PSTORE_LOG} | grep "^d" | wc -l)
		while [ ${pstore_log_cnt} -gt ${PSTORE_LOGMAX} ]; do
			local deldir_name=$(ls -ltr ${PSTORE_LOG} | grep "^d" | head -n 1 | awk '{print $9}')
			rm -rf ${PSTORE_LOG}/${deldir_name}
			pstore_log_cnt=$(ls -l ${PSTORE_LOG} | grep "^d" | wc -l)
		done
		sync
	fi
}

set_pstore 函数只有在系统启动原因为 PANIC （不能是 COLD_BOOT、UBOOT_RESET、WATCHDOG、REBOOT_CMD）的时候才会将 pstore 存储的日志文件移动到 pstore_log_dir 目录（/userdata/log/pstore/），并对日志文件数量进行控制，一旦容量超过了设定值，就会删除最旧的日志，确保不会超出设定容量。

转存后，在/userdata/log/pstore/ 会生成本次 panic 的日志目录：

root@buildroot:/userdata/log/pstore# ls
X5_Pstore-0074-1970_01_01_00_00_03  X5_Pstore-0075-1970_01_01_00_00_03

每次 panic 都会新增一个目录，每个目录中的日志文件就是从 /sys/fs/pstore 目录下复制而来的：

root@buildroot:/userdata/log/pstore/X5_Pstore-0075-1970_01_01_00_00_03# ls
console-ramoops-0  dmesg-ramoops-0  sched-ramoops-0

pstore 使用示例

在崩溃发生后，可以通过以下命令来查看日志信息：

# 触发 panic
echo c > /proc/sysrq-trigger

# 查看 pstore 日志
cat /sys/fs/pstore/console-ramoops-0

# 或者查看转存到 /userdata/log/pstore/ 目录下的最新的一个子目录中的日志
 cd /userdata/log/pstore/X5_Pstore-0075-1970_01_01_00_00_03/console-ramoops-0

4.4.7.4. log debug

log 调试注意点

  1. 调试时大量日志可以单独保存，防止丢失，方便查看：

    • 内核日志：dmesg -w > /userdata/dmesg.log &。

    • ALOG 日志：logcat -v time -f /userdata/logcat.log &。

  2. 每个转存周期（10min）内产生超过 rotate 数量的日志会造成日志丢失：

    • 首先应只输出必要的日志。

    • 如果输出较多 log，在设置 rotate 的数量时候，要考虑好所需大小。

  3. 不要在串口、ssh 窗口实时查看日志。可能会发现丢日志，原因是输出慢，覆盖导致。如果必须，建议 ssh 窗口实时查看日志。

    • 比如使用 logcat 在串口实时查看输出，内核若输出 “logcat lost message”，则说明有日志丢失。

  4. 日志写入存储设备保存。考虑到存储设备的寿命有限和大量存储日志对 IO/CPU 性能的影响，应只输出必要的日志，正式版本不应输出大量调试日志：

    • 比如当存储设备是 eMMC（64GB、MLC、3000次擦写）时，若每分钟写入 10MB 日志，则连续工作十年消耗27%寿命，考虑写入放大，消耗更多。

死机情况如何保存有效日志记录

  1. 在出现系统 panic 死机的时候，pstore 的机制是可以将发生 panic 的内核 log 信息存储到 pstore 的目录中的，但需要注意 BL31 的 panic 信息没法保存。

  2. 关于 panic 的具体原因可以去系统稳定性排查指南中去按照指导进一步分析。

有效获取问题时刻日志

  1. 在 log 分区中的文件的命名字段中包含对应 log 文件的最后修改时间的信息，可以去文件中查找问题时刻的 log。

  2. 如果在当前机器中对应的 log 没有对应的文件，可能出现问题时刻的 log 已经被覆盖了，可以去云端中获取上传的 log，寻找对应文件名的 log 去分析问题。

4.4.7.5. 记录 AB/BAK 异常切换原因

介绍

目前，启动失败，并且会造成 AB 或 BAK 切换的原因有以下几种：

  • miniboot 中的 BL3x 被 corrupted（BAK 切换）

  • misc 分区中记录 AB 信息的区域被 corrupted（包含 misc 分区为空的情况，切换到 A）

  • Uboot 被 corrupted（AB 切换）

  • boot 被 corrupted（AB 切换）

  • system 被 corrupted（即 dm-verity 失败，AB 切换）

当各级启动程序检测到以上这些 corrupted 时，会将对应 flag 写入到 AON（Always-On）寄存器，在下次启动时 BL2 会读取 AON 寄存器，将 corrupted 原因写入 misc 分区中，在 misc 分区中只会保存最近10次启动失败的原因。在板端文件系统中，提供了 hrut_switch_reason 工具，可以解析 misc 分区或 dump 后的 misc 分区文件，打印出上次启动失败的原因，或将10次原因全部打印出来。

另外也提供了 Python3 脚本，支持在 PC 上解析 dump 后的 misc 分区文件，打印启动失败的原因。路径位于 BSP 源码包的 hbre/hbutils/utility/pc_tools/hrut_switch_reason.py

hrut_switch_reason 工具使用

板端工具

root@buildroot:~# hrut_switch_reason -h
Usage: hrut_switch_reason [misc_path] <--current|--all>
misc_path: misc partition or file path (default: /dev/block/platform/by-name/misc)
--current: The reason for the last abnormal switch
--all: The reason for the all abnormal switch
example: hrut_switch_reason --all

  • misc_file：可选参数。指定 dump 出的 misc 分区文件路径。如果为空，默认路径是 misc 的分区节点 /dev/block/platform/by-name/misc，如果要指定路径，必须作为第一个参数

  • <–current|–all>：必选参数。–current 表示打印上次启动失败的原因；–all 表示打印所有启动失败的原因，共10次

PC工具

❯ ./hrut_switch_reason.py -h
Usage: ./hrut_switch_reason.py <misc_file> <--current|--all>

  • misc_file：必选参数。指定 dump 出的 misc 分区文件路径

  • <–current|–all>：必选参数。–current 表示打印上次启动失败的原因；–all 表示打印所有启动失败的原因，共10次

使用示例

# 板端工具
root@buildroot:~# hrut_switch_reason --current  # 打印上次启动失败原因
dm-verity corruped

root@buildroot:~# hrut_switch_reason --all  # 打印全部启动失败原因
All Reasons (From the latest to the oldest):
1: dm-verity corruped
2: misc broken
3: unused
4: unused
5: unused
6: unused
7: unused
8: unused
9: unused
10: unused

# PC工具
❯ ./hrut_switch_reason.py ~/misc_file --current   # 打印上次启动失败原因
miniboot corruped

❯ ./hrut_switch_reason.py ~/misc_file --all  # 打印全部启动失败原因
All Reasons (From the latest to the oldest):
1: miniboot corruped
2: miniboot corruped
3: miniboot corruped
4: uboot corruped
5: uboot corruped
6: dm-verity corruped
7: boot corruted
8: boot corruted
9: dm-verity corruped
10: misc broken

测试用例构造

测试 misc 分区 corrupted 可以在对板子烧写 disk 镜像后，这种情况下会将 misc 分区全部清空，记录启动失败原因的区域也会全部清空。

mmc
# system corrupted (dm-verity) 需要开启AVB验证
mount / -o rw,remount
echo 132 > ~/test
sync

# boot corrupted 需要开启AVB验证
dd if=/dev/random of=/dev/block/platform/by-name/boot_a bs=1 count=4

# uboot corrupted
dd if=/dev/random of=/dev/block/platform/by-name/uboot_a bs=1 count=4

# miniboot中的bl3x corrupted
dd if=/dev/random of=/dev/block/platform/by-name/miniboot seek=262144 bs=1 count=512
flash
# system corrupted (dm-verity)
# flash 上不支持 dm-verity

# boot corrupted 需要开启AVB验证
# uboot cmd 执行
mtd write boot_a ${kernel_addr} 0 0x1000

# uboot corrupted
mtd write uboot_a ${kernel_addr} 0 0x1000

# miniboot 中的 bl3x corrupted
mtd write miniboot ${kernel_addr} 0x40000 0x1000

通过 cmdline 查看

Uboot 也会读取 AON 寄存器，把上次启动失败的原因通过 bootargs 传递给 Kernel，并清除 AON 寄存器。

root@buildroot:~# cat /proc/cmdline
console=ttyS0,921600n8 root=/dev/mmcblk0p13 ro rootwait hobotboot.slot_suffix=_b hobotboot.reason=WATCHDOG hobotboot.medium=MMC hobotboot.mode=normal hobotboot.ab_switch_reason=dm-verity-corruted pmic_type=single-pmic

以下是对日志中各个参数的解析：

  • console=ttyS0,921600n8：这个参数指定了系统的控制台输出到哪个串行端口。ttyS0 是串行端口的名称，921600是波特率，n8 表示没有奇偶校验位（no parity），8个数据位。

  • root=/dev/mmcblk0p13：这个参数指定了系统的根文件系统所在的设备和分区。这里指定的是 /dev/mmcblk0 设备的第13个分区（p13）。

  • ro：这个参数表示根文件系统以只读模式挂载。

  • rootwait：这个参数告诉内核在启动过程中等待根文件系统设备准备好。这通常用于网络启动或 USB 启动，其中根文件系统设备可能需要一些时间才能准备好。

  • hobotboot.slot_suffix=_b：这是一个特定于某个系统的参数，表示启动时使用的 slot（插槽）后缀是 _b。

  • hobotboot.reason=WATCHDOG：这个参数表示启动原因是由于看门狗（WATCHDOG）触发的。看门狗是一种硬件或软件机制，用于检测系统是否在正常运行，如果系统停止响应，看门狗可以触发重启。

  • hobotboot.medium=MMC：这个参数表示启动介质是多媒体卡（MMC）。

  • hobotboot.mode=normal：这个参数表示启动模式是正常的启动模式。

  • hobotboot.ab_switch_reason=dm-verity-corruted：这个参数表示 AB 切换（可能是指双系统切换）的原因是 dm-verity 校验失败。dm-verity 是一种用于验证启动分区完整性的技术，如果校验失败，可能意味着启动分区被篡改或损坏。

  • pmic_type=single-pmic：这个参数表示电源管理集成电路（PMIC）的类型是单 PMIC。

cmdline 中启动原因的标志位是 hobotboot.ab_switch_reason。

通过系统 log 查看

在系统 log 文件中，也会记录每次启动的命令及上次启动失败的原因，log 文件位于板端的 /userdata/log/reset_reason.txt。例如第一次启动时 log 如下：

root@buildroot:~# cat /userdata/log/reset_reason.txt
1970-01-01-00-00-08: UBOOT_RESET        misc-broken             LNX6.1.83_PL5.1_V1.0.11_20240912-1542   0000

其中 misc-broken 表示此次启动时 misc 分区发生了初始化，从 A slot 启动。