现场出问题之后,日志往往是唯一的线索。但翻过的日志里,能真正回答问题的其实不多:通常只有一行“超时了”,既不知道当时在做什么任务,也不知道超时前最后一条有效反馈是什么。

后来我改了个做法——先写下复盘时要回答哪几个问题,再倒推该记什么字段。这比事后加日志有效得多。

定要回答的问题→确定必要字段→统一时间基准→贯穿任务与请求 ID→记状态转换而非只记错误→可检索可复现
可用日志的要素时间、身份、状态和原因缺一个,就只能证明“出过问题”。
时间戳统一时钟来源,并区分事件发生和写入时刻。任务与请求 ID把跨进程、跨层的事件串成一次执行。状态转换从什么状态到什么状态,而不是只记失败。原因码可枚举的分类,便于统计和对比。上下文当时的配置、输入摘要和版本指纹。可检索结构化字段比自由文本好筛。

先列问题

要回答的问题大概这几类:这次任务从哪台设备、哪个请求开始;在哪一步超时;超时前最后一条有效反馈是什么;同一时刻还有没有别的错误;这个问题在这台设备上出现过几次。

字段是这些问题推出来的,不是反过来。先写日志再想用途,很容易得到一堆“进入函数”“离开函数”,关键判断点反而没有信息。

身份字段比详细描述更管用

只有时间和文本的日志,跨进程的同一件事串不起来。加上这几个字段,可检索性会明显不一样:

1
2
3
4
5
6
7
8
9
ts=2026-09-14T09:30:12.481+08:00
level=WARN
component=device_bridge
task_id=task-2026-09-14-0007
request_id=cmd-0042
from=WAITING_ACK
to=SAFE_STOP
reason=ack_timeout
elapsed_ms=253

关键是 task_id 和 request_id 要贯穿所有层。上层任务、设备命令和设备侧反馈都带同一个标识,事后就能按时间排成一条链,不用在文本里猜哪条相关。

时间基准要说清楚

不同进程用不同时钟,排出来的顺序就没意义了。至少要明确时间戳来自哪个时钟、有没有和外部时间同步、单位是什么。

有超时逻辑的系统,记单调时钟差值比记墙上时间靠谱,因为墙上时间可能被对时调整。需要跨机器比的时候再记同步后的墙上时间,并标注同步状态。

只记墙上时间不记单调时间,“时钟跳变导致误判超时”这类问题就发现不了。

状态转换比错误字符串有用

只记“ack 超时”只能说明发生了什么,记状态转换才能说明系统当时怎么理解这件事。上面例子里的 from、to 和 reason 三项合起来,既能做统计也能重建流程。

原因码建议用可枚举的集合,自由文本适合补充细节,不适合聚合。一个稳定的原因码集合,能直接支持“这台设备最近两周最常出现哪种停止原因”这种问题。

高频路径上的日志得限流

有一类日志出现在高频路径上,比如每个控制周期或者每帧。在这些位置无差别打印会改变时序,让原本要观察的性能问题被日志本身盖住。

分层是个可行做法:正常路径只在状态变化时记,异常路径按原因码记并限流,详细跟踪用运行时开关控制。限流要在日志里显式写“已丢弃 N 条”,否则事后没法判断记录是否完整。

日志和可复现不是一回事

日志让问题可解释,但不一定让问题可复现。要复现,得记录输入和环境:当时的配置、软件版本,以及关键输入数据有没有存下来。

一次超时如果和某个传感器输入相关,而输入没存,日志只能说明超时发生了,没法重放。这时候补数据录制比加日志更有效。两者是互补的:日志说发生了什么,录制数据说为什么发生。

参考资料

证据边界:本文不含任何具体系统的日志样例数据。字段集合要按你要回答的问题裁剪。日志能证明系统当时如何判断,证明不了物理世界发生了什么——涉及执行器行为的结论还得靠设备侧反馈或独立测量。