profile

profile的中文被翻譯輪廓，對于計(jì)算機(jī)程序而言，拋開業(yè)務(wù)邏輯不談，它的輪廓是是啥呢？不就是cpu，內(nèi)存，各種阻塞開銷，線程，協(xié)程概況 這些運(yùn)行指標(biāo)或環(huán)境。golang語言自帶了工具庫來幫助我們描述，探測，分析這些指標(biāo)或者環(huán)境信息，讓我們來學(xué)習(xí)它。

在上一篇golang pprof 監(jiān)控系列(1) —— go trace 統(tǒng)計(jì)原理與使用  里我講解了下golang trace 工具的統(tǒng)計(jì)原理，它能夠做到對程序運(yùn)行中的各種事件進(jìn)行耗時統(tǒng)計(jì)。而今天要將的memory,block,mutex 統(tǒng)計(jì)的原理與之不同，這是一個在一段時間內(nèi)進(jìn)行采樣得到的累加值。

還記得之前用go trace 生成的網(wǎng)頁圖嗎?

trace 網(wǎng)頁顯示

里面是不是也有 3個名字帶有blocking的 profile的輪廓圖，分別是Network blocking profile，Synchronization blocking profile，Syscall blocking profile ，而它與今天要說的block 統(tǒng)計(jì)有沒有什么關(guān)聯(lián)？先說下結(jié)論，block統(tǒng)計(jì)的內(nèi)容有重合，但是不多，并且統(tǒng)計(jì)數(shù)據(jù)來源是不同的。

Synchronization blocking profile 和 今天的block統(tǒng)計(jì) 內(nèi)容 是一致的，都是blobk信息，不過統(tǒng)計(jì)方式不同。

然后之所以 memory，block，mutex 把這3類數(shù)據(jù)放在一起講，是因?yàn)樗麄兘y(tǒng)計(jì)的原理是很類似的，好的,在了解統(tǒng)計(jì)原理之前，先簡單看下如何使用golang提供的工具對這些數(shù)據(jù)類型進(jìn)行分析。

如何使用

在看使用代碼前，還需要了解清楚對這3種類型的指標(biāo)對哪些數(shù)據(jù)進(jìn)行統(tǒng)計(jì)。

兩種方式都比較常見，首先來看下http 接口暴露這些性能指標(biāo)的方式。

http 接口暴露的方式

package?main
import?(
?"log"
??"net/http"
?_?"net/http/pprof"
)
func?main()?{
??log.Println(http.ListenAndServe(":6060",?nil))
}

使用方式相當(dāng)容易，直接代碼引入net/http/pprof ，便在默認(rèn)的http處理器上注冊上了相關(guān)路由，引入包的目的就是為了調(diào)用對應(yīng)包的init方法注冊路由。下面就是引用包的init方法。

//?src/net/http/pprof/pprof.go:80
func?init()?{
?http.HandleFunc("/debug/pprof/",?Index)
?http.HandleFunc("/debug/pprof/cmdline",?Cmdline)
?http.HandleFunc("/debug/pprof/profile",?Profile)
?http.HandleFunc("/debug/pprof/symbol",?Symbol)
?http.HandleFunc("/debug/pprof/trace",?Trace)
}

接下來訪問路由 http://127.0.0.1:6060/debug/pprof/  便能看到下面網(wǎng)頁內(nèi)容了。

標(biāo)注為紅色的部分就是今天要講的內(nèi)容，點(diǎn)擊它們的鏈接會跳到對應(yīng)的網(wǎng)頁看到統(tǒng)計(jì)信息。我們挨個來看下。

allocs ,heap

這兩個值都是記錄程序內(nèi)存分配的情況。

heap?profile:?7:?5536?[110:?2178080]?@?heap/1048576
2:?2304?[2:?2304]?@?0x100d7e0ec?0x100d7ea78?0x100d7f260?0x100d7f78c?0x100d811cc?0x100d817d4?0x100d7d6dc?0x100d7d5e4?0x100daba20
#?0x100d7e0eb?runtime.allocm+0x8b??/Users/lanpangzi/goproject/src/go/src/runtime/proc.go:1881
#?0x100d7ea77?runtime.newm+0x37??/Users/lanpangzi/goproject/src/go/src/runtime/proc.go:2207
#?0x100d7f25f?runtime.startm+0x11f??/Users/lanpangzi/goproject/src/go/src/runtime/proc.go:2491
#?0x100d7f78b?runtime.wakep+0xab??/Users/lanpangzi/goproject/src/go/src/runtime/proc.go:2590
#?0x100d811cb?runtime.resetspinning+0x7b?/Users/lanpangzi/goproject/src/go/src/runtime/proc.go:3222
#?0x100d817d3?runtime.schedule+0x2d3??/Users/lanpangzi/goproject/src/go/src/runtime/proc.go:3383
#?0x100d7d6db?runtime.mstart1+0xcb??/Users/lanpangzi/goproject/src/go/src/runtime/proc.go:1419
#?0x100d7d5e3?runtime.mstart0+0x73??/Users/lanpangzi/goproject/src/go/src/runtime/proc.go:1367
#?0x100daba1f?runtime.mstart+0xf??/Users/lanpangzi/goproject/src/go/src/runtime/asm_arm64.s:117

