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 实战:组合使用
实际项目中,我通常这样组合使用:
- 开发阶段:用
pr_debug和dev_dbg写满调试信息,日志级别用 KERN_DEBUG - 测试阶段:通过动态打印只打开关注的函数,避免刷屏
- 发布阶段:保留
pr_debug,但默认关闭。客户出问题时,远程打开动态打印收集信息
我曾经帮一个客户排查存储驱动问题。设备在客户现场,我远程登录后,用动态打印只打开了 IO 路径上的几个函数。几分钟就定位到是 DMA 对齐问题。要是没有动态打印,要么重新编译内核,要么加一堆 printk 再编译——想想就头大。
核心要点:printk 不是「低级工具」,而是调试的基石。格式化输出让你看清数据,日志级别让你控制噪音,动态打印让你精准打击。这三板斧用好了,大部分驱动问题都能搞定。
嗯,这一章就到这里。下一章咱们聊聊 dev_dbg 和 pr_debug 的进阶用法,以及如何用 trace_printk 做轻量级跟踪。到时候见。