通過實例理解 Go Execution Tracer

本文永久鏈接 [1] - https://tonybai.com/2021/06/28/understand-go-execution-tracer-by-example

Netflix(奈飛公司)的性能架構師 Brendan Gregg[2] 在其《BPF Performance Tools》[3] 一書中對 tracing、sampling 等概念做了細緻描述,以幫助開發人員理解這些概念,並基於這些概念對性能優化輔助工具進行分類,明確它們的適用場合。這裏引用部分內容如下:

採樣工具(Sampling tools)採用一個測量的子集來描繪目標的粗略情況;這也被稱爲創建一個 profile 或 profiling(剖析)。profiling 工具對運行中的代碼採用基於定時器的採樣。其缺點是,採樣只能提供一個關於目標的粗略的圖像,並且可能會遺漏事件。

追蹤(tracing)是基於事件的記錄,一旦開啓跟蹤,跟蹤工具便能夠記錄所有原始事件和事件元數據。

在 Go 工具鏈中,go tool pprof[4](與 runtime/pprof 或 net/http/pprof 聯合使用)便是一個基於採樣(sampling)的性能剖析 (profiing) 輔助工具。它基於定時器對運行的 go 程序進行各種採樣,包括諸如 CPU 時間、內存分配等方面。但 go pprof 也具有上面所說的基於採樣的工具的不足,那就是採樣的頻度不足導致的精確性問題,在 Go 運行時內部,CPU 分析使用操作系統計時器來定期(每秒約 100 次,即 10ms 一次)中斷執行。在每個中斷(也稱爲樣本)上,它同時收集當時的調用堆棧。當爲了實現更高頻度採樣時(比如微秒級別的採樣),目前的 go profile 無法支持(爲此 uber 工程師提了一個名爲 pprof++ 的高精度、更精確並支持硬件監控的提案 [5])。

Go 語言同樣也提供了基於追蹤(tracing)策略的工具,一旦開啓 trace,Go 應用中發生的所有特定事件(event)便會被記錄下來,並支持將其保存在文件中以備後續分析,這個工具由谷歌工程師 Dmitry Vyukov[6] 提出設計方案 [7] 並實現,並在 Go 1.5 版本 [8] 發佈時加入 Go 工具鏈 [9],這個工具被稱爲 Go Execution Tracer,中文直譯就是 Go 執行跟蹤器

相對於 go pprof,Go Execution Tracer 的使用相對少一些,但在特定場景下,Go Execution Tracer 能發揮出巨大作用,能幫助 gopher 找出 go 應用中隱藏較深的疑難雜症。在這篇文章中,我們就來系統地瞭解一下 Go Execution Tracer(以下簡稱爲 Tracer)。

1. Go Execution Tracer 究竟能做什麼?

我們日常使用最多的 go 性能剖析工具是 pprof(go tool pprof),通過定時採樣並結合 Go 標準庫中的 runtime/pprof 或 net/http/pprof 包,pprof 可以幫助我們挖掘出被剖析目標中的 “熱點”,比如:哪些行代碼消耗 CPU 較多、哪些行代碼分配內存較多、哪些代碼被阻塞的時間較長等。但是有些時候這些基於定時器採樣的數據還不夠,我們還需要更多關於 Go 應用中各個 goroutine 的執行情況的更爲詳細的信息。在 Dmitry Vyukov 最初的設計中,他希望 Tracer 能爲 Go 開發者提供至少如下的關於 goroutine 執行情況的信息:

有了這些事件信息,我們可以從 P(goroutine 調度器 [10] 概念中的 processor) 和 G(goroutine 調度器概念中的 goroutine)的視角完整的看到每個 P 和每個 G 在 Tracer 開啓期間的全部 “所作所爲”。而開發人員正是通過對 Tracer 輸出數據中的每個 P 和 G 的行爲分析並結合詳細的 event 數據來輔助問題診斷的

圖 3:通過 go tool trace 以圖形化形式查看 P 和 G 的行爲和事件

另外與 pprof 基於系統定時器支持 10ms 頻度的採樣不同,Tracer 爲每個 event 打的時間戳都精確到納秒(nanosecond)級精度,在查看 Tracer 數據時,我們可以通過縮放的方式查看不同時間精度下各個 P 和 G 呈現的特徵,並可以在納秒精度上查看發生事件的詳細信息。

