ARTICLE · INTELLIGENCE

战地情报 · 详情页

来自尧图项目组的一线实战观察与深度解析

日志系统的双刃剑:如何设计一个生产环境下可动态开启且不影响实时性的 printf 重定向方案

日志系统的双刃剑:如何设计一个生产环境下可动态开启且不影响实时性的 printf 重定向方案

摘要:日志是嵌入式调试的刚需,但日志系统设计不当会直接破坏实时性——这一点在第 2 篇《你的 printf 正在拖垮实时性》里已经用真实事故验证过。然而那篇只给出了"环形缓冲区 + DMA"的骨架,生产环境的日志系统还需要解决更多问题:如何按等级过滤?如何动态开关?如何在中断中安全使用?如何避免日志本身占用太多 RAM?本文给出一套经过量产验证的生产级日志系统,包含完整的等级过滤、动态开关、多后端输出(串口 / Flash / RTT)、溢出保护与性能实测。建议收藏。

一、引子:一次“日志本身导致的故障”

去年做一款工业数据采集器,STM32F429 跑 FreeRTOS。设备在现场跑了三个月后,客户反馈:“设备每天会自动重启一次,没有规律。”

我们远程抓了日志,发现重启前最后一行日志是:

[ERROR] DMA buffer overflow, data lost

MA 缓冲区溢出。但检查代码,DMA 缓冲区的设计非常保守,正常场景下不可能溢出。

进一步排查发现:日志系统本身在偷偷吃 RAM 和 CPU。

具体来说:

  • 日志使用了环形缓冲区,但在缓冲区满时,没有丢弃新日志,而是等待,导致调用者被阻塞

  • 而写日志的是 ADC 中断回调,中断被阻塞后,DMA 得不到及时处理,最终溢出

  • 溢出后触发看门狗复位

根因:日志系统设计不当,反而成了系统不稳定因素。

这个故事告诉我们:日志系统不是“打个 printf”那么简单。生产环境的日志系统是一套完整的子系统,需要考虑等级、开关、性能、安全、存储、输出等方方面面。

本文给出一套经过多个量产项目验证的日志系统设计方案。

二、生产级日志系统的六大需求

从需求出发,一套合格的日志系统需要满足:

这八条需求,看起来都不难,但要同时满足并且不影响实时性,就需要精心设计。

三、整体架构

日志系统的整体架构分为四层:

┌─────────────────────────────────────────┐ │ 应用层:LOG_DEBUG() / LOG_INFO() / ... │ ├─────────────────────────────────────────┤ │ 过滤层:等级过滤 + 模块过滤 + 动态开关 │ ├─────────────────────────────────────────┤ │ 缓冲层:环形缓冲区(可配置多后端) │ ├─────────────────────────────────────────┤ │ 输出层:串口 / RTT / Flash / 内存转储 │ └─────────────────────────────────────────┘

关键设计原则:

  • 应用层调用零开销(等级过滤在编译期或常数时间完成)

  • 过滤层快速失败(不通过直接 return,不占缓冲区)

  • 缓冲层只写内存,不做 I/O(纳秒级)

  • 输出层异步(中断或 DMA 驱动)

四、实现:从 API 到后端

4.1 API 设计

