4. 日志格式设计:时间戳、线程ID、模块名、日志级别、上下文信息的格式化技巧

日志这东西,说白了就是系统的「黑匣子」。

我做了十几年嵌入式,见过太多系统出问题后抓瞎的场景。代码跑飞了,数据错了,或者干脆死机了——这时候你翻日志,如果格式乱七八糟,那真是欲哭无泪。

所以今天咱们聊聊日志格式怎么设计。嗯,这可不是随便写个printf就完事的事。

4.1 日志格式的核心要素

一个合格的日志条目,至少得包含这五样东西:

  • 时间戳——什么时候发生的
  • 线程ID——哪个任务干的
  • 模块名——哪个功能模块
  • 日志级别——严重程度如何
  • 上下文信息——当时的状态数据

我个人习惯把这五样东西固定成一个模板。不管哪个模块写日志,都按这个格式来。这样后期用脚本分析日志,或者人工排查问题,都省心不少。

推荐格式模板:

[2025-03-21 14:32:18.456] [TASK:0x1234] [MOD:DRV_CAN] [INFO] CAN frame received, id=0x7FF, dlc=8

你看,一眼扫过去就知道:什么时间、哪个任务、哪个模块、什么级别、发生了什么。这就是好日志的样子。

4.2 时间戳:精度与可读性的平衡

时间戳是日志的灵魂。没有时间戳的日志,基本等于废纸。

我遇到过一种情况:系统跑着跑着突然卡住,然后恢复。如果没有毫秒级的时间戳,你根本看不出卡了多久。所以我的建议是——

  • 实时系统:至少毫秒级。用 %Y-%m-%d %H:%M:%S.%3N 这种格式
  • 高精度场景:微秒级。比如电机控制、传感器采集,用 %H:%M:%S.%6N
  • 资源受限的MCU:用系统滴答计数。比如 [TICK:12345678],配合启动时间换算

小技巧: 时间戳里别用中文。你想想看,日志文件可能要在不同语言环境下解析,中文编码容易出问题。一律用英文数字和符号。

4.3 线程ID:谁干的坏事

多任务系统里,线程ID是定位问题的关键。

我记得有一次,一个全局变量莫名其妙被改了。查了半天,发现是某个低优先级任务在中断里偷偷写了数据。如果没有线程ID,你根本不知道是谁干的。

线程ID的格式化建议:

  • 用十六进制,比如 [TASK:0x1234]
  • 或者用任务名,比如 [TASK:can_rx]
  • 长度固定,方便对齐。比如统一8个字符

我个人更倾向于任务名。因为十六进制ID你得去查表,任务名一眼就知道是谁。

4.4 模块名:别让日志变成大杂烩

一个嵌入式系统,少说也有十几个模块。CAN、SPI、UART、FATFS、TCP/IP……每个模块的日志混在一起,如果没有模块名,那简直是一场灾难。

模块名的设计原则:

  • 简短:3-5个字符,比如 CANSPIFAT
  • 统一前缀:比如 MOD:,方便脚本过滤
  • 层级关系:比如 DRV_CANAPP_CAN,区分驱动层和应用层

注意: 模块名不要用数字编号。比如 MOD_01MOD_02,时间久了你根本记不住01是哪个模块。用有意义的英文缩写。

4.5 日志级别:控制输出量

日志级别这东西,说白了就是给日志分个三六九等。

我常用的级别:

级别 含义 使用场景
ERROR 错误 系统无法正常运行,必须处理
WARN 警告 可能有问题,但不影响当前运行
INFO 信息 正常流程的关键节点
DEBUG 调试 开发阶段用的详细输出
TRACE 跟踪 函数调用、变量变化等细粒度信息

级别设计有个坑:别把DEBUG和TRACE混用。我曾经在一个项目里,DEBUG和TRACE都输出大量信息,结果生产环境忘了关,日志文件一天涨了2GB……嗯,从那以后我严格区分:DEBUG只输出关键调试信息,TRACE才输出函数级调用。

4.6 上下文信息:让日志有血有肉

光有「谁、什么时间、什么级别」还不够。你得告诉看日志的人,当时发生了什么。

上下文信息包括:

  • 关键数据:比如接收到的CAN帧ID、传感器原始值
  • 状态码:函数返回值、错误码
  • 变量值:当前关键变量的数值
  • 堆栈信息:发生错误时的调用栈

举个例子:

[2025-03-21 14:32:18.456] [TASK:0x1234] [MOD:DRV_CAN] [ERROR] CAN bus off, status_reg=0xE0, err_cnt=128

你看,最后那个 status_reg=0xE0, err_cnt=128 就是上下文。光说「CAN bus off」没用,你得知道为什么off了。状态寄存器值和错误计数,直接告诉你是总线关闭还是硬件故障。

我的习惯: 上下文信息用 key=value 格式,多个信息用逗号分隔。这样既好读,又好用脚本解析。

4.7 整体格式设计:一个完整的例子

说了这么多,咱们来个完整的日志格式定义:

[时间戳] [线程ID] [模块名] [级别] 消息内容, key1=value1, key2=value2

实际输出:

[2025-03-21 14:32:18.456] [TASK:0x1234] [MOD:DRV_CAN] [INFO] CAN frame received, id=0x7FF, dlc=8, data=0x01 0x02 0x03 0x04
[2025-03-21 14:32:18.789] [TASK:0x5678] [MOD:APP_MOTOR] [WARN] Motor overcurrent, current=12.3A, limit=10.0A
[2025-03-21 14:32:19.001] [TASK:0x1234] [MOD:DRV_CAN] [ERROR] CAN bus off, status_reg=0xE0, err_cnt=128

这个格式,我用了好几年。不管是人工看,还是用grep、awk分析,都非常顺手。

4.8 日志格式的知识体系

下面这张图,把日志格式设计的核心逻辑串起来了:

日志格式设计核心要素 日志条目 时间戳 线程ID 模块名 日志级别 上下文信息 毫秒/微秒/滴答计数 十六进制ID / 任务名 简短缩写 / 层级前缀 ERROR/WARN/INFO/DEBUG/TRACE key=value 格式 最终格式:[时间] [线程] [模块] [级别] 消息, key=val

4.9 避坑指南

最后,分享几个我踩过的坑:

  • 别用可变长度格式。比如时间戳有时用毫秒,有时用微秒,解析起来很痛苦。固定下来,别变。
  • 别在日志里加敏感信息。比如密码、密钥。日志文件可能被到处传,小心泄露。
  • 别让日志影响性能。尤其是高频日志,比如每毫秒打印一次。用环形缓冲区异步写入,别在中断里直接打印。
  • 别用中文。嗯,前面说过了,但值得再说一遍。日志文件可能要在Linux下用grep处理,中文编码会让你怀疑人生。

好了,日志格式设计就聊到这儿。记住一句话:好的日志格式,是系统调试的第一道防线。花点时间把格式定好,后面能省你无数个通宵。


公众号:蓝海资料掘金营,微信deep3321