前面說過,Tracer 是基於事件而不是定時採樣的,因此與定時採樣相比,Tracer 開啓帶來的開銷是很大的,是肉眼感覺得到的那種影響(輸出到文件中的數據體量也要比 pprof 的採樣數據文件多出很多)。在最初設計稿中,Dmitry Vyukov 給出的估計是性能下降 35%,但實際上可能要比這略好一些,但我們一般也不會在生產環境持續開啓 Tracer。

大致瞭解 Tracer 的運行原理與輔助診斷機制,那麼 Tracer 究竟適合診斷哪些問題呢?Tracer 作者 Dmitry Vyukov 在 Tracer 設計文檔中提到了三點,在實際應用中,Tracer 主要也是用於輔助診斷這三個場景下的具體問題的:

Go Tracer 從 Go 1.5 版本加入 Go 工具鏈,之後演化不大,這裏簡單梳理一下 Go 1.5 到 Go 1.16 版本 Go Tracer 的演化歷程:

$go tool trace -pprof=TYPE trace.out > TYPE.pprof

同時,在 trace 查看視圖中,GC 事件展示更爲清晰,GC 活動在其自己的單獨的行上顯示,並且輔助 GC 的 goroutine 也會被標記上其在 GC 過程中的角色。

2. 爲 Go 應用添加 Tracer

Go 爲在 Go 應用中添加 Tracer 提供了三種方法 [18],我們逐一看一下。

1) 手工通過 runtime/trace 包在 Go 應用中開啓和關閉 Tracer

無論使用哪一種方法,runtime/trace 包都是基礎與核心。我們可以直接使用 runtime/trace 包提供的 API 在 Go 應用中手工開啓和關閉 Tracer:

package main

  import (
    "os"
    "runtime/trace"
)

func main() {
    trace.Start(os.Stdout)
    defer trace.Stop()
    // 下面是業務代碼
    ... ...
}

上面代碼中,我們通過 trace.Start 開啓 Tracer,並在程序結束時通過 trace.Stop 停止 Tracer,Tracer 收集到的數據輸出到 os.Stdout(標準輸出)上,我們可以將其重定向到一個文件中保存,我們亦可以向 trace.Start 傳入一個文件的句柄,讓 Tracer 將數據直接寫到文件中,就像下面這樣:

func main() {
    f, _ := os.Create("trace.out")
    defer f.Close()
    trace.Start(f)
    defer trace.Stop()
    // 下面是業務代碼
    ... ...
}

從代碼來看,Tracer 是支持動態開啓的,但要注意的是每次開啓都要對應一個獨立的文件。如果多次開啓後將數據(續)寫入同一文件,那麼 go tool trace 在讀取該文件時會報類似如下錯誤:

$go tool trace trace.out
2021/06/23 05:50:01 Parsing trace...
failed to parse trace: unknown event type 50 at offset 0x73c

2) 通過 net/http/pprof 提供基於 http 進行數據傳輸的 Tracer 服務

如果一個 Go 應用通過 net/http/pprof 包提供對 pprof 採樣的支持,那麼我們就可以像獲取 cpu 或 heap profile 數據那樣,通過 / debug/pprof/trace 端點來開啓 Tracer 並獲取 Tracer 數據:

$wget -O trace.out http://localhost:6060/debug/pprof/trace?seconds=5

net/http/pprof 包中的 Trace 函數 [19] 負責處理發向 / debug/pprof/trace 端點的 http 請求,見下面代碼:

// $GOROOT/src/net/http/pprof/pprof.go

func Trace(w http.ResponseWriter, r *http.Request) {
    w.Header().Set("X-Content-Type-Options""nosniff")
    sec, err := strconv.ParseFloat(r.FormValue("seconds"), 64)
    if sec <= 0 || err != nil {
        sec = 1
    }

        if durationExceedsWriteTimeout(r, sec) {
        serveError(w, http.StatusBadRequest, "profile duration exceeds server's WriteTimeout")
        return
    }

        // Set Content Type assuming trace.Start will work,
    // because if it does it starts writing.
    w.Header().Set("Content-Type""application/octet-stream")
    w.Header().Set("Content-Disposition"`attachment; file`)
    if err := trace.Start(w); err != nil {
        // trace.Start failed, so no writes yet.
        serveError(w, http.StatusInternalServerError,
            fmt.Sprintf("Could not enable tracing: %s", err))
        return
    }
    sleep(r, time.Duration(sec*float64(time.Second)))
    trace.Stop()
}

