Java

同一个 API 只有部分实例变慢,应该先查什么?

14:07,只有 3 台 `account-api` 的 `/profile/query` P99 从 220ms 顶到 3s,另外 9 台还稳着。碰到这种形状时,我更愿意先把慢实例和正常实例绑成对照,看请求样本、节点现实、配置来源和启动后状态到底从哪一步开始分叉。

  • 接口慢
  • 实例差异
  • Spring Boot
  • 故障排查
  • Java
17 分钟阅读

14:07,监控上只有 3 台 account-api/profile/query 开始抬头。

实例QPSP95P99timeout rate
account-api-7f6fd6-182240ms310ms0.1%
account-api-7f6fd6-279260ms340ms0.1%
account-api-7f6fd6-377230ms320ms0.1%
account-api-7f6fd6-8811.2s3.1s4.8%
account-api-7f6fd6-9841.4s3.4s5.2%
account-api-7f6fd6-10801.1s2.9s4.6%

这种时候,我第一反应不是“这条接口整体退化了”,而是:先把这 3 台和另外 9 台到底从哪里分叉找出来。

因为“同一个 API,只有部分实例慢”本身就已经把入口缩得很窄了。它不像全链路一起变慢那样要先看共享依赖,也不像单条 SQL 突然爆炸那样适合直接钻数据库。这里更值钱的,是把实例差异坐实。

先别盯整体平均值,先认出它是“少数实例先分叉”

这类现场最容易把人带偏的,是大盘还没完全红。

整体 P95 可能只从 260ms 抬到 480ms,看上去像一次普通抖动;但如果你把实例拆开,会发现问题已经很具体了:

  • 只有 3 台慢,其他实例还稳
  • 慢实例的 RT 形状接近,说明不是随机噪声
  • 超时率也集中在这 3 台,而不是全体一起抬

只要看到这种形状,我就不太愿意继续用“接口整体慢了”这种大词。因为这会把后面的排查顺序彻底带偏。

一旦把它当成整体问题,团队就很容易直接冲向:

  • 最近哪个 SQL 改了
  • 哪段业务逻辑新增了 RPC
  • 数据库是不是顶住了

这些方向不能说错,但在这个时刻通常还太早。先找实例差异,比先翻代码和 SQL 更快。

第一轮对照,我通常只拉三张表

这一步我不会贪多。真到线上,第一轮对照只要把下面三件事拉齐,方向通常就会站稳。

第一张:慢实例和正常实例接到的是不是同一种请求

先排掉样本偏差。

/profile/query 这种接口,真正把实例拉开的,常常不是代码差异,而是请求差异:

  • 某几台专门接到了大租户
  • 某些 Header 打开了额外的实验逻辑
  • 只有少数实例吃到了来自某个网关分组的流量
  • 某些请求参数触发了补查或降级分支

所以我会先抽同一个时间窗里的样本,把慢实例和正常实例摆成对照。

维度慢实例正常实例结论
tenantId 分布前 20 大租户占比 61%前 20 大租户占比 58%差异不大
needTagMerge=true34%32%差异不大
网关入口全部来自 gateway-prod-a同样来自 gateway-prod-a不是入口分流
请求体大小 P9518KB17KB不是样本体积差异

这张表一出来,至少可以先把“是不是慢实例刚好撞上了更脏的流量”排掉。

第二张:它们跑在什么现实里

如果请求样本差不多,我接下来会看实例现实,而不是先看业务逻辑。

最常抓出问题的其实是这些:

  • 节点池不一样
  • 启动时吃到的环境变量不一样
  • 挂载文件不一样
  • 容器 limit / request 不一样
  • JVM 参数或时区不一样

那次我拉出来的对照很简单:

项目慢实例正常实例
node groupworker-cold-02worker-hot-01
Pod 启动时间13:56 左右3 天前
SPRING_PROFILES_ACTIVEprodprod
启动命令一致一致
挂载目录 /app/config一致一致

这一步没有直接给出根因,但它给了我一个很重要的信号:慢实例全是刚拉起不久的新 Pod。

