服务响应慢排查
问题
用户反馈页面加载很慢,监控显示 API 延迟从 200ms 上升到 5s+,如何排查?
答案
排查思路:分层定位
Step 1:确认慢在哪里
# 1. 用 curl 拆解请求各阶段耗时
curl -o /dev/null -s -w "\
DNS: %{time_namelookup}s\n\
TCP 连接: %{time_connect}s\n\
TLS 握手: %{time_appconnect}s\n\
首字节: %{time_starttransfer}s\n\
总耗时: %{time_total}s\n" \
https://api.example.com/v1/users
# 输出分析:
# DNS: 0.012s → DNS 正常
# TCP 连接: 0.025s → 网络正常
# TLS 握手: 0.058s → TLS 正常
# 首字节: 4.892s → ❌ 服务端处理慢(从 TCP 到首字节 4.8s)
# 总耗时: 4.920s
Step 2:应用层排查
# 查看应用日志中的慢请求
grep "duration" /var/log/app/access.log | \
awk '$NF > 3000 {print}' | tail -20
# Java:查看线程状态
jstack <pid> | grep -c "BLOCKED" # 阻塞线程数
jstack <pid> | grep -c "WAITING" # 等待线程数
jstack <pid> | grep -c "RUNNABLE" # 运行线程数
# GC 导致的停顿
jstat -gc <pid> 1000 | tail -5
# 关注 FGCT(Full GC 总时间)和 FGC(Full GC 次数)
# Go:查看 goroutine 数量
curl http://localhost:6060/debug/pprof/goroutine?debug=1 | head -5
Step 3:数据库排查
# 查看当前慢查询
mysql -e "SHOW PROCESSLIST" | grep -v "Sleep"
# 查看慢查询日志
mysqldumpslow -s t -t 10 /var/log/mysql/slow.log
# 查看锁等待
mysql -e "SELECT * FROM information_schema.INNODB_LOCK_WAITS\G"
# 查看连接池使用率
mysql -e "SHOW STATUS LIKE 'Threads_%'"
# Threads_connected: 150 (当前连接数)
# Threads_running: 80 (活跃线程,> 50 就要关注)
Step 4:中间件排查
# Redis 延迟
redis-cli --latency -h redis-host
redis-cli INFO | grep -E "used_memory|connected_clients|blocked_clients"
# Redis 慢命令
redis-cli SLOWLOG GET 10
# 查看 Redis 大 Key(可能阻塞)
redis-cli --bigkeys
快速定位表
| 现象 | 可能原因 | 排查命令 |
|---|---|---|
| 所有接口都慢 | GC / 线程池满 / 连接池满 | jstat -gc, 线程/连接池监控 |
| 特定接口慢 | 慢 SQL / 外部调用超时 | 慢查询日志, 链路追踪 |
| 间歇性慢 | GC 停顿 / 锁竞争 / 网络抖动 | GC 日志, jstack, mtr |
| 高峰期慢 | 容量不足 / 队列堆积 | top, 连接数, QPS 监控 |
| 近期发版后变慢 | 代码回归 | 对比版本性能指标 |
常见面试问题
Q1: 如何通过链路追踪定位慢请求?
答案:
- 接入链路追踪(如 Jaeger / Zipkin / SkyWalking),每个请求生成唯一 TraceID
- 在日志中记录 TraceID,方便关联
- 查看 Span 瀑布图:
- 找到耗时最长的 Span(通常是 DB 查询或外部调用)
- 分析是串行调用可以改并行,还是单个调用本身慢
- 对比正常请求和慢请求的 Trace,找到差异点
典型发现:
- 某个 SQL 查询耗时 3s → 加索引
- 串行调用 3 个外部 API 共 3s → 改为并行,总耗时 1s
- Redis 某个大 Key 操作耗时 500ms → 拆分 Key