深夜告警之后:全栈工程师的生产环境排障实战——从一条告警到根因的完整路径
发布时间:2026/9/29 15:07:05来源:尧图网络
摘要全栈工程师和只会写代码的分水岭不在平时而在深夜告警响起的那一刻。这篇不讲理论而是完整复盘一次真实的生产排障细节脱敏某个周五晚上 21:47订单接口的 P99 延迟从 200ms 飙到 4 秒——从第一条告警到定位根因、再到修复和复盘每一步都是真实动作看什么指标、跑什么命令、什么现象指向什么嫌疑、以及那些看起来相关其实是巧合的坑。配完整命令、Trace 样例、示意图和排查决策表。建议收藏——下次告警响起时照着走。目录事故现场21:47P99 飙了 20 倍排障总纲先止血再查因金线原则第一步缩小范围——它到底慢在哪一层第二步数据库层排查——慢查询与锁第三步应用层排查——线程池、GC 与连接池第四步基础设施层排查——CPU 饱和的真相第五步根因确认——一次发布引发的雪崩修复与验证怎么确认真的好了复盘与沉淀把一次事故变成三份资产排障方法论总结一张决策表带走1. 事故现场21:47P99 飙了 20 倍先摆现场。当晚的监控大盘上三个指标几乎同时异常指标正常值21:47 后说明订单接口 P99 延迟200ms4.1s用户侧体感页面转圈数据库活跃连接数35 / 100100 / 100打满⚠️ 连接池耗尽错误率5xx0.01%2.3%超时导致的 502/504P99 延迟曲线示意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, queryFROM pg_stat_activity WHERE state ! idleORDER 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_conn3180ms77%——应用在等数据库连接而不是在等 SQL 执行db.query才 42msrecommend.call820ms20%——推荐服务也慢了。这不是两个独立问题连接被慢占住后面的请求排队等连接是典型的级联效应。级联效应示意本次事故的核心机制推荐服务变慢(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, queryFROM pg_stat_activityWHERE state ! idle ORDER BY running_for DESC;-- 结果大量连接处于 idle in transaction-- ← 这是本次事故的第一个关键线索-- ② 有没有锁等待SELECT count(*), wait_event_type FROM pg_locksWHERE NOT granted GROUP BY wait_event_type;-- 结果无锁等待。排除锁问题这个分支。-- ③ 慢查询有变化吗SELECT query, calls, mean_exec_timeFROM 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 变 820ms5. 第三步应用层排查——线程池、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└ 证据Tracerecommend-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% ✓治本次日内修掉 ⑥——把推荐服务调用移出事务# ❌ 修复前事务内调远程服务连接被空闲占用 820msasync 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 viewedtrue 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 viewedtrue WHERE id$1, order_id)rec await recommend_client.get(order[user_id],timeout0.2, # 超时兜底circuit_breakerTrue) # 熔断防雪崩return {**dict(order), recommend: rec}三个必须一起做的加固缺一不可超时兜底远程调用必须有超时timeout0.2永不等待是分布式系统的第一戒律。熔断器下游持续超时自动熔断快速失败 降级数据把下游慢的爆炸半径掐断——本次如果有熔断⑥ 的放大链在第 ③ 步就断了。事务边界纪律事务里只放数据库操作。这个要写成团队规范 code review 必查项因为它是编译器和运行时都不会报错的缺陷只有人能拦住。验证修复后一周把 analytics v2.31.0 修好 CPU 问题后重新发布同时在预发环境做一次故障演练——用 toxiproxy 给推荐服务注入 1 秒延迟验证订单接口在下游 1s 延迟下的 P99 从 4.1s 降到 240ms熔断生效。修复没有经过故障演练验证就不算修复完成。9. 复盘与沉淀把一次事故变成三份资产事故的最终价值在于沉淀。本次复盘产出三份资产资产一无责复盘文档Blameless Postmortem。时间线、因果链、影响面、改进项——注意是无责的追问系统为什么允许这个缺陷存在而不是谁写的这行代码。复盘的输出是改进项清单改进项负责人期限验证方式移除事务内远程调用order-svc3 天code review 故障演练推荐服务调用加超时熔断order-svc3 天toxiproxy 注入测试新增监控idle in transaction 连接数告警DBA1 周告警演练发布前检查下游服务是否依赖实时路径data-team2 周发布 checklist 更新熔断器全服务铺开平台组1 月巡检脚本资产二两条新告警这是下次更快的关键新告警①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│├─ 第四步多服务共同异常 → 查共同依赖/基础设施/变更│└─ 第五步修复三件套 止血回滚 治本加固 故障演练验证现象第一嫌疑验证命令/手段P99 飙升 连接池打满连接被空闲占用事务内远程调用pg_stat_activity看 idle in transaction下游延迟突然 ×10下游的下游变慢 / 下游变更跨服务 Trace 发布日历CPU 100% 节流限流设置 / 新发布引入重计算kubectl top rollout historyFull GC 频繁内存泄漏 / 堆太小GC 日志 jmap histo缓存命中率骤降大批 key 同时过期 / 缓存实例重启Redis 监控 TTL 配置错误率突升 重试风暴级联故障熔断状态 Trace六句话收束全文先止血再查因——两条线并行止血的人不能同时查因。先看曲线形状再猜原因——跳变查变更、渐进查泄漏、锯齿查定时任务。分清因和症状连接池耗尽是症状谁占着连接才是病调大池子是把病养肥。idle in transaction 是事务内远程调用的特征签名——事务里只放数据库操作这条要写进团队规范。别人的变更你控制不了自己的放大器可以——超时、熔断、事务边界纪律决定爆炸半径。每次事故沉淀三份资产无责复盘、新告警、更新的排障手册——事故的最终价值是让下一次更快。深夜排障最迷人的地方你是在读一个分布式系统案发现场的侦探。这篇文章是请求生命周期的续篇——上一篇讲系统怎么运转这一篇讲系统怎么坏掉、怎么查、怎么让它不再坏。想看缓存雪崩或消息堆积的专场复盘评论区点单。参考与延伸阅读Google SRE Book: Emergency Response / Postmortem Culture《Designing Data-Intensive Applications》——连接池与事务的原理根基OpenTelemetry / 分布式追踪实践PostgreSQL: pg_stat_activity 与锁监控文档
网站建设高端定制企业官网