trace view 視圖簡介

在go代碼里，我們可以通過trace.Start和trace.Stop方法開啟和關(guān)閉trace統(tǒng)計(jì)，之后我們會(huì)得到一個(gè)trace文件，可以用go tool trace命令打開它·。

go tool trace -http=:8080  trace799152559

在瀏覽器的打開界面，可以看到trace view視圖包含了幾個(gè)維度的統(tǒng)計(jì)信息。

view trace 和 goroutine analysis 都是時(shí)間線的視圖，不過觀看的角度不同，view trace 是從processor(Gpm模型中的p) 角度，goroutine analysis 則是從協(xié)程角度。

接著是各種類型的profile 視圖，包含Network,Sync block,syscall block,scheduler latancy ，這些都可以用于分析系統(tǒng)延遲。

然后是用戶自定義的埋點(diǎn)統(tǒng)計(jì)，由于本節(jié)主要是看原生的trace view視圖含義，所以可以先略去這部分。

接著是minimum mutator utilization的視圖，它可以用于分析垃圾回收對應(yīng)用程序的影響。因?yàn)閰f(xié)程在分配內(nèi)存時(shí)，在某些條件下也會(huì)觸發(fā)垃圾回收，這將導(dǎo)致這部分時(shí)間內(nèi)，協(xié)程不能執(zhí)行用戶程序邏輯，所以這個(gè)視圖能夠看到cpu用了多少時(shí)間在執(zhí)行業(yè)務(wù)程序，多少時(shí)間用于垃圾回收。

接下來，我們仔細(xì)分析下各部分視圖的含義。

view trace

如上圖所示，整個(gè)view trace 分為兩個(gè)部分，stats和procs部分。

stats

stats 部分統(tǒng)計(jì)了在時(shí)間線上協(xié)程，線程數(shù)量，以及堆棧大小的變化情況。

當(dāng)點(diǎn)擊某個(gè)一欄數(shù)據(jù)時(shí)，還會(huì)顯示統(tǒng)計(jì)詳情，比如點(diǎn)擊時(shí)間線上線程這一欄，

如上圖所示，trace view視圖最下方會(huì)出現(xiàn)當(dāng)前時(shí)刻，處于運(yùn)行狀態(tài)和系統(tǒng)調(diào)用狀態(tài)的線程數(shù)量。

procs

stats部分比較好理解，我們再來看看procs部分，首先來看下GC這一欄。

GC這一欄也就是視圖中時(shí)間線上藍(lán)色這一段表示程序在這段時(shí)間內(nèi)，在進(jìn)行垃圾回收。注意垃圾回收并不是全過程都會(huì)STW的，所以在GC這段時(shí)間，應(yīng)用程序還是會(huì)對外提供服務(wù)的。并且點(diǎn)擊藍(lán)色區(qū)域，在視圖下方還會(huì)顯示GC開始的堆棧。

注意: golang的垃圾回收除了定時(shí)掃描回收內(nèi)存，還會(huì)在分配內(nèi)存時(shí)，判斷正在執(zhí)行的協(xié)程是否需要執(zhí)行垃圾回收邏輯，如果需要，則會(huì)執(zhí)行g(shù)cStart的邏輯，mallocgc就是golang進(jìn)行內(nèi)存分配的函數(shù)，所以你可以看到圖中的gc正是由于當(dāng)前協(xié)程分配內(nèi)存才觸發(fā)執(zhí)行的，并且同一時(shí)期，只能有一個(gè)協(xié)程執(zhí)行g(shù)cStart邏輯。

接著簡單說下Network和syscall 事件，它們在時(shí)間線上的點(diǎn)都是解除阻塞時(shí)的時(shí)間點(diǎn)。

然后來看proc這一欄，proc代表的是processor ，它數(shù)量一般與cpu核心數(shù)相同，也可以通過GOMAXPROCS 設(shè)置其數(shù)量，協(xié)程需要放到proc隊(duì)里里進(jìn)行調(diào)度執(zhí)行，proc的時(shí)間線上顯示的則是各個(gè)協(xié)程在其上的運(yùn)行時(shí)間。放大trace視圖后會(huì)看的更加明顯。如下圖所示:

trace視圖中，按w是放大，s是縮小，a是左移，d是右移。