我們看到在該處理函數中,函數開啓了 Tracer:trace.Start,並直接將 w 作爲 io.Writer 的實現者傳給了 trace.Start 函數,接下來 Tracer 採集的數據便會源源不斷地通過 http 應答發回客戶端,處理完後,Trace 函數關閉了 Tracer。

我們看到通過這種方式實現的動態開關 Tracer 是相對理想的一種方式,生產環境可以採用這種方式,這樣可以將 Tracer 帶來的開銷限制在最小範圍。

3) 通過 go test -trace 獲取 Tracer 數據

如果要在測試執行時開啓 Tracer,我們可以通過 go test -trace 來實現:

$go test -trace trace.out ./...

命令執行結束後,trace.out 中便存儲了測試執行過程中的 Tracer 數據,後續我們可以用 go tool trace 對其進行展示和分析。

3. Tracer 數據分析

有了 Tracer 輸出的數據後,我們接下來便可以使用 go tool trace 工具對存儲 Tracer 數據的文件進行分析了:

$go tool trace trace.out

go tool trace 會解析並驗證 Tracer 輸出的數據文件,如果數據無誤,它接下來會在默認瀏覽器中建立新的頁面並加載和渲染這些數據,如下圖所示:

圖 4:go tool trace 打開的 Tracer 數據分析首頁

我們看到首頁顯示了多個數據分析的超鏈接,每個鏈接將打開一個分析視圖,其中:

圖 5:Goroutine analysis 的各個子頁面

通常我們最爲關注的是 View trace 和 Goroutine analysis,下面將詳細說說這兩項的用法。

目前關於 Go Execution Tracer 的官方文檔資料十分稀缺 [20],尤其是對 go tool trace 分析 tracer 數據過程中的各個視圖的資料更是少之又少,網上能看到的也多是第三方在使用 go tool trace 過程中積累的 “經驗資料”。

1) View trace

點擊 “View trace” 進入 Tracer 數據分析視圖,見下圖 6:

圖 6:View trace 視圖

View trace 視圖是基於 google 的 trace-viewer[21] 實現的,其大體上可分爲四個區域:

時間線爲 View trace 提供了時間參照系,View trace 的時間線始於 Tracer 開啓時,各個區域記錄的事件的時間都是基於時間線的起始時間的相對時間

時間線的時間精度最高爲納秒,但 View trace 視圖支持自由縮放時間線的時間標尺,我們可以在秒、毫秒的 “宏觀尺度” 查看全局,就像上面圖 6 中那樣;我們亦可以將時間標尺縮放到微秒、納秒的 “微觀尺度” 來查看某一個極短暫事件的細節:

圖 7:在微秒的微觀尺度查看短暫事件

如果 Tracer 跟蹤時間較長,trace.out 文件較大,go tool trace 會將 View trace 按時間段進行劃分,避免觸碰到 trace-viewer 的限制:

圖 8:View trace 按時間段劃分

View trace 使用快捷鍵來縮放時間線標尺:w 鍵用於放大(從秒向納秒縮放),s 鍵用於縮小標尺(從納秒向秒縮放)。我們同樣可以通過快捷鍵在時間線上左右移動:s 鍵用於左移,d 鍵用於右移。如果你記不住這些快捷鍵,可以點擊 View trace 視圖右上角的問號?按鈕,瀏覽器將彈出 View trace 操作幫助對話框:

圖 9:View trace 幫助對話框

View trace 視圖的所有快捷操作方式都可以在這裏查詢到。

這個區內展示了三個指標:Goroutines、Heap 和 Threads,某個時間點上的這三個指標的數據是這個時間點上的狀態快照採樣:

Goroutines:某一時間點上應用中啓動的 goroutine 的數量,當我們點擊某個時間點上的 goroutines 採樣狀態區域時(我們可以用快捷鍵 m 來準確標記出那個時間點),事件詳情區會顯示當前的 goroutines 指標採樣狀態:

圖 10:某一個時間點上的 goroutines 指標採樣狀態

