2890 字
约 9 分钟
15
S09-A09 · Go 的运行时观测:pprof、trace 与采样成本
2024-12-31
2026-11-09

CPU 打满,top 显示 800% 全在 Go 进程上,却不知道在哪——这是运行时观测最典型的起点。日志说"谁来过",指标说"坏了多严重",只有运行时剖面能回答CPU 花在哪几行代码上。

Go 把它做成了标准库:net/http/pprof 一个 import 就有整套端点,runtime/trace 一个调用就能录轨迹。门槛低到危险——低门槛意味着成本没被算过。这篇只算这笔账。


1. 四类信号,四种问题

信号 回答的问题 时间尺度 开销
CPU profile 时间花在哪些函数(含栈聚合) 10–30 秒窗口 采样期 1%–5% 量级,按版本核对
heap profile 谁在占内存、谁在分配 瞬时快照 一次 GC 配合,短暂停顿
goroutine dump 谁在等、等什么 瞬时 极低,但输出体积大
execution trace 调度、GC、阻塞如何交错 毫秒到秒窗口 高,只用于排障

从哪一类开始,看问题是"哪一个函数"还是"哪一段时间":前者用 profile,后者用 trace。用错类别的症状是"采了一堆 CPU profile,函数耗时都不高"——问题在等待,不在计算。


2. 采样:开销来自哪里

机制 采样方式 开销来源 精度影响
CPU profile 按固定频率中断取栈(约 100Hz) 每次中断的栈遍历 + 聚合 短窗口内样本数不足,热点会被"稀释"
heap profile 按分配字节数概率采样 采样判定本身 小对象多的程序统计偏差大
goroutine dump 全量抓栈 输出体积与序列化 不影响精度,影响磁盘与延迟
trace 全事件记录(调度、GC、系统调用) 每事件写缓冲 精度最高,开销也最高

CPU profile 的约束是样本数与窗口的乘积:100Hz × 30 秒约 3000 个样本,分到几十个热点上每处只剩几十个——分辨率就这么粗。占比 1% 的函数在此窗口基本不可见,要看清只能延长窗口或提频(后者按版本核对)。

// 30 秒 CPU profile,写文件后再用 go tool pprof 打开
f, _ := os.Create("cpu.pprof")
pprof.StartCPUProfile(f)
time.Sleep(30 * time.Second)
pprof.StopCPUProfile()

3. pprof 端点的暴露成本

net/http/pprof 挂在业务端口上,等于把"触发采样"与"导出堆"做成公开接口。风险不在开销,在谁能触发、能触发几次。

暴露方式 风险 最低要求
业务端口 /debug/pprof 公网可达 任何人可高频触发 CPU 采样与堆导出 禁止
独立端口绑 127.0.0.1 需 SSH 隧道才能用 推荐默认
独立端口 + 内网 ACL 网内可直取,审计靠网络层 可接受
// 独立端口 + 仅回环;与业务端口分离,避免被同一套鉴权绕过
go func() {
    mux := http.NewServeMux()
    mux.HandleFunc("/debug/pprof/", pprof.Index)
    mux.HandleFunc("/debug/pprof/profile", pprof.Profile)
    _ = http.ListenAndServe("127.0.0.1:6060", mux)
}()

审计写清三条就够:谁能取、取过几次、单次最长多久。堆导出在 2GB 堆上是秒级停顿加数 GB 文件,被反复触发等价于自我 DoS。


4. heap profile 的三种取法

取法 含什么 指向的问题 误读风险
inuse_space 当前仍存活对象的字节数 谁占着内存不放 只看它会把"分配多但活得短"的问题漏掉
alloc_space 累计分配的字节数 谁在制造 GC 压力 不看它会把 GC 频繁误判成泄漏
alloc_objects 累计分配的对象个数 小对象风暴、指针密集结构 个数多不代表占内存多
go tool pprof -http=:0 http://127.0.0.1:6060/debug/pprof/heap
# 默认 inuse_space;比较分配压力时显式切样本类型:
go tool pprof -sample_index=alloc_space http://127.0.0.1:6060/debug/pprof/heap

顺序应是先 alloc_space 看压力,再 inuse_space 看留存。反过来容易把"分配多但都能回收"的服务误判为泄漏,去改一个本来没问题的缓存。


5. goroutine 泄漏:看趋势不看绝对值

判据 观察方式 结论
数量随时间单调上升 周期采样 runtime.NumGoroutine() 高度可疑泄漏
数量随 QPS 波动后回到基线 同上,画趋势线 正常
栈去重后同一处堆积成百上千 dump 后按栈首行聚合 定位到具体阻塞点
# dump 后按栈顶聚合,比逐行读十万行栈快得多
curl -s http://127.0.0.1:6060/debug/pprof/goroutine?debug=2 \
  | awk '/^goroutine /{getline; print}' | sort | uniq -c | sort -rn | head -20

绝对值无意义:正常服务有几千个 goroutine 也不奇怪。趋势 + 栈去重才是判据:前者答"是否泄漏",后者答"漏在哪"。


6. block 与 mutex:只在怀疑等待时开

profile 记录什么 默认状态 开销
block 同步原语上的阻塞时长 关闭(需 SetBlockProfileRate) 中,计时有成本
mutex 锁竞争等待 关闭(需 SetMutexProfileFraction) 中高,随竞争放大
runtime.SetBlockProfileRate(1)        // 1 = 全采样;生产建议先用较大值
runtime.SetMutexProfileFraction(100)  // 每 100 次竞争采一次,降低开销

