第 15 / 23 篇

第14章 pprof:CPU、分配量与存活堆

先提出一个可检验的问题

pprof 不是性能结论生成器。采样之前应先问:CPU 忙在哪里,累计分配为什么高,还是 GC 后仍有对象存活?这三种问题对应不同观察。CPU profile 记录采样窗口中的执行成本;alloc_space 观察累计分配;inuse_space 更接近当前仍保留的对象。把累计分配解释成内存泄漏,是常见误判。

随书服务在独立管理地址暴露 pprof,默认绑定本机。业务路由不使用默认管理 mux,避免把诊断端点混进普通接口。采集 profile 是有成本的,某些采样还会影响时序。生产应通过受控管理网络与授权机制访问,书中本地默认值不是开放公网的部署建议。

获取 CPU 或 heap 后,保留二进制版本、Go 版本、负载、采样窗口和命令。只保存一张火焰图截图,无法让别人确认符号、采样类型或当时工作量。原始 profile 可保存在内部证据目录,公开书稿则记录命令、关键摘要与适用范围,不需要把每个二进制采样都塞进电子书。

本机采样实际说明了什么

实验对工作池执行基准并生成 CPU 与内存 profile。在本机累计分配样本中,context.WithDeadlineCause 和 time.newTimer 占据主要部分。这与每次任务执行创建超时 context 和计时器的实现一致。但它说明的是该负载下的累计分配来源,不能直接说这些对象一直存活,更不能据此宣称程序内存泄漏。

本次 CPU 样本在 runtime 等待与平台相关函数上占比较高。基准包含任务交接、调度和等待完成,样本不适合用来推断真实 HTTP 业务的热点。这里正确的结论是采样问题需要调整,而不是从最大的栈框随意选一个优化。书中保存具体摘要,是为了让读者看到证据限制,而不是只展示理想图形。

如果想研究业务 CPU,应加入代表性的解析、编码或计算负载,并确认采样期间 CPU 确实忙碌。若系统主要在等待网络,CPU profile 很可能解释不了延迟。此时应转向 goroutine、阻塞信息与请求阶段测量。工具选择来自问题,不来自某个图看起来更专业。

flat、cum 与调用路径

flat 表示成本直接归在某函数,cum 包含它调用的下游。一个顶层处理函数 cum 很高,可能只是所有请求都经过它;真正分配或执行发生在内部函数。阅读 top 列表后还要看调用路径,避免把框架入口当作根因。采样误差和内联也会影响归属,尤其是短小操作。

比较 profile 时保持工作量可比。一个样本处理一万次任务,另一个处理十万次,累计分配当然可能差十倍。可以按完成任务归一化,再结合分布与峰值。若优化减少拒绝却增加实际完成量,绝对 CPU 上升也不一定更差。单一数字必须放回吞吐、延迟和拒绝语境。

heap profile 也有采样机制,不是逐对象完整清单。小对象分配和采样比例可能导致估计差异。强制 GC 后再看存活堆有时有助于调查保留,但会改变工作状态,也不能无限频繁进行。公开结果应写清是否手工触发 GC、负载是否停止,以及采集时仍在运行哪些任务。

优化首先保护正确性

看到每任务 context 有成本,不代表应该删除截止。超时对象支撑的是故障有界性。优化可以研究是否在无截止需求的路径复用更合适的生命周期,或减少不必要的层级,但必须保留原先取消和退出契约。为了几百字节分配让任务永远挂住,是把局部成本换成无界风险。

sync.Pool 也不保证对象永远存在,不适合做任务状态存储。复用缓冲区前要保证没有其他使用者;清空敏感字段和大切片引用也有必要。只有 profile 证明分配确实重要,并且行为测试仍保持通过时,才值得增加对象复用复杂度。

一次优化验收至少包含可重复基准、相关 profile 以及原先行为测试。不要反复运行直到得到最好数字,然后只发布那次。报告多次结果、环境与方法,让读者判断噪声。若差异小于波动,应承认当前测量不能支持结论。

练习:回答三个不同内存问题

分别观察累计分配、负载结束后的存活堆和持续负载时的峰值。给每个数字写出它能回答的问题。再让一个任务错误地保留大缓冲区引用,比较累计分配与 GC 后保留量的变化。修复引用后重新采样,确认资源释放而不是只让分配速度降低。

最后为 CPU profile 写一句范围声明:这个负载代表什么,不代表什么。若样本主要是等待,保留这个结果并解释下一步应采集哪类证据。诊断的可信度来自承认工具限制,而不是保证每次采样都有一个漂亮热点。

本章实测证据

以下是本次 go tool pprof -top -alloc_space 的实际摘要,完整命令见附录B。它解释累计分配来源,不表示同等大小存活堆。

Showing nodes accounting for 663.06MB, 98.71% of 671.74MB total
344.03MB  51.21%  context.WithDeadlineCause
254.53MB  37.89%  time.newTimer