從上圖我們看到,那個時間點上共有 9 個 goroutine,8 個正在運行,另外 1 個準備就緒,等待着被調度。處於 GCWaiting 狀態的 goroutine 數量爲 0。

而 Heap 指標則顯示了某個時間點上 Go 應用 heap 分配情況(包括已經分配的 Allocated 和下一次 GC 的目標值 NextGC):

圖 11:某一個時間點上的 heap 指標採樣狀態

Threads 指標顯示了某個時間點上 Go 應用啓動的線程數量情況,事件詳情區將顯示處於 InSyscall(整阻塞在系統調用上)和 Running 兩個狀態的線程數量情況:

圖 12:某一個時間點上的 threads 指標採樣狀態

連續的採樣數據按時間線排列就描繪出了各個指標的變化趨勢情況。

這裏將 View trace 視圖中最大的一塊區域稱爲 “P 視角區”。這是因爲在這個區域,我們能看到 Go 應用中每個 P(Goroutine 調度概念中的 P)上發生的所有事件,包括:EventProcStart、EventProcStop、EventGoStart、EventGoStop、EventGoPreempt、Goroutine 輔助 GC 的各種事件以及 Goroutine 的 GC 阻塞(STW)、系統調用阻塞、網絡阻塞以及同步原語阻塞(mutex) 等事件。除了每個 P 上發生的事件,我們還可以看到以單獨行顯示的 GC 過程中的所有事件。

另外我們看到每個 Proc 對應的條帶都有兩行,上面一行表示的是運行在該 P 上的 Goroutine 的主事件,而第二行則是一些其他事件,比如系統調用、運行時事件等,或是 goroutine 代表運行時完成的一些任務,比如代表 GC 進行並行標記。下圖 13 展示了每個 Proc 的條帶:

圖 13:每個 Proc 對應的條帶都有兩行

我們放大圖像,看看 Proc 對應的條帶的細節:

圖 14:每個 Proc 對應的條帶細節

我們以上圖中的 proc4 中的一段條帶爲例,這裏包含三個事件。在條帶的兩行中的第一行的事件表示的是 G1 這個 goroutine 被調度到 P4 上進行運行,當我們選中該事件後,我們在事件詳情區可以看到關於該事件的詳細信息:

- Title:事件的可讀名稱;
- Start:事件的開始時間,相對於時間線上的起始時間;
- Wall Duration:這個事件的持續時間,這裏表示的是G1在P4上此次持續執行的時間;
- Start Stack Trace:當P4開始執行G1時G1的調用棧;
- End Stack Trace:當P4結束執行G1時G1的調用棧;從上面End Stack Trace棧頂的函數爲runtime.asyncPreempt來看,該Goroutine G1是被強行搶佔了,這樣P4才結束了其運行;
- Incoming flow:觸發P4執行G1的事件;
- Outgoing flow:觸發G1結束在P4上執行的事件;
- Preceding events:與G1這個goroutine相關的之前的所有的事件;
- Follwing events:與G1這個goroutine相關的之後的所有的事件
- All connected:與G1這個goroutine相關的所有事件。

proc4 條帶的第二行按順序先後發生了兩個事件,一個是 stw,即 GC 暫停所有 goroutine 執行;另外一個是讓 G1 這個 goroutine 輔助執行 GC 過程的併發標記(可能是 G1 分配內存較多較快,GC 選擇讓其交出部分算力做 gc 標記)。

通過上面描述,我們可以看到通過 P 視角區我們可以可視化地顯示整個程序(每個 Proc)在程序執行的時間線上的全部情況,尤其是按時間線順序顯示每個 P 上運行的各個 goroutine(每個 goroutine 都有唯一獨立的顏色)相關的事件的細節。

P 視角區顯式的各個事件間存在關聯關係,我們可以通過視圖上方的 "flow events" 按鈕打開關聯事件流,這樣在圖中我們就能看到某個事件的前後關聯事件關係了(如下圖 15):

圖 15:關聯事件流

View trace 視圖的最下方爲 “事件詳情區”,當我們點選某個事件後,關於該事件的詳細信息便會在這個區域顯示出來,就像上面圖 14 那樣。