判据:CPU 不高、延迟却高时答案通常在等待。


7. trace:代价极高,只开短窗口

维度 profile trace
记录内容 采样后的栈 全事件(调度、GC、syscall、阻塞)
开销 低到中 高,随 goroutine 数与事件率放大
可用窗口 10–30 秒 毫秒到秒级
输出体积 数百 KB 到数 MB 数十 MB/秒,需限流
回答 哪个函数热 这段时间里发生了什么顺序
// trace 必须在短窗口内停,且写文件要有大小上限
f, _ := os.Create("trace.out")
trace.Start(f)
time.Sleep(500 * time.Millisecond)   // 别按秒计,按百毫秒计
trace.Stop()

trace 的正确用法是复现一个已知的坏现象:"偶发 200ms 卡顿"就在卡顿发生时抓 500ms。拿它做常态观测,等于给服务加一道持续的税。


8. 持续剖析:收益与新增成本

维度 按需抓取 持续剖析
定位能力 事后无法回溯 可回溯"昨天 3 点那次尖峰"
常驻开销 0 采样开销 + 上传带宽 + 存储
运维复杂度 低 需采集器、聚合后端、标签体系
适用 低频排障 多服务且性能是核心指标

真实成本在标签与存储:缺 service、version、instance 标签,剖面无法与发布、实例、时间对齐。上它之前先确认标签体系存在。


9. 容器里的采样参数

容器有两个参数会直接改变采样结论:CPU 限额决定进程能拿到多少时间片,GOMAXPROCS 决定并行度。两者不一致时,profile 里会出现大量"运行态但未被调度"的假象。

# 核对容器内看到的世界,而不是宿主机的
cat /sys/fs/cgroup/cpu.max                 # cgroup v2:quota period
nproc                                       # 可能仍是宿主机核数
GOMAXPROCS=4 ./svc                          # 与 quota 对齐,避免过度并行

限额低时同样窗口的样本数明显更少,跨实例比较前先确认限额一致。


10. 先看 GC,再看分配

顺序 指标 判断
1 GC 频率与 CPU 占比 占比高 → 分配压力问题,不是"函数慢"
2 堆增长曲线 上升且 GC 后不回落 → 留存问题
3 alloc_space 热点 定位分配点
GODEBUG=gctrace=1 ./svc        # 每次 GC 一行,含堆大小与停顿

把 GC 停顿归因到业务函数是常见误读:profile 记的是 CPU 时间归属,而 STW 发生在所有 goroutine 之外,不进函数级统计。


11. 接入统一平台的三种方式

方式 机制 成本 适用
拉模式 平台定期抓端点 需网络可达 + 鉴权 内网、实例少
推模式 边车定期抓取上传 每实例一份边车资源 容器化、实例多
SDK 内嵌 应用内定时采样上报 侵入代码与依赖 需精细标签控制

判据是可达性与实例规模:拉模式跨集群几乎必被防火墙挡住;实例上百后边车资源要单独算。


12. 火焰图读法与三种误读

误读 表现 正解
看宽度不看层级 把宽条当最慢函数 宽度是占比,根因在叶子
忽略自身耗时 顶层框架很宽 那是过客,看自身占比
采样缺失当不存在 某函数不出现 短窗口样本不足,延长再看
忽略内联 小函数消失 被内联,看调用者自身耗时

判据:宽度是"这段时间被采到多少次",不是"这段代码有多慢"。二者只在单线程纯计算时近似相等。


13. 排错

现象 原因 处理
profile 里全是 runtime 函数 采样窗口内 GC 或调度占比高 先看 GC 指标,再重采
热点函数占比都很低 样本数不足 延长窗口或提高频率
堆导出把服务拖慢 堆大 + 导出频繁 限频、限大小、改按需
trace 文件打不开 采集期间被截断或未 Stop 保证 Stop 执行,限窗口
容器与宿主数字不一致 GOMAXPROCS 与 quota 不匹配 对齐后再比

14. 边界:不必开持续剖析的情况

情境 更轻的做法 理由
QPS 极低 按需抓一次 样本太少,持续采也无信息
内部工具、无性能诉求 只看错误日志 成本高于收益
已定位到函数 读代码与基准 观测已完成使命
问题在外部依赖 客户端指标与追踪 剖面看不到下游
只想知道有没有问题 指标告警 剖面答"在哪",不答"是否"

15. 自测

  1. CPU 打满但 profile 里函数占比都很低,先怀疑哪一类信号?
  2. 100Hz × 30 秒能分辨多小的热点?为什么"占比 1%"的函数常看不见?
  3. alloc_space 与 inuse_space 分别指向什么问题,判读顺序为什么不能反?
  4. goroutine 数量为什么不能用绝对值判断泄漏?
  5. trace 的窗口为什么按百毫秒计而不是按秒计?
  6. 容器 CPU 限额很低时,同样的 30 秒窗口分辨率如何变化?
S09-A09 · Go 的运行时观测:pprof、trace 与采样成本
https://www.clxhxhhr.top/posts/6247/
作者
clxstart
发布于
2024-12-31
许可协议
CC BY-NC-SA 4.0
评论
0 条
还没有评论,先写一条吧。