一:背景
當正在運行的golang程序消耗預期之外的內存和時間,我們這個時候就需要去弄明白,到底是是我們的代碼哪個地方消耗了這些內存及相應時間。但此時編譯好的golang程序對我們而言是黑盒,如果去分析具體的內存及時間使用情況?這個時候我們可以去了解和使用pprof來分析golang進程的內存使用。
二:實戰
2.1.環境搭建
下載安裝golang,需要進到pod容器中(或者也可以將這些打到基礎鏡像中)
$ wget https://go.dev/dl/go1.15.15.linux-amd64.tar.gz
$ tar -C /usr/local -xzf go1.4.linux-amd64.tar.gz
# 添加到環境變量中
$ export PATH=$PATH:/usr/local/go/bin
安裝生成svg圖的依賴
$ yum install graphviz -y
2.2.修改和添加業務代碼
在相關業務服務代碼main中添加以下代碼
// pprof 的init函數會將pprof里的一些handler注冊到http.DefaultServeMux上
// 當不使用http.DefaultServeMux來提供http api時,可以查閱其init函數,自己注冊handler
import _ "net/http/pprof"
go func() {
http.ListenAndServe("0.0.0.0:9090", nil)
}()
修改完成后編譯二進制,並運行對應二進制。
2.3.通過 Web 界面查看
查看當前總覽:訪問 http://127.0.0.1:9090/debug/pprof/,可以查看到如下圖相關信息。
可以直接點擊上面的鏈接,進入子頁面,查看相關的匯總信息。
2.4.go tool分析法
2.4.1.內存分析
我們可以采用go tool pprof -inuse_space http://127.0.0.1:9090/debug/pprof/heap
命令連接到進程中 查看正在使用的一些內存相關信息,此時我們得到一個可以交互的命令行。
我們可以看數據top10
來查看正在使用的對象較多的10個函數入口。通常用來檢測有沒有不符合預期的內存 對象引用。
# go tool pprof -inuse_space http://127.0.0.1:9090/debug/pprof/heap
Fetching profile over HTTP from http://127.0.0.1:9090/debug/pprof/heap
Saved profile in /root/pprof/pprof.yaohong.alloc_objects.alloc_space.inuse_objects.inuse_space.003.pb.gz
File: test_exporter
Type: inuse_space
Time: Dec 15, 2021 at 1:05pm (CST)
Entering interactive mode (type "help" for commands, "o" for options)
(pprof) top10
Showing nodes accounting for 512.69kB, 100% of 512.69kB total
Showing top 10 nodes out of 12
flat flat% sum% cum cum%
512.69kB 100% 100% 512.69kB 100% crypto/x509.parseCertificate
0 0% 100% 512.69kB 100% crypto/x509.(*CertPool).AppendCertsFromPEM
0 0% 100% 512.69kB 100% crypto/x509.ParseCertificate
0 0% 100% 512.69kB 100% crypto/x509.SystemCertPool
0 0% 100% 512.69kB 100% crypto/x509.initSystemRoots
0 0% 100% 512.69kB 100% crypto/x509.loadSystemRoots
0 0% 100% 512.69kB 100% crypto/x509.systemRootsPool (inline)
0 0% 100% 512.69kB 100% harbor_exporter/collector.New
0 0% 100% 512.69kB 100% main.main
0 0% 100% 512.69kB 100% runtime.main
(pprof)
然后我們在用go tool pprof -alloc_space http://127.0.0.1:9090/debug/pprof/heap
命令鏈接程序來查看 內存對象分配的相關情況。然后輸入top
來查看累積分配內存較多的一些函數調用:
# go tool pprof -alloc_space http://127.0.0.1:9090/debug/pprof/heap
Fetching profile over HTTP from http://127.0.0.1:9090/debug/pprof/heap
Saved profile in /root/pprof/pprof.yaohong.alloc_objects.alloc_space.inuse_objects.inuse_space.004.pb.gz
File: test_exporter
Type: alloc_space
Time: Dec 15, 2021 at 1:08pm (CST)
Entering interactive mode (type "help" for commands, "o" for options)
(pprof) top
Showing nodes accounting for 29601.22kB, 86.52% of 34211.94kB total
Showing top 10 nodes out of 95
flat flat% sum% cum cum%
9272.51kB 27.10% 27.10% 9272.51kB 27.10% os.(*File).readdirnames
3610.34kB 10.55% 37.66% 3610.34kB 10.55% compress/flate.NewWriter
3587.75kB 10.49% 48.14% 3587.75kB 10.49% bytes.makeSlice
3584.50kB 10.48% 58.62% 5120.55kB 14.97% os.Readlink
2560.13kB 7.48% 66.10% 2560.13kB 7.48% strings.(*Builder).grow (inline)
2368.55kB 6.92% 73.03% 2368.55kB 6.92% runtime/pprof.StartCPUProfile
1542.01kB 4.51% 77.53% 1542.01kB 4.51% bufio.NewReaderSize (inline)
1536.05kB 4.49% 82.02% 1536.05kB 4.49% syscall.ByteSliceFromString
1024.38kB 2.99% 85.02% 5126.52kB 14.98% github.com/shirou/gopsutil/internal/common.ReadLinesOffsetN
515kB 1.51% 86.52% 515kB 1.51% crypto/x509.(*CertPool).AddCert
(pprof)
我們可以根據如上內存分配情況去review代碼,如何減少這些相關的調用,或者優化相關代碼邏輯。
當我們不明確這些調用時是被哪些函數引起的時,我們可以輸入top -cum
來查找,-cum
的意思就是,將函數調用關系 中的數據進行累積,比如A函數調用的B函數,則B函數中的內存分配量也會累積到A上面,這樣就可以很容易的找出調用鏈。
(pprof) top20 -cum
Showing nodes accounting for 14393.43kB, 42.07% of 34211.94kB total
Showing top 20 nodes out of 95
flat flat% sum% cum cum%
0 0% 0% 25669.06kB 75.03% harbor_exporter/collector.(*Exporter).scrape.func1
0 0% 0% 25669.06kB 75.03% harbor_exporter/collector.ScrapeSystemSocketInfo.Scrape
0 0% 0% 14905.07kB 43.57% github.com/shirou/gopsutil/process.(*Process).OpenFiles (inline)
0 0% 0% 14905.07kB 43.57% github.com/shirou/gopsutil/process.(*Process).OpenFilesWithContext
0 0% 0% 14905.07kB 43.57% github.com/shirou/gopsutil/process.(*Process).fillFromfdWithContext
0 0% 0% 9272.51kB 27.10% github.com/shirou/gopsutil/process.(*Process).fillFromfdListWithContext
0 0% 0% 9272.51kB 27.10% os.(*File).Readdirnames (inline)
9272.51kB 27.10% 27.10% 9272.51kB 27.10% os.(*File).readdirnames
0 0% 27.10% 8713.24kB 25.47% github.com/shirou/gopsutil/process.(*Process).CreateTimeWithContext
0 0% 27.10% 8713.24kB 25.47% github.com/shirou/gopsutil/process.(*Process).createTimeWithContext
0 0% 27.10% 8713.24kB 25.47% github.com/shirou/gopsutil/process.(*Process).fillFromStatWithContext
512.05kB 1.50% 28.60% 8713.24kB 25.47% github.com/shirou/gopsutil/process.(*Process).fillFromTIDStatWithContext
0 0% 28.60% 8713.24kB 25.47% github.com/shirou/gopsutil/process.NewProcessWithContext
0 0% 28.60% 8713.24kB 25.47% github.com/shirou/gopsutil/process.Processes (inline)
0 0% 28.60% 8713.24kB 25.47% github.com/shirou/gopsutil/process.ProcessesWithContext
0 0% 28.60% 5126.52kB 14.98% github.com/shirou/gopsutil/internal/common.BootTimeWithContext
0 0% 28.60% 5126.52kB 14.98% github.com/shirou/gopsutil/internal/common.ReadLines (inline)
1024.38kB 2.99% 31.59% 5126.52kB 14.98% github.com/shirou/gopsutil/internal/common.ReadLinesOffsetN
3584.50kB 10.48% 42.07% 5120.55kB 14.97% os.Readlink
0 0% 42.07% 4685.97kB 13.70% net/http.(*ServeMux).ServeHTTP
2.4.2.CPU耗時分析
我們可以采用go tool pprof http://127.0.0.1:9090/debug/pprof/profile
命令連接到進程中 查看正在使用的一些CPU相關信息。
Type: cpu
Time: Dec 15, 2021 at 2:17pm (CST)
Duration: 30s, Total samples = 10ms (0.033%)
Entering interactive mode (type "help" for commands, "o" for options)
(pprof) top 10
Showing nodes accounting for 10ms, 100% of 10ms total
flat flat% sum% cum cum%
10ms 100% 100% 10ms 100% runtime.runqgrab
0 0% 100% 10ms 100% runtime.findrunnable
0 0% 100% 10ms 100% runtime.mcall
0 0% 100% 10ms 100% runtime.park_m
0 0% 100% 10ms 100% runtime.runqsteal
0 0% 100% 10ms 100% runtime.schedule
(pprof)
(pprof) top20 -cum
Showing nodes accounting for 10ms, 100% of 10ms total
flat flat% sum% cum cum%
0 0% 0% 10ms 100% runtime.findrunnable
0 0% 0% 10ms 100% runtime.mcall
0 0% 0% 10ms 100% runtime.park_m
10ms 100% 100% 10ms 100% runtime.runqgrab
0 0% 100% 10ms 100% runtime.runqsteal
0 0% 100% 10ms 100% runtime.schedule
2.3.3.獲取svg圖
在我們執行go tool pprof -inuse_space http://127.0.0.1:9090/debug/pprof/heap
命令和go tool pprof http://127.0.0.1:9090/debug/pprof/profile
命令都可以在回顯中注入svg,這樣將會產生一個.svg
圖片,其會把這些累積關系畫成一個拓撲圖,提供給 我們。
下面我們取一個圖片中的一個片段進行分析:
每一個方塊為pprof記錄的一個函數調用棧,連線上的標簽代表指定的方法調用的采樣值(例如時間、內存分配大小等),方框的大小與方法運行的采樣值的大小有關。
每個方框由兩個標簽組成:在 cpu profile 中,一個是方法運行的時間占比,一個是它在采樣的堆棧中出現的時間占比(前者是 flat 時間,后者則是 cumulate 時間占比);框越大,代表耗時越多或是內存分配越多。
--inuse/alloc_space
--inuse/alloc_objects
區別
通常情況下:
1.--inuse_space:用來分析程序常駐內存的占用情況;
2.--alloc_objects:用來分析內存的臨時分配情況,可以提高程序的運行速度。
原文:https://www.cnblogs.com/yaohong/