pprof 和火焰图
发现有同事还不会用 pprof 来排查性能问题。希望看完这篇文章以后能学会。
go 里自带的 pprof 是非常强大的工具。平常可以用来排查线上的 cpu 问题，内存问题。官方的 pprof 使用起来非常简单。如果你的进程是个 web 服务，只要：
import _ "net/http/pprof"
然后你的 web 应用就有了生成 profile 的能力。当线上出现问题的时候，如果是进程 cpu 占用过高，我们可以先用 cpuprofile 来鉴定是哪个环节出了问题。
从一个简单的 web 应用开始
比如下面这个非常简单的程序：
package main
import (
"log"
"net/http"
_ "net/http/pprof"
"regexp"
)
func handler(wr http.ResponseWriter, r *http.Request) {
var pattern = regexp.MustCompile(`^(\w+)@didichuxing.com$`)
account := r.URL.Path[1:]
res := pattern.FindSubmatch([]byte(account))
if len(res) > 1 {
wr.Write(res[1])
} else {
wr.Write([]byte("None"))
}
}
func main() {
http.HandleFunc("/", handler)
err := http.ListenAndServe(":9999", nil)
if err != nil {
log.Fatal("ListenAndServe:", err)
}
}
这个例子来自某著名主播(误，golang 的官方开发组成员。
这样一段代码在线上突然遇到了性能问题，比如频繁/偶尔 GC 导致接口出现超时，或者 cpu 高峰时段占用奇高无比。怎么定位问题？
抓瞎的修改肯定是不行的。
cpu 问题定位
以定位 cpu 消耗问题为例，如果是已经在线上跑的服务，可以通过
go tool pprof ./binname localhost:9999/debug/pprof/profile
来进行采样。
如果是在线下进行问题定位，思路也差不多，但是因为线下没有有效的负载，所以还额外需要类似 wrk 这样的压测工具来进行辅助。
因此线下的流程分为两步：
step 1
wrk -c500 -t30 -d1m http://localhost:9999/kkkkaaa@didichuxing.com
step 2
go tool pprof ./binname localhost:9999/debug/pprof/profile
采样完毕之后自动进入 pprof 的交互命令行界面：
top 10
可以看到采样期间内 cpu 使用 top 10 的函数。
(pprof) top 10
10550ms of 12190ms total (86.55%)
Dropped 135 nodes (cum <= 60.95ms)
Showing top 10 nodes out of 96 (cum >= 100ms)
flat flat% sum% cum cum%
9280ms 76.13% 76.13% 9280ms 76.13% syscall.Syscall
230ms 1.89% 78.01% 230ms 1.89% runtime.mach_semaphore_timedwait
170ms 1.39% 79.41% 170ms 1.39% runtime.mach_semaphore_signal
150ms 1.23% 80.64% 320ms 2.63% runtime.pcvalue
150ms 1.23% 81.87% 150ms 1.23% runtime.usleep
130ms 1.07% 82.94% 680ms 5.58% runtime.gentraceback
120ms 0.98% 83.92% 340ms 2.79% runtime.gcAssistAlloc1
110ms 0.9% 84.82% 140ms 1.15% runtime.scanblock
110ms 0.9% 85.73% 200ms 1.64% runtime.scanobject
100ms 0.82% 86.55% 100ms 0.82% runtime.freedefer
(pprof)
竟然什么都看不出来。。那么执行:
(pprof) web
这样就可以输出采样得到的调用流程图了，如果你的机器上没有 Graphviz 会报错，不过这么简单的问题相信你可以自行解决。这个流程图是比较典型的 dag 图，在结点比较多的时候输出会自动把一些耗时少的结点 drop 掉。也是合理的，没性能问题的流程你优化个啥啊，耍流氓？
有了图我们就可以一步步从自己代码的入口函数去跟踪整个调用环节上，到底是在哪一步出现了问题。pprof 输出的 svg 图比较有意思，耗时长的调用线条会加黑加粗，时间长的函数所在的方块也会被加黑加粗。所以你就去找黑又粗就好了。当然了，我们运行的图上你可能发现有很多 read 和 write 比较耗时，这个这里暂时先不谈。先看业务逻辑，这张图上的 regexp.MustCompile 非常可疑。
再回去看看代码，每次请求来了都会重新 compile，显然不太靠谱(事后分析谁不会啊)。
func handler(wr http.ResponseWriter, r *http.Request) {
// 罪魁祸首
var pattern = regexp.MustCompile(`^(\w+)@didichuxing.com$`)
account := r.URL.Path[1:]
如果是线上服务，这里可能就是几行没有想太多的逻辑代码，比如本来可以用 strings.Trim 来做的字符串处理，用了 strings.Replace 什么的。之前也有基础架构部的同学用 pprof 来分析线上长连接服务的 Gzip 压缩 cpu 性能问题。也是通过观察 pprof 输出的 svg 图来查找黑又粗。
但 pprof 不只局限于 cpu 占用问题，也可以拿来分析内存问题。例如某个模块发生了 goroutine 泄露，而且调用比较频繁，那么通过 pprof 一定可以找到大量的内存分配。
不过 pprof 也不是没有缺点。因为 svg 是 pprof 输出的一个 dag 图，如果在你的系统本身逻辑比较复杂的时候，这张 dag 图也毫无疑问会变得异常复杂。虽然我们可以哪粗找哪，哪黑找哪(误，但毕竟看到一张几十个结点的图的时候会感到生理上的抗拒。
有没有更直观的方法？
比 pprof 更直观的火焰图
这里先要感谢 netflix 的 Brendan Gregg 大神发明的火焰图。这里我们用了某商开发的 go-torch，这个工具实际上本身读取的也是 pprof 的输出，但根据火焰图的定义进行了展示优化。还是用上面的样例程序，我们来生成项目的火焰图看看。
在执行 wrk 的同时运行：
理论上输出火焰图之后我们最主要应该关注的是较宽的这些“平顶山”，不过这里尽是一些 syscall 或者网络的读写，并不能进行多少优化，还是先看自己的业务逻辑部分。整个程序是从左到右从下到上执行的。展开 main.Handler ：
定位代码的问题几乎就是秒级了，直观万岁！也可能有人觉得火焰图虽直观，但并不具体。比如我想知道一个函数里每行消耗比较大的调用在整个过程中占用了多少时间，占用了百分之多少，这样我优化了以后才好去吹牛逼，我这次的优化使性能提高了百分之多少多少。这要怎么办呢。这时候还是得用 pprof。
通过之前的命令我们进入 pprof 的交互命令行：
(pprof) list handler
Total: 12.16s
ROUTINE ======================== main.handler in /Users/Xargin/pprof_md/pprofff.go
0 1.47s (flat, cum) 12.09% of Total
. . 6: _ "net/http/pprof"
. . 7: "regexp"
. . 8:)
. . 9:
. . 10:func handler(wr http.ResponseWriter, r *http.Request) {
. 1.18s 11: var pattern = regexp.MustCompile(`^(\w+)@didichuxing.com$`)
. . 12: account := r.URL.Path[1:]
. 250ms 13: res := pattern.FindSubmatch([]byte(account))
. . 14: if len(res) > 1 {
. 40ms 15: wr.Write(res[1])
. . 16: } else {
. . 17: wr.Write([]byte("None"))
. . 18: }
. . 19:}
. . 20:
(pprof)
也可以非常方便地看出来瓶颈在 MustCompile。并可以明确地算出瓶颈代码在整个运行时间中所占的百分比。优化以后去吹牛也更真实了！
干掉网络传输干扰
这时候可能有同学跳出来喷，你这个测试还有网络传输 read/write 的干扰，实际上结果不一定准确，我可能是因为读取太多影响到我的正常业务逻辑处理导致 xxx 太慢了
blabla 呢？
先不说这问题是不是胡搅蛮缠，我们确实可以在干掉网络传输的情况下进行 http 测试。
这时候我们可以借助 golang 提供的 benchmark。
package main
import "testing"
import "net/http/httptest"
import "net/http"
func BenchmarkHandler(b *testing.B) {
for i := 0; i < b.N; i++ {
req, err := http.NewRequest(
http.MethodGet, "http://localhost:9999/aabbccdd@didichuxing.com",
nil,
)
if err != nil {
b.Error("cannot")
}
rec := httptest.NewRecorder()
handler(rec, req)
if rec.Code != http.StatusOK {
b.Error("response error")
}
}
}
执行：
go test -bench . -cpuprofile cpu.prof
然后
go-torch --alloc_objects -t 5 --colors=mem localhost:9999/debug/pprof/heap
瓶颈函数在火焰图上更宽了~更有说服力了对不对。
如果你的进程遇到的是 cpu 的问题那上面的手段就够用了。如果是你的线上服务遇到 GC 之类内存导致的问题怎么办？
也很简单~
内存分析
内存的统计结果是一个统计值，不需要采样。随便压段时间，然后直接运行：
go-torch --alloc_objects -t 5 --colors=mem localhost:9999/debug/pprof/heap
和 cpu 的火焰图其实差不多。也可以秒级锁定问题点。
(pprof) list handler
Total: 29.02GB
ROUTINE ======================== main.handler in /Users/caochunhui/Downloads/pprof_md/pprofff.go
0 25.56GB (flat, cum) 88.08% of Total
. . 7: "regexp"
. . 8:)
. . 9:
. . 10:func handler(wr http.ResponseWriter, r *http.Request) {
. . 11: var pattern = regexp.MustCompile(`^(\w+)@didichuxing.com$`)
. 22.56GB 12: account := r.URL.Path[1:]
. 3GB 13: res := pattern.FindSubmatch([]byte(account))
. . 14: if len(res) > 1 {
. . 15: wr.Write(res[1])
. . 16: } else {
. . 17: wr.Write([]byte("None"))
. . 18: }
ROUTINE ======================== net/http/pprof.handler.ServeHTTP in /usr/local/go/src/net/http/pprof/pprof.go
0 5.82MB (flat, cum) 0.02% of Total
. . 205: gc, _ := strconv.Atoi(r.FormValue("gc"))
. . 206: if name == "heap" && gc > 0 {
. . 207: runtime.GC()
. . 208: }
. . 209: p.WriteTo(w, debug)
. 5.82MB 210: return
. . 211:}
(pprof)
这一次 list 就没那么直观了。我们可以进 web，再在图上看细节~
啊哈，看起来可以想怎么定位问题就怎么定位问题了。
要不要优化
性能优化和代码可读之间往往是矛盾的。像批量读批量写这种在最开始写的时候就应该做到的不在讨论范畴。
大多数时候，你为了优化一段代码的性能，几乎是必然地会让这段代码变丑(除非原作者过于没有节操)。
如果在一个项目还没有碰到性能瓶颈的时候，尽量不要没事就去优化它。即使你坚持要把代码改得性能更好但晦涩，那至少请把注释加上。
但即使你不去做优化，像本文中介绍的工具也应该在你的工具箱里以防万一。
再从知名主播的视频系列里盗个图：