📚 课程目录第3章 printk高级用法

3. printk 高级用法：格式化输出、动态调试与封装宏

printk 是内核中最基础的日志输出接口，但它的能力远不止简单的字符串打印。掌握格式化输出的控制、动态调试的开关机制以及 pr_debug / pr_info 等封装宏的语义差异，是高效定位内核问题的关键。本节从这三个维度展开，帮助你构建生产环境可用的日志调试体系。

3.1 格式化输出：从基础到进阶

printk 的格式化语法与标准 C 库 printf 高度兼容，但增加了内核特有的格式说明符，用于直接输出指针、MAC 地址、IP 地址、资源大小等内核数据类型。

3.1.1 常用格式说明符速查

格式符	用途	示例输出
`%d` / `%u`	有符号 / 无符号十进制整数	`-123` / `456`
`%x` / `%X`	十六进制小写 / 大写	`1a2b` / `1A2B`
`%p`	指针地址（自动省略前导零）	`ffff888012345678`
`%pK`	安全指针（根据 kptr_restrict 隐藏）	`0000000000000000`（受限时）
`%pM`	MAC 地址（6 字节，冒号分隔）	`00:1a:2b:3c:4d:5e`
`%pI4`	IPv4 地址（点分十进制）	`192.168.1.1`
`%pI6`	IPv6 地址（冒号十六进制）	`fe80::1`
`%pE`	转义字符串（不可打印字符转义）	`hello\tworld`
`%ph`	小端序十六进制缓冲区（最多 64 字节）	`01 02 03 04 ...`
`%pV`	struct va_format 格式化	可变参数格式化

安全提示： 在公开日志中输出内核指针时，务必使用 %pK 而非 %p。通过 /proc/sys/kernel/kptr_restrict 控制指针可见性：0 表示全部可见，1 表示仅特权进程可见，2 表示全部隐藏。

3.1.2 日志级别与输出控制

printk 通过日志级别宏控制消息的紧急程度，级别越低（数值越小）越紧急。系统根据 console_loglevel 决定哪些级别的消息可以输出到控制台。

宏名称	数值	含义	典型场景
`KERN_EMERG`	0	紧急事件	系统崩溃前
`KERN_ALERT`	1	必须立即处理	严重硬件故障
`KERN_CRIT`	2	临界条件	驱动初始化失败
`KERN_ERR`	3	错误条件	I/O 操作失败
`KERN_WARNING`	4	警告	资源不足
`KERN_NOTICE`	5	正常但重要	模块加载/卸载
`KERN_INFO`	6	信息	驱动版本信息
`KERN_DEBUG`	7	调试信息	开发阶段日志

// 带级别的 printk 示例
printk(KERN_ERR "my_driver: DMA transfer failed at offset %llx\n", offset);
printk(KERN_INFO "my_driver: version %s loaded\n", DRV_VERSION);
printk(KERN_DEBUG "my_driver: register value = 0x%08x\n", readl(reg));

3.2 动态调试（Dynamic Debug）

动态调试是内核提供的一种零开销的日志开关机制。它允许在运行时按模块、文件、函数、行号精确控制 pr_debug() 和 dev_dbg() 的输出，无需重新编译内核或模块。

3.2.1 核心原理

动态调试在编译时通过 CC_FLAGS_FTRACE 在 pr_debug 调用点插入 jump_label 或 dynamic_printk 桩。默认情况下这些桩处于关闭状态，仅消耗一条 NOP 指令的开销。通过 debugfs 接口写入匹配规则后，内核会动态修改桩代码为有效分支，激活日志输出。

3.2.2 控制接口与匹配语法

动态调试的控制文件位于 /sys/kernel/debug/dynamic_debug/control。写入规则时使用以下匹配字段：

字段	含义	示例
`module`	模块名	`module my_driver`
`file`	源文件名（支持通配符）	`file usb`
`func`	函数名	`func probe`
`line`	行号或范围	`line 123` 或 `line 100-200`
`format`	格式化字符串匹配	`format "DMA"`

# 启用 my_driver 模块中所有 pr_debug
echo "module my_driver +p" > /sys/kernel/debug/dynamic_debug/control

# 启用 usb 相关文件中 probe 函数的调试输出
echo "file *usb* func probe +p" > /sys/kernel/debug/dynamic_debug/control

# 启用特定行范围的调试输出
echo "file my_driver.c line 100-200 +p" > /sys/kernel/debug/dynamic_debug/control

# 禁用所有调试输出
echo "module my_driver -p" > /sys/kernel/debug/dynamic_debug/control

注意事项： 动态调试仅对使用 pr_debug()、dev_dbg()、netdev_dbg() 等宏的代码生效。直接使用 printk(KERN_DEBUG ...) 的调用点不受动态调试控制，且始终有运行时开销。

