代码优化别瞎猜:我用 pprof 把接口 P99 从 780ms 压到 110ms 的完整记录
先说件我不太愿意承认的事。去年我接手一个订单导出接口,P99 780ms,组里几个人的第一反应是「肯定是返回的 JSON 太大了」。于是我们花了整整两天,把返回结构从 42 个字段砍到 18 个,序列化体积从 5.3MB 降到 3.1MB,然后重新压测——P99 变成了 752ms。基本等于没动,那两天的加班白熬了。
真正的问题是我后来用 go tool pprof -http=:8080 http://localhost:6060/debug/pprof/profile?seconds=30 抓了 30 秒 CPU profile 才看出来的:encoding/json 在所有采样里只占 8.2%,而 runtime.mallocgc 连同下游的 runtime.gcDrain、runtime.scanobject 加起来占了 34%。也就是说,我们花两天优化的那部分,只值 8%;真正吃掉三分之一 CPU 的是分配和随之而来的 GC,而它压根没进过我们的讨论范围。
那次之后我给自己定了个规矩:没有 profile 数据支撑的优化建议,一律当噪音处理。
先看一组数量级,很多人的优化方向从第一步就错了
下面这些数字,一部分是我自己在 2023 年的 x86 消费级机器上实测的,一部分是公认参考值,单位统一到纳秒级方便比较(1ms = 1,000,000ns):
| 操作 | 大致耗时 |
|---|---|
| L1 cache 命中 | ~1ns(约 4 个 cycle) |
| 主存随机访问 | ~80–100ns |
| 一次小对象堆分配(无 GC 压力时) | ~20–30ns |
fmt.Sprintf("%d", n) |
~60–90ns |
strconv.Itoa(n) |
~15–25ns |
| 同机架内网 RTT | ~200–500μs |
| 同城跨可用区 RTT | ~1–2ms |
| 跨地域(北京→上海)RTT | ~25–35ms |
| NVMe SSD 4K 随机读 | ~30–80μs |
注意这里的数量级鸿沟。你在一个循环里把某个操作优化掉了 20ns,循环跑 1000 次,总共省了 20μs;但如果这个循环里藏着一次跨可用区的 RPC,那就是 1.5ms,前者得重复 75 次才能抵得上后者一次。我见过太多人(包括几年前的我)为了 i++ 和 ++i 争得面红耳赤,却对每个请求都往 Redis 打一次 GET 视而不见。
顺带提一句,网上流传最广的那份 Latency Numbers Every Programmer Should Know 是 2012 年 Jeff Dean 给的,里面 SSD 随机读写的是 150μs、磁盘寻道 10ms。这数据现在严重过时了,主流 NVMe 的 4K 随机读已经能进 30μs,差了将近 5 倍。如果你还拿着那张 2012 年的表做存储方向的决策,结论大概率是错的。
我那次到底改了什么
profile 出来后问题很清晰:单次请求平均分配堆内存 1.2GB ÷ 3000 请求 ≈ 400KB,分配次数约 18 万次。三个凶手:
第一,热路径里的 fmt.Sprintf。 有个日志键的拼接用了 fmt.Sprintf("%d:%s", id, code),单次 70ns 看着不疼,但它在每个订单上被调一次,一个导出请求 2000 个订单就是 140μs,而且每次都产出一个新 string。换成 strconv.Itoa 加普通拼接后,这一处相关的分配掉了 60%。
第二,循环里的 bytes.Buffer 是从零开始长的。 代码写成 var buf bytes.Buffer 然后在循环里 Write,一路 2 倍扩容到 8KB,中间复制了七八次。改成从 sync.Pool 里取 buffer、buf.Reset() 后复用,每次请求的分配次数从 2000 次降到接近 0。
第三,循环查 Redis 拿商品名。 2000 个订单,平均 2000 次 GET,同可用区单次 0.3ms,加起来 600ms——这就是 780ms 里真正的大头。改成先收集全部 SKU id,用 MGET 分批(每批 500 个 key,避免单命令过大阻塞主线程),4 次网络往返,总共约 2ms。
三处改完,P99 从 780ms 掉到 110ms,单请求内存分配从 400KB 降到 22KB,GC 相关 CPU 占用从 31% 降到 6%。有意思的是,我们最开始砍字段那个改动其实也有效,它贡献了大约 28ms——只不过被那 600ms 的 Redis 循环彻底淹没了,肉眼根本看不出来。
优化收益的排序,我的个人版本
市面上的性能文章喜欢按「算法复杂度 → 数据结构 → 编译优化 → 手写汇编」这个顺序讲。我觉得这个顺序对实际写业务代码的人有误导,因为它是按技术难度排的,不是按投入产出比排的。
我自己的排序是这样的:
- 减少跨进程、跨网络的往返次数。批量、pipeline、连接复用。收益通常是一个数量级,而改动量往往是所有优化里最小的。上面那个 Redis 的例子,改 30 行代码换回 600ms。
- 减少堆分配,尤其是热路径上的小对象。收益来自两处:分配本身的 25ns 左右,加上 GC 的摊销成本(后者经常更大)。Go 里看
go test -bench=. -benchmem输出的 allocs/op,Java 里用 JFR 看 TLAB 分配速率。把 allocation 降一个数量级,GC 停顿往往跟着降一个数量级。 - 数据局部性。这个很多人没意识到:同样的算法,把
[]struct{A,B,C}拆成[]A、[]B、[]C三个切片,遍历求和的耗时可能差 3~5 倍,原因纯粹是 cache line 的有效利用率——一个 64 字节的 struct 里如果有 40 字节的冷字段,你就浪费了 60% 的内存带宽。 - 算法和数据结构。注意我把它排第四。因为真实业务里 n 通常只有几十到几千,O(n²) 和 O(n log n) 在这个规模下差的是微秒级,除非 n 真的上到十万量级,否则优先级远低于前三条。
- 微观优化:
i++vs++i、手动内联、位运算替乘除。编译器通常比你做得更好,现代 CPU 的分支预测和乱序执行又会吃掉大部分差异。99.9% 的情况下,这类优化只影响 benchmark 上的小数点,不影响线上。
可以直接抄的几个具体做法
Go 项目方面:
- 起一个独立的
net/http/pprof端口,别和业务端口混:go func() { log.Println(http.ListenAndServe('localhost:6060', nil)) }()。生产环境记得只监听 127.0.0.1 或加鉴权。 - 看内存分配时,
-alloc_space和-alloc_objects经常给出完全相反的结论:一个 10KB 的大 buffer 在 alloc_space 里排第一,但在 alloc_objects 里根本排不上号——而真实瓶颈可能恰恰是那 10 万次 32 字节的小分配。两个都要看。 - slice 能预估容量就一定预分配:
make([]Item, 0, len(src))。100 万个元素不做预分配,Go 会扩容四十多次,累计拷贝的元素数量大概在最终长度的 3~5 倍这个量级。 - 想确认某个变量有没有逃逸,跑
go build -gcflags='-m -m' ./... 2>&1 | grep 'escapes to heap'。 sync.Pool从 Go 1.13 起每个 P 有私有缓存,命中路径基本无锁,但它每次 GC 会被清空(victim cache 让对象多活一轮)。所以它适合放 buffer 这种廉价对象,不适合放数据库连接这种创建成本高的东西。
数据库和连接池方面:
- N+1 是永远的冠军。定位方法很土但有效:把 ORM 的 SQL 日志打开,数单个请求打了多少条 SQL。我见过最夸张的一个列表接口,一个请求打了 1400 条。
- 连接池别乱调大。HikariCP 官方文档给的公式是
connections = (core_count * 2) + effective_spindle_count,8 核配 SSD 大概就是 17 左右。我曾把连接数从 20 调到 200,压测时 P99 反而涨了 40%——数据库端的上下文切换和锁竞争被放大了。这个坑我踩得很实。
什么时候别优化
这部分很少被写进教程,但它比前面所有内容都重要。
如果一段代码一年跑不了几次,或者它占总耗时的比例不到 1%,那你为它引入 sync.Pool、预分配、位运算,换来的只是一份更难读、更容易出并发 bug 的代码,收益是零。我在一个统计任务里手写过一个对象池,后来发现那个任务一天跑一次,单次 3 秒,其中 2.9 秒在等第三方 API。那个池子唯一的作用,就是三个月后我自己看不懂那段代码了。
还有一点,优化前务必把基线数据存下来。我当时忘了保存 baseline 的 profile 文件,后来想确认「Redis 循环究竟占多少」,只能 git stash 回滚代码重新压测一遍。pprof 导出的 profile 是可以存档的,go tool pprof -base baseline.prof current.prof 能直接做差异对比,早用早省事。
如果你现在正准备打开 IDE 改某段代码,先问自己一个问题:我手上有没有它当前实际耗时的数据?如果没有,先把 profile 跑起来。这十分钟,比后面十个小时都值。