在宏觀尺度上,每個 P 條帶的第二行的事件因爲持續事件較短而多呈現爲一條豎線,我們點選這些事件不是很容易。點選這些事件的方法,要麼將圖像放大,要麼通過左箭頭或右箭頭兩個鍵盤鍵順序選取,選取後可以通過 m 鍵顯式標記出這個事件(再次敲擊 m 鍵取消標記)。

2) Goroutine analysis

就像前面圖 5 中展示的 Goroutine analysis 的各個子頁面那樣,Goroutine analysis 爲我們提供了從 G 視角看 Go 應用執行的圖景。

點擊圖 5 中位於表第一列中的任一個 Goroutine id,我們將進入 Go 視角視圖:

圖 16:Goroutine analysis 提供的 G 視角視圖

我們看到與 View trace 不同,這次頁面中最廣闊的區域提供的 G 視角視圖,而不再是 P 視角視圖。在這個視圖中,每個 G 都會對應一個單獨的條帶(和 P 視角視圖一樣,每個條帶都有兩行),通過這一條帶我們可以按時間線看到這個 G 的全部執行情況。通常我們僅需在 goroutine analysis 的表格頁面找出執行最快和最慢的兩個 goroutine,在 Go 視角視圖中沿着時間線對它們進行對比,以試圖找出執行慢的 goroutine 究竟出了什麼問題。

4. 實例理解

下面用一個實例理解一下 Go Execution Tracer 幫我們解決問題的過程。編寫這樣的例子不易,恰之前 Francesc Campoy 在其 justforfun 專欄 [22] 中曾舉過一個可用於 Tracer 的不錯的例子 [23],這裏借用一下 ^_^。

Francesc Campoy 舉的是一個生成分形圖片的例子,第一版代碼如下:

// main.go
package main

  import (
    "image"
    "image/color"
    "image/png"
    "log"
    "os"
    "runtime/trace"
)

const (
    output     = "out.png"
    width      = 2048
    height     = 2048
    numWorkers = 8
)

func main() {
    trace.Start(os.Stdout)
    defer trace.Stop()

    f, err := os.Create(output)
    if err != nil {
        log.Fatal(err)
    }

    img := createSeq(width, height)

    if err = png.Encode(f, img); err != nil {
        log.Fatal(err)
    }
}

// createSeq fills one pixel at a time.
func createSeq(width, height int) image.Image {
    m := image.NewGray(image.Rect(0, 0, width, height))
    for i := 0; i < width; i++ {
        for j := 0; j < height; j++ {
            m.Set(i, j, pixel(i, j, width, height))
        }
    }
    return m
}

// pixel returns the color of a Mandelbrot fractal at the given point.
func pixel(i, j, width, height int) color.Color {
    // Play with this constant to increase the complexity of the fractal.
    // In the justforfunc.com video this was set to 4.
    const complexity = 1024

    xi := norm(i, width, -1.0, 2)
    yi := norm(j, height, -1, 1)

    const maxI = 1000
    x, y := 0., 0.

    for i := 0; (x*x+y*y < complexity) && i < maxI; i++ {
        x, y = x*x-y*y+xi, 2*x*y+yi
    }

    return color.Gray{uint8(x)}
}

func norm(x, total int, min, max float64) float64 {
    return (max-min)*float64(x)/float64(total) - max
}

這一版代碼通過 pixel 函數算出待輸出圖片中的每個像素值,這版代碼即便不用 pprof 也基本能定位出來程序熱點在 pixel 這個關鍵路徑上的函數上,更精確的位置是 pixel 中的那個循環。那麼如何優化呢?pprof 已經沒招了,我們用 Tracer 來看看:

$go build main.go
$./main > seq.trace
$go tool trace seq.trace

go tool trace 展示的 View trace 視圖如下:

圖 17:示例第一版代碼的 View trace 視圖

通過上面 View trace 視圖,我們一眼便可以看到這一版程序僅利用了機器上多個 cpu core 中的一個 core,其餘的 cpu core 處於空閒狀態。

之後作者給出極端的併發方案,即每個像素點計算都對應啓動一個新 goroutine(用下面的 createPixcel 替換上面 main.go 中的 createSeq):

