2、printk实战技巧:格式化输出、调试开关、动态打印

printk 是内核调试的「瑞士军刀」。说实话,我见过不少工程师一上来就上 ftrace 或者 kprobe,结果连最基本的内核打印都没用好。我个人习惯是:先玩透 printk,再谈其他高级工具。这一章,咱们就把 printk 的十八般武艺掰开揉碎讲清楚。

2.1 格式化输出:不只是 printf

printk 的格式化语法和用户态 printf 很像,但有几个关键区别。你想想看,内核里没有浮点运算单元怎么办?地址打印用什么格式?这些坑我都踩过。

先看个基础例子:

// 最常用的几种格式
printk("pid = %d, name = %s\n", current->pid, current->comm);
printk("物理地址 = %llx\n", (unsigned long long)phys_addr);
printk("内核指针 = %p\n", ptr);

这里有个细节:%p 默认会打印哈希值,不是真实地址。这是内核的安全机制。我在项目中遇到过,调试时死活看不到真实地址,后来才发现是 %p 被「保护」了。

避坑指南:想打印真实地址,用 %px 或者 %pK。但注意,生产环境千万别用 %px,会泄露内核布局。

常用的格式化扩展符:

格式符 含义 示例
%p 指针(哈希后) 00000000abcdef12
%px 真实指针 ffff888012345678
%pK 根据权限打印 取决于 kptr_restrict
%pI4 IPv4 地址 192.168.1.1
%pI6 IPv6 地址 ::1
%pM MAC 地址 00:11:22:33:44:55
%pD dentry 名称 /home/user/file

嗯,这里要注意:打印结构体字段时,尽量用 %p 系列扩展符。比如打印 struct sk_buff 的 MAC 地址,用 %pM 比手动拼格式优雅得多。

2.2 调试开关:用日志级别控制输出

printk 有 8 个日志级别,从 KERN_EMERG 到 KERN_DEBUG。说白了,就是给每条打印贴个「紧急程度」标签。内核根据 console_loglevel 决定哪些打印能上控制台。

// 日志级别定义
#define KERN_EMERG    "<0>"  // 系统崩溃
#define KERN_ALERT    "<1>"  // 必须立即处理
#define KERN_CRIT     "<2>"  // 严重错误
#define KERN_ERR      "<3>"  // 错误
#define KERN_WARNING  "<4>"  // 警告
#define KERN_NOTICE   "<5>"  // 正常但重要
#define KERN_INFO     "<6>"  // 信息
#define KERN_DEBUG    "<7>"  // 调试信息

我调试驱动时,习惯这样用:

// 调试信息用 KERN_DEBUG,上线前关掉
printk(KERN_DEBUG "my_driver: irq happened, status=0x%x\n", status);

// 错误信息用 KERN_ERR,永远显示
printk(KERN_ERR "my_driver: DMA transfer failed!\n");

小技巧:调试阶段把 console_loglevel 设成 8,所有打印都能看到。命令:echo 8 > /proc/sys/kernel/printk。生产环境设成 4,只显示警告以上。

我曾经在调试网卡驱动时,打印太多导致系统响应变慢。后来用日志级别区分,调试信息只写 KERN_DEBUG,配合 dmesg 查看,问题就解决了。

2.3 动态打印:调试的终极武器

动态打印(dyndbg)是 printk 的「进化版」。它允许你在不重新编译内核的情况下,动态开关某段代码的打印。你想想看,这有多方便?

首先,驱动代码里要声明动态打印:

// 在驱动中定义动态打印
#define pr_fmt(fmt) KBUILD_MODNAME ": " fmt
#include <linux/printk.h>

// 使用 pr_debug() 或 dev_dbg()
pr_debug("enter function, arg=%d\n", arg);
dev_dbg(&pdev->dev, "probe success, irq=%d\n", irq);

然后,通过 /sys/kernel/debug/dynamic_debug/control 控制:

# 查看所有动态打印点
cat /sys/kernel/debug/dynamic_debug/control

# 打开 my_driver 模块的所有打印
echo "module my_driver +p" > /sys/kernel/debug/dynamic_debug/control

# 只打开某个函数的打印
echo "func my_function +p" > /sys/kernel/debug/dynamic_debug/control

# 按行号打开
echo "file my_driver.c line 123 +p" > /sys/kernel/debug/dynamic_debug/control

注意:动态打印依赖 CONFIG_DYNAMIC_DEBUG 内核配置。我遇到过客户说「动态打印不生效」,结果一查,内核没开这个选项。编译内核时记得勾上。

动态打印的匹配规则很灵活:

  • module:按模块名匹配
  • func:按函数名匹配
  • file:按源文件名匹配
  • line:按行号匹配
  • format:按打印格式字符串匹配

举个例子,我只想看到 my_driver 中中断处理函数的打印:

echo "module my_driver func my_irq_handler +p" > /sys/kernel/debug/dynamic_debug/control

这样就不会被其他函数的打印干扰。我在调试 USB 驱动时,就用这招精准定位问题,效率提升不少。

2.4 实战:组合使用

实际项目中,我通常这样组合使用:

  1. 开发阶段:用 pr_debugdev_dbg 写满调试信息,日志级别用 KERN_DEBUG
  2. 测试阶段:通过动态打印只打开关注的函数,避免刷屏
  3. 发布阶段:保留 pr_debug,但默认关闭。客户出问题时,远程打开动态打印收集信息

我曾经帮一个客户排查存储驱动问题。设备在客户现场,我远程登录后,用动态打印只打开了 IO 路径上的几个函数。几分钟就定位到是 DMA 对齐问题。要是没有动态打印,要么重新编译内核,要么加一堆 printk 再编译——想想就头大。

核心要点:printk 不是「低级工具」,而是调试的基石。格式化输出让你看清数据,日志级别让你控制噪音,动态打印让你精准打击。这三板斧用好了,大部分驱动问题都能搞定。

嗯,这一章就到这里。下一章咱们聊聊 dev_dbgpr_debug 的进阶用法,以及如何用 trace_printk 做轻量级跟踪。到时候见。