在 go1.17.12 這兩者的信息輸出其實(shí)是一樣的，實(shí)現(xiàn)的代碼也基本一致，僅僅是在名稱上做了區(qū)分

按pprof http服務(wù)器啟動網(wǎng)頁上的顯示來說，allocs 是過去內(nèi)存的采樣，heap 是存活對象的采用記錄，然而實(shí)際上在代碼實(shí)現(xiàn)上兩者是一致的。并沒有做區(qū)分。

下面來講下網(wǎng)頁輸出內(nèi)容的含義

heap?profile:?7:?5536?[110:?2178080]?@?heap/1048576

輸出的第一行含義分別是: 7 代表 當(dāng)前活躍的對象個數(shù) 5536 代表 當(dāng)前活躍對象占用的字節(jié)數(shù) 110 代表 所有(包含歷史的對象)對象個數(shù) 2178080 代表 所有對象(包含歷史的對象)占用的對象字節(jié)數(shù) 1048576  控制了內(nèi)存采樣的頻率，1048576 是兩倍的內(nèi)存采樣頻率的大小，默認(rèn)采樣頻率是512kb 即平均每512kb就會采樣一次，注意這個值512kb不是絕對的達(dá)到512kb就會進(jìn)行采樣，而是從一段時間內(nèi)的采樣來看的一個平均值。

接下來就是函數(shù)調(diào)用堆棧信息，來看第一行

2:?2304?[2:?2304]?@?0x100d7e0ec?0x100d7ea78?0x100d7f260?0x100d7f78c?0x100d811cc?0x100d817d4?0x100d7d6dc?0x100d7d5e4?0x100daba20

從左往右看: 2 代表 在該函數(shù)棧上當(dāng)前活躍的對象個數(shù) 2304 代表 在該函數(shù)棧上當(dāng)前活躍的對象所占用的字節(jié)數(shù) 方括號內(nèi)的2   代表 在該函數(shù)棧上所有(包含歷史的對象)對象個數(shù) 方括號內(nèi)的2304 代表 在該函數(shù)棧上所有(包含歷史的對象)對象所占用的字節(jié)數(shù)

然后是棧上pc寄存器的值。再往后就是具體的棧函數(shù)名信息了。

block

接下來看看block會對哪些行為產(chǎn)生記錄，每次程序鎖阻塞發(fā)生時，select 阻塞，channel通道阻塞,wait group 產(chǎn)生阻塞時就會記錄一次阻塞行為。對阻塞行為的記錄其實(shí)是和trace 的Synchronization blocking profile 是一致的，但是和其他兩個blocking profile 不一樣。

要得到block的輸出信息首先要開啟下記錄block的開關(guān).

???//?1?代表?全部采樣，0?代表不進(jìn)行采用，?大于1則是設(shè)置納秒的采樣率
?runtime.SetBlockProfileRate(1)

這個采樣率是怎樣計(jì)算的，我們來看下具體代碼。

//?src/runtime/mprof.go:409
func?blocksampled(cycles,?rate?int64)?bool?{
?if?rate?<=?0?||?(rate?>?cycles?&&?int64(fastrand())%rate?>?cycles)?{
??return?false
?}
?return?true
}

cycles你可以把它理解成也是一個納秒級的事件，rate就是我們設(shè)置的納秒時間，如果 cycles大于等于rate則直接記錄block行為，如果cycles小于rate的話，則需要fastrand函數(shù)乘以設(shè)置的納秒時間rate 來決定是否采樣了。

然后回過頭來看看網(wǎng)頁的輸出信息

---?contention:
cycles/second=1000000000
180001216583?1?@?0x1002a1198?0x1005159b8?0x100299fc4
#?0x1002a1197?sync.(*Mutex).Lock+0xa7?/Users/lanpangzi/goproject/src/go/src/sync/mutex.go:81
#?0x1005159b7?main.main.func2+0x27?/Users/lanpangzi/goproject/src/go/main/main.go:33

contention 是為這個profile文本信息取的名字，總之中文翻譯是爭用。

cycles/second 是每秒鐘的周期數(shù)，用它來表示時間也是為了更精確，其實(shí)你可以發(fā)現(xiàn)在我的機(jī)器上每秒是10的9次方個周期，換算成納秒就是1ns一個周期時間了。

接著的180001216583 是阻塞的周期數(shù)，其實(shí)周期就是cputicks，那么180001216583除以 cycles/second 1000000000得到的就是阻塞的秒數(shù)了。

接著 1代表阻塞的次數(shù)。

無論是阻塞周期時長還是次數(shù)，都是一個累加值，即在相同的地方阻塞會導(dǎo)致這個值變大，并且次數(shù)會增加。剩下的部分就是函數(shù)堆棧信息了。

mutex

接著來看mutex相關(guān)內(nèi)容，block也在鎖阻塞時記錄阻塞行為，那么mutex與它有什么不同？

