Linux 调试之动态打印

[toc]

一、概述

在 kernel 驱动代码中，使用动态输出是系统内核调试的重要手段之一，printk 打印是全局的，只能设置输出等级，而且使用 printk 每次都要重新编译内核，很不方便。。而动态输出可以在不需要重新编译内核的情况下，方便的打印出内核的 debug 信息。动态输出可以动态选择打开某个内核子系统的输出，可以有选择性地打开某些模块的输出，printk 被 dev_info，dev_dbg，dev_err 之类的函数代替，dev_xxx 函数的本质还是使用 printk 打印的，只是对 printk 进行了一层包装。

在系统运行时候，动态打印可以由系统维护者动态打开内核子系统的打印，可以有选择性地打开某些模块的打印。要使用动态打印，必须在内核配置时打开 CONFIG_DYNAMIC_DEBUG 宏。

1
2
CONFIG_DEBUG_FS=y
CONFIG_DYNAMIC_DEBUG=y

CONFIG_DYNAMIC_DEBUG 是配置动态输出，它依赖于 CONFIG_DEBUG_FS，而 CONFIG_DEBUG_FS 是 debugfs 文件系统。debugfs默认会挂载到 /sys/kernel/debug，如果没有挂载，可以执行以下命令挂载： 

1
$ mount -t debugfs none /sys/kernel/debug

二、printk

1、printk 消息级别

Linux 内核共提供了八种不同的消息级别，分为级别 0~7。数值越大，表示级别越低，对应的消息越不重要。相应的宏定义在 include/linux/kern_levels.h 文件中。

1
2
3
4
5
6
7
8
9
10
11
#define KERN_SOH    "\001"      /* ASCII Start Of Header */
#define KERN_SOH_ASCII  '\001'

#define KERN_EMERG  KERN_SOH "0"    /* system is unusable */
#define KERN_ALERT  KERN_SOH "1"    /* action must be taken immediately */
#define KERN_CRIT   KERN_SOH "2"    /* critical conditions */
#define KERN_ERR    KERN_SOH "3"    /* error conditions */
#define KERN_WARNING    KERN_SOH "4"    /* warning conditions */
#define KERN_NOTICE KERN_SOH "5"    /* normal but significant condition */
#define KERN_INFO   KERN_SOH "6"    /* informational */
#define KERN_DEBUG  KERN_SOH "7"    /* debug-level messages */
  • KERN_EMERG 表示紧急事件，一般是系统崩溃之前提示的消息；
  • KERN_ALERT 表示必须立即采取行动的消息；
  • KERN_CRIT 表示临界状态，通常涉及严重的硬件或软件操作失败；
  • KERN_ERR 用于报告错误状态，设备驱动程序会经常使用该级别来报告来自硬件的问题；
  • KERN_WARNING 对可能出现问题的情况进行警告，这类情况通常不会对系统造成严重的问题；
  • KERN_NOTICE 表示有必要进行提示的正常情形，许多与安全相关的状况用这个级别进行汇报；
  • KERN_INFO 表示内核提示信息，很多驱动程序在启动的时候，用这个级别打印出它们找到的硬件信息；
  • KERN_DEBUG 用于调试信息。

2、调整内核 printk 打印级别

通过 /proc/sys/kernel/printk 文件可以调节 printk 的输出等级，该文件有 4 个数字值：

1
2
$ cat /proc/sys/kernel/printk
4	4	1	7

四个数值含义分别如下：

  • 控制台日志级别：优先级高于该值的消息将被打印至控制台；
  • 默认的消息日志级别：将用该优先级来打印没有优先级的消息（即 printk 没有指定消息级别）；
  • 最低的控制台日志级别：控制台日志级别可被设置的最小值（最高优先级）；
  • 默认的控制台日志级别：控制台日志级别的缺省值。

通过修改 /proc/sys/kernel/printk 中的值来改变内核打印效果。例如，屏蔽掉所有的内核 printk 打印，只需要把第一个数值调到最小值 1 或者 0，指令如下:

1
$ echo 1 4 1 7 > /proc/sys/kernel/printk

