4. printf调试法：内核态打印函数、日志级别控制、动态打印开关、性能开销分析
说到调试，很多工程师第一反应就是上JTAG、用trace工具。但说实话，在我十几年的QNX开发经历中，printf调试法反而是用得最多、最顺手的手段。别笑，这招虽然“土”，但往往最管用。
你想想看，内核态出了问题，系统可能直接就panic了。这时候你连用户态的程序都跑不起来，更别说那些花哨的调试工具了。而printf，只要串口还能输出，你就能看到问题在哪。
4.1 内核态打印函数：你的“眼睛”
QNX内核态下，你不能用标准的printf。原因很简单——printf依赖文件系统，而内核态下文件系统可能还没初始化。我刚开始做驱动时就在这上面栽过跟头，打印死活不出来，还以为是代码没执行到。
内核态下，我们用的是这几个函数：
| 函数 | 说明 | 使用场景 |
|---|---|---|
kprintf() |
内核态标准打印 | 通用调试，最常用 |
kerrprintf() |
错误级别打印 | 异常情况、错误处理 |
slogf() |
系统日志输出 | 需要持久化记录时 |
vwarn() |
带警告信息的打印 | 非致命但需要注意的情况 |
我个人习惯是，调试阶段全用kprintf。它直接往串口写，不经过任何中间层，可靠性最高。但要注意，kprintf是同步的，也就是说它会阻塞当前执行流直到数据写完。这在中断上下文里用要格外小心。
4.2 日志级别控制：别让打印淹没了你
调试初期，你可能到处都加打印。但等到问题定位完，这些打印就成了累赘——不仅刷屏，还影响性能。这时候就需要日志级别控制了。
QNX的日志级别通常这样定义：
#define LOG_EMERG 0 // 系统不可用
#define LOG_ALERT 1 // 必须立即处理
#define LOG_CRIT 2 // 严重错误
#define LOG_ERR 3 // 错误
#define LOG_WARNING 4 // 警告
#define LOG_NOTICE 5 // 正常但重要
#define LOG_INFO 6 // 信息
#define LOG_DEBUG 7 // 调试信息我一般这样封装：
#define DEBUG_LEVEL 4 // 编译时控制
#define DBG_PRINT(level, fmt, ...) \
do { \
if (level <= DEBUG_LEVEL) { \
kprintf("[%s:%d] " fmt, __func__, __LINE__, ##__VA_ARGS__); \
} \
} while(0)这样，发布版本时把DEBUG_LEVEL设成3或更低，调试信息就全没了。嗯，这里要注意：别在生产版本里留大量打印，我见过有人把LOG_DEBUG级别的打印留在驱动里，结果产品上线后串口被刷爆，CPU占用率飙升到80%。
4.3 动态打印开关：运行时控制的艺术
编译时控制日志级别有个问题——你得重新编译。有时候问题只在特定场景下出现，你不可能每次都重新编译烧写。这时候就需要动态打印开关了。
QNX下实现动态打印，我常用的方法是利用syspage或共享内存：
// 驱动初始化时注册一个调试接口
int drv_debug_level = 3; // 默认级别
// 通过devctl或ioctl动态修改
int set_debug_level(int level) {
if (level < 0 || level > 7) {
return -EINVAL;
}
drv_debug_level = level;
return 0;
}
// 打印时检查级别
#define DPRINT(level, fmt, ...) \
do { \
if (level <= drv_debug_level) { \
kprintf("[DRV] " fmt, ##__VA_ARGS__); \
} \
} while(0)我曾经在一个网络驱动里用这个办法调试一个间歇性丢包的问题。白天正常跑，晚上流量高峰才出现。我通过远程登录修改调试级别，逐步缩小范围，最后定位到是DMA描述符回收逻辑有bug。要是没有动态开关，我估计得熬好几个通宵。
/proc/driver/mydev/debug，写个0就关掉所有打印，写个7就全开。这样调试时echo一下就行，连代码都不用改。
4.4 性能开销分析：printf不是免费的
很多人觉得printf就是打印几个字符，能有多大开销？说实话，我以前也这么想，直到有一次被性能问题折磨得够呛。
咱们来算笔账：
| 操作 | 耗时（典型值） | 说明 |
|---|---|---|
| kprintf（串口输出） | ~100-500 μs | 取决于串口波特率，115200bps下约100μs/字符 |
| slogf（异步日志） | ~10-50 μs | 写入环形缓冲区，不阻塞调用者 |
| 内存拷贝（1KB） | ~1-2 μs | 对比用，感受一下差距 |
你看，一次kprintf可能耗时几百微秒。如果你的驱动在关键路径上每秒调用1000次，那就是几百毫秒的开销——这还没算格式化字符串的时间。
我建议你记住这几条原则：
- 中断上下文里绝对不要用kprintf——除非你确定中断频率很低
- 热路径（hot path）上慎用打印——比如每收到一个包就打印一次
- 用slogf替代kprintf做常规日志——异步方式对性能影响小得多
- 发布版本前清理所有调试打印——或者用条件编译彻底关掉
我的经验：曾经有个音频驱动，播放时总有咔嗒声。查了三天，最后发现是调试打印导致的——每次DMA中断都打印一次，打印耗时比中断处理本身还长，导致下一个中断被延迟处理。关掉打印后，问题立刻消失。从那以后，我养成了一个习惯：调试时用打印，定位后立刻删掉或注释掉。
4.5 实战建议：怎么用好printf调试
说了这么多，总结几条我自己的经验：
- 先确认串口能输出——很多新手上来就加kprintf，结果串口根本没配置好，打印全丢了
- 加打印时带上上下文信息——函数名、行号、关键变量值，不然你都不知道打印从哪来的
- 用统一的打印格式——比如
[DRV_NAME] [LEVEL] message，方便grep过滤 - 善用条件打印——只在特定条件下打印，比如错误码非零时才输出
- 别忘了关掉——调试完记得清理，不然上线后就是性能炸弹
说白了，printf调试法就是给你一双眼睛，让你能看到内核里发生了什么。它不高级，但很实用。配合上动态开关和级别控制，你就能在运行时灵活地“看”到你想看的信息，而不会被打死的信息淹没。
下一章我会讲怎么用QNX的tracelogger做更高级的追踪分析，到时候你会看到，printf和tracelogger配合使用，效果1+1>2。