深夜告警之后：全栈工程师的生产环境排障实战——从一条告警到根因的完整路径

摘要：全栈工程师和"只会写代码"的分水岭，不在平时，而在深夜告警响起的那一刻。这篇不讲理论，而是完整复盘一次真实的生产排障（细节脱敏）：某个周五晚上 21:47，订单接口的 P99 延迟从 200ms 飙到 4 秒——从第一条告警到定位根因、再到修复和复盘，每一步都是真实动作：看什么指标、跑什么命令、什么现象指向什么嫌疑、以及那些"看起来相关其实是巧合"的坑。配完整命令、Trace 样例、示意图和排查决策表。建议收藏——下次告警响起时，照着走。

目录

1. 事故现场：21:47，P99 飙了 20 倍
2. 排障总纲：先止血，再查因（金线原则）
3. 第一步：缩小范围——它到底慢在哪一层
4. 第二步：数据库层排查——慢查询与锁
5. 第三步：应用层排查——线程池、GC 与连接池
6. 第四步：基础设施层排查——CPU 饱和的真相
7. 第五步：根因确认——一次发布引发的雪崩
8. 修复与验证：怎么确认"真的好了"
9. 复盘与沉淀：把一次事故变成三份资产
10. 排障方法论总结：一张决策表带走

1. 事故现场：21:47，P99 飙了 20 倍

先摆现场。当晚的监控大盘上，三个指标几乎同时异常：

P99 延迟曲线（示意）：

400ms ┤
200ms ┤ ────────────╮
│ ╲
│ ╲___
│ ╲_______
4.1s ┤ ●—————————————● ← 平台期（不是继续恶化，
│ 21:47 21:55 说明系统"稳定地坏"）

一个立刻有用的判断：曲线的形状本身就是线索。21:47 是一个明确的拐点（说明有明确的触发事件），21:55 后进入平台期（说明不是"持续恶化的资源泄漏"，而是"稳定运行的错误配置或饱和状态"）。拐点 + 平台期 → 第一嫌疑：21:47 前后有什么东西变了——发布？配置？定时任务？流量？

这是排障的第一个纪律：先看曲线形状，再猜原因。渐进恶化 → 泄漏类（连接泄漏、内存泄漏、缓存击穿加剧）；突然跳变 → 变更类（发布、配置、流量）；周期性锯齿 → 定时任务类（每小时的批处理、每分钟的 cron）。

2. 排障总纲：先止血，再查因（金线原则）

深夜排障最大的坑，是在用户还在受苦的时候沉迷找根因。正确顺序是两条线并行：

┌─── 止血线（快，救用户）──────────────────────┐
│ ① 回滚最近发布（如果是变更引起，5分钟见效） │
事故 ──┤ ② 降级非核心功能（砍掉推荐/日志等旁路依赖） │
│ ③ 扩容（如果是容量问题，加机器先扛住） │
│ ④ 熔断（把对故障依赖的调用熔掉，防雪崩扩散） │
└──────────────────────────────────────────┘

┌─── 查因线（慢，找根因）──────────────────────┐
│ ① 保留现场：堆栈/慢查询/指标快照，别急着重启 │
│ ② 分层定位：慢在哪一层（第 3 节） │
│ ③ 顺藤摸瓜：从最慢的 span 往下钻（第 4~7 节） │
└──────────────────────────────────────────┘

两条线的分工要明确到人：止血的人和查因的人不能是同一个（一个人做不到边回滚边分析）。本次事故里，值班同学 21:52 先执行了"扩容应用实例 + 开启对推荐服务的熔断"止血，我留在查因线上保留现场分析——止血措施本身会改变现场（比如回滚会让 Trace 和堆栈变得不可解读），所以查因线要抢在止血前把关键现场快照下来：

# 保留现场三件套（在止血动作之前执行）
kubectl exec -it app-7d9f8c2-abc12 -- jstack 1 > /tmp/stack1.txt # 线程堆栈
kubectl exec -it app-7d9f8c2-abc12 -- jmap -histo 1 | head -30 # 对象直方图
psql -c "SELECT pid, now()-query_start AS dur, state, query
FROM pg_stat_activity WHERE state != 'idle'
ORDER BY dur DESC LIMIT 20" # 活跃 SQL 快照

