使用 pprof 分析 go-callvis

go-callvis 是一个可视化的项目源码调用链路分析工具。

这里有篇简要分析源码的文章 https://mp.weixin.qq.com/s/dUXXGd8hqEhKE_Cj4EY2Lw

pprof 是 golang 内置的性能优化工具。

今天就介绍下用 pprof 来分析 go-callvis 的性能，看看到底耗时在哪。

先把 go-callvis 下载到本地

git clone https://github.com/ofabry/go-callvis.git
cd go-callvis

再在 main.go 的开头处中加上 pprof 相关函数来分析一波

defer func(t int64) {
	end := time.Now().UnixNano()-t
	fmt.Println("go-callvis 程序执行时间：", end, "纳秒", end/int64(time.Millisecond), "毫秒", end/int64(time.Second), "秒")
}(time.Now().UnixNano())

cpuProfile, _ := os.Create("cpu_profile")
err := pprof.StartCPUProfile(cpuProfile)
if err != nil {
	fmt.Println("cpu err", err.Error())
	return
}
defer pprof.StopCPUProfile()

同时，为了更好分析主要函数的耗时，就把上面代码的第一个 defer 里的语句分别加到 Analysis.Render()、Analysis.DoAnalysis 处，接下来在命令行执行以下命令

go run ./  -nostd -format=png -file stock -group pkg,type github.com/ofabry/go-callvis

上述中的 ./ 意思是把入口的所有 go 文件都加载上（也可以换成 *.go），因为这个项目中除了入口 main.go 外，其他几个 go 文件都是 package main 的，且 main.go 引用里面的变量和函数，如果只执行 main.go 会提示 undefined 之类的错误的。

执行完毕，控制台输出如下

DoAnalysis 程序执行时间： 8205012000 纳秒 8205 毫秒 8 秒
Render 程序执行时间： 47695902000 纳秒 47695 毫秒 47 秒
2022/02/28 23:31:01 writing dot output..
2022/02/28 23:31:01 converting dot to png..
dotToImage 程序执行时间： 304492000 纳秒 304 毫秒 0 秒
程序执行时间： 56206939000 纳秒 56206 毫秒 56 秒

同时 go-callvis 的自身的函数调用链如下

最后，来查看下 pprof 分析的结果

go tool pprof -http=":8081" go-demo cpu_profile

这是会自动跳转到到浏览器，输出如下

分为两栏，上面一栏是菜单，下面一栏默认显示调用函数及耗时图。

比如，要看调用耗时列表，可以依次点击 VIEW - Top

也可以看火焰图，依次点击 VIEW - Flame Graph

二者还有更好的玩法，接下来就靠各位读者自己发掘了，cheers。