第二讲：printk调试技巧——日志级别、动态调试、trace_printk与缓冲区管理
大家好，欢迎来到驱动调试的第二讲。今天咱们聊聊printk。
printk，说白了就是内核版的printf。很多新手觉得它太简单，不就是打印信息吗？但我在实际项目中踩过不少坑，才发现用好printk其实是个技术活。日志级别设不对，系统可能直接卡死；缓冲区管理不好，关键信息说丢就丢。嗯，今天我就把这些经验掰开揉碎了讲给你听。
2.1 printk日志级别：你的信息该有多紧急？
printk和printf最大的区别，就是它带了一个日志级别。这个级别决定了这条消息会不会出现在控制台上，以及它有多“紧急”。
内核定义了8个级别，从0到7，数字越小越紧急：
| 宏定义 | 数值 | 含义 | 典型场景 |
|---|---|---|---|
| KERN_EMERG | 0 | 紧急事件 | 系统崩溃前最后一句话 |
| KERN_ALERT | 1 | 必须立即处理 | 硬件故障报警 |
| KERN_CRIT | 2 | 严重条件 | 驱动初始化失败 |
| KERN_ERR | 3 | 错误条件 | DMA传输超时 |
| KERN_WARNING | 4 | 警告 | 寄存器值异常 |
| KERN_NOTICE | 5 | 正常但重要 | 设备热插拔事件 |
| KERN_INFO | 6 | 信息 | 驱动版本号打印 |
| KERN_DEBUG | 7 | 调试信息 | 变量值跟踪 |
你可能会问：级别设错了会怎样？
我举个例子。有一次我在调试一个USB驱动，为了跟踪中断频率，在中断处理函数里加了printk(KERN_INFO ...)。结果呢？控制台疯狂输出，系统响应变得极慢，最后直接hung住了。原因很简单——中断上下文里频繁调用printk，而且级别设得太低，导致大量信息冲刷控制台。
控制台默认只显示级别小于console_loglevel的消息。这个值可以通过/proc/sys/kernel/printk查看和修改。文件里有4个数字，第一个就是控制台日志级别。我习惯在调试时把它设为8，这样所有信息都能看到：
# 查看当前设置
cat /proc/sys/kernel/printk
# 输出示例：4 4 1 7
# 临时修改为显示所有级别
echo 8 > /proc/sys/kernel/printk2.2 动态调试（Dynamic Debug）：按需开启，精准定位
printk有个硬伤：一旦编译进内核，不管用不用，它都在那里。调试信息太多影响性能，太少又查不到问题。动态调试就是来解决这个矛盾的。
动态调试允许你在运行时动态开启或关闭某个文件、某个函数、甚至某一行代码的printk输出。前提是编译内核时开启了CONFIG_DYNAMIC_DEBUG。
我个人非常喜欢这个功能。以前调试一个网络驱动，怀疑某个函数有问题，但又不想重新编译整个内核。用动态调试，几秒钟就搞定了。
基本用法是通过debugfs控制：
# 挂载debugfs
mount -t debugfs none /sys/kernel/debug
# 查看所有动态调试点
cat /sys/kernel/debug/dynamic_debug/control
# 开启某个文件的全部调试信息
echo "file mydriver.c +p" > /sys/kernel/debug/dynamic_debug/control
# 开启某个函数的调试信息
echo "func my_function +p" > /sys/kernel/debug/dynamic_debug/control
# 开启某一行
echo "file mydriver.c line 123 +p" > /sys/kernel/debug/dynamic_debug/control
# 关闭调试
echo "file mydriver.c -p" > /sys/kernel/debug/dynamic_debug/control这里有个关键点：你的驱动代码里必须使用pr_debug()、dev_dbg()这类宏，而不是直接printk。这些宏在动态调试关闭时，编译后不产生任何代码，零开销。
我曾经遇到一个场景：一个I2C驱动在特定条件下会卡死，但正常运行时没问题。我怀疑是某个错误处理路径有问题。用动态调试只开启了那个错误处理函数的pr_debug，然后复现问题。结果很快就定位到了——一个空指针解引用。如果没有动态调试，我可能要在代码里加一堆printk，然后重新编译、烧录、复现，来回折腾好几轮。
2.3 trace_printk：比printk更轻量，比ftrace更灵活
printk再轻量，在频繁调用的路径上也是负担。比如调度器、网络收发包路径，用printk会严重影响性能。这时候就该trace_printk出场了。
trace_printk是ftrace框架提供的一个轻量级打印函数。它把信息写入内核的trace buffer，而不是直接输出到控制台或日志文件。写入速度极快，对系统性能影响极小。
用法很简单：
#include <linux/trace_seq.h>
trace_printk("irq_handler: irq=%d, status=0x%x\n", irq, status);查看输出需要读取trace文件：
# 挂载tracefs
mount -t tracefs none /sys/kernel/tracing
# 查看trace_printk输出
cat /sys/kernel/tracing/trace
# 也可以只查看trace_printk相关的条目
cat /sys/kernel/tracing/trace_pipeprintk事件类型中。你可以用grep过滤，或者用trace-cmd工具更优雅地查看。我个人习惯用trace-cmd record -e printk录制，然后用trace-cmd report分析。
trace_printk最大的优势是低延迟。我在调试一个高速网卡驱动时，需要在每个数据包的处理路径上打印一些信息。用printk直接导致吞吐量下降50%以上，换成trace_printk后，性能损失几乎可以忽略不计。
但要注意，trace_printk也不是完全没有开销。它仍然会触发一次trace事件记录，在极端高频的场景下（比如每微秒触发一次），还是会有影响。不过对于绝大多数驱动调试场景，它已经足够轻量了。
2.4 日志缓冲区管理：别让关键信息丢了
printk的输出最终会写入内核的日志缓冲区（log buffer）。这个缓冲区是一个环形缓冲区，大小固定。如果写入速度超过读取速度，旧的信息会被覆盖。
默认的缓冲区大小通常是4个页面（16KB on 4K页系统），或者通过CONFIG_LOG_BUF_SHIFT配置。你可以通过dmesg命令查看缓冲区内容。
这里有个坑：系统崩溃时，最后几条printk信息可能还没来得及写入磁盘，就随着内存一起丢失了。这就是为什么有时候看/var/log/messages找不到崩溃原因。
kdump抓了crash dump，才发现死锁前最后一条printk是“尝试获取锁A”，但之后就没有然后了——因为获取锁B失败，系统卡死，缓冲区里的后续信息根本没来得及输出。
如何管理好日志缓冲区？我有几个建议：
- 增大缓冲区：通过内核启动参数
log_buf_len=4M，把缓冲区扩大到4MB。这样能保留更多历史信息。 - 使用pstore/ramoops：在内存中保留一块独立的区域用于存储崩溃前后的日志。即使系统崩溃，重启后还能读取到。
- 控制打印频率：在循环或中断中加
printk_ratelimit()限制，避免缓冲区被无意义的信息填满。 - 区分调试日志和错误日志：调试信息用pr_debug，错误信息用pr_err。这样生产环境可以只保留错误日志。
代码示例：使用限速打印
if (printk_ratelimit()) {
pr_err("mydev: DMA timeout, status=0x%x\n", status);
}默认限速是5秒内最多10条消息。你可以通过/proc/sys/kernel/printk_ratelimit和printk_ratelimit_burst调整。
知识体系总览
下面这张图总结了printk调试的核心知识结构，我建议你保存下来，以后调试时对照着看：
好了，关于printk调试的核心技巧就讲到这里。日志级别让你控制信息的“音量”，动态调试让你精准“点射”，trace_printk帮你“偷窥”高频路径，缓冲区管理确保关键信息不丢失。这四个维度配合使用，大部分驱动调试问题都能搞定。
记住一点：调试信息是给开发者看的，不是给用户看的。发布驱动前，记得清理不必要的printk，或者用动态调试控制好开关。这是专业驱动开发者的基本素养。
可可精品资料库