用 grep 和 awk 从日志里快速定位问题的一次实战

上周三下午，部署在云服务器上的一套订单服务突然出现接口超时，监控先报了 5xx 比例升高，随后客服群里也开始有人反馈下单失败。没有现成的链路追踪面板可用，我手边只有一台能登录的服务器和 /var/log/app/order.log，最后就是靠 grep 和 awk 在二十分钟里把问题范围从“整个服务”缩小到了“一行配置”。把这次的思路和命令记录下来，希望对同样需要在线上救火的同学有用。

第一步：先看量，再看错

出问题先不要急着翻具体报错，先确认影响面有多大。第一条命令是统计当天错误日志的数量和分布：

grep -c "ERROR" /var/log/app/order.log
grep "ERROR" /var/log/app/order.log | head -20

grep -c 只计数不输出内容，适合先判断量级；head -20 则看前几条报错长什么样。那天的情况是：错误数在十分钟内从每小时几条涨到了上千条，而且报错集中在下单接口，登录和查询接口基本正常。这一步就排除了“整台机器挂了”的猜测，问题大概率出在下单链路的某个环节。

第二步：用时间窗把故障切出来

日志文件很大，直接全文翻等于大海捞针。先从监控上确认故障开始的大致时间是 15:20 左右，再用 grep 只取这个时间段：

grep "2026-10-28 15:2" /var/log/app/order.log | grep "ERROR" | head -30

这里利用了日志时间格式是文本前缀的特点：15:2 可以匹配 15:20 到 15:29 的全部记录。如果日志里的时间格式不同，可以先 head -5 看一眼格式再写模式。切出时间窗之后，报错一下子清晰了：大量 DownstreamTimeoutException，后面跟着 payment-service，几乎没有别的异常类型。

第三步：用 awk 做一次错误分布统计

知道异常类型还不够，还要知道它发生在哪些订单、哪些用户、哪些下游上。我们的日志格式是固定的：时间 级别 模块 订单号 耗时ms 消息，字段之间用空格分隔，正好适合 awk 按列处理：

grep "2026-10-28 15:2" /var/log/app/order.log | grep "ERROR" | awk '{print $3, $6}' | sort | uniq -c | sort -nr | head -10

这条管道的思路是：先用 grep 过滤，再用 awk 取出模块和消息关键词，sort | uniq -c | sort -nr 做计数和倒序。结果显示，payment-service 的超时占了九成以上，其他模块的报错只是零星的重试记录。顺手再按订单号统计一次，发现失败订单分散在不同用户之间，排除了“某个大客户在刷单”的可能。

第四步：顺藤摸瓜找到根因

既然矛头指向支付下游，就继续追问两个问题：是下游真的慢，还是我们这边等得太短？先看耗时分布：

grep "payment-service" /var/log/app/order.log | grep "2026-10-28 15:2" | awk '{print $5}' | sort -n | awk '{a[NR]=$1} END{print "中位数:", a[int(NR/2)], "最大值:", a[NR]}'

中位数耗时从平时的 120 毫秒涨到了 2900 毫秒左右，最大值接近 3 秒——正好卡在我们配置的 3 秒超时上。这说明下游确实变慢了，而我们的超时时间又设得太紧，稍有波动就大面积失败。后来和支付侧同学确认，他们当天在做一次灰度发布，部分节点响应变慢；我们这边把超时从 3 秒放宽到 8 秒，并给下单接口加了有限次数的重试和熔断，错误率在十分钟内回落到正常水平。

复盘：三条可以复用的习惯

第一，日志格式先定好再谈排查。时间、级别、模块、耗时这些字段固定下来，grep 和 awk 才能直接按列切分；如果日志是自由文本，排查成本会成倍上升。第二，先统计再细读。grep -c、uniq -c 这类聚合命令能在几十秒内告诉你“问题集中在哪里”，比逐行翻日志快得多。第三，修完要验证。改完配置后，我用同样的命令再跑了一遍 16:00 之后的时间窗，确认错误数回落、耗时中位数回到 150 毫秒以内，才算真正收尾。

grep 和 awk 都是几十年的老工具，单看都不起眼，但组合起来就是一套随手可用的日志分析流水线：grep 负责按关键字和时间切出范围，awk 负责按字段统计和聚合，sort 和 uniq 负责排序计数。下次再遇到线上告警，不妨先别急着重启服务，花五分钟跑一遍这套组合，很多时候答案就藏在日志里。