Golang?pprof監(jiān)控之cpu占用率統(tǒng)計(jì)原理詳解
經(jīng)過前面的幾節(jié)對(duì)pprof的介紹,對(duì)pprof統(tǒng)計(jì)的原理算是掌握了七八十了,我們對(duì)memory,block,mutex,trace,goroutine,threadcreate這些維度的統(tǒng)計(jì)原理都進(jìn)行了分析,但唯獨(dú)還沒有分析pprof 工具是如何統(tǒng)計(jì)cpu使用情況的,今天我們來分析下這部分。
http 接口暴露的方式
還記得 golang pprof監(jiān)控系列(2) —— memory,block,mutex 使用 里我們啟動(dòng)了一個(gè)http服務(wù)來暴露各種性能指標(biāo)信息。讓我們?cè)倩氐疆?dāng)時(shí)啟動(dòng)http服務(wù)看到的網(wǎng)頁圖。
當(dāng)點(diǎn)擊上圖中profile鏈接時(shí),便會(huì)下載一個(gè)關(guān)于cpu指標(biāo)信息的二進(jìn)制文件。這個(gè)二進(jìn)制文件同樣可以用go tool pprof 工具去分析,同樣,關(guān)于go tool pprof的使用不是本文的重點(diǎn),網(wǎng)上的資料也相當(dāng)多,所以我略去了這部分。
緊接著,我們來快速看下如何用程序代碼的方式生成cpu的profile文件。
程序代碼生成profile
os.Remove("cpu.out") f, _ := os.Create("cpu.out") defer f.Close() pprof.StartCPUProfile(f) defer pprof.StopCPUProfile() // .... do other things
代碼比較簡(jiǎn)單,pprof.StartCPUProfile 則開始統(tǒng)計(jì) cpu使用情況,pprof.StopCPUProfile則停止統(tǒng)計(jì)cpu使用情況,將程序使用cpu的情況寫入cpu.out文件。cpu.out文件我們則可以用go tool pprof去分析了。
好的,在快速的看完如何在程序中暴露cpu性能指標(biāo)后,我們來看看golang是如何統(tǒng)計(jì)各個(gè)函數(shù)cpu使用情況的。接下來,正戲開始。
cpu 統(tǒng)計(jì)原理分析
首先要明白,我們究竟要統(tǒng)計(jì)的是什么內(nèi)容?我們需要知道cpu的使用情況,換言之就是cpu的工作時(shí)間花在了哪些函數(shù)上,最后是不是就是看函數(shù)在cpu上的工作時(shí)長(zhǎng)。
那么函數(shù)的在cpu上工作時(shí)長(zhǎng)應(yīng)該如何去進(jìn)行統(tǒng)計(jì)?
golang還是采用部分采樣的方式,通過settimmer 系統(tǒng)調(diào)用設(shè)置了 發(fā)送SIGPROF 的定時(shí)器,當(dāng)達(dá)到runtime.SetCPUProfileRate設(shè)置的周期間隔時(shí),操作系統(tǒng)就會(huì)向進(jìn)程發(fā)送SIGPROF 信號(hào),默認(rèn)情況下是100Mz(10毫秒)。
一旦設(shè)置了 發(fā)送SIGPROF信號(hào)的定時(shí)器,操作系統(tǒng)便會(huì)定期向進(jìn)程發(fā)送SIGPROF信號(hào)。
設(shè)置定時(shí)器的代碼便是在我們調(diào)用pprof.StartCPUProfile方法開啟cpu信息采樣的時(shí)候。代碼如下,
// src/runtime/pprof/pprof.go:760 func StartCPUProfile(w io.Writer) error { const hz = 100 cpu.Lock() defer cpu.Unlock() if cpu.done == nil { cpu.done = make(chan bool) } // Double-check. if cpu.profiling { return fmt.Errorf("cpu profiling already in use") } cpu.profiling = true runtime.SetCPUProfileRate(hz) go profileWriter(w) return nil }
在倒數(shù)第三行的時(shí)候調(diào)用了設(shè)置采樣的周期,并且緊接著profileWriter 就是用一個(gè)協(xié)程啟動(dòng)后去不斷的讀取cpu的采樣數(shù)據(jù)寫到文件里。而調(diào)用settimer的地方就是在runtime.SetCPUProfileRate里,runtime.SetCPUProfileRate最終會(huì)調(diào)用 setcpuprofilerate方法 ,setcpuprofilerate 又會(huì)去調(diào)用setProcessCPUProfiler方法設(shè)置settimer 定時(shí)器。
// src/runtime/signal_unix.go:269 func setProcessCPUProfiler(hz int32) { ..... var it itimerval it.it_interval.tv_sec = 0 it.it_interval.set_usec(1000000 / hz) it.it_value = it.it_interval setitimer(_ITIMER_PROF, &it, nil) ....
經(jīng)過上述步驟后,cpu的采樣就真正開始了,之后就是定時(shí)器被觸發(fā)送SIGPROF信號(hào),進(jìn)程接收到這個(gè)信號(hào)后,會(huì)對(duì)當(dāng)前函數(shù)的調(diào)用堆棧進(jìn)行記錄,由于默認(rèn)的采樣周期設(shè)置的是100Mz,所以,你可以理解為每10ms,golang就會(huì)統(tǒng)計(jì)下當(dāng)前正在運(yùn)行的是哪個(gè)函數(shù),在采樣的這段時(shí)間內(nèi),哪個(gè)函數(shù)被統(tǒng)計(jì)的次數(shù)越多,是不是就能說明這個(gè)函數(shù)在這段時(shí)間內(nèi)占用cpu的工作時(shí)長(zhǎng)就越多了。
由于golang借助了linux的信號(hào)機(jī)制去進(jìn)行cpu執(zhí)行函數(shù)的采樣,這里有必要額外介紹下linux 進(jìn)程與信號(hào)相關(guān)的知識(shí)。首先來看下線程處理信號(hào)的時(shí)機(jī)在什么時(shí)候。
線程處理信號(hào)的時(shí)機(jī)
線程對(duì)信號(hào)的處理時(shí)機(jī)一般 是在由內(nèi)核態(tài)返回到用戶態(tài)之前,也就是說,當(dāng)線程由于系統(tǒng)調(diào)用或者中斷進(jìn)入內(nèi)核態(tài)后, 當(dāng)系統(tǒng)調(diào)用結(jié)束或者中斷處理完成后,在返回到用戶態(tài)之前,操作系統(tǒng)會(huì)檢查這個(gè)線程是不是有未處理的信號(hào),如果有的話,那么會(huì)先切回到用戶態(tài)讓 線程會(huì)首先處理信號(hào),信號(hào)處理完畢后 又返回內(nèi)核態(tài),內(nèi)核此時(shí)才會(huì)將調(diào)用棧設(shè)置為中斷或者系統(tǒng)調(diào)用時(shí) 用戶進(jìn)程中斷的地方 ,然后切換到用戶態(tài)后就繼續(xù)在用戶進(jìn)程之前中斷的地方繼續(xù)執(zhí)行程序邏輯了。由于進(jìn)程幾乎每時(shí)每刻都在進(jìn)行諸如系統(tǒng)調(diào)用的工作,可以認(rèn)為,信號(hào)的處理是幾乎實(shí)時(shí)的。 如下是線程內(nèi)核態(tài)與用戶態(tài)切換的過程,正式信號(hào)處理檢查的地方。整個(gè)過程可以用下面的示意圖表示。
知道了信號(hào)是如何被線程處理的,還需要了解下,內(nèi)核會(huì)如何發(fā)送信號(hào)給進(jìn)程。
內(nèi)核發(fā)送信號(hào)的方式
內(nèi)核向進(jìn)程發(fā)信號(hào)的方式是對(duì)進(jìn)程中的一個(gè)線程發(fā)送信號(hào),而通過settimmer 系統(tǒng)調(diào)用設(shè)置定時(shí)器 發(fā)送SIGPROF 信號(hào)的方式就是隨機(jī)的對(duì)進(jìn)程中的一個(gè)運(yùn)行中線程去進(jìn)行發(fā)送。而運(yùn)行中線程接收到這個(gè)信號(hào)后,就調(diào)用自身的處理函數(shù)對(duì)這個(gè)信號(hào)去進(jìn)行處理,對(duì)于SIGPROF 信號(hào)而言,則是將線程中斷前的函數(shù)棧記錄下來,用于后續(xù)分析函數(shù)占用cpu的工作時(shí)長(zhǎng)。
由于只是隨機(jī)的向一個(gè)運(yùn)行中的線程發(fā)送SIGPROF 信號(hào),這里涉及到了兩個(gè)問題?
第一因?yàn)橥粋€(gè)進(jìn)程中只有一個(gè)線程在進(jìn)行采樣,所以在隨機(jī)選擇運(yùn)行線程發(fā)送SIGPROF信號(hào)時(shí),要求選擇線程時(shí)的公平性,不然可能會(huì)出現(xiàn)A,B兩個(gè)線程,A線程接收到SIGPROF信號(hào)的次數(shù)遠(yuǎn)遠(yuǎn)大于B 線程接收SIGPROF信號(hào)的次數(shù),這樣對(duì)A線程進(jìn)行采樣的次數(shù)將會(huì)變多,影響了我們采樣的結(jié)果。
而golang用settimmer 設(shè)置定時(shí)器發(fā)送SIGPROF 信號(hào) 的方式的確被證實(shí)在linux上存在線程選擇公平性問題(但是mac os上沒有這個(gè)問題) 關(guān)于這個(gè)問題的討論在github上有記錄,這是鏈接 這個(gè)問題已經(jīng)在go1.18上得到了解決,解決方式我會(huì)在下面給出,我們先來看隨機(jī)的向一個(gè)運(yùn)行中的線程發(fā)送SIGPROF 信號(hào) 引發(fā)的第二個(gè)問題。
第二 因?yàn)槭窍蛞粋€(gè)運(yùn)行中的線程去發(fā)送信號(hào),所以我們只能統(tǒng)計(jì)到采樣時(shí)間段內(nèi)在cpu上運(yùn)行的函數(shù),而那些io阻塞的函數(shù)將不能被統(tǒng)計(jì)到,關(guān)于這點(diǎn)業(yè)內(nèi)已經(jīng)有開源庫幫助解決,https://github.com/felixge/fgprof,不過由于這個(gè)庫進(jìn)行采樣時(shí)會(huì)stop the world ,所以其作者強(qiáng)烈建議如果go協(xié)程數(shù)量比較多時(shí),將go版本升級(jí)到1.19再使用。后續(xù)有機(jī)會(huì)再來探討這個(gè)庫的實(shí)現(xiàn)吧,我們先回到如何解決settimer函數(shù)在選擇線程的公平性問題上。
采樣數(shù)據(jù)的公平性
為了解決公平性問題,golang在settimer的系統(tǒng)調(diào)用的基礎(chǔ)上增加了timer_create系統(tǒng)調(diào)用timer_create 可以單獨(dú)的為每一個(gè)線程都創(chuàng)建定時(shí)器,這樣每個(gè)運(yùn)行線程都會(huì)采樣到自己的函數(shù)堆棧了。所以在go1.18版本對(duì)pprof.StartCPUProfile內(nèi)部創(chuàng)建定時(shí)器的代碼進(jìn)行了改造。剛才有提到pprof.StartCPUProfile 底層其實(shí)是調(diào)用setcpuprofilerate 這個(gè)方法去設(shè)置的定時(shí)器,所以我們來看看go1.18和go1.17版本在這個(gè)方法的實(shí)現(xiàn)上主要是哪里不同。
// go1.17 版本 src/runtime/proc.go:4563 func setcpuprofilerate(hz int32) { if hz < 0 { hz = 0 } _g_ := getg() _g_.m.locks++ setThreadCPUProfiler(0) for !atomic.Cas(&prof.signalLock, 0, 1) { osyield() } if prof.hz != hz { // 設(shè)置進(jìn)程維度的 SIGPROF 信號(hào)發(fā)送器 setProcessCPUProfiler(hz) prof.hz = hz } atomic.Store(&prof.signalLock, 0) lock(&sched.lock) sched.profilehz = hz unlock(&sched.lock) if hz != 0 { // 設(shè)置線程維度的SIGPROF 信號(hào)定時(shí)器 setThreadCPUProfiler(hz) } _g_.m.locks-- }
上述是go1.17版本的setcpuprofilerate 代碼,如果你再去看 go1.18版本的代碼,會(huì)發(fā)現(xiàn)他們?cè)谶@個(gè)方法上是一模一樣的,都是調(diào)用了setProcessCPUProfiler 和setThreadCPUProfiler,setProcessCPUProfiler 設(shè)置進(jìn)程維度的發(fā)送SIGPROF信號(hào)定時(shí)器,setThreadCPUProfiler設(shè)置線程維度的發(fā)送SIGPROF信號(hào)的定時(shí)器,但其實(shí)setThreadCPUProfiler 在go1.17的實(shí)現(xiàn)上并不完整。
// go 1.17 src/runtime/signal_unix.go:314 func setThreadCPUProfiler(hz int32) { getg().m.profilehz = hz }
go1.17版本上僅僅是為協(xié)程里代表線程的m變量設(shè)置了一個(gè)profilehz(采樣的頻率),并沒有真正實(shí)現(xiàn)線程維度的采樣。
// go 1.18 src/runtime/os_linux.go:605 .... // setThreadCPUProfiler 方法內(nèi)部 timer_create的代碼段 var timerid int32 var sevp sigevent sevp.notify = _SIGEV_THREAD_ID sevp.signo = _SIGPROF sevp.sigev_notify_thread_id = int32(mp.procid) ret := timer_create(_CLOCK_THREAD_CPUTIME_ID, &sevp, &timerid) if ret != 0 { return } ....
在go1.18版本上的setThreadCPUProfiler則真正實(shí)現(xiàn)了這部分邏輯,由于go1.18版本它同時(shí)調(diào)用了setProcessCPUProfiler以及setThreadCPUProfiler,這樣在接收SIGPROF信號(hào)時(shí)就會(huì)出現(xiàn)重復(fù)計(jì)數(shù)的問題。
所以go1.18在處理SIGPROF信號(hào)的時(shí)候也做了去重處理,所以在golang信號(hào)處理的方法sighandler 內(nèi)部有這樣一段邏輯。
func sighandler(sig uint32, info *siginfo, ctxt unsafe.Pointer, gp *g) { _g_ := getg() c := &sigctxt{info, ctxt} if sig == _SIGPROF { mp := _g_.m // Some platforms (Linux) have per-thread timers, which we use in // combination with the process-wide timer. Avoid double-counting. if validSIGPROF(mp, c) { sigprof(c.sigpc(), c.sigsp(), c.siglr(), gp, mp) } return } .....
如果發(fā)現(xiàn)信號(hào)是_SIGPROF 那么會(huì)通過validSIGPROF 去檢測(cè)此次的_SIGPROF信號(hào)是否應(yīng)該被統(tǒng)計(jì)。validSIGPROF的檢測(cè)邏輯這里就不展開了。
總結(jié)
cpu的統(tǒng)計(jì)原理與前面所講的指標(biāo)統(tǒng)計(jì)的原理稍微復(fù)雜點(diǎn),涉及到了linux信號(hào)處理相關(guān)的內(nèi)容,cpu統(tǒng)計(jì)的原理,簡(jiǎn)而言之,就是通過設(shè)置一個(gè)發(fā)送SIGPROF信號(hào)的定時(shí)器,然后用戶程序通過接收操作系統(tǒng)定時(shí)發(fā)送的SIGPROF信號(hào)來對(duì)用戶程序正在執(zhí)行的堆棧函數(shù)進(jìn)行統(tǒng)計(jì)。在采樣時(shí)間內(nèi),同一個(gè)函數(shù)被統(tǒng)計(jì)的越多,說明該函數(shù)占用的cpu工作時(shí)長(zhǎng)就越長(zhǎng)。
到此這篇關(guān)于Golang pprof監(jiān)控之cpu占用率統(tǒng)計(jì)原理詳解的文章就介紹到這了,更多相關(guān)Golang pprof cpu占用率統(tǒng)計(jì)內(nèi)容請(qǐng)搜索腳本之家以前的文章或繼續(xù)瀏覽下面的相關(guān)文章希望大家以后多多支持腳本之家!
相關(guān)文章
Go語言Gin框架前后端分離項(xiàng)目開發(fā)實(shí)例
本文主要介紹了Go語言Gin框架前后端分離項(xiàng)目開發(fā)工程化實(shí)例,文中通過示例代碼介紹的非常詳細(xì),對(duì)大家的學(xué)習(xí)或者工作具有一定的參考學(xué)習(xí)價(jià)值,需要的朋友們下面隨著小編來一起學(xué)習(xí)學(xué)習(xí)吧2023-11-11golang?xorm?自定義日志記錄器之使用zap實(shí)現(xiàn)日志輸出、切割日志(最新)
這篇文章主要介紹了golang?xorm?自定義日志記錄器,使用zap實(shí)現(xiàn)日志輸出、切割日志,包括連接postgresql數(shù)據(jù)庫的操作方法及?zap日志工具?,本文結(jié)合實(shí)例代碼給大家介紹的非常詳細(xì),對(duì)大家的學(xué)習(xí)或工作具有一定的參考借鑒價(jià)值,需要的朋友可以參考下2022-10-10Go語言學(xué)習(xí)之操作MYSQL實(shí)現(xiàn)CRUD
Go官方提供了database包,database包下有sql/driver。該包用來定義操作數(shù)據(jù)庫的接口,這保證了無論使用哪種數(shù)據(jù)庫,操作方式都是相同的。本文就來和大家聊聊Go語言如何操作MYSQL實(shí)現(xiàn)CRUD,希望對(duì)大家有所幫助2023-02-02詳解Golang互斥鎖內(nèi)部實(shí)現(xiàn)
本篇文章主要介紹了詳解Golang互斥鎖內(nèi)部實(shí)現(xiàn),小編覺得挺不錯(cuò)的,現(xiàn)在分享給大家,也給大家做個(gè)參考。一起跟隨小編過來看看吧2017-06-06Go語言學(xué)習(xí)之golang-jwt/jwt的教程分享
jwt是?json?web?token的簡(jiǎn)稱。go使用jwt目前,主流使用的jwt庫是golang-jwt/jwt。本文就來和大家講講golang-jwt/jwt的具體使用,需要的可以參考一下2023-01-01Golang定時(shí)器的2種實(shí)現(xiàn)方法與區(qū)別
這篇文章主要給大家介紹了關(guān)于Golang定時(shí)器的2種實(shí)現(xiàn)方法與區(qū)別的相關(guān)資料,文中通過圖文介紹的非常詳細(xì),對(duì)大家的學(xué)習(xí)或者工作具有一定的參考學(xué)習(xí)價(jià)值,需要的朋友們下面隨著小編來一起學(xué)習(xí)學(xué)習(xí)吧2021-02-02