func createPixel(width, height int) image.Image {
    m := image.NewGray(image.Rect(0, 0, width, height))
    var w sync.WaitGroup
    w.Add(width * height)
    for i := 0; i < width; i++ {
        for j := 0; j < height; j++ {
            go func(i, j int) {
                m.Set(i, j, pixel(i, j, width, height))
                w.Done()
            }(i, j)
        }
    }
    w.Wait()
    return m
}

這一版的程序執行性能的確有提升,並且充分利用了 cpu,查看其 Tracer 數據(由於這一版的 Tracer 數據文件 pixel.trace 較大,需要一段時間的等待)如下:

圖 18:示例第二版代碼的 View trace 視圖

以 261.954ms 附近的事件數據爲例,我們看到系統的 8 個 cpu core 都滿負荷運轉,但從 goroutine 的狀態採集數據看到,僅有 7 個 goroutine 處於運行狀態,而有 21971 個 goroutine 正在等待被調度,這給 go 運行時的調度帶去很大壓力;另外由於這一版代碼創建了 2048x2048 個 goroutine(400 多 w 個),導致內存分配頻繁,給 GC 造成很大壓力,從視圖上來看,每個 Goroutine 似乎都在輔助 GC 做並行標記。由此可見,我們不能創建這麼多 goroutine,於是作者又給出了第三版代碼,僅創建 2048 個 goroutine,每個 goroutine 負責一列像素的生成(用下面 createCol 替換 createPixel):

// createCol creates one goroutine per column.
func createCol(width, height int) image.Image {
    m := image.NewGray(image.Rect(0, 0, width, height))
    var w sync.WaitGroup
    w.Add(width)
    for i := 0; i < width; i++ {
        go func(i int) {
            for j := 0; j < height; j++ {
                m.Set(i, j, pixel(i, j, width, height))
            }
            w.Done()
        }(i)
    }
    w.Wait()
    return m
}

這一版代碼的效果十分理想!性能提升近 5 倍。還可以再優化麼?於是作者又實現了一版基於 Worker 併發模式的代碼:

// createWorkers creates numWorkers workers and uses a channel to pass each pixel.
func createWorkers(width, height int) image.Image {
    m := image.NewGray(image.Rect(0, 0, width, height))

    type px struct{ x, y int }
    c := make(chan px)

    var w sync.WaitGroup
    for n := 0; n < numWorkers; n++ {
        w.Add(1)
        go func() {
            for px := range c {
                m.Set(px.x, px.y, pixel(px.x, px.y, width, height))
            }
            w.Done()
        }()
    }

    for i := 0; i < width; i++ {
        for j := 0; j < height; j++ {
            c <- px{i, j}
        }
    }
    close(c)
    w.Wait()
    return m
}

作者的機器是 8 核主機,於是它預創建了 8 個 worker goroutine,主 goroutine 通過一個 channel c 向各個 goroutine 派發工作。但作者並沒有看到預期的性能,其性能還不如每個像素一個 goroutine 的版本。查看 Tracer 情況如下(這一版代碼的 Tracer 數據更多,解析和加載時間更長):

圖 19:示例第四版代碼的 View trace 視圖

我們看到適當放大後的 View trace 視圖,我們看到了很多大段的 Proc 暫停以及不計其數的小段暫停,顯然 goroutine 發生阻塞了,我們接下來通過 Synchronization blocking profile 查看究竟在哪裏阻塞時間最長:

圖 20:示例第四版代碼的 Synchronization blocking profile

我們看到在 channel 接收上所有 goroutine 一共等待了近 60s。從這版代碼來看,main goroutine 要進行近 400 多 w 次發送,而其他 8 個 worker goroutine 都得耐心阻塞在 channel 接收上等待,這樣的結構顯然不夠優化,即便將 channel 換成帶緩衝的也依然不夠理想。

作者想到了 createCol 的思路,即不將每個像素點作爲一個 task 發給 worker,而是將一個列作爲一個工作單元發送給 worker,每個 worker 完成一個列像素的計算,這樣我們來到了最終版代碼 (使用下面的 createColWorkersBuffered 替換 createWorkers):

func createColWorkersBuffered(width, height int) image.Image {
    m := image.NewGray(image.Rect(0, 0, width, height))

    c := make(chan int, width)

    var w sync.WaitGroup
    for n := 0; n < numWorkers; n++ {
        w.Add(1)
        go func() {
            for i := range c {
                for j := 0; j < height; j++ {
                    m.Set(i, j, pixel(i, j, width, height))
                }
            }
            w.Done()
        }()
    }

    for i := 0; i < width; i++ {
        c <- i
    }

    close(c)
    w.Wait()
    return m
}

