Java

线上故障排查时,为什么“最近一次变更”总值得先查?

那天明明没人发版,21:07 的超时却紧贴着路由权重调整、回填任务恢复和证书轮换长出来。把暂停回填后的回落、权重调回后的样本变化放回现场后,“最近变更值得先查”就不再像一句主张,而像一条被验证过的收敛路径。

  • 线上故障
  • 故障排查
  • 变更管理
  • 稳定性
  • Java
15 分钟阅读

很多人一听“先查最近一次变更”,会下意识想到一句有点空的话:

反正出了事,总得先找个最近动过的地方看看。

我后来越来越不想这么讲它。因为这条线真正值钱的时候,不是它像一种经验偏好,而是它能在现场里被很快验证。

那次 21:07 的超时就是这样。

群里一开始的判断很直接:

“今天没发版,先别浪费时间查变更。”

但把最近半小时真正动过的东西列出来,现场马上就不是这句话了。

时间变更现场影响
20:42gateway-route-order 权重从 old=80/new=20 调成 old=50/new=50更多订单流量进新网关分组
20:55coupon-rule-backfill 从暂停改成恢复执行开始扫历史订单和优惠券规则
21:00支付下游证书轮换完成TLS 建连抖动约 2 分钟
21:07submitOrder timeout 开始抬用户开始感知

到这里,“最近变更”还只是线索,不算结论。真正让它从线索变成主线的,是后面几次很具体的验证。

第一条证据:异常的形状和变更边界先对上了

如果最近变更只是碰巧最近,它通常解释不了异常样本为什么长成现在这个样子。

那次 submitOrder 超时抬头以后,我们先把请求样本按网关分组拆开,结果非常偏:

时间窗 21:07 - 21:12请求量占比timeout rateP99
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 sessionscoupon_rule 热点索引读 IOPSsubmitOrder timeout rate
20:54431.2k/s0.4%
20:58793.9k/s0.9%
21:031126.8k/s2.6%
21:071287.4k/s8.7%

21:12 我们没有先动路由,先暂停了回填任务。后面几分钟的回落很干净:

时间DB active sessionscoupon_rule 热点索引读 IOPSsubmitOrder timeout rate
21:111267.1k/s8.1%
21:14843.2k/s4.5%
21:16581.9k/s2.8%
21:18491.4k/s2.3%

这里很难再把“最近变更值得先查”理解成一句口号。因为暂停一个 20:55 才恢复的任务以后,最先回落的正是它最可能影响到的那组指标:

  • 数据库活跃会话数往下掉
  • 热点索引读压降下来
  • submitOrder timeout 跟着回落一截

这说明回填任务至少不是背景噪音,它确实在事故窗口里给主链路加了负担。

第三条证据:把路由权重调回去后,坏样本跟着迁回去了

但为什么 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 分组 P993.8s1.1s
全链路 timeout rate2.6%0.7%

这组变化很值钱,因为它不是一句“调回去就好了”的空话,而是异常样本的归属真的跟着权重一起动了:

  • 分到 gateway-new 的订单流量占比从一半掉到两成
  • timeout 样本里属于 gateway-new 的部分,从 76% 掉到 28%
  • 整体超时率跟着一起压下去

到这里,最近变更已经不只是“值得怀疑”,而是被现场证明过两次:

  1. 暂停 20:55 恢复的回填任务,数据库等待和接口超时先回落
  2. 调回 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 恢复的回填任务。

所以“最近变更值得先查”,不是因为它方便,而是因为它最容易被证伪或证实

回头看这次现场,最值钱的动作其实很朴素:

  • 先把最近半小时真正动过的东西列出来
  • 看异常样本是不是贴着这些变更的边界长出来
  • 对验证成本低的那几条,直接做回退或暂停
  • 观察是不是有一组会同步回落、样本会同步迁移

这条路之所以常常比空猜更快,不是因为变更天然更可疑,而是因为它天然更适合做验证。

那次如果一直停在“今天没发版,所以别查变更”,现场就会把路由调整、回填恢复、证书轮换全都排除在外。可真正让故障线收紧的,恰恰就是把这些变化重新摆回时间线,然后看谁能被现场证据压实。

所以我现在更愿意把题目里的那句话改写成更具体的一句:

最近一次变更总值得先查,不是因为它听起来像经验,而是因为你往往能用几分钟内的回退、暂停、样本迁移和指标回落,迅速知道它到底是不是主线。