最近我在整理日志排查工具链的时候,顺手把命令行里最常用的一个动作——“看上下文”——抽成了一个小命令,名字就叫 context-mode。它不是一个大项目,核心代码加上辅助脚本不到 600 行,但几乎每天都在帮我节省半小时到一小时。如果你也遇到过这样的经历:拿到一条 ERROR 日志,不知道它之前发生了什么、之后又发生了什么,那这篇文章大概率对你有用。
context-mode 解决的是一个很朴素的问题:日志里的关键行只是事故现场的一小块碎片,真正的线索在它前面几十行和后面几十行里。你可能觉得grep -C 10就够用了,但实际排查日志时,你会发现纯文本的“上下文”根本不够——你还需要知道哪些行属于同一次请求、哪些行是同一个堆栈、哪些行只是无关的心跳噪音。这些结构信息,才是 context-mode 想补全的东西。
1. 为什么需要 context-mode:日志排查的老大难
1.1 一条错误日志背后缺了哪三样信息
我先给你看一条非常典型的错误日志:
2026-05-12 10:00:00,123 ERROR [order-service] [trace_id=abc123] 创建订单失败单看这一行,你能定位到根因吗?大概率不能。你需要至少三样东西:
第一,前因。这条请求是怎么走到这一步的?是不是上游传过来的参数有问题,还是库存扣减先执行了一半?没有前因,你连该去翻哪个服务的日志都不知道。
第二,后果。这个错误发生之后,本地缓存有没有被删除,消息有没有发出去,事务有没有回滚?这些后续行为可能不会跟在 ERROR 行后面,而是隔了几行无关日志才出现。
第三,边界。这条日志前后可能混着大量心跳日志、访问日志、定时任务日志,它们跟当前事故没有关系。如果没有边界概念,你会把不相干的内容全看一遍,很快就看晕了。
很多人在排查故障时,最大的问题不是没有日志,而是被日志淹没了。grep "ERROR"能帮你找到那几行,但给不了前因、后果和边界。这正是我写 context-mode 的初衷:把“上下文”变成一个可以配置、可以折叠、可以识别结构的模式,而不只是简单地打印前后 N 行。
1.2 从 grep -C 到 context-mode:差的不是功能,是结构
先别急着觉得我在否定 grep。grep -C 5是整个方案的基础,它至少能让你看到报错前后的固定行数。但它有三个硬伤:
- 行数固定,不看内容。不管前后行是堆栈还是心跳,统统打印出来。
- 连续命中多个关键字时,上下文会重复打印,输出里到处是重复片段。
- 没有分组概念。一次请求的日志可能被另外几个线程的日志打断,grep 只能按文件原始顺序硬切。
我举个具体例子。假设日志文件里一个异常长这样:
10:00:00,100 INFO request start, order_id=100 10:00:00,101 DEBUG cache key=order:100 not found 10:00:00,102 INFO stock deduct, sku=233, qty=1 10:00:00,103 ERROR create order failed: out of stock 10:00:00,104 WARN retry count=1, sleep 100ms 10:00:00,205 ERROR create order failed again 10:00:00,206 ERROR send retry event failed 10:00:01,500 INFO heartbeat ...用grep -C 1 ERROR会输出:
10:00:00,102 INFO stock deduct 10:00:00,103 ERROR create order failed 10:00:00,104 WARN retry count=1 10:00:00,205 ERROR create order failed again 10:00:00,206 ERROR send retry event failed你看到两条 ERROR,但没法一眼看出它们其实是同一次失败流程的两次重试。而 context-mode 在同样配置下会做两件事:把连续的 ERROR / WARN / RETRY 行识别为同一个事件块,折叠掉中间无关的心跳日志,并且把第二个 ERROR 前面的“前因”也合并进去。简单说,grep 给你的是“以错误行为中心的切片”,context-mode 给你的是“以事故为中心的事件块”。
2. 核心设计:上下文窗口怎么算、怎么拼
2.1 窗口大小不是拍脑袋,先讲两个计算维度
我在最初做 context-mode 时,第一个功能就是抄grep -C,默认设置--before 5 --after 5。但用了一阵子发现,不同场景下的最佳窗口差很远。窗口太小,看不全前因;窗口太大,噪音成倍增加。后来我总结出两个参考维度。
第一个维度是日志密度。如果平均每秒钟只产生 3 行日志,那错误发生前的 30 行可能覆盖了 10 秒内的所有操作,这对排查超时有意义。如果平均每秒钟产生 200 行日志,往前看 30 行可能只覆盖 0.15 秒,根本看不到请求入口。所以我给了个配置参数--tail-seconds,让 context-mode 根据当前日志流的时间戳自动计算目标行数:
行数 = 期望覆盖秒数 × 近 5 分钟内日志平均每秒行数比如我想看错误前 30 秒都发生了什么,那么工具会先扫描文件前 1000 行,估算统计到的日志行数除以覆盖的时间跨度的日志密度,再乘以 30,得到一个动态窗口。这个估算不需要特别精确,够用就行。
第二个维度是事件完整度。一个多行堆栈通常有 10~20 行,一条完整 SQL 慢查询可能有 5~10 行,一次分布式调用的链路日志可能有几十行。所以我设了一个更大的上限:--before 200 --after 50,并配合“事件边界识别”来自动截断,而不是真的把 200 行全打印出来。窗口大小是上限,不是目标——这是 context-mode 和 grep 的又一个区别。
你可以根据自己的业务场景参考这张表:
| 场景 | 推荐窗口 | 原因 |
|---|---|---|
| 应用业务报错 | before 8,after 8 | 堆栈和参数一般在 16 行内能看完 |
| 数据库慢查询 | before 20,after 20 | SQL 计划和执行耗时语句可能分散较广 |
| 分布式链路超时 | before 50,after 30 | 需要在跨服务日志里找到 trace_id 关联的入口和出口 |
| 崩溃/重启类问题 | before 100,after 200 | 需要看启动过程、依赖连接和线程堆栈 |
这只是起点,不用死记。我实际落地时会把配置写进项目里的context-mode.yaml,不同项目用不同建好的配置,而不是每次敲命令行都重新想一次。
2.2 行类型识别与上下文分组的规则
context-mode 里最核心的部分不是“显示前后 N 行”,而是“识别哪些行应该被当作同一段上下文”。我从纯文本规则起步,总结了几种常见的日志结构。
第一种是空行分隔。大多数框架在打印一段完整异常时,会留下一个空行作为段落分隔符。context-mode 看到空行,就把空行当作事件边界。空行之后的下一行如果是一个新时间戳,就说明上一个事件结束。
第二种是时间戳跳变。如果前一行时间是10:00:00,123,下一行直接跳到了10:00:00,456,中间没有匹配段落结束时,context-mode 会把超过 5 秒的间隔当作一个软边界,输出时会额外加一行-- gap 5s --的提示。这个功能在定位“卡住”的问题时特别好用。
第三种是堆栈关键字。Java 日志里的at、Caused by:、Suppressed:,Python 日志里的Traceback (most recent call last):、File "...", line,Go 日志里的goroutine 123 [running]:,这些行都属于异常事件的一部分,不能拆开。context-mode 提供了几种内置规则,如果命中这些关键字,就会自动扩大合并范围,把整个堆栈归到同一个上下文块。
第四种是缩进变化。很多 Python 和 JSON 格式的多行日志,子行前面有 2 或 4 个空格。如果中间某行缩进变深或变浅,通常意味着结构层级变化。在做上下文分组时,缩进连续的行会被尽量放在一起,缩进跳变的行则可能触发一条新分组。
这套规则不追求完美,因为日志格式太多了。它更关键的价值是:给后续的渲染和折叠提供结构化判断,而不是每一条规则都写死。
2.3 输出配色与折叠策略:信息密度怎么控制
只看上下文还不够,还得让人看得快。我给自己提的要求是:“一屏之内,一眼看到关键变化。”
context-mode 的默认输出会把命中行用高亮颜色标出来,上下文行则保持白色或灰色。但真正省时间的是折叠策略:
- 如果同一个“事件块”里,连续 30 行都是相同前缀的 DEBUG 日志,只保留第一行和最后一行,中间用
... 省略 28 行 ...代替。 - 如果命中关键字的那一行本身就是某段重复日志的一部分,比如重试间隔日志,那么如果前面已经出现过相同 pattern,就把后续重复都折叠掉,只显示“相同日志 ×N”。
- 如果一段上下文里时间戳跨度超过 60 秒,输出时会在中间插入时间轴标记,例如
-- 60s later --,提醒你这段时间内发生了明显卡顿。
折叠不是删掉信息,而是把噪音变成摘要。这样在终端里滚动时,眼睛只需要处理真正有变化的行。你可能觉得这些输出策略太“花哨”,但真实场景下,排查一个 CPU 飙高问题,日志里可能有几十段完全相同的INFO slow query输出,如果不折叠,你根本看不到异常段落在哪里。
3. 实操:40 行 Python 实现一个最小可用版本
3.1 读取与匹配阶段的实现要点
如果你想快速上手,可以先从一个最小可用的 Python 实现开始。它不需要依赖第三方库,底层就是流式读取 + 正则匹配 + 环形队列。我一开始在 shell 里就是用这样一个版本跑起来的,后面才逐步加入分组和识别。
#!/usr/bin/env python3 """context-mode 最小实现:给匹配行输出前后上下文""" import argparse import re import sys from collections import deque def main(): parser = argparse.ArgumentParser(description="Print context around matching lines") parser.add_argument("pattern", help="regex pattern to match") parser.add_argument("--before", type=int, default=5, help="lines before match") parser.add_argument("--after", type=int, default=5, help="lines after match") args = parser.parse_args() regex = re.compile(args.pattern) ring = deque(maxlen=args.before) # 只保留前 N 行,控制内存 printed_positions = set() # 避免同一行被重复打印 after_count = -1 # 命中后还需要输出几行 for lineno, raw_line in enumerate(sys.stdin, 1): line = raw_line.rstrip("\n") # 命中主模式 if regex.search(line): # 先补打缓存中的 before 行 for idx, prev_line in enumerate(ring, start=lineno - len(ring)): if idx not in printed_positions: print(f"{idx:>6}: {prev_line}") printed_positions.add(idx) print(f"{lineno:>6}: {line}") after_count = args.after # 命中后的 after 上下文 elif after_count >= 0: print(f"{lineno:>6}: {line}") after_count -= 1 ring.append(line) if __name__ == "__main__": main()这段代码做了几个关键决策:
- 用
deque(maxlen=args.before)保存“当前行之前的 before 行”,每读入一行就自动淘汰旧行,内存占用是 O(before),不随文件行数增长。比如 before 设为 50,那就最多占用 50 行文本。 - 用
printed_positions记录已经打印过的行号,防止同一个上下文被多次命中时重复输出。比如两条匹配行只隔 3 行,before 窗口有重叠,如果不记录,中间那 3 行会被打印两遍。 - 用
after_count记住“命中后还要打印几行”。这是最简单的无状态实现,但已经做到了流式处理。
你在复用时,可以直接把这段代码存成context_mode.py,然后这样跑:
cat app.log | python3 context_mode.py "发货失败" --before 10 --after 8它会像 grep 一样,给所有匹配行和前后文加上行号。也许你会问:“这不就是个带行号的 grep -C 吗?”是的,最小实现就是。真正拉开差距的是之后的分组和折叠逻辑。
3.2 上下文拼接与渲染:结构怎么加进去
最小版只能解决“看几行”的问题,解决不了“按事件块看”的问题。于是我在上面基础上,加了一层“事件缓冲区”逻辑。
核心思路是:不是每匹配一行就立刻输出,而是先把匹配行放进一个临时 buffer,等待后续行进入,然后判断哪些行应该归为一个块。判断的依据就是我在 2.2 里提到的堆栈关键字、时间戳间隔和缩进。归完块之后,统一渲染输出。
具体做起来,我会定义一个EventBlock数据对象,包含start_line、end_line、rows、kind这几个字段。每次从标准输入读入一行,就根据规则决定是追加到当前块,还是结束当前块并开始新块。当块结束时,再调用渲染函数。
这里有个需要注意的细节:流式处理时,很多“事件是否结束”的判断只能延迟下决心。比如你要看at连续堆栈行,但你不知道下一行会不会继续at,所以得先把当前块缓存住,等读到下一行再做决定。这样配置一个max_block_lines防止异常日志特别长导致缓存占用过大,我默认是 200 行。
渲染函数要做的事也比较机械:
- 给命中行加背景高亮;
- 给上下文行加行号和时间戳;
- 对超过折叠阈值的连续重复行做折叠;
- 在块与块之间输出分隔行
------。
这些逻辑虽然不难,但能让你在一大堆日志里快速看清楚“同一段时间内发生了哪几件事”。
3.3 进阶参数与常用命令
开发到后面,context-mode 支持这样一组二级子命令,使用频率非常高:
# 第一种:查找关键字并带上上下文 context-mode search "支付回调失败" --before 12 --after 10 # 第二种:只看某个 trace_id 相关的所有行,并要求按时间排序 context-mode trace "trace_id=78f0a9" --sort # 第三种:把上下文中相同 ERROR 的相邻错误聚合成一个块 context-mode block --type error --fold # 第四种:输出 JSON,方便给上游分析脚本继续处理 context-mode search "队列消费超时" --after 30 --json--json是我后来加的。因为在前端或监控里,人可能不需要直接看终端颜色,而是想拿到结构化数据,比如“这条匹配行出现在文件的哪一行、前 10 行文本是什么、后 10 行文本是什么、上下文块的开始和结束行分别在哪里”。输出 JSON 以后,你可以随手用jq再做过滤,或者丢给故障分析脚本。
一个比较实用的组合是:
cat order-service.log | context-mode search "ERROR" --before 8 --after 8 --json | jq '.blocks[] | select(.rows[] | test("out of stock"))'这实际上就是把 context-mode 当成一个“日志切片器”,把切片结果交给其他程序继续处理。这也是为什么我会坚持让你保留流式读取和 JSON 输出,而不是把结果硬塞进终端彩色的样式里。
4. 更高阶的 context-mode:把识别结果变成可读的“事故报告”
4.1 堆栈识别与日志级别聚合
我使用中发现,一个调用里面经常会有多个 ERROR 出现。比如业务方法里先抛一个 A 异常,捕获后重试,重试又抛一个 B 异常。它们时间上相距不到 100ms,日志上却分成两段,中间还夹着 WARN。如果不做聚合,你会误以为是两条独立事故。
context-mode 的--aggregate模式会把“同一个 trace_id、时间跨度在 10 秒以内、且级别为 ERROR 或 WARN”的多条记录合并为一组。合并后会看到这样的输出:
------ block 1: 10:00:00,103 ~ 10:00:00,206 ------ [1] ERROR create order failed: out of stock [2] WARN retry count=1, sleep 100ms [3] ERROR create order failed again [4] ERROR send retry event failed这种聚合对“定位循环重试”特别有效。我曾经靠它排查过一个线上问题:某个任务一直失败重试,每条 ERROR 都换了一个错误码,从 500 到 502 再到 504。如果不聚合,看起来就是三五个不相干的问题;聚合之后才发现,它们其实是同一个死循环的三次迭代。
实现上也不难:先按 trace_id 或 thread ID 做一个分组,然后对组内日志按时间排序,再设置间隔阈值。比如两条记录间隔超过了 60 秒,就不再强行合并,避免把两个完全独立的错误硬凑在一起。
4.2 时间戳对齐与慢查询归因
context-mode 可以自动解析常见时间戳格式:
YYYY-MM-DD HH:MM:SS,mmm YYYY-MM-DD HH:MM:SS.mmm MM-dd HH:MM:SS,mmm当一个上下文块被渲染时,工具会计算每相邻两行的时间差,并把异常间隔标记出来。举个例子:
10:00:00,100 INFO request start, id=123 10:00:00,101 INFO check permission -- 5.02s gap -- 10:00:05,122 INFO call remote service 10:00:05,200 ERROR timeout这里最关键的其实是那个 5 秒 gap。它告诉你“卡在权限校验之后、调用远程服务之前”。如果没有这个标记,你可能会先去看远程服务的日志,白费一堆工夫。
这个功能后来又被我扩展成--timezone-local选项,用于处理不同时区的日志文件。分析跨服务日志时,不同机器可能用的是 UTC 和本地时间混着写。context-mode 允许在命令行里声明时间偏移量,比如--tz-offset +8,内部统一转成 UTC 后再计算 gap,这样就不会因为时区问题把正常日志间隔误判成慢请求。
4.3 多文件合并上下文
真正的生产环境一般不会只有一个日志文件。一个请求可能先打到 Nginx,再到网关,再到业务服务,最后落到 MySQL 慢日志。如果想还原完整上下文,你会发现“context”不只是文件内的前后行,还应该是不同文件之间的时间线。
我做了context-mode range --start "2026-05-12 10:00:00,100" --end "2026-05-12 10:00:00,206"这个功能:它接受多个文件参数,按时间戳做归并排序,输出一个统一的事件流。每个事件会标记来源文件和原始行号,方便你反查。
这样虽然不能主动拉取其他服务的日志,但如果你已经把相关日志都收集到本地,那么 context-mode 可以帮你把所有上下文拼成一条时间线,而不是让你在两个终端窗口里人工对照时间。
5. 常见问题与排查技巧实录
5.1 为什么某些日志段被错误合并
我最早发现的一个问题是:多行日志里某些行并没有缩进,例如 Java 堆栈中间的空行,或者 Log4j 配置了“pattern 后跟异常堆栈但堆栈行不缩进”。这些行如果没有明确的边界特征,会被 context-mode 当成上一段的一部分,合并出一个超大的“事件块”。
解决思路是加一条“行尾判断”规则:如果当前行以:结尾、以空格结尾或长度特别短,下一行又突然出现新时间戳,就强制分割。同时,我允许你自定义--block-start-regex和--block-end-regex,对于你们项目的特殊格式,直接传正则去覆盖默认规则。
这里也提醒一点:不是任何日志都适合自动合并。如果日志格式本身没有时间戳,那么 time-gap 判断会失效,只剩下缩进和空行判断,效果会差很多。做项目落地前,最好先确认日志格式是否规范。
5.2 大日志文件下内存占用过高怎么办
有些同事拿 context-mode 去查上百 GB 的日志,发现内存上涨很快。这不是工具本身的流式处理有问题,而是你把--before调得太大了,或者错误地用了context-mode search的--json输出并全部缓存。
如果 before 设为 500,而日志行又很长,比如每行 10KB,那么环形队列里就有 5MB 数据。同时,如果匹配模式太宽,命中几千处,打印出的行数也会很多,但内存不会一直涨。真正的风险来源是:如果你为了做 sort 或 aggregate,把文件readlines()全读进内存,那就容易爆。
我的建议是:
- 使用最小版本那样的
deque流式模型,不要一次性读入所有行。 --before尽量不要超过 1000,除非你明确知道上下文行很长。--aggregate模式下,内部会有分组缓冲区。如果 trace_id 非常多,需要设置--aggr-bucket-size限制同时缓存的分组数,超出后按时间最老的分组先输出并释放。
实际压测过:一个 2.3GB 的日志文件,before=20,after=10,流式跑完全程耗时约 12 秒,内存峰值不到 30MB。这个数值在同配置的 grep 和 sed 组合下也算合理,完全能接受。
5.3 context-mode 在不同 shell 环境下的小坑
如果你把 context-mode 放进.bashrc或者拿来跑管道,有几个坑我踩了不止一次。
第一个坑是退出码。很多命令在管道里会因为日志中没有匹配行而“安静地成功”,或者不应该因为没匹配就返回非 0。我在最小实现里没有处理退出码,后来加了--exit-status:默认 0;开启后,如果没有任何匹配行,返回 1。这样方便在 CI 脚本里判断“这次日志里到底有没有出现这个错误”。
第二个坑是颜色转义。在终端里输出颜色没问题,但如果你把输出重定向到文件,颜色码会污染文件内容。所以我加了--color选项,默认自动:如果 stdout 是终端就开启,否则关闭。如果你发现重定向后的文件里有一堆\033[31m,记得检查是不是你手动指定了--color=always。
第三个坑是 Windows 和编码。Windows 下默认编码可能是 GBK,而日志是 UTF-8。读取时不要用open(sys.stdin)就完事,建议显式指定encoding="utf-8", errors="replace",否则碰到非法字节会直接抛异常。现在 Python 多数版本默认还是跟随系统编码,所以跨平台封装时,最好在入口处做一次sys.stdin.reconfigure(encoding="utf-8")。
第四个坑是信号处理。管道下游如果只看了 20 行就中断,比如context-mode ... | head -20,上游的 Python 进程会收到 SIGPIPE。如果默认不处理,终端可能显示BrokenPipeError。这时要在 main 里捕获BrokenPipeError和SIGPIPE,并在退出前把 stdout 的缓冲 flush 掉。否则你的脚本会残留一堆可笑的异常堆栈。
5.4 写出你自己的规则时,建议先画三张小表
最后分享一个我个人的经验:在给 context-mode 自定义规则时,不要一上来就写正则。先在纸上画三张表:
- 行特征表:哪些行特征代表“前因”,哪些代表“后果”,哪些代表“噪音”。
- 边界表:哪些特征会强制断开当前上下文块,比如空行、时间跳跃、缩进恢复。
- 输出策略表:遇到命中行、重复行、堆栈行分别怎么展示。
这三张表画完,你的实现就清晰了。很多人把这个工具做得越来越复杂,最后反而不好用,就是因为跳过了这一步,不断往里面加 if,却没有形成一个稳定的规则框架。
我后来把 context-mode 的规则设计成一个 YAML 配置,里面允许为不同日志格式定义独立的“模式文件”。这样换到一个新项目,只需要跟着业务日志格式写一个模式文件,不用改 Python 代码。这也是它能在我的个人工具链里持续活下来的原因——不绑定具体业务,但能适配具体格式。
如果你也想写一个自己用的上下文查看工具,我的建议是从最小版本开始,先解决“打印前 N 行后 N 行”的问题,再逐步加入分组和折叠。别想着一步到位做出一套通用规则,因为你手里的日志格式、你所在的团队习惯,都会影响“上下文”到底该怎么定义。工具是死的,模式是活的,真正的 context-mode 应该是你重新认识日志的一把钥匙,而不是又一个自动生成“看起来有上下文”的脚本。