3. 第一步：缩小范围——它到底慢在哪一层

现场保留后，第一件事是回答：4 秒的延迟，分布在哪一层？拿一条真实慢请求的 Trace：

{
"trace_id": "t-7a2e",
"total_ms": 4120,
"spans": [
{"service": "gateway", "span": "route", "ms": 2},
{"service": "order-svc", "span": "auth.check", "ms": 4},
{"service": "order-svc", "span": "db.wait_conn", "ms": 3180}, ← ⚠️ 77% 在等连接！
{"service": "order-svc", "span": "db.query", "ms": 42},
{"service": "order-svc", "span": "recommend.call", "ms": 820}, ← ⚠️ 20% 在等推荐服务
{"service": "order-svc", "span": "kafka.send", "ms": 1},
{"service": "gateway", "span": "response", "ms": 2}
]
}

Trace 一眼就给出了嫌疑排序：db.wait_conn3180ms（77%）——应用在等数据库连接，而不是在等 SQL 执行（db.query才 42ms）；recommend.call820ms（20%）——推荐服务也慢了。这不是两个独立问题：连接被"慢"占住，后面的请求排队等连接，是典型的级联效应。

级联效应示意（本次事故的核心机制）：

推荐服务变慢(820ms)
↓
每个请求占用数据库连接的时间变长
↓
连接池(15/实例)被慢请求占满
↓
新请求在 db.wait_conn 排队(3180ms)
↓
排队 → 超时 → 重试 → 更多的请求 → 雪崩

这个现象给出排查的第二个纪律：分清"因"和"症状"。db.wait_conn高是症状，不是病；真正的因在"谁把连接占住了"。很多团队看到"连接池耗尽"就去调大连接池——这是把病治得更重：池越大，被慢请求占住的连接越多，数据库压力越大。正确方向是查"为什么请求持连接的时间变长了"。

顺藤摸瓜：为什么recommend.call从平时的 60ms 变成 820ms？先看推荐服务——它不在本服务的代码库里，但 Trace 显示它的延迟也涨了 13 倍。跨服务的共同异常，往往指向共同的基础设施或共同的依赖。继续往下钻。

4. 第二步：数据库层排查——慢查询与锁

虽然db.query只有 42ms，但连接打满必须确认数据库本身是否健康。标准四连：

-- ① 谁在占连接？在干什么？
SELECT pid, state, now()-query_start AS running_for, wait_event_type, query
FROM pg_stat_activity
WHERE state != 'idle' ORDER BY running_for DESC;

-- 结果：大量连接处于 'idle in transaction'！
-- ← 这是本次事故的第一个关键线索

-- ② 有没有锁等待？
SELECT count(*), wait_event_type FROM pg_locks
WHERE NOT granted GROUP BY wait_event_type;
-- 结果：无锁等待。排除"锁问题"这个分支。

-- ③ 慢查询有变化吗？
SELECT query, calls, mean_exec_time
FROM pg_stat_statements ORDER BY mean_exec_time DESC LIMIT 5;
-- 结果：Top5 慢查询的均值和平时一致。排除"SQL 变慢"分支。

-- ④ 数据库本身资源如何？
-- iostat -x 1（磁盘 util）、vmstat（负载）——都在正常范围。

第 ① 条的结果是本次事故的决定性线索：大量连接处于idle in transaction——事务开着，但不在执行任何 SQL。这是典型的应用侧问题：代码在事务里做了"和数据库无关的事"（比如调用了推荐服务！），事务期间连接被白白占住。

idle in transaction 的成因图：

❌ 错误模式（本次事故）：
BEGIN;
SELECT ... FROM orders; ← 42ms
调用推荐服务 HTTP 请求... ← 820ms！！连接全程空转占用
UPDATE orders SET ...;
COMMIT;
连接占用 = 42 + 820 + 5 ≈ 870ms（其中 820ms 是纯浪费）

