Linux Kernel pr_debug(), dev_dbg() 以及动态调试

pr_err(), pr_info(), ... / dev_err(), dev_info(), ... 系列函数,在 pr_fmt / dev_fmt 的基础上,调用 vprintk_emit() 实现打印输出。但 pr_debug() / dev_dbg() 比较特殊,有不一样的代码路径。

文件:include/linux/printk.h

/* If you are writing a driver, please use dev_dbg instead */
#if defined(CONFIG_DYNAMIC_DEBUG) || \
        (defined(CONFIG_DYNAMIC_DEBUG_CORE) && defined(DYNAMIC_DEBUG_MODULE))
#include <linux/dynamic_debug.h>

/**
 * pr_debug - Print a debug-level message conditionally
 * @fmt: format string
 * @...: arguments for the format string
 *
 * This macro expands to dynamic_pr_debug() if CONFIG_DYNAMIC_DEBUG is
 * set. Otherwise, if DEBUG is defined, it's equivalent to a printk with
 * KERN_DEBUG loglevel. If DEBUG is not defined it does nothing.
 *
 * It uses pr_fmt() to generate the format string (dynamic_pr_debug() uses
 * pr_fmt() internally).
 */
#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

文件:include/linux/dev_printk.h

#if defined(CONFIG_DYNAMIC_DEBUG) || \
        (defined(CONFIG_DYNAMIC_DEBUG_CORE) && defined(DYNAMIC_DEBUG_MODULE))
#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

这里有三条路径:

  1. 如果开启编译选项 CONFIG_DYNAMIC_DEBUG,会进入 dynamic debug 功能(并且,这时某个模块是否开启 DEBUG,决定了这个模块里的 dynamic debug 是否默认使能);
  2. 如果开启编译选项 DEBUG 后,就跟其他的 pr_() / dev_() 函数一样(除了不同的 log level);
  3. 否则,就关闭 debug 打印;

这里要走读一下第一种情况:

dev_dbg
  dynamic_dev_dbg
    _dynamic_func_call(..., __dynamic_dev_dbg, ...)

pr_debug
  dynamic_pr_debug
    _dynamic_func_call(..., __dynamic_pr_debug, ...)

这两个函数在 lib/dynamic_debug.c 文件里实现,所以就走到了动态调试(dynamic debug)功能里。

动态调试(dynamic debug)

这个功能,由编译选项 CONFIG_DYNAMIC_DEBUG 控制。

开启以后,可以通过 <debugfs>/dynamic_debug/control 在运行时动态地打开或者关闭 pr_debug() / dev_dbg() 的打印输出:

mount -t debugfs none /proc/sys/debug
cd /proc/sys/debug/dynamic_debug

运行 cat control,可以显示所有 pr_debug / dev_dbg 的调用,以及每个调用当前的 debug print 的 flag。比如:

drivers/mmc/core/core.c:269 [mmc_core]mmc_mrq_pr_debug =p "<%s: starting CMD%u arg %08x flags %08x>\012"
drivers/mmc/core/core.c:275 [mmc_core]mmc_mrq_pr_debug =p "%s: starting %sCMD%u arg %08x flags %08x\012"
...
init/main.c:1414 [main]run_init_process =p "  with arguments:\012"
init/main.c:1416 [main]run_init_process =p "    %s\012"
...

每一行表示了一个调用的位置,按 filename:lineno [module]function flags format 的格式,依次是调用所在的文件、行号、所属内核模块、函数、控制 flag 以及格式化字符串。其中的 flag,如果是下划线,表示关闭打印;如果是 p 表示使能。目前可以使用的,包括:

p    enables the pr_debug() callsite.
_    enables no flags.

Decorator flags add to the message-prefix, in order:
t    Include thread ID, or <intr>
m    Include module name
f    Include the function name
s    Include the source file name
l    Include line number

使能和关闭某个打印:

echo "file a/b/c/xxx.c +p" > control
echo "file a/b/c/xxx.c =_" > control

除了 file 控制单个文件外,还有 func 来指定函数、module 指定模块、format 指定格式化字符串,等等。并且支持通配符,方便操作,比如:

echo "module xxx =p" > control
echo "func yyy +pfl" > control
echo "func zzz* =_" > control
echo "format \"string\" +pmfl" > control

bootargs

在为某个设备实现驱动的过程中,出于调试目的,如果每次这样调用 echo,还是有点麻烦的。这时,可以在 bootargs 里设置启动参数:

setenv bootargs ... <module>.dyndbg="+p"

这样,这个驱动模块的调试打印就打开了。

使用举例

比如在开发时,遇到 mmc 相关的问题,可以对 mmc_core 驱动模块进行调试和观察。

先看一下驱动模块里已经包含了哪些调试打印:

# cat control | grep mmc_core
drivers/mmc/core/core.c:269 [mmc_core]mmc_mrq_pr_debug =p "<%s: starting CMD%u arg %08x flags %08x>\012"
drivers/mmc/core/core.c:275 [mmc_core]mmc_mrq_pr_debug =p "%s: starting %sCMD%u arg %08x flags %08x\012"
...
drivers/mmc/core/host.c:269 [mmc_core]mmc_of_parse =_ "\042bus-width\042 property is missing, assuming 1 bit.\012"
...

mmc_core 模块的打印全部使能或者关闭:

echo "module mmc_core +p" > control
echo "module mmc_core =_" > control

针对某个函数:

echo "func mmc_mrq_pr_debug +p" > control

针对某个文件:

echo "file drivers/mmc/core/core.c +pfl" > control

针对某个文件的某些行:

echo "file drivers/mmc/core/core.c:200-400 +pmfl" > control

这样就可以在运行时通过动态地开关来观察打印和判断问题,而不是到处加打印、重新编译、安装内核并重启。而且,模块里已有调试打印的地方,通常是这个模块在开发和调试时最需要注意的一些关键位置,或者关键配置字段,相对于一边走读代码一边加打印,这样要有效率的多。

对比

通常系统的 printk 默认设置:

# cat /proc/sys/kernel/printk
4       4       1       7

实际使用中,需要定义 DEBUG 宏并重新编译;并且在运行时:

echo 8 >  /proc/sys/kernel/printk

这样才可以得到调试打印。

所以,也可以通过 /proc/sys/kernel/printk 设置 log level,但细度不一样,也不能像 dynamic debug 这样在运行时精确地控制文件、模块、函数甚至某一行。

参考资料

  • lib/dynamic_debug.c
  • include/linux/printk.h
  • include/linux/dev_printk.h
  • Documentation/admin-guide/dynamic-debug-howto.rst

Read More: