📚 课程目录第4章日志调试法

4. 日志调试法：串口日志输出、日志等级管理、环形缓冲区日志、时间戳记录

日志调试，说白了就是给嵌入式系统装一个“黑匣子”。

我刚开始做嵌入式那会儿，调试全靠LED灯闪烁和示波器。后来项目越来越复杂，一个Bug可能要跑几个小时才能复现，LED灯根本不够用。那时候我才意识到——没有日志，你就是在盲人摸象。

4.1 串口日志输出：最基础的调试手段

串口日志是最直接的方式。你只需要一个UART接口，一根USB转串口线，就能把设备内部的状态实时打印出来。

我个人习惯在开发阶段就把串口日志作为标配。哪怕量产时关掉，调试阶段也一定要有。

核心要点：串口日志的瓶颈在于打印速度。115200波特率下，每秒最多传输约11.5KB数据。如果日志量太大，会拖慢系统响应。

来看一个最简单的串口日志实现：

// 简易串口日志输出
void log_printf(const char *fmt, ...) {
    char buf[256];
    va_list args;
    va_start(args, fmt);
    vsnprintf(buf, sizeof(buf), fmt, args);
    va_end(args);
    
    // 阻塞式发送，简单但效率低
    for (char *p = buf; *p != '\0'; p++) {
        while (!(USART1->SR & USART_SR_TXE));
        USART1->DR = *p;
    }
}

这段代码能工作，但有个问题——vsnprintf 格式化字符串很耗时。我在一个项目中测过，打印一条50字节的日志，竟然花了将近2ms。如果中断里调用这个函数，系统直接卡死。

我的建议：中断服务函数里绝对不要做格式化输出。把日志数据扔进队列，让后台任务去处理。或者用更轻量的 itoa 替代 sprintf。

4.2 日志等级管理：别让日志淹死你

日志不是越多越好。你想想看，如果系统每秒打印几百条“进入循环”、“退出循环”这种信息，真正有用的错误信息早就被冲走了。

我习惯把日志分成5个等级：

等级	宏定义	使用场景
ERROR	LOG_LEVEL_ERROR	系统无法继续运行的致命错误
WARNING	LOG_LEVEL_WARN	不影响运行但需要关注的异常
INFO	LOG_LEVEL_INFO	关键状态变化、初始化完成等
DEBUG	LOG_LEVEL_DEBUG	开发阶段跟踪变量值、函数调用
TRACE	LOG_LEVEL_TRACE	极详细的流程跟踪，通常只在定位Bug时开启

实现等级控制其实很简单：

#define LOG_LEVEL LOG_LEVEL_DEBUG  // 全局日志等级

