3. 日志格式设计：时间戳、模块名、线程ID、上下文ID的标准格式
日志格式这东西，看着简单，但真踩过坑的人才知道有多重要。我刚入行那会儿，觉得能打出信息就行，结果有一次线上定位问题，日志乱成一锅粥，光对齐时间就花了半天。从那以后，我对日志格式就特别较真。
说白了，日志格式就是协议栈的“黑匣子”。格式设计得好，排查问题事半功倍；设计得不好，你就是在垃圾堆里找针。这一节，我把我这些年沉淀下来的格式规范分享给你。
3.1 一条好日志的四个要素
我个人习惯，一条日志必须包含四个核心字段。缺一个，排查时就会多一分痛苦。
| 字段 | 作用 | 我踩过的坑 |
|---|---|---|
| 时间戳 | 确定事件发生的绝对时刻 | 曾经用毫秒级精度，结果两个事件在同一毫秒内，根本分不清先后 |
| 模块名 | 快速定位问题出在哪一层 | 曾经不写模块名，满屏日志不知道是RRC还是NAS出的 |
| 线程ID | 区分并发路径，追踪异步流程 | 曾经两个线程同时写日志，输出顺序和实际执行顺序完全对不上 |
| 上下文ID | 串联一次完整的事务流程 | 曾经没有上下文ID，一个信令流程的日志散落在各处，手动拼凑到崩溃 |
核心原则：日志格式要让人一眼就能回答三个问题——什么时候发生的？谁产生的？属于哪个流程？
3.2 时间戳：精度与可读性的平衡
时间戳是日志的灵魂。我建议用 UTC+8 的绝对时间，别用相对时间。为什么？因为协议栈经常跨设备、跨板卡，相对时间一同步就乱。
格式上，我推荐这个：
2025-03-15 14:23:45.678 123解释一下：
- 日期+时分秒：人类可读，一眼知道大概时间
- 毫秒：三位数，够用
- 微秒：后三位，用于高精度排序
我的小技巧：微秒部分用系统 tick 的低位来填充，这样即使两个事件在同一毫秒内，也能通过微秒区分先后顺序。我曾经靠这个特性，在 5G NR 的 HARQ 重传排查中，精确锁定了时序冲突的根因。
3.3 模块名：分层清晰，一目了然
协议栈分层多，模块名必须能反映层级关系。我习惯用 大模块.子模块 的命名方式。
| 模块名 | 含义 | 典型日志内容 |
|---|---|---|
RRC.ASN1 |
RRC层的ASN.1编解码模块 | 解码SIB1成功，cellId=0x1234 |
MAC.SCHED |
MAC层的调度器模块 | UL grant分配，rnti=0xC123，size=512 |
PDCP.CIPHER |
PDCP层的加密模块 | 加密算法NEA2，keyId=3 |
NAS.MOB |
NAS层的移动性管理模块 | TAU请求，oldGuti=...，newGuti=... |
注意：模块名不要超过 16 个字符。太长的话，日志对齐会很难看，而且 grep 的时候也麻烦。我见过有人用 RRC_CONNECTION_ESTABLISHMENT_HANDLER 这种名字，说实话，看着就累。
3.4 线程ID：区分并发，还原时序
协议栈是多线程的，这一点你肯定知道。但你知道线程ID在日志里有多重要吗？
我建议用 系统线程ID（TID），而不是 pthread_t。因为 TID 在系统层面是唯一的，而且可以跟 perf top 等工具关联起来。
格式上，用十六进制，固定 4 字节宽度：
[TID:0x3A1B]为什么用十六进制？因为线程ID在 /proc/<pid>/task/ 目录下就是十六进制显示的，保持一致方便交叉排查。
实战经验：我曾经排查过一个偶发性的 RRC 重建失败问题。日志里看到两条日志时间戳完全一样，但线程ID不同。一条是主线程发的 RRCReconfiguration，另一条是定时器线程发的 T310 超时。两个线程同时操作同一个 UE 上下文，导致了竞态。如果没有线程ID，这个 bug 我可能永远都找不到。
3.5 上下文ID：串联流程的“线”
上下文ID，也叫 Correlation ID 或 Transaction ID。它的作用是把一次完整的事务流程串起来。
我推荐用 UUID 的短格式，取前 8 位十六进制字符：
[CTX:A3F9C2E1]为什么用短格式？因为长 UUID 太占地方，而且日志里不需要全局唯一，只需要在短时间内不重复就行。8 位十六进制，理论上可以支持 4 亿个并发事务，够用了。
上下文ID的生成时机：
- 新流程开始时（如收到 RRCSetupRequest）生成一个新的上下文ID
- 流程结束时（如 RRCSetupComplete 发送完成）释放该上下文ID
- 子流程继承父流程的上下文ID，方便追溯
3.6 标准格式：一条完整的日志长什么样
好了，四个要素都讲完了。把它们拼起来，就是一条标准日志：
2025-03-15 14:23:45.678 123 [RRC.ASN1] [TID:0x3A1B] [CTX:A3F9C2E1] 解码SIB1成功，cellId=0x1234，plmn=46001这个格式有几点好处：
- 固定宽度：时间戳、模块名、线程ID、上下文ID都是固定长度，日志对齐漂亮
- 可解析：用空格或制表符分隔，脚本解析非常方便
- 可读性强：人类阅读时，关键信息一目了然
我的习惯：在代码里定义一个日志宏，自动填充这些字段。这样开发人员写日志时，只需要关心消息内容，格式由宏统一保证。我见过太多因为手写格式导致的不一致问题，用宏可以一劳永逸。
3.7 格式设计的避坑指南
这些年我踩过的坑，总结成几条，你记一下：
- 不要用浮点数表示时间：浮点数精度问题会导致时间戳错乱。我见过有人用
gettimeofday的 double 值，结果毫秒位偶尔会跳变。 - 模块名不要用数字编号：比如
MOD_01、MOD_02，时间久了没人记得住编号对应哪个模块。直接用英文单词，清晰明了。 - 线程ID不要用线程名：线程名可能重复，而且长度不固定。用 TID 最可靠。
- 上下文ID要保证在日志文件中唯一：至少在同一秒内不能重复。我曾经因为上下文ID生成算法有 bug，导致两个不同流程用了同一个 ID，排查时被误导了整整两天。
3.8 知识体系：日志格式设计全景图
下面这张图，把日志格式设计的核心逻辑串起来了。你可以把它当作一个检查清单，设计日志格式时对照着来。
这张图把日志格式设计的核心逻辑都画出来了。你设计日志格式时，对着这张图检查一遍，基本不会出大问题。
嗯，格式设计就讲到这里。记住，好的日志格式是排查问题的第一道防线。格式设计得越规范，后面排查问题就越轻松。这个道理，我是在吃了无数次亏之后才真正理解的。