接口慢排查全流程
接口慢是最常见也最容易查歪的故障：所有人都在说「系统慢」，但慢的接口、慢的用户、慢的时间段可能完全不同。本章给一条固定路径——确定范围、看入口指标、定位层次、逐层排除，最后必须落到具体哪一层、哪个函数、哪条 SQL。
第一步：确定范围
「接口慢」这句话本身没有信息量，先把它拆成四个问题：
| 问题 | 判断方法 | 指向 |
|---|---|---|
| 全部接口慢还是个别接口慢 | 对比入口各 path 的 P99 | 全部慢看系统层，个别慢看代码 |
| 全部用户慢还是个别用户慢 | 按 uid/租户聚合延迟分位 | 个别慢看数据量、慢查询、大客户 |
| 全部机器慢还是个别机器慢 | 逐实例延迟对比 | 个别慢看单机、宿主机、发布差异 |
| 一直慢还是突然慢 | 与上周同时段对比、对齐发布与变更时间 | 突然慢优先怀疑变更 |
能回答这四个问题，范围基本已经缩到一两个组件。答不出来，说明缺的是可观测性，而不是排查技巧。
第二步：看入口四项指标
动手之前先把四条曲线拉出来：
| 指标 | 看什么 | 异常组合的解读 |
|---|---|---|
| QPS | 是否突增或骤降 | QPS 涨而延迟涨＝容量不足；QPS 降而延迟涨＝内部阻塞 |
| 延迟分位 P50/P95/P99 | 整体平移还是只有尾部 | 整体平移＝全链路变慢；只有 P99 涨＝长尾问题 |
| 错误率 | 5xx、超时、连接拒绝占比 | 错误率开始涨说明已过瓶颈，进入雪崩区间 |
| 饱和度 | CPU、线程池、连接池、队列长度 | 接近 100% 时延迟非线性上升 |
只报平均值等于没报。平均值被大量快请求拉低，一次 3 秒的请求被 1000 次 10 毫秒的请求平均之后，看起来一切正常。
第三步：定位层次
按请求路径自上而下逐层收窄：
客户端 → DNS → LB/接入层(Nginx) → 应用 → 缓存(Redis) → 数据库 → 下游 RPC
↑ 每一层都有一份耗时，先找出耗时突然放大的那一层
| 层次 | 可观测点 | 关键指标 |
|---|---|---|
| 接入层 | Nginx access log、LB 指标 | $request_time、$upstream_response_time、499 |
| 应用 | 应用日志、APM、线程栈 | 各阶段耗时、线程池排队、GC 停顿 |
| 缓存 | Redis slowlog、latency | 慢命令、大 key、连接数 |
| 数据库 | 慢查询日志、SHOW FULL PROCESSLIST | 执行时间、锁等待、扫描行数 |
| 下游 | 依赖方监控、自身埋点 | 超时率、重试次数、连接池等待 |
Nginx：用两个时间字段先分层
接入层日志是最容易拿到的证据，但必须分清两个字段：
| 字段 | 含义 | 用途 |
|---|---|---|
$request_time | 从收到请求第一个字节到发完响应最后一个字节 | 用户实际等待时间 |
$upstream_response_time | 从与上游建立连接到收完上游响应体 | 后端应用耗时 |
判读规则只有一条：看两者的差值。
| request_time | upstream_response_time | 结论 |
|---|---|---|
| 大 | 大 | 后端慢，去查应用 |
| 大 | 小 | 客户端网络慢、响应体大，或 Nginx 写回受阻 |
| 小 | 小 | 后端没问题，去查 LB 之前的链路 |
| 出现逗号分隔的多个值 | — | 发生过重试，实际多次回源，要查重试策略 |
把这两个字段加进日志格式，是接入层改造里性价比最高的一件事：
log_format main '$remote_addr "$request" $status '
'rt=$request_time urt=$upstream_response_time '
'uaddr=$upstream_addr $body_bytes_sent';
拿日志做最快的统计：
awk '{print $7}' access.log | sort | uniq -c | sort -rn | head # 访问量 top 接口
grep -o 'rt=[0-9.]*' access.log | cut -d= -f2 | sort -n | tail -20 # 最慢的 20 个请求
awk -F'rt=' '{split($2,a," "); if (a[1]+0 > 1) print}' access.log | wc -l # 慢请求占比
curl -w：没有 APM 时拆客户端侧耗时
curl -o /dev/null -s -w 'dns=%{time_namelookup} tcp=%{time_connect} tls=%{time_appconnect} ttfb=%{time_starttransfer} total=%{time_total}\n' \
-H 'Host: api.example.com' http://10.0.0.12/health
注意这几个值是累计的，要算分段耗时必须相减：
| 分段 | 计算方式 | 异常时的指向 |
|---|---|---|
| DNS | time_namelookup | 解析慢，查 resolver 与本地缓存 |
| TCP 握手 | time_connect - time_namelookup | 握手慢，查网络与 SYN 队列 |
| TLS 握手 | time_appconnect - time_connect | 证书链过长、OCSP、会话复用未开 |
| 首字节 | time_starttransfer - time_appconnect | 服务端处理慢，对应 Nginx 的 urt |
| 内容传输 | time_total - time_starttransfer | 响应体大或带宽受限 |
第四步：逐层排除的固定动作
| 怀疑层 | 动作 | 命令 |
|---|---|---|
| 应用自身 | 间隔 5 秒抓三次线程栈，看卡在哪 | jstack <pid> |
| 数据库 | 看正在执行的语句与锁等待 | SHOW FULL PROCESSLIST、慢查询日志 |
| 缓存 | 看慢命令与大 key | redis-cli slowlog get 20、--bigkeys |
| 下游 RPC | 看超时与重试次数 | 应用日志超时关键字 + 依赖方监控 |
| 主机 | 看 CPU、IO、网络与系统调用 | top -H、iostat -x 1、strace -f -T -tt -p <pid> |
压测复现比猜快得多：用 wrk 在预发环境打同一接口，能稳定复现说明是代码或容量问题；不能复现就要怀疑线上特有条件（数据分布、并发用户、网络路径）。
wrk -t4 -c100 -d60s --latency http://10.0.0.12:8080/api/order/detail
ab -n 20000 -c 200 http://10.0.0.12:8080/api/order/detail
hey -n 20000 -c 200 -m GET http://10.0.0.12:8080/api/order/detail
结论必须落到具体位置
一份合格的排查结论长这样：
现象：/api/order/detail 的 P99 从 120ms 涨到 2.8s，P50 无变化，错误率 0.2%
定位：Nginx rt=2.81s urt=2.79s → 后端慢
三次线程栈都停在 OrderMapper.selectByUser → 数据库慢
慢查询日志：SELECT ... 扫描 87 万行，order_item 缺 (user_id, created_at) 索引
处置：加复合索引，P99 回落到 130ms
只写「优化了数据库」不算结论，因为没人能验收。
预防与巡检项
- 入口日志必须包含
$request_time、$upstream_response_time、$upstream_addr。 - 每个接口的 P99 与错误率单独设阈值，不要只看全局平均。
- 慢查询日志阈值设 200ms，每周评审一次新增慢查询。
- 每个下游依赖单独统计超时率与重试率，避免被平均值掩盖。
- 发布前后各保留 30 分钟分位数据，便于判断是否由变更引入劣化。
小结：先把「谁的哪个接口什么时候慢」问清楚，再看 QPS、分位、错误率、饱和度四条曲线，然后用 Nginx 的 $request_time 与 $upstream_response_time 分层，最后逐层排除到具体函数或 SQL，结论必须能被验收。