线上故障排查时,为什么“最近一次变更”总值得先查?
那天明明没人发版,21:07 的超时却紧贴着路由权重调整、回填任务恢复和证书轮换长出来。把暂停回填后的回落、权重调回后的样本变化放回现场后,“最近变更值得先查”就不再像一句主张,而像一条被验证过的收敛路径。
很多人一听“先查最近一次变更”,会下意识想到一句有点空的话:
反正出了事,总得先找个最近动过的地方看看。
我后来越来越不想这么讲它。因为这条线真正值钱的时候,不是它像一种经验偏好,而是它能在现场里被很快验证。
那次 21:07 的超时就是这样。
群里一开始的判断很直接:
“今天没发版,先别浪费时间查变更。”
但把最近半小时真正动过的东西列出来,现场马上就不是这句话了。
| 时间 | 变更 | 现场影响 |
|---|---|---|
| 20:42 | gateway-route-order 权重从 old=80/new=20 调成 old=50/new=50 | 更多订单流量进新网关分组 |
| 20:55 | coupon-rule-backfill 从暂停改成恢复执行 | 开始扫历史订单和优惠券规则 |
| 21:00 | 支付下游证书轮换完成 | TLS 建连抖动约 2 分钟 |
| 21:07 | submitOrder timeout 开始抬 | 用户开始感知 |
到这里,“最近变更”还只是线索,不算结论。真正让它从线索变成主线的,是后面几次很具体的验证。
第一条证据:异常的形状和变更边界先对上了
如果最近变更只是碰巧最近,它通常解释不了异常样本为什么长成现在这个样子。
那次 submitOrder 超时抬头以后,我们先把请求样本按网关分组拆开,结果非常偏:
| 时间窗 21:07 - 21:12 | 请求量占比 | timeout rate | P99 |
|---|---|---|---|
gateway-new 分组 | 52% | 11.8% | 4.6s |
gateway-old 分组 | 48% | 1.9% | 780ms |
权重在 20:42 被调成 50/50,21:07 开始最严重的超时也正好主要落在 gateway-new 分组里。这里有两个事实先站住了:
- 异常不是均匀打在所有入口上的
- 新近调高权重的那一边,样本明显更差
这还不能说明根因一定是路由,但它已经足够说明:最近的路由调整,不只是“最近”,而且和异常边界是对得上的。
第二条证据:暂停回填后,先回落的是数据库等待和应用超时
接着看回填任务。
coupon-rule-backfill 20:55 恢复后,数据库上和订单相关的两组指标先开始挤:
| 时间 | DB active sessions | coupon_rule 热点索引读 IOPS | submitOrder timeout rate |
|---|---|---|---|
| 20:54 | 43 | 1.2k/s | 0.4% |
| 20:58 | 79 | 3.9k/s | 0.9% |
| 21:03 | 112 | 6.8k/s | 2.6% |
| 21:07 | 128 | 7.4k/s | 8.7% |
21:12 我们没有先动路由,先暂停了回填任务。后面几分钟的回落很干净:
| 时间 | DB active sessions | coupon_rule 热点索引读 IOPS | submitOrder timeout rate |
|---|---|---|---|
| 21:11 | 126 | 7.1k/s | 8.1% |
| 21:14 | 84 | 3.2k/s | 4.5% |
| 21:16 | 58 | 1.9k/s | 2.8% |
| 21:18 | 49 | 1.4k/s | 2.3% |
这里很难再把“最近变更值得先查”理解成一句口号。因为暂停一个 20:55 才恢复的任务以后,最先回落的正是它最可能影响到的那组指标:
- 数据库活跃会话数往下掉
- 热点索引读压降下来
submitOrdertimeout 跟着回落一截
这说明回填任务至少不是背景噪音,它确实在事故窗口里给主链路加了负担。
第三条证据:把路由权重调回去后,坏样本跟着迁回去了
但为什么 21:18 以后超时还没完全消失?
因为还有另一半证据没做完:入口流量分布。
21:20,我们把 gateway-route-order 的权重从 old=50/new=50 调回 old=80/new=20。这次最关键的不是总量变化,而是坏样本怎么迁移。
调整前后 5 分钟,对照是这样的:
| 样本 | 调整前(21:15 - 21:20) | 调整后(21:21 - 21:26) |
|---|---|---|
落在 gateway-new 的订单请求占比 | 51% | 19% |
全部 timeout 样本里来自 gateway-new 的占比 | 76% | 28% |
gateway-new 分组 P99 | 3.8s | 1.1s |
| 全链路 timeout rate | 2.6% | 0.7% |
这组变化很值钱,因为它不是一句“调回去就好了”的空话,而是异常样本的归属真的跟着权重一起动了:
- 分到
gateway-new的订单流量占比从一半掉到两成 - timeout 样本里属于
gateway-new的部分,从 76% 掉到 28% - 整体超时率跟着一起压下去
到这里,最近变更已经不只是“值得怀疑”,而是被现场证明过两次:
- 暂停 20:55 恢复的回填任务,数据库等待和接口超时先回落
- 调回 20:42 改过的路由权重,坏样本从
gateway-new分组明显退潮
证书轮换这条线为什么最后没被放到最前面
21:00 的支付证书轮换也是真变更,而且时间也贴得很近。
但把它和前两条线放在一起看,优先级就自然往后排了。
因为证书轮换对应的证据只有一段短时建连抖动:
21:00:14 WARN ssl handshake retry upstream=pay-core cost=412ms
21:01:07 WARN ssl handshake retry upstream=pay-core cost=537ms
21:02:31 INFO tls session resumed upstream=pay-core
21:03 之后,这组握手重试已经明显回落,可 submitOrder 的 timeout 还在继续爬,直到 21:12 暂停回填、21:20 调回权重以后才真正往下走。
也就是说,证书轮换不是没影响,而是它解释不了 21:07 以后那段持续的异常形状。真正能解释并且能被验证压下去的,还是 20:42 的路由调整和 20:55 恢复的回填任务。
所以“最近变更值得先查”,不是因为它方便,而是因为它最容易被证伪或证实
回头看这次现场,最值钱的动作其实很朴素:
- 先把最近半小时真正动过的东西列出来
- 看异常样本是不是贴着这些变更的边界长出来
- 对验证成本低的那几条,直接做回退或暂停
- 观察是不是有一组会同步回落、样本会同步迁移
这条路之所以常常比空猜更快,不是因为变更天然更可疑,而是因为它天然更适合做验证。
那次如果一直停在“今天没发版,所以别查变更”,现场就会把路由调整、回填恢复、证书轮换全都排除在外。可真正让故障线收紧的,恰恰就是把这些变化重新摆回时间线,然后看谁能被现场证据压实。
所以我现在更愿意把题目里的那句话改写成更具体的一句:
最近一次变更总值得先查,不是因为它听起来像经验,而是因为你往往能用几分钟内的回退、暂停、样本迁移和指标回落,迅速知道它到底是不是主线。