✅ 正确模式：
第一段事务：SELECT ...; UPDATE ...; COMMIT; ← 连接占用 47ms
事务外：调用推荐服务 ← 不占数据库连接

到这里，根因链已经清晰：有人在事务里串了一次推荐服务的 HTTP 调用 → 推荐服务一慢，每个请求占连接 870ms → 连接池 15 个连接被迅速占满 → 后续请求排队 → P99 飙到 4 秒。但还剩一个问题：推荐服务为什么突然从 60ms 变 820ms？

5. 第三步：应用层排查——线程池、GC 与连接池

顺藤摸瓜到推荐服务。它的 Trace 显示自身处理只要 30ms，但 P99 有 820ms——大头不在处理，在排队。三个标准嫌疑：

# 嫌疑① GC 停顿：看 GC 日志
kubectl logs recommend-svc-xxx | grep "Pause Full" | tail -5
# 结果：Full GC 20 分钟一次、每次 1.2s —— 有嫌疑但不致命（不够 820ms 的频率）

# 嫌疑② 上游线程池/下游连接池打满
curl -s localhost:9090/metrics | grep -E "pool_active|pool_queued"
# pool_active = 200/200, pool_queued = 3400 ← ⚠️ 下游连接池打满 + 大量排队！

# 嫌疑③ 它的下游是谁？
# Trace 显示 recommend-svc → 数据分析服务的调用延迟 750ms

嫌疑②命中：推荐服务自己的下游连接池打满了。继续追一层：推荐服务依赖"数据分析服务"，而后者延迟 750ms。为什么？

# 数据分析服务的 CPU 与负载
kubectl top pod | grep analytics
# analytics-xxx 980m / 1000m ← CPU 饱和（98% 限额，正在被节流）

CPU 98% 限额 + 节流（throttling）——查因线在这个瞬间指向了基础设施层。

6. 第四步：基础设施层排查——CPU 饱和的真相

Pod CPU 98% 但限流是 1000m——它一直这么吃 CPU 吗，还是 21:47 之后才开始？Prometheus 里拉历史曲线：

analytics CPU 使用率（过去 6 小时）：

1000m ┤ ●●●●●●●●
│ ●●
200m ┤ ●●●●●●●●●●●●●●●●●●●●●●●●●●●●●●●
│
└────────────────────────────┬──────────────→
21:47（又是这个时间点！）

21:47 整点跳变——和订单接口的异常时间完全吻合。查这个时间点发生了什么变更：

# 发布记录
kubectl rollout history deployment/analytics
# 21:46 revision 42 → analytics v2.31.0（新版本：实时特征计算）

# 对照发布日历
# 21:45 ># 21:47 order-svc P99 飙升 ← 两分钟延迟差 = 级联传导时间

根因浮出水面：data-team 21:45 发布了 analytics v2.31.0，新版本在同步调用路径里加了一个重计算（实时特征计算），CPU 直接打满并被限额节流 → 依赖它的推荐服务排队 → 依赖推荐服务的订单接口在事务里等它 → 连接池被占满 → 全站 P99 飙升。

一条 750ms 的下游延迟，跨过四个服务，最终以"连接池耗尽"的形态爆炸——这就是级联故障的典型形态，也是为什么排障不能只看自己的服务。

7. 第五步：根因确认——一次发布引发的雪崩

把完整的因果链画出来，确认每一环都有证据：

根因链（每一环都有监控/日志证据）：

① 21:45>└ 证据：rollout history + 发布日历
② 新版本同步路径引入重计算，CPU 饱和并节流
└ 证据：CPU 曲线 21:47 跳变 + kubectl top 节流状态
③ 分析服务延迟 60ms → 750ms
└ 证据：Trace（recommend-svc 下游 span）
④ 推荐服务下游连接池打满，排队 3400
└ 证据：pool_active/pool_queued 指标
⑤ 推荐服务延迟 60ms → 820ms
└ 证据：订单接口 Trace
⑥ ⭐ 订单服务在事务内调用推荐服务 → 连接被 idle in transaction 占住
└ 证据：pg_stat_activity 大量 idle in transaction
⑦ 订单服务连接池耗尽，请求排队 → P99 4.1s、错误率 2.3%
└ 证据：全局监控 + db.wait_conn span