// log.h #ifndef __LOG_H #define __LOG_H #include <stdint.h> #include <stddef.h> // 日志等级 typedef enum { LOG_LEVEL_NONE = 0, // 关闭所有日志 LOG_LEVEL_ERROR = 1, LOG_LEVEL_WARN = 2, LOG_LEVEL_INFO = 3, LOG_LEVEL_DEBUG = 4, LOG_LEVEL_VERBOSE = 5, } log_level_t; // 模块 ID(每个模块一个开关) typedef enum { LOG_MODULE_MAIN = 0, LOG_MODULE_ADC = 1, LOG_MODULE_UART = 2, LOG_MODULE_MODBUS = 3, LOG_MODULE_MAX = 16, } log_module_t; // 初始化 void Log_Init(void); // 运行时设置等级(全局) void Log_SetLevel(log_level_t level); // 运行时设置某模块等级 void Log_SetModuleLevel(log_module_t module, log_level_t level); // 核心输出函数 void Log_Output(log_level_t level, log_module_t module, const char *file, int line, const char *fmt, ...); // 中断安全版本 void Log_OutputFromISR(log_level_t level, log_module_t module, const char *file, int line, const char *fmt, ...); // 宏:编译期优化掉不需要的等级 #define LOG_ERROR(mod, ...) Log_Output(LOG_LEVEL_ERROR, mod, __FILE__, __LINE__, __VA_ARGS__) #define LOG_WARN(mod, ...) Log_Output(LOG_LEVEL_WARN, mod, __FILE__, __LINE__, __VA_ARGS__) #define LOG_INFO(mod, ...) Log_Output(LOG_LEVEL_INFO, mod, __FILE__, __LINE__, __VA_ARGS__) #define LOG_DEBUG(mod, ...) Log_Output(LOG_LEVEL_DEBUG, mod, __FILE__, __LINE__, __VA_ARGS__) // 中断安全版本 #define LOG_ERROR_ISR(mod, ...) Log_OutputFromISR(LOG_LEVEL_ERROR, mod, __FILE__, __LINE__, __VA_ARGS__) #endif

宏设计的要点:

  • __FILE__和__LINE__在宏里展开,让日志包含准确位置

  • 使用__VA_ARGS__支持变参,但不推荐浮点(后面会讲)

  • 每个等级一个宏,方便以后编译期裁剪

4.2 过滤层:快速失败

// log.c static log_level_t s_global_level = LOG_LEVEL_INFO; static log_level_t s_module_levels[LOG_MODULE_MAX]; // 过滤:任何一级不通过,立即返回 static inline int log_should_output(log_level_t level, log_module_t module) { log_level_t effective = s_module_levels[module]; if (effective == LOG_LEVEL_NONE) { effective = s_global_level; // 模块未单独配置,用全局 } return level <= effective; }

关键设计:

  • 模块级可以覆盖全局:某个模块 DEBUG,另一个模块只 ERROR

  • 运行时配置:不需要重新编译,通过串口命令修改

  • 常数时间:一次数组访问 + 一次比较

模块过滤比等级过滤更实用:现场调试时,通常只想打开某个模块的日志,而不是全局打开。

4.3 缓冲层:环形缓冲区

环形缓冲区的实现在第 2 篇已经给过(log_ringbuf.c),这里强调几点:

// 缓冲区满时的行为:三种策略 typedef enum { LOG_OVERFLOW_DROP_NEW = 0, // 丢弃新日志(推荐) LOG_OVERFLOW_DROP_OLD = 1, // 丢弃旧日志 LOG_OVERFLOW_BLOCK = 2, // 阻塞调用者(危险) } log_overflow_policy_t;

为什么默认是 DROP_NEW?

  • DROP_OLD:需要移动 tail 指针,破坏环形结构,实现复杂

  • BLOCK:会阻塞调用者,在中断里会死锁

  • DROP_NEW:直接返回,零风险

经验值:生产环境用 DROP_NEW,并且记录丢弃计数,便于事后分析:

