TT Lab
开始
学习 学习路径 课程

从日志里找原因

一行未必是一件事

在 TT Lab 中继续学习

一句话总结

日志分析的第一步不是计数,而是确定什么算一条记录。在格式混杂的一批日志中,如果把行数误当作记录数,一个异常就会变成十个错误,并原样写进报告。

为什么需要它

从客户那里收到的第一批日志,通常都没有整理过。应用按自己喜欢的格式打印,前端 Web 服务器使用 Combined 访问日志,防火墙和代理则通过 syslog 发送。把这三个文件放进同一个目录,运行 grep -c ERROR,会得出一个数字,而这个数字毫无意义。

原因有两个。第一,Java 或 Python 的异常是多行的。一行标题之后,有五六行 at … 栈帧,后面还接着 Caused by:。按行来数,一个异常就变成了十个。第二,每一行的时间写法各不相同。有的带着 +09:00,有的是 05/Mar/2026:14:22:31 +0900,有的是 UTC 加上 Z。如果把时间当作字符串来排序,这三种写法会乱成一团。

所以在分析之前需要一个步骤。把这三种格式变成一行一条记录的结构化形式,把时间统一到同一个基准,并统一字段名称。这项工作叫做规范化。

工作原理

规范化由四个决定组成。

第一,以什么作为记录的开头。最稳妥的方法是:“如果一行以时间开头,就是新记录,否则是前一条记录的延续。”异常栈帧以制表符或空格开头,Caused by: 没有时间,所以会自动接在前面。只靠这一条规则,就解决了多行异常。

第二,把时间固定成什么样的字符串。RFC 3339 规定了互联网上使用的写法。这份文档的第 5.1 节还写明了为什么使用这种写法——如果偏移量的写法相同、小数位数相同,字符串排序就等同于按时间排序。所以,只要把所有时间都固定成像 2026-03-05T05:22:31.118Z 这样的 UTC、毫秒三位数、Z,之后所有的工作,只要 sort 一下就够了。

第三,把结构化的结果放在哪里。实际工作中的默认选择是 JSON Lines(NDJSON)。它是每行放一个 JSON 对象的格式,所以 head、tail、split 这类按行处理的工具可以直接使用,即使是 100GB 的文件也可以流式读取。整体的 JSON 数组必须读到文件末尾才能使用第一条记录,不适合大日志。

第四,字段名称统一成什么。在这里没有必要重新造轮子。OpenTelemetry 日志数据模型把日志记录规定为 Timestamp、ObservedTimestamp、SeverityText、SeverityNumber、Body、Attributes 等字段,并把“必须能够把现有的日志格式无歧义地转换成这个模型”写成设计要求。Elastic Common Schema 也是瞄准同一个位置的另一部词典。无论用哪一个,重要的是在团队内部确定其中一种。

如果要处理 syslog,值得读一读 RFC 5424。开头的 <134> 称为 PRI,其中的一个数字同时包含 facility 和 severity 两者——facility 是商,severity 是余数(除以 8)。第 6.2.3 节进一步收紧:TIMESTAMP 是 RFC 3339 的子集,T 和 Z 必须是大写。

在现场相遇的样子

被丢弃的行会悄悄出现。如果解析器用 continue 跳过无法读取的行,这种损失不会在任何地方留下记录。RFC 5424 在第 6.1 节写道,传输接收方对超出所支持大小的消息,可以截断,也可以丢弃(至少支持 480 个八位字节,最多要支持到 2048 个八位字节)。也就是说,被截断的行是正常出现的。所以要把解析失败当作一种结果,而不是异常情况,并附上原文、文件名、行号,单独保存。以后被问到“这个时间点为什么没有记录”时,那个文件就是答案。

出于同样的原因,RFC 5424 第 8.3 节建议把重要信息放在消息的前面。因为即使后面被截掉,前面仍会留下。

规范化规则不是代码,而是契约。把哪一行视为记录的开头,时间如何固定,无法读取的行放在哪里——如果不把这些写成文档,下一个人用同一个文件会得出不同的数字。在与客户的下一次交流中,要求“下次请以一行一个 JSON 的形式提供”,依据也在这份文档里。

下一项实验要做什么

做出原样复现客户日志的三个文件,把行数和记录数分开统计。然后把多行异常合并成一条记录,分别对访问日志和 syslog 做结构化,并把无法解析的行隔离起来。最后把三者合并为通用 schema 并按时间排序,把规范化规则和被丢弃的行写成报告。评分器会自己重新解析原始文件,并与你的结果进行核对。