⭐ 标记的 ⑥ 是"放大器"：把一次普通的下游变慢，放大成全站雪崩。

⑤ 和 ⑥ 是两根引线：⑤ 是别人的变更（外部诱因），⑥ 是自己的代码缺陷（内部放大器）。这次事故的教训要拆成两半：data-team 的发布触发了它，但 order-svc 的"事务内远程调用"决定了它的爆炸半径。别人的变更你控制不了，自己的放大器可以。

7.5 四个经典误判：看起来相关，其实是巧合

排障中比"找不到线索"更危险的是抓住假线索猛钻。本次复盘时把当晚差点走偏的四个方向记下来，供对号入座：

误判一："连接池耗尽 → 调大连接池"。当晚值班同学的第一反应是扩容应用实例（相当于加连接）。幸好查因线抢在扩容生效前抓到了idle in transaction——池调大后，被空闲事务占住的连接更多，数据库压力更大，雪崩只会更重。连接池耗尽永远先查"占连接的时间"，再谈池大小。

误判二："慢查询日志没变化 → 数据库没问题"。pg_stat_statements的 Top5 和平时一致，差点让团队跳过数据库层。但本次数据库层的问题不在 SQL——在连接的使用方式。"SQL 没变慢"不等于"数据库层没问题"，连接状态、锁等待、事务行为都要看全。

误判三："推荐服务一直慢 → 是老问题"。有人提出"推荐服务上周也慢过，是历史遗留"。但 Trace 显示它上周是 90ms，今晚 820ms——量级完全不同的"慢"是两个问题。经验数据（上周的基线）和今晚的异常不能混为一谈，这也正是要给每个服务的延迟建立"基线"的原因。

误判四："CPU 飙升 → 有人在做批处理"。cellspacing="0">

误判

为什么诱人

反驳证据

调大连接池

见效最快的"常识"

idle in transaction——占连接的是空闲，不是并发

跳过数据库层

SQL 没变慢

连接使用方式变了（idle in transaction）

归因历史问题

省事的解释

基线 90ms vs 今晚 820ms，量级不同

归因定时任务

时间点吻合

调度日志显示批处理没提前跑

这四个误判共同指向排障的核心纪律："合理的解释"不等于"有证据的解释"——每个归因都要有一条日志或指标背书，否则就继续查。

8. 修复与验证：怎么确认"真的好了"

修复分三个层次，按紧急度排列：

止血（当晚 22:10）：回滚 analytics 到 v2.30.0。2 分钟后全链路指标恢复：

回滚后 5 分钟：
P99 延迟 4.1s → 230ms ✓
连接池 100/100 → 38/100 ✓
错误率 2.3% → 0.02% ✓

治本（次日内）：修掉 ⑥——把推荐服务调用移出事务：

# ❌ 修复前：事务内调远程服务（连接被空闲占用 820ms）
async def get_order_detail(order_id: int):
async with db.transaction():
order = await db.fetchrow("SELECT * FROM orders WHERE id=$1", order_id)
rec = await recommend_client.get(order["user_id"]) # ← 820ms，占连接
await db.execute("UPDATE orders SET viewed=true WHERE id=$1", order_id)
return {**dict(order), "recommend": rec}

# ✅ 修复后：事务只包数据库操作，远程调用移到事务外
async def get_order_detail(order_id: int):
async with db.transaction():
order = await db.fetchrow("SELECT * FROM orders WHERE id=$1", order_id)
await db.execute("UPDATE orders SET viewed=true WHERE id=$1", order_id)
rec = await recommend_client.get(order["user_id"],
timeout=0.2, # 超时兜底
circuit_breaker=True) # 熔断防雪崩
return {**dict(order), "recommend": rec}

三个必须一起做的加固，缺一不可：