#define LOG_ERROR(fmt, ...)  \
    do { if (LOG_LEVEL >= LOG_LEVEL_ERROR) log_printf("[ERR] " fmt, ##__VA_ARGS__); } while(0)
#define LOG_WARN(fmt, ...)   \
    do { if (LOG_LEVEL >= LOG_LEVEL_WARN)  log_printf("[WRN] " fmt, ##__VA_ARGS__); } while(0)
#define LOG_INFO(fmt, ...)   \
    do { if (LOG_LEVEL >= LOG_LEVEL_INFO)  log_printf("[INF] " fmt, ##__VA_ARGS__); } while(0)
#define LOG_DEBUG(fmt, ...)  \
    do { if (LOG_LEVEL >= LOG_LEVEL_DEBUG) log_printf("[DBG] " fmt, ##__VA_ARGS__); } while(0)
#define LOG_TRACE(fmt, ...)  \
    do { if (LOG_LEVEL >= LOG_LEVEL_TRACE) log_printf("[TRC] " fmt, ##__VA_ARGS__); } while(0)

注意：宏定义里的 do { ... } while(0) 不是摆设。它保证了宏在使用时像普通函数一样，不会因为 if 语句的括号问题而出错。我曾经见过同事因为这个吃了大亏——日志宏里没加这个，结果 if (cond) LOG_DEBUG("xxx"); else ... 编译直接报错。

量产时，把 LOG_LEVEL 改成 LOG_LEVEL_ERROR，所有 DEBUG 和 TRACE 日志在编译阶段就被优化掉了，零开销。

4.3 环形缓冲区日志：不阻塞主流程

串口打印是阻塞的。如果系统正在处理一个时间敏感的任务，你打印一条日志，可能就把时序破坏了。

环形缓冲区（Ring Buffer）就是解决这个问题的。日志先写入内存缓冲区，后台任务再慢慢往外发。

来看一个典型的实现：

#define RING_BUF_SIZE 4096

typedef struct {
    uint8_t buffer[RING_BUF_SIZE];
    volatile uint32_t head;  // 写指针
    volatile uint32_t tail;  // 读指针
} ring_buffer_t;

ring_buffer_t log_ring;

// 写入环形缓冲区（中断安全）
int ring_write(ring_buffer_t *rb, const uint8_t *data, uint32_t len) {
    for (uint32_t i = 0; i < len; i++) {
        uint32_t next_head = (rb->head + 1) % RING_BUF_SIZE;
        if (next_head == rb->tail) {
            return -1;  // 缓冲区满，丢弃数据
        }
        rb->buffer[rb->head] = data[i];
        rb->head = next_head;
    }
    return 0;
}

// 从环形缓冲区读取（在后台任务中调用）
int ring_read(ring_buffer_t *rb, uint8_t *data, uint32_t len) {
    for (uint32_t i = 0; i < len; i++) {
        if (rb->tail == rb->head) {
            return i;  // 缓冲区空
        }
        data[i] = rb->buffer[rb->tail];
        rb->tail = (rb->tail + 1) % RING_BUF_SIZE;
    }
    return len;
}

经验之谈：环形缓冲区的大小要根据你的日志量和系统响应速度来定。我一般给日志分配4KB~16KB。如果缓冲区满了，我选择丢弃新数据而不是覆盖旧数据——因为旧数据里可能藏着导致崩溃的线索。

有了环形缓冲区，日志写入变成了纯粹的内存操作，微秒级就能完成。串口发送则放在空闲任务或者定时器里慢慢处理。

4.4 时间戳记录：还原事故现场

没有时间戳的日志，就像没有日期的日记——你知道发生了什么，但不知道什么时候发生的。

时间戳有两种常见方案：

绝对时间戳：从RTC获取年月日时分秒，适合记录低频事件。
相对时间戳：从系统滴答定时器（SysTick）获取毫秒数，适合记录高频事件。

我个人更常用相对时间戳。因为嵌入式系统里，我们更关心事件之间的间隔，而不是具体是几点几分。

// 获取系统滴答（假设SysTick每1ms中断一次）
volatile uint32_t system_tick_ms;

void SysTick_Handler(void) {
    system_tick_ms++;
}

uint32_t get_tick_ms(void) {
    return system_tick_ms;
}

// 带时间戳的日志宏
#define LOG_INFO(fmt, ...)  \
    do { \
        if (LOG_LEVEL >= LOG_LEVEL_INFO) { \
            log_printf("[%lu] " fmt, get_tick_ms(), ##__VA_ARGS__); \
        } \
    } while(0)

输出效果：

[00001234] [INF] System initialized, heap: 2048 bytes free
[00001256] [INF] Sensor detected, ID: 0xA5
[00004210] [WRN] Battery voltage low: 3.1V
[00014211] [ERR] Watchdog timeout, resetting...

看到没？从初始化到传感器检测，间隔22ms。从传感器检测到电池低压告警，间隔约30秒。从告警到看门狗超时复位，间隔约100秒。这些时间信息，能帮你快速定位问题发生的节奏。

关键点：时间戳的精度取决于你的系统时钟。如果SysTick是1ms中断一次，那时间戳精度就是1ms。对于大多数嵌入式调试场景，这个精度足够了。如果需要微秒级精度，可以用硬件定时器的计数器值。

4.5 知识体系总览

下面这张图，把日志调试法的核心脉络梳理了一遍：

4.6 避坑指南

最后，分享几个我踩过的坑：

不要在中断里直接打印。 我曾经在一个定时器中断里加了日志，结果中断执行时间超过了定时周期，系统直接死循环。后来改成中断里只往环形缓冲区写数据，问题解决。
日志等级别设太多。 我见过有人搞了8个等级，结果团队里没人分得清。5个等级足够了，再多就是负担。
时间戳的溢出问题。 32位毫秒计数器大约49天溢出一次。如果你的系统需要长期运行，记得处理溢出，或者用64位计数器。
格式化字符串的栈开销。 vsnprintf 内部会分配栈空间。在栈空间紧张的MCU上（比如只有2KB RAM），建议用固定格式的日志函数，避免变参。

一个小技巧：调试阶段，我会在关键函数入口和出口各打一条TRACE日志。这样一旦系统跑飞，看最后一条日志就知道跑到哪个函数里了。配合时间戳，还能看出函数执行时间是否异常。

日志调试法，说白了就是给系统装一个“行车记录仪”。串口输出是摄像头，日志等级是录像清晰度，环形缓冲区是存储卡，时间戳是录像时间。四者配合，你就能在系统崩溃后，完整回放事故现场。