pprof
pprof是GoLang程序性能分析工具，prof是profile（画像）的缩写 .通过pprof,我们可以得到程序执行的以下数据:
Profile Descriptions:
- allocs:
内存分配数据采样信息 - block:
导致同步原语阻塞的堆栈跟踪 - cmdline:
当前程序的命令行调用
goroutine:
所有当前goroutine的堆栈跟踪 - heap:
活动对象的内存分配采样。您可以指定gcGET参数以在获取堆样本之前运行gc。 - mutex:
争用互斥锁持有者的堆栈跟踪 - profile:
CPU配置文件。可以在秒GET参数中指定持续时间。获取配置文件后，使用go工具pprof命令调查配置文件。 - threadcreate:
导致创建新操作系统线程的堆栈跟踪 - trace:
A trace of execution of the current program. You can specify the duration in the seconds GET parameter. After you get the trace file, use the go tool trace command to investigate the trace.
真正分析时常用4种
- CPU Profiling：CPU 分析，按照一定的频率采集所监听的应用程序 CPU（含寄存器）的使用情况，可确定应用程序在主动消耗 CPU 周期时花费时间的位置
- Memory Profiling：内存分析，在应用程序进行堆分配时记录堆栈跟踪，用于监视当前和历史内存使用情况，以及检查内存泄漏
- Block Profiling：阻塞分析，记录 goroutine 阻塞等待同步（包括定时器通道）的位置
- Mutex Profiling：互斥锁分析，报告互斥锁的竞争情况
做性能分析，第一步需要先获取数据，然后对数据进行分析。所以下面展示一下如何进行数据获取。
数据获取方式
go的运行有2种情况,一种是常驻内存 服务式运行,例如http,tcp服务,一直运行接收请求,一种是工具脚本形式,运行完则退出
工具型应用
工具型应用调用比较简单,主要是用 runtime/pprof库,将画像数据写入文件中:
package main import ( "os" "runtime/pprof" _ "runtime/pprof" ) func main() { //获取cpu profile cpuFile, _ := os.OpenFile("cpu.prof", os.O\_CREATE|os.O\_RDWR, 0644) defer cpuFile.Close() pprof.StartCPUProfile(cpuFile) defer pprof.StopCPUProfile() //获取内存profile memFile, _ := os.OpenFile("mem.prof", os.O\_CREATE|os.O\_RDWR, 0644) defer memFile.Close() pprof.WriteHeapProfile(memFile) //执行循环1000次 for i := 0; i < 1000; i++ { } }
执行完毕之后,可以直接看到cpu.prof和mem.prof文件,里面包含了画像数据:
(base) tioncico@appledeMacBook-Pro test % ls *.prof cpu.prof mem.prof
文件不能直接查看,需要通过go tool pprof 工具读取显示,在下面会讲到
服务型应用
服务型应用通过 "net/http/pprof"库进行获取,在http库中,默认使用了defaultServerMux,可以直接使用即可获取:
package main import ( "fmt" "net/http" _ "net/http/pprof" ) func hello(w http.ResponseWriter, r *http.Request) { fmt.Fprintf(w, "hello world!") } func main() { http.HandleFunc("/", hello) //设置访问的路由 err := http.ListenAndServe(":8080", nil) //设置监听的端口 if err != nil { fmt.Printf("ListenAndServe: %s", err) } }
访问 http://localhost:8080 可以输出 hello world
访问 http://localhost:8080/debug/pprof/ 可以查看到画像信息:
serverMux
可以看出,本身没有注册/debug/pprof,但是直接访问依然还是有数据的,那是因为在 http.ListenAndServe 时,没有传入自定义的serverMux进行路由处理,则pprof库自动进行了注册:
如果你使用了自定义的serverMux,则需要自己注册,才能获取到pprof
http.HandleFunc("/debug/ppprof/", pprof.Index)
这样的话,访问 http://localhost:8080/debug/ppprof/ 也是有用的
开源框架
在不同的开源框架中,有提供自己封装好的pprof包,调用更加方便,具体使用请参考框架文档
pprof主要核心就是将pprof路由注册到服务中,并可以访问此服务即可
数据分析
数据分析通过命令 go tool pprof 进行,主要有2种查看模式
1:通过http路径进入交互模式
2:通过文件进入交互模式或者进入web页面查看
交互模式
进入命令行,基于http路径的数据分析:
(base) tioncico@appledeMacBook-Pro test % go tool pprof http://localhost:8080/debug/pprof/profile Fetching profile over HTTP from http://localhost:8080/debug/pprof/profile Saved profile in /Users/tioncico/pprof/pprof.samples.cpu.003.pb.gz Type: cpu Time: Nov 22, 2022 at 5:16pm (CST) Duration: 30s, Total samples = 20ms (0.067%) Entering interactive mode (type "help" for commands, "o" for options) (pprof)
执行此命令后,会采集默认30秒之后的cpu数据,然后生成记录,进行数据分析,可以通过?=seconds=60改成60秒
也可以通过 go tool pprof cpu.prof(文件名) 方式进入
进入命令行交互模式之后,可以使用help查看所有命令,通过help <cmd|option> 查看子命令使用方法
(pprof) help Commands: callgrind Outputs a graph in callgrind format comments Output all profile comments disasm Output assembly listings annotated with samples dot Outputs a graph in DOT format eog Visualize graph through eog evince Visualize graph through evince gif Outputs a graph image in GIF format gv Visualize graph through gv kcachegrind Visualize report in KCachegrind list Output annotated source for functions matching regexp pdf Outputs a graph in PDF format peek Output callers/callees of functions matching regexp png Outputs a graph image in PNG format proto Outputs the profile in compressed protobuf format ps Outputs a graph in PS format raw Outputs a text representation of the raw profile svg Outputs a graph in SVG format tags Outputs all tags in the profile text Outputs top entries in text form top Outputs top entries in text form topproto Outputs top entries in compressed protobuf format traces Outputs all profile samples in text form tree Outputs a text rendering of call graph web Visualize graph through web browser weblist Display annotated source in a web browser o/options List options and their current values q/quit/exit/^D Exit pprof
可以自行研究
通过top,可以查看到cpu占用最高的排序:
(pprof) top Showing nodes accounting for 20ms, 100% of 20ms total flat flat% sum% cum cum% 10ms 50.00% 50.00% 10ms 50.00% runtime.libcCall 10ms 50.00% 100% 20ms 100% runtime.pthread\_cond\_wait 0 0% 100% 20ms 100% runtime.findrunnable 0 0% 100% 20ms 100% runtime.mPark 0 0% 100% 20ms 100% runtime.mcall 0 0% 100% 20ms 100% runtime.notesleep 0 0% 100% 20ms 100% runtime.park_m 0 0% 100% 20ms 100% runtime.schedule 0 0% 100% 20ms 100% runtime.semasleep 0 0% 100% 20ms 100% runtime.stopm (pprof)
这个东西看不出啥,我们改造下http服务的helloworld,使其计算1000次快速排序:
package main import ( "fmt" "math/rand" "net/http" _ "net/http/pprof" ) func hello(w http.ResponseWriter, r *http.Request) { //生成一个100个随机数字的数组 arr := make(\[\]int, 100) for i := 0; i < 100; i++ { arr\[i\] = rand.Intn(100) } for i := 0; i < 10000; i++ { //快速排序 quickSort(arr, 0, len(arr)-1) } fmt.Fprintf(w, "hello world!") } func main() { http.HandleFunc("/", hello) //设置访问的路由 err := http.ListenAndServe(":8080", nil) //设置监听的端口 if err != nil { fmt.Printf("ListenAndServe: %s", err) } } //快速排序 func quickSort(arr \[\]int, left, right int) { if left < right { pivot := partition(arr, left, right) quickSort(arr, left, pivot-1) quickSort(arr, pivot+1, right) } } func partition(arr \[\]int, left int, right int) int { pivot := arr\[left\] for left < right { for left < right && arr\[right\] >= pivot { right-- } arr\[left\] = arr\[right\] for left < right && arr\[left\] <= pivot { left++ } arr\[right\] = arr\[left\] } arr\[left\] = pivot return left }
重新执行分析命令进行分析,top命令查看:
(pprof) top Showing nodes accounting for 144.72s, 99.70% of 145.16s total Dropped 21 nodes (cum <= 0.73s) flat flat% sum% cum cum% 114.47s 78.86% 78.86% 114.83s 79.11% main.partition 30.03s 20.69% 99.55% 144.90s 99.82% main.quickSort 0.22s 0.15% 99.70% 117.12s 80.68% main.hello 0 0% 99.70% 114.42s 78.82% net/http.(*ServeMux).ServeHTTP 0 0% 99.70% 111.58s 76.87% net/http.(*conn).serve 0 0% 99.70% 115.71s 79.71% net/http.HandlerFunc.ServeHTTP 0 0% 99.70% 112.95s 77.81% net/http.serverHandler.ServeHTTP (pprof)
每一行都代表一个函数的信息,每列的标识为:
flat：函数在 CPU 上运行的时间
flat%：函数在CPU上运行时间的百分比
sum%：是从上到当前行所有函数累加使用 CPU 的比例，如第二行sum=48.52=28.79+19.73
cum：这个函数以及子函数运行所占用的时间，应该大于等于flat
cum%：这个函数以及子函数运行所占用的比例，应该大于等于flat%
最后一列：函数的名字
如果应用程序有性能问题，上面这些信息应该能告诉我们时间都花费在哪些函数的执行上
查看函数具体执行问题
通过 交互模式 list 函数名,即可查看到该函数的具体哪一行耗时:
(pprof) list hello Total: 145.16s ROUTINE ------------------------ main.hello in /Users/tioncico/go/src/test/server.go 220ms 117.12s (flat, cum) 80.68% of Total . . 11: //生成一个100个随机数字的数组 . . 12: arr := make(\[\]int, 100) . . 13: for i := 0; i < 100; i++ { . . 14: arr\[i\] = rand.Intn(100) . . 15: } 210ms 210ms 16: for i := 0; i < 10000; i++ { . . 17: //快速排序 . 116.90s 18: quickSort(arr, 0, len(arr)-1) . . 19: } 10ms 10ms 20: fmt.Fprintf(w, "hello world!") . . 21:} . . 22: . . 23:func main() { . . 24: http.HandleFunc("/", hello) //设置访问的路由 . . 25: err := http.ListenAndServe(":8080", nil) //设置监听的端口 (pprof)
可看到,for循环里面的quickSort耗时比较长
生成函数调用图
可以通过svg命令,生成一个svg文件,拖动到浏览器打开即可查看函数调用图,但是需要安装 graphviz 才可以使用,具体安装方法可以自行百度
mac安装方法:
brew install graphviz go get -u github.com/ofabry/go-callvis
内存画像
执行go tool pprof http://localhost:8080/debug/pprof/heap 即可,其他和cpu操作同理
web页面模式
通过-http 选项进入web页面:
go tool pprof -http=:9091 http://localhost:8080/debug/pprof/profile go tool pprof -http=:9091 文件名
其他可以执行了解探索