1. 超时兜底：远程调用必须有超时（timeout=0.2），永不等待是分布式系统的第一戒律。
2. 熔断器：下游持续超时自动熔断（快速失败 + 降级数据），把"下游慢"的爆炸半径掐断——本次如果有熔断，⑥ 的放大链在第 ③ 步就断了。
3. 事务边界纪律：事务里只放数据库操作。这个要写成团队规范 + code review 必查项，因为它是编译器和运行时都不会报错的缺陷，只有人能拦住。

验证（修复后一周）：把 analytics v2.31.0 修好 CPU 问题后重新发布，同时在预发环境做一次故障演练——用 toxiproxy 给推荐服务注入 1 秒延迟，验证订单接口在"下游 1s 延迟"下的 P99 从 4.1s 降到 240ms（熔断生效）。修复没有经过故障演练验证，就不算修复完成。

9. 复盘与沉淀：把一次事故变成三份资产

事故的最终价值在于沉淀。本次复盘产出三份资产：

资产一：无责复盘文档（Blameless Postmortem）。时间线、因果链、影响面、改进项——注意是无责的：追问"系统为什么允许这个缺陷存在"，而不是"谁写的这行代码"。复盘的输出是改进项清单：

资产二：两条新告警（这是"下次更快"的关键）：

新告警①：idle in transaction 连接数 > 20 持续 2 分钟 → warning
（本次事故在 P99 飙升前 2 分钟就有这个信号，比用户投诉早得多）

新告警②：下游依赖延迟 > 500ms 持续 1 分钟 → warning
（级联传导的早期信号，比"自己 P99 飙升"早 2 分钟）

资产三：更新排障手册。本次新学到的三条进手册：idle in transaction是"事务内远程调用"的特征签名；连接池耗尽先查"占连接的时间"而不是"调大池子"；跨服务共同异常优先查共同依赖。

10. 排障方法论总结：一张决策表带走

把本次事故的方法论压缩成一张可复用的决策表：

告警响起
│
├─ 第一步：看曲线形状
│ ├ 突然跳变 → 查变更（发布/配置/定时任务）
│ ├ 渐进恶化 → 查泄漏（连接/内存/缓存）
│ └ 周期锯齿 → 查定时任务
│
├─ 第二步：保现场（止血前抓堆栈/SQL 快照）
│
├─ 第三步：拿慢请求 Trace，定位最慢的 span
│ ├ 慢在 db.query → 数据库层（慢查询/锁/索引）
│ ├ 慢在 wait_conn → 查"谁占着连接"（idle in transaction!）
│ ├ 慢在下游 rpc 调用 → 顺藤摸瓜到下游，查它的池和 CPU
│ └ 慢在自己代码 → 堆栈/火焰图/GC
│
├─ 第四步：多服务共同异常 → 查共同依赖/基础设施/变更
│
└─ 第五步：修复三件套 = 止血回滚 + 治本加固 + 故障演练验证

六句话收束全文：

1. 先止血，再查因——两条线并行，止血的人不能同时查因。
2. 先看曲线形状，再猜原因——跳变查变更、渐进查泄漏、锯齿查定时任务。
3. 分清因和症状：连接池耗尽是症状，"谁占着连接"才是病；调大池子是把病养肥。
4. `idle in transaction` 是"事务内远程调用"的特征签名——事务里只放数据库操作，这条要写进团队规范。
5. 别人的变更你控制不了，自己的放大器可以——超时、熔断、事务边界纪律，决定爆炸半径。
6. 每次事故沉淀三份资产：无责复盘、新告警、更新的排障手册——事故的最终价值是让下一次更快。

深夜排障最迷人的地方：你是在读一个分布式系统"案发现场"的侦探。这篇文章是"请求生命周期"的续篇——上一篇讲系统怎么运转，这一篇讲系统怎么坏掉、怎么查、怎么让它不再坏。想看"缓存雪崩"或"消息堆积"的专场复盘，评论区点单。

参考与延伸阅读：

• Google SRE Book: Emergency Response / Postmortem Culture
• 《Designing Data-Intensive Applications》——连接池与事务的原理根基
• OpenTelemetry / 分布式追踪实践
• PostgreSQL: pg_stat_activity 与锁监控文档