调试基础:printk与动态调试

内核调试这事儿,说白了就是跟黑盒子打交道。你写了个驱动,加载进去,系统没反应,或者直接崩了——这时候你怎么办?我刚开始做驱动开发时,第一反应就是加printk。别笑,这招虽然土,但确实管用。

printk:内核的printf

printk跟用户空间的printf很像,但有个关键区别——它带日志级别。为什么要分级?你想想看,生产环境下一堆调试信息刷屏,那不乱套了?

// 最基本的用法
printk(KERN_INFO "Hello, driver world!\n");

// 或者用更简洁的写法
pr_info("Hello, driver world!\n");

我个人习惯用pr_xxx系列宏,少打几个字,代码也干净。内核提供了这些级别:

宏定义 数字值 含义
KERN_EMERG 0 紧急事件,系统不可用
KERN_ALERT 1 必须立即处理
KERN_CRIT 2 严重条件
KERN_ERR 3 错误条件
KERN_WARNING 4 警告条件
KERN_NOTICE 5 正常但重要
KERN_INFO 6 信息性消息
KERN_DEBUG 7 调试级别消息

关键点:数字越小,优先级越高。默认情况下,只有级别低于console_loglevel的消息才会打印到控制台。

控制台日志级别

你可以在运行时调整控制台日志级别。我在项目中遇到过一个问题——驱动加载时一堆调试信息刷屏,把关键的错误信息给淹没了。后来怎么解决的?调整日志级别。

// 查看当前控制台日志级别
cat /proc/sys/kernel/printk

// 输出示例:7 4 1 7
// 分别对应:console_loglevel, default_message_loglevel, minimum_console_loglevel, default_console_loglevel

// 临时调整(只打印KERN_WARNING及以上级别)
echo "4 4 1 7" > /proc/sys/kernel/printk

嗯,这里要注意:/proc/sys/kernel/printk里的四个数字,第一个最重要——它决定了哪些级别的消息能显示在控制台上。数字越小,显示的消息越少。

动态调试:printk的进阶玩法

printk有个硬伤——你加了太多调试信息,生产环境里性能会受影响。不加吧,出了问题又抓瞎。动态调试就是来解决这个矛盾的。

说白了,动态调试让你能在运行时开关特定的调试信息,不用重新编译内核。我当年调试一个USB驱动时,这功能救了我一命。

启用动态调试:编译内核时需要开启CONFIG_DYNAMIC_DEBUG。大多数发行版内核默认都开了,但嵌入式系统不一定。

// 在驱动中使用动态调试
pr_debug("dma transfer completed, status: %d\n", status);
dev_dbg(&pdev->dev, "probe called for device %s\n", dev_name(&pdev->dev));

// 运行时控制
// 开启某个文件的调试信息
echo "file drivers/usb/core/hub.c +p" > /sys/kernel/debug/dynamic_debug/control

// 开启某个函数的调试信息
echo "func hub_probe +p" > /sys/kernel/debug/dynamic_debug/control

// 开启某个模块的所有调试信息
echo "module usbcore +p" > /sys/kernel/debug/dynamic_debug/control

// 关闭调试信息(把+p换成-p)
echo "file drivers/usb/core/hub.c -p" > /sys/kernel/debug/dynamic_debug/control

我曾经踩过的坑:动态调试依赖debugfs文件系统。如果你没挂载debugfs,/sys/kernel/debug/目录是空的。记得先执行:mount -t debugfs none /sys/kernel/debug

查看所有可用的动态调试点

你可能会问:我怎么知道哪些地方加了pr_debug?好问题。你可以这样查:

// 查看所有动态调试点(数量可能很大)
cat /sys/kernel/debug/dynamic_debug/control

// 按模块过滤
cat /sys/kernel/debug/dynamic_debug/control | grep "module usbcore"

// 按文件过滤
cat /sys/kernel/debug/dynamic_debug/control | grep "drivers/usb"

输出格式大概是这样的:

drivers/usb/core/hub.c:123 [usbcore]hub_probe =_ "probe called for device %s\012"
drivers/usb/core/hub.c:456 [usbcore]hub_port_connect_change =_ "port %d connect change\012"

每一行代表一个调试点。格式是:文件名:行号 [模块名]函数名 =标志位 "格式化字符串"。标志位里的=_表示当前是关闭状态,=p表示开启状态。

printk的注意事项

用printk有几个坑,我帮你列一下:

  • 不要加换行符?不,一定要加!printk不会自动加换行,不加的话多条消息会粘在一起。
  • 格式说明符:内核里不能用%f(浮点数),内核态浮点运算是大忌。
  • 性能影响:printk是同步的,会阻塞调用者。高频调用时影响很大。我见过一个网卡驱动,在数据路径上加了printk,吞吐量直接掉到十分之一。
  • 日志缓冲区:默认是16KB,满了会覆盖旧消息。可以用dmesg查看完整日志。

我的建议:开发阶段用pr_debug配合动态调试,生产环境默认关闭。出了问题再远程打开相关模块的调试信息。这样既不影响性能,又能快速定位问题。

实战小技巧

最后分享几个我常用的技巧:

  1. 给调试信息加标签:比如pr_debug("[my_driver] irq handler called\n"),方便grep过滤。
  2. 用dev_dbg代替pr_debug:dev_dbg会打印设备名,多设备时更容易区分。
  3. rate-limited printk:pr_err_ratelimited()防止高频消息刷爆日志。
  4. hex dump:print_hex_dump()打印二进制数据,调试协议时特别有用。

好了,printk和动态调试就讲这么多。说白了,这是内核调试的入门功夫,但也是最实用的。下一章我们聊聊怎么用ftrace跟踪内核函数调用——那才是真正的高级玩法。