Go 高并发实战(6):压测、pprof、Trace 与线上事故排查
排障不是随机抓火焰图,而是从用户影响和资源饱和提出假设,再选择能证伪它的证据。
本期完成系列闭环:建立压测方法、诊断端口和线上 Runbook,并复现 goroutine 泄漏、锁竞争、连接池耗尽与内存增长。
排障架构图:从症状到最小证据
决策树先区分“运行资源饱和”还是“等待资源饱和”,再选择 profile。CPU 低时抓 CPU 火焰图通常只有 idle/runtime 噪音,不能解释锁、semaphore 或连接池等待。
一、先建立 RED + USE 观测面
应用 RED:Rate、Errors、Duration。资源 USE:Utilization、Saturation、Errors。
至少关联这些指标:
- 请求 RPS、P50/P95/P99、按类型分类的错误;
- accepted/rejected、入口与下游 queue wait;
- goroutine、OS thread、heap in-use、allocation rate、GC CPU;
- DB/HTTP pool in-use、waiting、timeout;
- CPU、run queue、cgroup throttling、文件描述符和 socket。
只看平均 CPU 和平均延迟,会错过单实例热点与长尾。
二、安全暴露诊断端口
func diagnosticServer(ctx context.Context) error {
mux := http.NewServeMux()
mux.HandleFunc("/debug/pprof/", pprof.Index)
mux.HandleFunc("/debug/pprof/profile", pprof.Profile)
mux.HandleFunc("/debug/pprof/trace", pprof.Trace)
for _, name := range []string{"allocs", "block", "goroutine", "heap", "mutex"} {
mux.Handle("/debug/pprof/"+name, pprof.Handler(name))
}
server := &http.Server{
Addr: "127.0.0.1:6060",
Handler: mux,
ReadHeaderTimeout: time.Second,
}
go func() {
<-ctx.Done()
shutdown, cancel := context.WithTimeout(context.Background(), 2*time.Second)
defer cancel()
_ = server.Shutdown(shutdown)
}()
return server.ListenAndServe()
}
绑定 loopback 或管理网络并加访问控制,不把栈、命令行和 profile 暴露到公网。一次只采最需要的 profile,选择单个副本评估开销。
runtime.SetMutexProfileFraction(10)
runtime.SetBlockProfileRate(10000)
三、症状到证据
| 症状 | 第一假设 | 采集 | 典型证据 |
|---|---|---|---|
| CPU 高、吞吐不升 | 热点/忙循环/GC | CPU profile | 热函数或 runtime GC 占比 |
| CPU 低、P99 高 | 锁/池/下游等待 | block、mutex、pool 指标 | 同一等待栈聚集 |
| goroutine 单调增长 | 泄漏 | goroutine debug=2 | 大量重复 chan send/I/O 栈 |
| RSS 增长 | 队列/缓存/保留对象 | 两时点 heap diff | in-use 路径持续增加 |
| 周期尖刺 | GC/调度/限额 | runtime trace | GC、syscall、throttle 时间重合 |
go tool pprof -http=:0 'http://127.0.0.1:6060/debug/pprof/profile?seconds=30'
curl -s 'http://127.0.0.1:6060/debug/pprof/goroutine?debug=2' > goroutines.txt
go tool pprof -http=:0 http://127.0.0.1:6060/debug/pprof/mutex
go tool pprof -http=:0 http://127.0.0.1:6060/debug/pprof/block
curl -s 'http://127.0.0.1:6060/debug/pprof/trace?seconds=5' -o trace.out
go tool trace trace.out
CPU profile 看“正在运行什么”;block/mutex 看“为何没有运行”;trace 看“这个窗口里 runtime 如何调度”。
四、四个故障实验
4.1 goroutine 泄漏
注入:下游不接受 context,结果发送到无缓冲 channel,入口 50 ms 超时。证据:压测停止后 goroutine 不回落,dump 大量停在 chan send。修复:下游接受 context、结果 buffer 覆盖发送者、owner 等待子任务。
4.2 锁竞争
注入:全局锁内 sleep 5 ms。证据:CPU 不高,mutex delay 集中在同一 Unlock,P99 随并发线性恶化。修复:移出 I/O、缩短临界区、分片或所有权模型。
4.3 数据库池耗尽
注入:慢查询占满 MaxOpenConns。证据:InUse 贴顶、WaitCount/WaitDuration 增长,goroutine 堵在连接获取。修复:查询/事务 deadline、慢 SQL、池预算与入口许可对齐。
4.4 内存增长
注入:扩大有界队列并让消费者降速。分别比较 alloc_space 与 inuse_space:前者代表分配流量,后者代表仍被引用的活对象。
curl -s http://127.0.0.1:6060/debug/pprof/heap -o before.pb.gz
# 保持稳定负载后
curl -s http://127.0.0.1:6060/debug/pprof/heap -o after.pb.gz
go tool pprof -http=:0 -base before.pb.gz after.pb.gz
五、正确的压测流程
- 基线:低流量确认功能和指标;
- 阶梯:固定到达率逐级增加,寻找吞吐拐点;
- 过载:达到 150%~200% 容量,验证拒绝和资源上限;
- 故障:注入慢下游、错误和丢包;
- 恢复:降低流量,验证队列、连接、goroutine 和 P99 回落。
wrk -t8 -c1000 -d60s --latency \
'http://127.0.0.1:8080/aggregate?items=3&delay_ms=20'
echo 'GET http://127.0.0.1:8080/aggregate?items=3&delay_ms=20' | \
vegeta attack -rate=12000/s -duration=2m | vegeta report
闭环压测在服务变慢时会自然降速,可能低估最差延迟;固定到达率用于过载验证。压测端与服务端分离,并记录版本、机器、CPU quota、所有池配置和原始结果。
六、如何阅读一个 CPU Profile
先看 top 的 flat 与 cum:flat 是函数自身采样,cum 包含后代。一个 JSON handler 的 cum 很高、flat 很低,真正热点可能在反射、内存复制或 allocator。
排查步骤:
- 确认采样窗口包含故障而非恢复阶段;
- 对比健康实例和异常实例;
- 从 top 进入 graph/flame,再用 source/weblist 定位行;
- 检查优化是否改变业务结果或只是把 CPU 转移;
- 在相同负载和配置下复测。
不要看到 runtime 函数就直接归因 GC;大量分配、锁、channel 操作最终都会出现在 runtime 栈中,要沿调用链回到业务来源。
七、Runtime Trace 的实战读法
选 1~5 秒问题窗口,回答:
- P 是否持续 busy,还是存在空闲但 runnable G 很多;
- goroutine 是网络等待、syscall、同步阻塞还是 runnable;
- GC 与延迟尖刺是否时间重合;
- user region 的 DB/RPC/编码阶段哪一段变长;
- scheduler latency 是否集中在容器 throttling 时段。
用 runtime/trace 的 task/region 给业务阶段加标注:
taskCtx, task := trace.NewTask(ctx, "aggregate")
defer task.End()
region := trace.StartRegion(taskCtx, "database")
value, err := query(taskCtx)
region.End()
执行 trace 与其他高开销 profile 可能互相影响,先做短窗口并单独采集。
八、系统层证据
应用 profile 正常时继续看:
- CPU throttling 与 run queue;
- TCP retransmit、SYN backlog、TIME_WAIT 与端口;
- 文件描述符、线程数、内存/OOM 事件;
- DNS、负载均衡、跨区网络;
- 节点 noisy neighbor 和磁盘延迟。
goroutine [IO wait] 通常表示由网络轮询器挂起,不等于占用一条 OS 线程。大量 syscall/cgo 栈则要结合 threadcreate profile 和系统线程检查。
九、事故复盘模板
影响:何时、哪些用户、错误率与 SLO
检测:首个有效信号与缺失信号
时间线:发布/配置/流量/依赖/处置
根因:触发条件 + 放大机制 + 防线为何失效
证据:指标、profile、trace、栈、日志
修复:止血、永久修复、回归实验
行动项:owner、截止时间、可验证完成条件
根因不要写“流量太大”或“数据库慢”,要写清系统为何没有在容量边界拒绝、为何重试放大、为何告警未提前发现 queue wait。
9.1 完整证据时间线示例
10:00:00 RPC P99 从 40 ms 升到 500 ms
10:00:08 rpc_permit_wait P99 超过 20 ms
10:00:12 handler in-flight 触顶,goroutine 开始增长
10:00:18 gateway timeout 上升,客户端重试率翻倍
10:00:23 DB wait 上升:RPC/DB 共用入口资源导致扩散
10:00:35 启用 optional RPC 降级并降低入口许可
10:00:50 已接纳请求 P99 回落,goroutine 开始下降
10:01:20 下游恢复;控制放量,30 秒内资源回基线
时间线同时包含触发、饱和、放大和止血。如果第一个告警是 10:00:18 的 timeout,而 10:00:08 已有 queue wait 信号,行动项应补充更早的饱和告警。
9.2 Healthy 与 Unhealthy 实例对照
同一时刻从健康/异常实例各采一份相同 profile,比单份火焰图更能排除正常热点。若两者 CPU 栈相同,但异常实例 DB wait 高,根因更可能是连接/下游分片,而不是代码函数本身。
十、生产事故 Runbook
- 确认接口、租户、实例、版本和地域影响面;
- 限流、降级或摘异常实例,保留现场而非重启全部;
- 保存指标、goroutine dump、单份对应 profile、变更和下游状态;
- 按 CPU、锁、池、泄漏、GC、内核限额逐一建立可证伪假设;
- 对比健康/异常实例,一次只改一个变量;
- 最小复现并固化为 race、压力、故障注入测试和告警。
系列回顾:Go 高并发实战 6 期路线。
跨语言继续:Rust 高并发实战 6 期路线。