三、dynamic debug 的使用

1、dev_xxx 函数

下面简述下几个 dev_xxx 函数的基本使用规则，以及动态调试使用方式。

  • dev_info()： 启动过程、或者模块加载过程等 “通知类的” 信息等，一般只会通知一次，例如 probe 函数；
  • dev_dbg()： 一般使用在普通错误，如 -EINVAL、-ENOMEM 等 errno 发生处，用于调试；
  • dev_err()： 一般使用在严重错误，尤其是用户无法得到 errno 的地方，或者程序员不容易猜测系统哪里出了问题的地方。

dev_debug 的定义在文件 include/linux/device.h：

1
2
3
4
5
6
7
8
9
10
11
12
13
#if defined(CONFIG_DYNAMIC_DEBUG)
#define dev_dbg(dev, fmt, ...)	\
 dynamic_dev_dbg(dev, dev_fmt(fmt), ##__VA_ARGS__)
#elif defined(DEBUG)
#define dev_dbg(dev, fmt, ...)	\
 dev_printk(KERN_DEBUG, dev, dev_fmt(fmt), ##__VA_ARGS__)
#else
#define dev_dbg(dev, fmt, ...)	\
({	\
 if (0)	\
  dev_printk(KERN_DEBUG, dev, dev_fmt(fmt), ##__VA_ARGS__); \
})
#endif

pr_debug 的定义在文件 include/linux/printk.h，从 pr_debug 的源码注释建议：如果写驱动，请用 dev_dbg。

1
2
3
4
5
6
7
8
9
10
11
12
13
14
/* If you are writing a driver, please use dev_dbg instead */
#if defined(CONFIG_DYNAMIC_DEBUG)
#include <linux/dynamic_debug.h>

/* dynamic_pr_debug() uses pr_fmt() internally so we don't need it here */
#define pr_debug(fmt, ...) \
 dynamic_pr_debug(fmt, ##__VA_ARGS__)
#elif defined(DEBUG)
#define pr_debug(fmt, ...) \
 printk(KERN_DEBUG pr_fmt(fmt), ##__VA_ARGS__)
#else
#define pr_debug(fmt, ...) \
 no_printk(KERN_DEBUG pr_fmt(fmt), ##__VA_ARGS__)
#endif
配置 pr_debug/dev_dbg输出情况
CONFIG_DYNAMIC_DEBUG=y
DEBUG=n		 调用 dynamic_pr_debug/dynamic_dev_dbg， echo -n “file xxx.c +p” > /sys/kernel/debug/dynamic_debug/control
CONFIG_DYNAMIC_DEBUG=y
DEBUG=y		 调用 dynamic_pr_debug/dynamic_dev_dbg，增加启动参数 loglevel=8 之后，kernel 启动阶段就能看到 log
CONFIG_DYNAMIC_DEBUG=n
DEBUG=y		 调用 printk，打印等级是 KERN_DEBUG=7，所以要将打印等级设置为 8（echo 8 > /proc/sys/kernel/printk）才能看到输出
CONFIG_DYNAMIC_DEBUG=n
DEBUG=n		 不打印

2、动态输出支持的特性

动态输出在 debugfs 文件系统中对应的是 control 文件节点。control 文件节点记录了系统中所有使用动态输出技术的文件名路径，输出语句所在的行号、模块名和将要输出的语句等。

你可以通过以下命令查看目前所有调试状态的行为配置：

1
$ cat /sys/kernel/debug/dynamic_debug/control

你也可以应用标准的 Unix 文本过滤命令来过滤这些数据, 例如：

1
$ grep -i rdma /sys/kernel/debug/dynamic_debug/control  | wc -l

3、命令行格式

在语法层面上，一个命令由一系列的规格匹配组成，最后由一个标记来改变这规格。

1
command ::= match-spec* flags-spec

match-spec 常用来选择一个已知的 dprintk() 调用点的子集来套用 flags-spec。把他们当做彼此之间的每对做隐式查询。注意，一个空的 match_specs 列表是有可能的，但不是非常有用，因为它不会匹配任何调用点的调试子句。

一个匹配规范由一个关键字组成，关键字控制被比较的调用点的属性和要比较的值。可能关键字是：

1
2
3
4
5
6
7
8
9
10
11
match-spec ::= 'func' string    |
	           'file' string    |
	           'module' string  |
	           'format' string  |
	           'line' line-range
	           

line-range ::= lineno |
       		'-'lineno |
       	    lineno'-' |
  	        lineno'-'lineno

注意：line-range 不能包含空格，例如，“1-30”是有效的范围，但“1 - 30”就是无效的

每个关键字的含义如下：

  • func：给定的字符串会和每个调用点的函数名比较。例如： func svc_tcp_accept
  • file：给定的字符串会和每个调用点的源文件的全路径名或者相对名比较。例如： file svcsock.c， file /usr/src/packages/BUILD/sgi-enhancednfs-1.4/default/net/sunrpc/svcsock.c
  • module：给定的字符串会和每个调用点的模块名进行比较。模块名是和在 ls mod 里看到的字符串一样。例如，module sunrpc
  • format：给定的字符串会在动态调试格式字符串里查找。注意这字符串不需要匹配这个格式。空格和其他特殊字符能够用八进制字符语法来转义，例如空字符是 \040。作为选择，这个字符串可以附上双引号 “ 或者是单引号 ‘。例如：
1
2
3
4
5
format svcrdma:         // NFS/RDMA 服务器的dprintks
format readahead        // 一些在预加载缓存里的dprintks
format nfsd:\040SETATTR // 一个使用空格来匹配格式的方式
format "nfsd: SETATTR"  // 一个整齐的方法来用空格匹配格式
format 'nfsd: SETATTR'  // 同样是一个用空格来匹配格式的方法和
  • line：给定的行号或者是行号范围会和每个 dprintk() 调用点的行号进行比较。例如：
1
2
3
4
line 1603      // 准确定位到1603行 
line 1600-1605 // 1600行到1605行之间的6行
line -1605     // 从第一行到1605行之间的1605行
line 1600-     // 从1600行到结尾的全部行

标记规范包含了一个由一个或多个标记字符跟随的变化操作。这变化操作如下所示：

1
2
3
4
5
6
7
8
- // 移除给定的标记
+ // 加入给定的标记
= // 设置标记到给定的标记上 
f // 包含已打印消息的函数名
l // 包含已在打印消息的行号
m // 包含已打印消息的模块名
p // 产生一个 printk() 消息到显示系统启动日志
t // 包含了不在中断上下文中产生的消息里的线程ID

4、动态打印

例：

1
2
3
4
5
6
7
8
9
10
11
# 打开一个文件中所有动态打印语句
$ echo -n "file gadget.c +p" > /sys/kernel/debug/dynamic_debug/control

# 打开一个模块所有动态打印语句
$ echo "moudle dwc3 +p" > /sys/kernel/debug/dynamic_debug/control

# 打开一个函数中所有的动态打印语句
$ echo "func svc_process +p" > /sys/kernel/debug/dynamic_debug/control

# 打开文件路径中包含 usb 的文件里所有的动态打印语句
echo -n "*usb* +p" > /sys/kernel/debug/dynamic_debug/control

上面是打开动态打印语句的例子，除了能打印 pr_debug() / dev_dbg() 函数中定义的输出外，还能打印一些额外信息，例如函数名、行号、模块名字和线程 ID 等。

参数：

  • p：打开动态打印语句。
  • f：打印函数名
  • l：打印行号
  • m：打印模块名字
  • t：打印线程 ID

另外，还可以在各个子系统的 Makefile 中添加 ccflags 来打开动态输出语句：

1
2
3
Makefile：
ccflags-y += -DDEBUG
ccflags-y += -DVERBOSE_DEBUG
Linux > 性能优化/调试
#Linux #性能优化/调试
Linux 调试之动态打印
http://example.com/2024/08/08/动态打印/
作者
Yu xin
发布于
2024年8月8日
许可协议