3. printk 实践：格式化输出、动态调试与日志缓冲区管理

printk 是内核态最基础的调试输出手段，但若使用不当，轻则日志淹没关键信息，重则导致系统实时性劣化甚至死锁。本节从格式化规范、动态调试开关到缓冲区管理，构建一套可运用于生产环境的 printk 实践体系。

3.1 格式化输出：规范与陷阱

printk 的格式化语法与标准 C 库 printf 基本一致，但内核环境存在若干特殊规则和限制。

3.1.1 常用格式说明符

3.1.2 日志级别与输出控制

printk 通过日志级别宏控制消息的紧急程度，级别低于 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>"   // 调试消息

// 使用示例
printk(KERN_ERR "DMA transfer failed, status = 0x%x\n", status);
printk(KERN_INFO "eth0: link up at 1000Mbps\n");

3.2 动态调试 (dynamic_debug)：按需开关的打印探针

dynamic_debug 是内核提供的一种运行时控制 printk 输出的机制，允许在不重新编译内核或模块的情况下，按文件、函数、行号或模块名动态启用/禁用调试打印。

3.2.1 启用 dynamic_debug

内核配置需要开启 CONFIG_DYNAMIC_DEBUG，且代码中使用 pr_debug()、dev_dbg() 或 printk(KERN_DEBUG ...) 宏。

// 驱动代码示例：使用 pr_debug
#include <linux/printk.h>

void my_driver_irq_handler(void)
{
    int status = readl(reg_base + STATUS);
    pr_debug("irq handled, status = 0x%x\n", status);
    // 正常处理逻辑
}

3.2.2 运行时控制接口

通过 debugfs 文件系统接口 /sys/kernel/debug/dynamic_debug/control 进行控制。

3.2.3 dynamic_debug 工作流程

3.3 日志缓冲区管理：环形缓冲区与并发安全

内核日志缓冲区是一个固定大小的环形缓冲区（ring buffer），所有 printk 输出都写入其中。理解其管理机制，是避免日志丢失和性能劣化的前提。

3.3.1 环形缓冲区结构

3.3.2 并发写入与锁机制

printk 可能被多个 CPU 同时调用（中断上下文、tasklet、进程上下文），内核使用 logbuf_lock 自旋锁保护缓冲区操作。

// 内核 printk 核心写入路径（简化）
asmlinkage int vprintk_emit(int facility, int level,
                            const char *dict, size_t dictlen,
                            const char *fmt, va_list args)
{
    unsigned long flags;
    int printed_len;

    // 1. 格式化消息到临时缓冲区
    printed_len = vscnprintf(printk_buf, sizeof(printk_buf), fmt, args);

    // 2. 获取日志缓冲区锁
    raw_spin_lock_irqsave(&logbuf_lock, flags);

    // 3. 写入环形缓冲区
    log_output(facility, level, printk_buf, printed_len);

    // 4. 释放锁
    raw_spin_unlock_irqrestore(&logbuf_lock, flags);

    // 5. 唤醒控制台线程（如果必要）
    wake_up_klogd();

    return printed_len;
}

3.3.3 缓冲区溢出与日志丢失

当写入速度超过消费速度（如 dmesg 或 syslogd 读取不及时），环形缓冲区会覆盖最旧的日志。

3.3.4 缓冲区大小调整

通过内核配置参数调整日志缓冲区大小：

// 内核 .config 配置
CONFIG_LOG_BUF_SHIFT=18    // 2^18 = 256KB
CONFIG_LOG_BUF_SHIFT=20    // 2^20 = 1MB
CONFIG_LOG_BUF_SHIFT=21    // 2^21 = 2MB

// 内核启动参数（运行时覆盖）
log_buf_len=2M             // 设置为 2MB

3.4 实践案例：驱动热路径的 printk 优化

以下案例展示如何将本节知识综合应用于实际驱动调试场景。

// 优化前：热路径中无条件打印
void my_nic_rx_handler(struct sk_buff *skb)
{
    // 问题：每个包都打印，10Gbps 下每秒数百万次调用
    printk(KERN_INFO "rx packet, len=%u\n", skb->len);
    // 正常处理...
}

// 优化后：动态调试 + 限速 + 级别控制
void my_nic_rx_handler(struct sk_buff *skb)
{
    // 使用 pr_debug，默认关闭，通过 dynamic_debug 按需开启
    pr_debug("rx packet, len=%u\n", skb->len);
    
    // 错误路径使用 KERN_ERR，始终打印但限速
    if (unlikely(skb->len < ETH_HLEN)) {
        printk_ratelimited(KERN_ERR "rx: packet too short, len=%u\n", skb->len);
        dev_kfree_skb(skb);
        return;
    }
    // 正常处理...
}