這里其實(shí)要特別注意的是Outgoing flow 并不是直接導(dǎo)致協(xié)程在p隊(duì)列上被切走的事件，實(shí)際上導(dǎo)致協(xié)程被切走的事件是阻塞事件，Outgoing flow 指的是阻塞事件之后被喚醒的那個(gè)時(shí)候的事件埋點(diǎn)。

實(shí)際上，當(dāng)前的trace view 視圖繪制的時(shí)間線不會(huì)對阻塞事件進(jìn)行繪制，只會(huì)對EvGoUnblock 事件進(jìn)行繪制（具體為啥這樣設(shè)計(jì)，我也不知道了????‍♀?）不過從協(xié)程離開p隊(duì)列時(shí)的堆棧也足夠說明協(xié)程被切走的原因了。

goroutine analysis

接著我們來看下trace文件中對協(xié)程信息的分析。

點(diǎn)擊goroutine analysis，出現(xiàn)下面的截圖:

左邊是協(xié)程創(chuàng)建時(shí)候的堆棧，右邊N 代碼在這行代碼上一共創(chuàng)建了多少個(gè)協(xié)程。隨便選擇一行點(diǎn)進(jìn)去，可以出現(xiàn)下面的截圖,

如上圖所示，有各種的profile graph，這里是對下面所有協(xié)程進(jìn)行統(tǒng)一分析得到的graph圖 ，分別是:

Network Wait Time(網(wǎng)絡(luò)調(diào)用時(shí)等待，直到數(shù)據(jù)可達(dá)時(shí)被喚醒)

Sync Block Time(mutex，channel，wait.Group產(chǎn)生的阻塞)

Blocking Syscall Time(系統(tǒng)調(diào)用產(chǎn)生的阻塞)

Scheduler Wait Time(協(xié)程阻塞后被喚醒并不會(huì)立馬執(zhí)行，而是在隊(duì)列里等待被調(diào)度，這個(gè)時(shí)間就是等待被調(diào)度的時(shí)間)

而最下面的表格則是每個(gè)協(xié)程在這些維度上的消耗時(shí)間,這里要注意下兩個(gè)gc相關(guān)的時(shí)間只有GC sweeping 才會(huì)阻塞協(xié)程 ，GC sweeping指的是協(xié)程在清除回收內(nèi)存時(shí)的處理時(shí)間，而GC pause 指的是采樣過程中整個(gè)gc的時(shí)長，這一列每個(gè)協(xié)程都是一樣的。

請注意，GC 過程中只有發(fā)送STW時(shí)才會(huì)讓協(xié)程阻塞。

profile graph

關(guān)于trcace 分析數(shù)據(jù) 除了像剛剛的特定堆棧產(chǎn)生的協(xié)程做各種延遲維度的分析，trace界面還提供了一個(gè)看所有協(xié)程的延遲維度的profile graph, 兩者的原理都是一致的，只是后者原數(shù)據(jù)多一些。

拿其中一個(gè)維度Scheduler Wait Time的 graph舉例:

指向每個(gè)函數(shù)框的箭頭都攜帶了一個(gè)時(shí)間，例如 273.31us，它代表 函數(shù)servserv.init.func1函數(shù)等待協(xié)程調(diào)度的等待時(shí)間，注意這個(gè)時(shí)間不包含它的子函數(shù)的時(shí)間。時(shí)間越大，函數(shù)框越大，所以，你在看此類的圖的時(shí)候，找最大的框就能發(fā)現(xiàn)延遲所在。

Minimum mutator utilization

最后我們來看下Minimum mutator utilization 這個(gè)視圖。這個(gè)視圖能夠觀測到垃圾回收對應(yīng)用程序的影響。

如上圖所示，縱坐標(biāo)表示應(yīng)用除gc外，占用cpu的比例。值越高，說明應(yīng)用得到的cpu資源越多，gc影響越小，最大值是1表示100%得到cpu資源。圖中，最后應(yīng)用cpu占用率達(dá)到了100%，可以暫時(shí)不用去管gc方面的影響。如果發(fā)現(xiàn)圖中cpu資源長時(shí)間不能漲上去，則說明程序受gc影響比較大，應(yīng)該對gc進(jìn)行優(yōu)化，像下面這種情況就應(yīng)該優(yōu)化gc了。

以上就是golang trace view視圖詳解的詳細(xì)內(nèi)容，更多關(guān)于golang trace view的資料請關(guān)注腳本之家其它相關(guān)文章！

最新評論