3.2.3 查询已注册的调试点

# 查看所有可用的动态调试点
cat /sys/kernel/debug/dynamic_debug/control

# 过滤查看 my_driver 模块的调试点
grep my_driver /sys/kernel/debug/dynamic_debug/control

# 输出示例（每行一个调试点）
# drivers/net/my_driver.c:123 [my_driver]my_probe =_ "Probing device %s\012"
# drivers/net/my_driver.c:145 [my_driver]my_probe =_ "IRQ number %d\012"

3.3 封装宏：pr_debug、pr_info 与 dev_dbg 系列

内核提供了一系列封装宏，统一了日志级别、格式规范和调试开关。正确选择这些宏可以提升代码可读性、可维护性和调试灵活性。

3.3.1 通用 pr_* 宏族

宏	对应级别	编译时是否可移除	动态调试支持
`pr_emerg()`	KERN_EMERG	否	否
`pr_alert()`	KERN_ALERT	否	否
`pr_crit()`	KERN_CRIT	否	否
`pr_err()`	KERN_ERR	否	否
`pr_warn()`	KERN_WARNING	否	否
`pr_notice()`	KERN_NOTICE	否	否
`pr_info()`	KERN_INFO	否	否
`pr_debug()`	KERN_DEBUG	是（`#ifdef DEBUG`）	是
`pr_cont()`	延续上一行	否	否

3.3.2 设备相关 dev_* 宏族

dev_dbg()、dev_info()、dev_err() 等宏自动在输出中包含设备名称，便于在多设备驱动中区分日志来源。

// 使用 dev_* 宏自动输出设备名
struct device *dev = &pdev->dev;

dev_info(dev, "Device initialized at MMIO 0x%llx\n", res->start);
dev_err(dev, "Failed to request IRQ %d\n", irq);
dev_dbg(dev, "Register dump: status=0x%08x ctrl=0x%08x\n",
        readl(priv->base + STATUS_REG),
        readl(priv->base + CTRL_REG));

3.3.3 编译时控制与动态调试的协同

pr_debug() 和 dev_dbg() 在编译时受 DEBUG 宏和 CONFIG_DYNAMIC_DEBUG 控制：

未定义 DEBUG 且未开启 CONFIG_DYNAMIC_DEBUG：pr_debug() 被编译为空，零开销。
定义了 DEBUG 但未开启 CONFIG_DYNAMIC_DEBUG：pr_debug() 展开为 printk(KERN_DEBUG ...)，始终输出。
开启了 CONFIG_DYNAMIC_DEBUG：无论是否定义 DEBUG，pr_debug() 都注册为动态调试点，默认关闭，可通过 debugfs 运行时开启。

  最佳实践： 在驱动开发中统一使用 dev_dbg() 替代 printk(KERN_DEBUG ...)，并确保内核开启了 CONFIG_DYNAMIC_DEBUG。这样既能在开发阶段通过 #define DEBUG 临时开启所有调试输出，又能在生产环境中按需动态激活特定调试点，无需重新编译。

3.3.4 自定义封装宏示例

对于复杂驱动，可以基于 dev_dbg 构建带前缀或条件控制的封装宏：

#define MY_DRV_NAME "mydrv"

#define my_dbg(dev, fmt, ...) \
    dev_dbg(dev, MY_DRV_NAME ": " fmt, ##__VA_ARGS__)

#define my_err(dev, fmt, ...) \
    dev_err(dev, MY_DRV_NAME " ERROR: " fmt, ##__VA_ARGS__)

// 使用示例
my_dbg(dev, "TX descriptor ring at %pad\n", &priv->tx_ring_dma);
my_err(dev, "DMA mapping failed for RX buffer %d\n", i);

3.4 实践建议与常见陷阱

避免在热路径中使用高开销格式符：%pM、%pI4 等格式符涉及内存拷贝和格式化，在中断上下文或高频调用点应谨慎使用。
日志缓冲区溢出：printk 环形缓冲区默认大小为 4 个页面（16KB 典型值），大量调试输出可能导致早期日志被覆盖。通过 log_buf_len 内核参数增大缓冲区。
rate-limited printk：对于可能高频触发的错误路径，使用 pr_err_ratelimited() 或 dev_err_ratelimited() 防止日志风暴。
动态调试与 ftrace 的冲突：同时开启动态调试和 ftrace 时，注意 jump_label 资源的竞争，建议在调试时只启用一种机制。

// 限速打印示例：防止中断风暴淹没日志
if (time_after(jiffies, priv->last_err_jiffies + HZ)) {
    dev_err_ratelimited(dev, "SPI transfer timeout\n");
    priv->last_err_jiffies = jiffies;
}