這版代碼的確是所有版本中性能最好的,其 Tracer 的 View trace 視圖如下:

圖 21:示例最終版代碼 View trace 視圖

這幾乎就是一幅完美的 View trace 視圖!

5. 小結

Go Execution Tracer 不是銀彈,它不能幫你解決 Go 程序中的所有問題。通常對 Go 應用做性能分析時,我們都會使用 pprof 先找熱點,等消除熱點後,再用 Go Execution Tracer 通盤查看整個 Go 應用中 goroutine 的執行情況,通過 View trace 或 Goroutine analysis 找出 “詭異點” 並進行細緻分析。

Go 應用的並行性、延遲、goroutine 阻塞等方面問題是 Go Execution Tracer 擅長的 “主戰場”。

6. 參考資料

我的聯繫方式:

商務合作方式:撰稿、出書、培訓、在線課程、合夥創業、諮詢、廣告合作。

參考資料

[1] 

本文永久鏈接: https://tonybai.com/2021/06/28/understand-go-execution-tracer-by-example

[2] 

Brendan Gregg: http://www.brendangregg.com

[3] 

《BPF Performance Tools》: https://book.douban.com/subject/34467459/

[4] 

go tool pprof: https://www.imooc.com/read/87/article/2440

[5] 

提案: https://go.googlesource.com/proposal/+/refs/changes/08/219508/2/design/36821-perf-counter-pprof.md

[6] 

Dmitry Vyukov: https://github.com/dvyukov

[7] 

設計方案: https://docs.google.com/document/u/1/d/1FP5apqzBgr7ahCCgFO-yoVhk4YZrNIDNf9RybngBc14/pub

[8] 

Go 1.5 版本: https://tonybai.com/2015/07/10/some-changes-in-go-1-5/

[9] 

加入 Go 工具鏈: https://talks.golang.org/2015/dynamic-tools.slide

[10] 

goroutine 調度器: http://tonybai.com/2017/11/23/the-simple-analysis-of-goroutine-schedule-examples

[11] 

加入 Go Execution Tracer 支持: https://tip.golang.org/doc/go1.5#trace_command

[12] 

Go 1.7 版本: https://tonybai.com/2016/06/21/some-changes-in-go-1-7/

[13] 

Go 1.8 版本: https://tonybai.com/2017/02/03/some-changes-in-go-1-8/

[14] 

Go 1.9 版本: https://tonybai.com/2017/07/14/some-changes-in-go-1-9/

[15] 

Go 1.11 版本: https://tonybai.com/2018/11/19/some-changes-in-go-1-11/

[16] 

用戶自定義應用層事件: https://tip.golang.org/pkg/runtime/trace/#hdr-User_annotation

[17] 

Go 1.12 版本: https://tonybai.com/2019/03/02/some-changes-in-go-1-12/

[18] 

添加 Tracer 提供了三種方法: https://tip.golang.org/cmd/trace/

[19] 

Trace 函數: https://tip.golang.org/pkg/net/http/pprof/#Trace

[20] 

關於 Go Execution Tracer 的官方文檔資料十分稀缺: https://github.com/golang/go/issues/16526

[21] 

trace-viewer: https://github.com/catapult-project/catapult

[22] 

justforfun 專欄: https://github.com/campoy/justforfunc

[23] 

一個可用於 Tracer 的不錯的例子: https://medium.com/justforfunc/using-the-go-execution-tracer-to-speed-up-fractal-rendering-c06bb3760507

[24] 

改善 Go 語⾔編程質量的 50 個有效實踐: https://www.imooc.com/read/87

[25] 

Kubernetes 實戰:高可用集羣搭建、配置、運維與應用: https://coding.imooc.com/class/284.html

[26] 

我愛發短信: https://51smspush.com/

[27] 

鏈接地址: https://m.do.co/c/bff6eed92687

本文由 Readfog 進行 AMP 轉碼,版權歸原作者所有。
來源https://mp.weixin.qq.com/s/L7HiqA02g-l-b2pD6aRtbw