直接說下結(jié)論，mutex是在解鎖unlock時才會記錄一次阻塞行為，而block在記錄mutex鎖阻塞信息時，是在開始執(zhí)行l(wèi)ock調(diào)用的時候記錄的。

要想記錄mutex信息，和block類似，也需要開啟mutex采樣開關(guān)。

???//?0?代表不進(jìn)行采用，?1則全部采用，大于1則是一個隨機(jī)采用
????runtime.SetMutexProfileFraction(1)

來看看采樣的細(xì)節(jié)代碼，代碼版本go1.17.12

if?rate?>?0?&&?int64(fastrand())%rate?==?0?{
??saveblockevent(cycles,?rate,?skip+1,?mutexProfile)
?}

可以看到fastrand() 與rate取模等于0才會去采樣，rate如果設(shè)置成1，則任何數(shù)與整數(shù)與1取模都會得到0，所以設(shè)置為1為完全采用，大于1比如rate設(shè)置為2，則要求fastrand必須是2的倍數(shù)才能被采樣。

接著來看下網(wǎng)頁的輸出信息。

---?mutex:
cycles/second=1000000812
sampling?period=1
180001727833?1?@?0x100b9175c?0x100e05840?0x100b567ec?0x100b89fc4
#?0x100b9175b?sync.(*Mutex).Unlock+0x8b?/Users/lanpangzi/goproject/src/go/src/sync/mutex.go:190
#?0x100e0583f?main.main+0x19f???/Users/lanpangzi/goproject/src/go/main/main.go:39
#?0x100b567eb?runtime.main+0x25b??/Users/lanpangzi/goproject/src/go/src/runtime/proc.go:255

第一行mutex就是profile文本信息的名稱了，同樣也和block一樣，采用cpu周期數(shù)計(jì)時，但是多了一個sampling period ，這個就是我們設(shè)置的采用頻率。

接下來的數(shù)據(jù)都和block類似，180001727833就是鎖阻塞的周期， 1為解鎖的次數(shù)。然后是解鎖的堆棧信息。

介紹完利用http服務(wù)查看pprof性能指標(biāo)的方式來看看，如何用代碼來生成這些pprof的二進(jìn)制或者文本文件。

代碼生成profile文件的方式

首先來看看如何對內(nèi)存信息生成pprof文件。

os.Remove("heap.out")
?f,?_?:=?os.Create("heap.out")
?defer?f.Close()

?err?:=?pprof.Lookup("heap").WriteTo(f,?1)
?if?err?!=?nil?{
??log.Fatal(err)
?}

lookup 傳遞的heap參數(shù)也可以改成allocs，不過輸出的內(nèi)容是一致的。

WriteTo 第二個參數(shù)叫做debug，傳1代表 會生成可讀的文本文件，就和http服務(wù)看heap allocs的網(wǎng)頁一樣的。傳0代表是要生成一個二進(jìn)制文件。生成的二進(jìn)制文件可以用go tool pprof pprof文件名 去分析，關(guān)于go tool pprof 工具的使用網(wǎng)上有相當(dāng)多的資料，這里就不再展開了。

然后來看看如何生成block的pprof文件。

runtime.SetBlockProfileRate(1)
?os.Remove("block.out")
?f,?_?:=?os.Create("block.out")
?defer?f.Close()

?err?:=?pprof.Lookup("block").WriteTo(f,?1)
?if?err?!=?nil?{
??log.Fatal(err)
?}

pprof.Lookup方法傳遞block即可生成文件了，使用方式和生成內(nèi)存分析文件一致，，傳1代表 會生成可讀的文本文件，就和http服務(wù)看block的網(wǎng)頁一樣的。傳0代表是要生成一個二進(jìn)制文件。生成的二進(jìn)制文件可以用go tool pprof pprof文件名 去分析。

最后看看mutex，和前面兩者基本一致僅僅是Lookup傳遞的參數(shù)有變化，這里就不再敘述了。

?runtime.SetMutexProfileFraction(1)
?os.Remove("mutex.out")
?f,?_?:=?os.Create("mutex.out")
?defer?f.Close()

?err?:=?pprof.Lookup("mutex").WriteTo(f,?1)
?if?err?!=?nil?{
??log.Fatal(err)
?}

總結(jié)

經(jīng)過上述的講解，應(yīng)該是能夠明白相關(guān)的指標(biāo)究竟是采集了哪些內(nèi)容并且何時采集的了，而go tool pprof 工具的使用不是此文的重點(diǎn)，所以我直接省略掉了，也是沒想到即使省略了，還是內(nèi)容有那么多，那就把這部分的統(tǒng)計(jì)原理留到下一篇文章了，下一篇，memory，block，mutex  統(tǒng)計(jì)的原理介紹。

以上就是golang pprof監(jiān)控memory block mutex使用指南的詳細(xì)內(nèi)容，更多關(guān)于golang pprof監(jiān)控的資料請關(guān)注腳本之家其它相關(guān)文章！

最新評論