go语言中的大杀器,对应用程序进行分析。
pprof
简介
采样方式
- runtime/pprof 采集程序(非server) 指定区块对运行数据进行分析
- net/http/pprof 基于http server运行,并且采集运行时对数据进行分析
使用模式:
- web ui
- 报告生成
- 交互式终端
可以用来做什么?
- cpu profiling cpu分析
- memory profiling 内存分析。内存泄漏,内存使用情况。
- block profiling goroutine 阻塞分析。 默认不开启 runtime.SetBlockProfileRate 进行开启
- mutex profiling 互斥锁分析。报告互斥锁对竞争情况。默认不开启,需要调用 runtime.SetMutexProfileFraction 进行开启
demo
1package main
2
3import (
4 "log"
5 "net/http"
6 _ "net/http/pprof"
7 "time"
8)
9
10var datas []string
11
12func main() {
13 go func() {
14 for {
15 log.Printf("len:%d", Add("crmoaodssdsd"))
16 time.Sleep(time.Millisecond * 10)
17 }
18 }()
19 _ = http.ListenAndServe("0.0.0.0:6060", nil)
20}
21
22func Add(str string) int {
23 datas = append(datas, str)
24 return len(datas)
25}
浏览器访问 http://localhost:6060/debug/pprof
cpu profiling
1go tool pprof http://localhost:6060/debug/pprof/profile\?seconds\=60
2go tool pprof https+insecure://localhost:6060/debug/pprof/profile\?seconds\=60
3
4# 输入top10, top20
Entering interactive mode (type “help” for commands, “o” for options) (pprof) top Showing nodes accounting for 1.06s, 96.36% of 1.10s total Showing top 10 nodes out of 52 flat flat% sum% cum cum% 0.30s 27.27% 27.27% 0.51s 46.36% runtime.kevent 0.28s 25.45% 52.73% 0.28s 25.45% runtime.libcCall 0.17s 15.45% 68.18% 0.17s 15.45% runtime.pthread_cond_signal 0.11s 10.00% 78.18% 0.18s 16.36% runtime.pthread_cond_wait 0.09s 8.18% 86.36% 0.10s 9.09% syscall.syscall 0.04s 3.64% 90.00% 0.18s 16.36% log.(*Logger).Output 0.03s 2.73% 92.73% 0.03s 2.73% runtime.write1 0.02s 1.82% 94.55% 0.02s 1.82% log.itoa (inline) 0.01s 0.91% 95.45% 0.11s 10.00% internal/poll.(*FD).Write 0.01s 0.91% 96.36% 0.03s 2.73% log.(*Logger).formatHeader
- flat:当前函数占用CPU的耗时
- flat::当前函数占用CPU的耗时百分比
- sum%:函数占用CPU的耗时累计百分比
- cum:当前函数加上调用当前函数的函数占用CPU的总耗时
- cum%:当前函数加上调用当前函数的函数占用CPU的总耗时百分比
- 最后一列:函数名称
heap profiling
1go tool pprof http://localhost:6060/debug/pprof/heap
2
3go tool pprof -inuse_space http://localhost:6060/debug/pprof/heap
常用类型
- inuse_space 分析应用程序常住内存对占用情况
- alloc_objects 分析应用程序对内存临时分配情况
- inuse_objects 查看每个函数对对象数量
- alloc_space 分配的内存空间大小
goroutine profiling
go tool pprof http://localhost:6060/debug/pprof/goroutine
输入traces 命令 ,打印出对应的所有调用栈,以及指标信息。
1➜ fashnv git:(main) ✗ go tool pprof http://localhost:6060/debug/pprof/goroutine
2Fetching profile over HTTP from http://localhost:6060/debug/pprof/goroutine
3Saved profile in /Users/maozhongyu/pprof/pprof.goroutine.001.pb.gz
4Type: goroutine
5Time: May 26, 2023 at 2:48pm (CST)
6Entering interactive mode (type "help" for commands, "o" for options)
7(pprof) traces
8Type: goroutine
9Time: May 26, 2023 at 2:48pm (CST)
10-----------+-------------------------------------------------------
111 runtime.gopark
12runtime.netpollblock
13internal/poll.runtime_pollWait
14internal/poll.(*pollDesc).wait
15internal/poll.(*pollDesc).waitRead (inline)
16internal/poll.(*FD).Accept
17net.(*netFD).accept
18net.(*TCPListener).accept
19net.(*TCPListener).Accept
20net/http.(*Server).Serve
21net/http.(*Server).ListenAndServe
22net/http.ListenAndServe (inline)
23main.main
24runtime.main
25-----------+-------------------------------------------------------
261 runtime.gopark
27time.Sleep
28main.main.func1
29-----------+-------------------------------------------------------
301 runtime/pprof.runtime_goroutineProfileWithLabels
31runtime/pprof.writeRuntimeProfile
32runtime/pprof.writeGoroutine
33runtime/pprof.(*Profile).WriteTo
34net/http/pprof.handler.ServeHTTP
35net/http/pprof.Index
36net/http.HandlerFunc.ServeHTTP
37net/http.(*ServeMux).ServeHTTP
38net/http.serverHandler.ServeHTTP
39net/http.(*conn).serve
40-----------+-------------------------------------------------------
mutex profiling
查看引起互斥锁的函数,以及锁开销的位置
go tool pprof http://localhost:6060/debug/pprof/mutex
输入 top 输入 list main
runtime.SetMutexProfileFraction(1) 采集频率。 0表示不采集
1package main
2
3import (
4 "net/http"
5 _ "net/http/pprof"
6 "runtime"
7 "sync"
8)
9
10func init() {
11 runtime.SetMutexProfileFraction(1)
12}
13
14func main() {
15 var m sync.Mutex
16 var datas = make(map[int]struct{})
17 for i := 0; i < 999; i++ {
18 go func(i int) {
19 m.Lock()
20 defer m.Unlock()
21 datas[i] = struct{}{}
22 }(i)
23 }
24 _ = http.ListenAndServe("0.0.0.0:6060", nil)
25}
1 fashnv git:(main) ✗ go tool pprof http://localhost:6060/debug/pprof/mutex
2Fetching profile over HTTP from http://localhost:6060/debug/pprof/mutex
3Saved profile in /Users/maozhongyu/pprof/pprof.contentions.delay.001.pb.gz
4Type: delay
5Time: May 26, 2023 at 3:09pm (CST)
6Entering interactive mode (type "help" for commands, "o" for options)
7(pprof) top
8Showing nodes accounting for 1.30ms, 100% of 1.30ms total
9 flat flat% sum% cum cum%
10 1.30ms 100% 100% 1.30ms 100% sync.(*Mutex).Unlock
11 0 0% 100% 1.30ms 100% main.main.func1
12(pprof) list
13command list requires an argument
14(pprof) list main
15Total: 1.30ms
16ROUTINE ======================== main.main.func1 in /Users/maozhongyu/code/fashnv/tmp.go
17 0 1.30ms (flat, cum) 100% of Total
18 . . 17: for i := 0; i < 999; i++ {
19 . . 18: go func(i int) {
20 . . 19: m.Lock()
21 . . 20: defer m.Unlock()
22 . . 21: datas[i] = struct{}{}
23 . 1.30ms 22: }(i)
24 . . 23: }
25 . . 24: _ = http.ListenAndServe("0.0.0.0:6060", nil)
26 . . 25:}
27(pprof) %
links
- go语言编程之旅 (第6章)