static volatile uint32_t s_dropped_count = 0; uint16_t Log_Write(const uint8_t *data, uint16_t len) { uint16_t written = 0; for (uint16_t i = 0; i < len; i++) { uint16_t next = (s_head + 1) & LOG_BUF_MASK; if (next == s_tail) { s_dropped_count++; // 记录丢弃 break; } s_log_buf[s_head] = data[i]; s_head = next; written++; } Log_KickDMA(); return written; }

丢弃计数本身也要防溢出——用uint32_t而不是uint16_t。

4.4 输出层:多后端支持

不同的调试场景需要不同的输出方式:

架构上,输出层应该可插拔:

// log_backend.h typedef struct { const char *name; int (*init)(void); int (*write)(const uint8_t *data, uint16_t len); void (*flush)(void); } log_backend_t; // 注册后端(编译期决定用哪个) void Log_RegisterBackend(const log_backend_t *backend);

推荐组合:调试阶段用 RTT,量产用 UART + Flash 双后端:

  • 正常运行:只输出 UART

  • 收到故障信号:把最近 N 条日志写 Flash

4.5 中断安全的实现

中断里调用日志,最大的风险是"缓冲区操作被中断打断"。如果主循环正在写缓冲区,中断也来写,head 指针会乱。

三种解决方案:

方案 A:分离缓冲区

主循环用一个缓冲区,中断用另一个。最简单,最安全。

static ringbuf_t s_main_buf; static ringbuf_t s_isr_buf;

方案 B:临界区保护

只在缓冲区指针更新的瞬间关中断:

void Log_WriteFromISR(const uint8_t *data, uint16_t len) { uint32_t primask = __get_PRIMASK(); __disable_irq(); // ... 写入缓冲区逻辑 ... __set_PRIMASK(primask); }

方案 C:无锁 SPSC 队列(推荐)

单生产者单消费者(Single Producer Single Consumer)队列,通过原子操作实现无锁:

// 生产者:只写 head // 消费者:只写 tail // 读写各自指针,天然无冲突 typedef struct { uint8_t *buf; uint32_t size; volatile uint32_t head; // 生产者写 volatile uint32_t tail; // 消费者写 } spsc_queue_t; // 生产者(中断或任务) int spsc_push(spsc_queue_t *q, uint8_t byte) { uint32_t next = (q->head + 1) % q->size; if (next == q->tail) return -1; // 满 q->buf[q->head] = byte; __DMB(); // 数据屏障,确保写入顺序 q->head = next; // 只有生产者写 head return 0; } // 消费者(DMA 中断或任务) int spsc_pop(spsc_queue_t *q, uint8_t *byte) { if (q->head == q->tail) return -1; // 空 *byte = q->buf[q->tail]; q->tail = (q->tail + 1) % q->size; // 只有消费者写 tail return 0; }

关键:head和tail分开写,生产者只更新 head,消费者只更新 tail。这样天然线程安全,无需关中断。

代价:如果缓冲区尺寸不是 2 的幂,% size会引入除法指令,消耗更多周期。建议缓冲区大小为 2 的幂。

4.6 格式化:为什么不用 sprintf

直接sprintf有几个问题:

  • 浮点支持会引入 20-40KB Flash(newlib 的完整实现)

  • 速度慢:一条sprintf可能耗时几微秒

  • 不线程安全:某些实现使用全局缓冲

推荐方案:自实现精简格式化

// 只支持 %d, %u, %x, %s, %c, %p int Log_Format(char *buf, size_t size, const char *fmt, va_list args) { char *p = buf; char *end = buf + size - 1; while (*fmt && p < end) { if (*fmt != '%') { *p++ = *fmt++; continue; } fmt++; switch (*fmt++) { case 'd': { int v = va_arg(args, int); p += format_int(p, end - p, v, 10, 0); break; } case 'u': { unsigned v = va_arg(args, unsigned); p += format_uint(p, end - p, v, 10, 0); break; } case 'x': { unsigned v = va_arg(args, unsigned); p += format_uint(p, end - p, v, 16, 0); break; } case 's': { const char *s = va_arg(args, const char *); while (*s && p < end) *p++ = *s++; break; } case 'c': { *p++ = (char)va_arg(args, int); break; } // 不支持浮点、宽字符 } } *p = '\0'; return p - buf; }

收益:

  • Flash 占用减少 20-40KB

  • 单次格式化耗时减少 50-70%

  • 不依赖 newlib 的复杂实现

浮点怎么办?如果必须打印浮点,可以在上位机解析——MCU 打印整数(如乘以 1000),上位机脚本还原浮点。

4.7 时间戳与元数据

每条日志应包含:

[时间戳] [等级] [模块] [文件:行号] 消息 [0012345678] [E] [MODBUS] [modbus.c:128] CRC error

实现:

void Log_Output(log_level_t level, log_module_t module, const char *file, int line, const char *fmt, ...) { if (!log_should_output(level, module)) return; char buf[128]; int pos = 0; // 时间戳(tick 数) pos += Log_Format(buf + pos, sizeof(buf) - pos, "[%08lu] ", (unsigned long)xTaskGetTickCount()); // 等级 static const char level_chars[] = "?EWIDV"; buf[pos++] = '['; buf[pos++] = level_chars[level]; buf[pos++] = ']'; buf[pos++] = ' '; // 模块 pos += Log_Format(buf + pos, sizeof(buf) - pos, "[%s] ", log_module_names[module]); // 消息 va_list args; va_start(args, fmt); pos += Log_Format(buf + pos, sizeof(buf) - pos, fmt, args); va_end(args); buf[pos++] = '\n'; buf[pos++] = '\r'; Log_Write((uint8_t *)buf, pos); }

文件路径优化:__FILE__展开通常是完整路径(/home/user/project/src/modbus.c),太长浪费空间。可以只用文件名:

// 编译时用宏截断到文件名 #define __FILENAME__ (strrchr(__FILE__, '/') ? strrchr(__FILE__, '/') + 1 : __FILE__) // 或者更高效:编译期截断(需配合 Makefile)

时间戳来源:FreeRTOS 用xTaskGetTickCount();裸机可以用 DWT 或 RTC。不要用HAL_GetTick(),因为它需要 SysTick 中断,低功耗场景下可能停摆。

五、性能实测

在 STM32F429 @180MHz、FreeRTOS、921600 波特率 UART + DMA 环境下测试:

关键结论:

  • 相比阻塞式 printf,耗时降低 160 倍

  • Flash 占用减少 22KB(去掉 newlib 浮点)

  • 加上等级过滤,未启用的日志 0 开销(编译期条件判断)

中断中的开销:

六、典型配置

不同场景推荐不同的配置:

关键:把等级、后端、缓冲大小都做成编译期宏 + 运行时可调的组合,同一份代码能适应所有场景。

// log_config.h #define LOG_DEFAULT_LEVEL LOG_LEVEL_INFO #define LOG_BUF_SIZE 2048 #define LOG_USE_RTT 0 #define LOG_USE_UART_DMA 1 #define LOG_USE_FLASH_BACKEND 1 // 量产开启 #define LOG_FORMAT_USE_FLOAT 0 // 禁用浮点格式化

七、避坑清单

、小结与预告

本文从"日志系统本身成为故障源"的真实事故出发,给出了一套生产级日志系统的完整设计——等级过滤、模块开关、环形缓冲区、中断安全、多后端输出、自实现格式化。实测显示,相比标准库 printf,耗时降低 160 倍、Flash 减少 22KB、RAM 增加 3KB,同时满足实时性、可靠性和可维护性要求。

三个核心要点:

  1. 日志系统是子系统,不是"printf 重定向"

  2. 中断安全靠 SPSC 无锁队列,不靠关中断

  3. 自实现格式化是必经之路,标准库 sprintf 会带来不可接受的资源占用

下篇预告:第 10 篇《栈溢出检测:不只是填充魔数 0xDEADBEEF,基于 MPU 的硬件级栈保护实现》

将拆解栈溢出的三种检测方案——编译期静态分析、运行时魔数检查、MPU 硬件保护。用一个真实事故说明为什么填充 0xDEADBEEF 会漏检、MPU 保护如何实现毫秒级发现、以及 FreeRTOS 与 MPU 的集成方式。包含完整可移植的 MPU 配置代码和实测数据。

本文是《嵌入式系统调优高手课》的付费内容。完整专栏收录 20 篇深度长文,涵盖 RTOS 调度器汇编级拆解、内存池设计、Cache 一致性、低功耗陷阱与安全启动。每一篇都包含真实事故复盘、可移植源码和实测数据。如果你不想再靠"重启试试"解决问题,这个专栏就是为你写的。

交付物清单(code/目录):

  • log.c/h:生产级日志系统核心实现(约 500 行)

  • log_ringbuf.c/h:SPSC 无锁环形缓冲区

  • log_format.c/h:自实现精简格式化

  • log_backend_uart.c/log_backend_rtt.c/log_backend_flash.c:三种后端

  • log_config.h:场景化配置模板

  • log_benchmark.c:性能对比测试

参考资源:

  • SEGGER RTT 官方文档:J-Link RTT – Real Time Transfer

  • FreeRTOS 官方文档:configUSE_TRACE_FACILITY与 trace 宏

  • 《Embedded Systems Architecture》Daniele Lacamera 著,第 7 章:日志系统设计

  • MISRA-C 2012 Rule 21.6:禁止使用 stdio.h(安全关键系统)

RELATED READING

延伸阅读

更多一线实战笔记与深度复盘,助您持续精进