这意味着我更想去看“启动后有没有什么状态没跟上”,而不是继续围着数据库打转。

第三张:运行态是不是已经收敛

真正把这次问题钉住的,就是这张运行态对照。

指标慢实例正常实例
uptime11 分钟3 天
profileRuleCache.size2.4k28.7k
profileRuleCache.hitRate13%96%
hikaricp.connections.pending18~250~1
/profile/query 里的远程规则拉取每请求 1~2 次几乎没有

这几项一摆在一起,画面就清楚了:

  • 代码是一套
  • 请求样本差不多
  • 配置和启动命令也一致
  • 但慢实例的本地规则缓存还没热起来

到这里,我已经不太相信“某个 SQL 退化”这条线了。因为如果 SQL 真有问题,不会只在刚启动的 3 台实例上长成这种形状。

这次真正把问题钉住的,不是 SQL,而是启动后的本地状态

继续翻日志,慢实例上能看到两段非常值钱的记录:

13:57:04 INFO  ProfileRuleWarmTask start totalRules=28743
13:57:09 WARN  ProfileRuleWarmTask skipped batch=1201 reason=lock held by profile-rule-sync
14:07:12 WARN  /profile/query cost=2874ms missLocalRuleCache tenantId=acme traceId=7c3f...

这里最关键的不是“warm task 报了个 warn”,而是它把前面的三张表串起来了:

  • 这 3 台都是新 Pod
  • 新 Pod 启动后,本地规则缓存没有热完整
  • /profile/query 只要碰到规则缺口,就会回源拉远程规则
  • 远程拉取把连接池 pending 顶上去,于是 RT 和 timeout 一起抬头

这就是为什么我说,这类问题不能一上来就把锅扣到接口整体。

接口当然慢了,但它慢的方式已经告诉你:先出问题的是实例状态,不是接口定义本身。

真到线上,我更愿意这样收敛

如果你也遇到“同一个 API 只有部分实例慢”,我会建议排查顺序尽量短一点,别又写成长清单。

先确认它是不是真的“少数实例先分叉”

别看整体平均值,直接把实例拆开。

如果慢点真的集中在固定几台实例上,这条线就成立;如果拆开以后其实大家都一起抬,只是某几台更明显,那就不要死守实例差异这条线了。

再把一台慢实例和一台正常实例绑成对照

不要一次比十几台。线上最怕的是样本失控。

我通常只会固定一组:

bad-pod:  account-api-7f6fd6-9
ok-pod:   account-api-7f6fd6-2
window:   14:05 - 14:15
api:      /profile/query

只要这组对照站稳,后面的证据就比较容易往一个方向收。

最后才决定往哪条细线下钻

  • 如果请求样本不同,先顺着流量和参数查
  • 如果环境现实不同,先顺着 profile、挂载文件、JVM 参数查
  • 如果运行态没收敛,先看预热、本地缓存、定时任务和连接池
  • 如果这些都一样,再回到数据库、RPC、代码路径本身

这个顺序看起来不花哨,但很少让我在第一轮就走偏。

什么时候该停止沿“实例差异”这条线继续查

也有些现场,看上去像部分实例慢,实际上只是全局问题先在少数实例上露头。

下面几种情况,我会很快退出这条线:

  • 拆开实例后,所有 Pod 的等待链都在同步变长,只是幅度不同
  • 慢实例和正常实例的请求样本、环境、运行态都对齐了
  • 数据库、下游 RPC 或线程池的全局指标已经一起抬
  • 切走这几台慢实例后,别的实例很快接着变慢

这说明“少数实例”只是第一个露头的位置,不一定是根因所在的位置。

但在多数线上现场里,只要你真的把慢实例和正常实例拉成对照,问题通常不会再是那句空话:“同一个 API 为什么只有部分实例慢?”

它会变成一句更具体、也更容易解决的话:

“这几台实例的请求、环境或运行状态,到底是哪一步和别人不一样了?”

问题一旦改写成这样,排查基本就开始收口了。