用 AI 定位瓶颈:指标、日志与 pprof 联动

压测发现问题之后,最常见的低效动作是「凭直觉改一处再压一遍」。瓶颈定位要靠三条互相独立的证据链交叉验证:指标回答「哪一层饱和了」,日志回答「请求死在哪一步」,剖析(profiling)回答「CPU 与内存具体花在哪里」。AI 在这件事上的正确用法不是替你猜,而是把零散现象整理成可执行的假设清单,并明确每条假设需要什么证据、怎么采集。

三条证据链各自回答什么

证据链观察对象能回答的问题典型采集入口
指标(metrics)应用:QPS、P99、错误率、线程池、连接池、goroutine;系统:CPU、内存、磁盘、网络、上下文切换;中间件:慢查询、缓存延迟、MQ 堆积哪一层先饱和、饱和发生在哪个时间点应用大盘、vmstat、ss -s、redis-cli --latency、慢查询日志
日志(logs)错误码分布、首个异常栈、慢请求阶段耗时失败与变慢发生在哪个步骤、是否有重试与超时应用日志、接入层日志、慢请求日志
剖析(profiling)CPU 热点、内存分配、goroutine 栈、阻塞与锁竞争资源到底被哪段代码消耗go tool pprof、火焰图、线程栈 dump

三条链缺一不可。只看指标容易把「排队」当成「算力不足」;只看火焰图可能在压测机打满时得出错误的 CPU 热点结论。

让 AI 输出「假设 → 证据 → 采集」表

现象:定速压测到 3000 QPS 时 P99 从 38ms 跳到 260ms,服务端 CPU 88%,
      系统态占比从 12% 升到 31%,上下文切换从 23k/s 升到 96k/s,
      错误码以 503 为主,DB 与 Redis 自身指标平稳。

请输出候选假设表,列:假设 | 该假设成立的证据 | 采集命令或入口 | 若为真的预期观测 | 排除该假设需要的数据。
要求:
1. 至少 4 条假设,覆盖应用、系统、中间件三层;
2. 每条假设必须给出可执行命令(写全参数),不确定的工具参数请标注"待核实",不许编造;
3. 按"先便宜后昂贵"排序:先抽样日志与指标,再上剖析;
4. 最后给出验证顺序,说明为什么先验证第一条。

「预期观测」这一列是关键:先写下「如果这个假设为真,我会看到什么」,再去采集。否则数据一到手,人总会不自觉地往已有结论上套。

假设表样例

假设支持证据采集方式若为真的预期观测
对象分配过多引发 GC 抢占 CPUGC CPU 占比升至 8%,系统态升高GODEBUG=gctrace=1 ./app、/debug/pprof/heap?debug=1GC 频率超过每秒 1 次、存活堆接近 GC 前堆
响应体过大导致序列化与网络开销系统态 CPU 高、平均响应体积增长访问日志响应体大小统计、encoding/json 热点CPU 剖析中 encoding/json 占比靠前
数据库连接池排队连接池 active 顶满、获取连接耗时长连接池指标、SHOW PROCESSLISTactive 长期等于上限、大量连接处于 Sleep 之外的等待态
下游 Redis 延迟毛刺客户端超时计数上升redis-cli --latency -h 10.0.0.9出现毫秒级周期性毛刺、--latency-history 有峰值
锁竞争或单点串行化上下文切换暴涨、延迟线性上升block 与 mutex 剖析、线程栈 dumpblock 剖析中集中于同一把锁或同一个 channel

按「先便宜后昂贵」排序很重要:日志抽样和指标几乎零成本,剖析会带来额外开销,压测过程中抓 CPU 剖析更要控制时长。

采集命令清单

# 1. 系统层:CPU、内存、调度、上下文切换
vmstat 1 10
pidstat -w -u -t -p <pid> 1 10      # 按线程看切换与 CPU

# 2. 网络与连接队列
ss -s                                # 汇总:连接数、TIME_WAIT、端口耗尽迹象
ss -lnt                              # 监听队列:Recv-Q 非零即堆积
nstat -az | grep -E 'TcpRetrans|ListenDrops|TcpExtListenOverflows'

# 3. 中间件
redis-cli -h 10.0.0.9 -p 6379 --latency
redis-cli -h 10.0.0.9 -p 6379 --latency-history -i 5
mysql -e "SHOW PROCESSLIST" | head -20
mysqldumpslow -s t -t 10 /var/log/mysql/slow.log     # 按总耗时排序的慢查询

# 4. 应用剖析(Go)
go tool pprof -http=:6060 'http://10.0.0.12:6060/debug/pprof/profile?seconds=30'
curl -s 'http://127.0.0.1:6060/debug/pprof/goroutine?debug=1' | head -30
go tool pprof http://10.0.0.12:6060/debug/pprof/block
输出判读
vmstat 的 cs 随压力超线性增长锁竞争、线程数失控或 IO 阻塞,而非算力不足
vmstat 的 r 长期大于核数有排队,加并发不会提升吞吐
ss -lnt 的 Recv-Q 持续非零应用 accept 不过来或处理线程被占满
nstat 出现重传与 listen 溢出网络或内核队列在丢弃连接,吞吐上限由内核决定
redis-cli --latency-history 有周期毛刺缓存侧毛刺会放大成全局长尾
goroutine?debug=1 栈大量聚集在同一函数该函数是阻塞点:等锁、等 IO 或等下游
CPU 剖析 top -cum 指向 runtime.mallocgc分配速率过高,先降低对象分配再谈优化算法

用日志把范围收窄

指标告诉你「慢」,日志告诉你「慢在哪一步」。压测期间日志要做三件事:按错误码聚合、按耗时区间聚合、保留可复现的样本请求。

# 错误码分布:先确认错误性质,再谈性能
awk '{print $9}' access.log | sort | uniq -c | sort -rn | head
grep -c 'context deadline exceeded' app.log
# 慢请求样本:取一条完整链路,人工核对阶段耗时
grep '\[slow\]' app.log | awk -F'total=' '{print $2}' | awk '{print $1}' | sort -n | tail -20
日志特征指向
错误集中在超时类异常下游或自身排队,先看超时预算与重试次数
首个异常栈之后同类异常刷屏连锁反应,只看第一个异常栈
503 占比高且集中在压测后段熔断或限流触发,或连接不被上游接受
慢请求的某阶段耗时随压力增长该阶段存在共享资源排队

验证与闭环

  • 一次只改一个变量:改连接池上限与改序列化库同时做,压测结果无法归因。
  • 改完必须重压同一档位、同一时长,并把前后数据放进同一张表对比。
  • 判断修复是否有效,看的是拐点是否右移,而不是峰值吞吐是否提高。
  • 结论要能落到证据链上:指标定位层级、日志确认环节、剖析落到代码行,三者对齐才算定位完成。
  • AI 给的工具参数一律先核对:用 <工具> --help 或官方文档确认后再执行,凭记忆拼出来的参数很可能是错的。

小结:指标、日志、剖析三条证据链分别回答「哪一层饱和」「请求死在哪一步」「资源花在哪段代码」;让 AI 产出「假设 → 证据 → 采集 → 预期观测」的表并先写预期再采集,用 vmstat、ss -s、redis-cli --latency、慢查询日志和 go tool pprof 逐条验证,一次只改一个变量,最后用拐点是否右移来判断修复是否真的有效。

笔记加载中…