golang trace 分析簡例

2020 年 4 月 18 日
筆記
golang

今天，通過一個例子，一方面熟悉trace在自定義範圍內的分析，另一方面golang 在協程調度策略上的淺析。

Show Code

// trace_example.go
package main

import (
	"context"
	"fmt"
	"os"
	"runtime"
	"runtime/trace"
	"sync"
)

func main(){
	// 為了看協程搶佔，這裡設置了一個cpu 跑
	runtime.GOMAXPROCS(1)

	f, _ := os.Create("trace.dat")
	defer f.Close()

	_ = trace.Start(f)
	defer trace.Stop()

	ctx,  task := trace.NewTask(context.Background(), "sumTask")
	defer task.End()

	var wg sync.WaitGroup
	wg.Add(10)
	for i := 0; i < 10; i ++ {
		// 啟動10個協程，只是做一個累加運算
		go func(region string) {
			defer wg.Done()
			
			// 標記region
			trace.WithRegion(ctx, region, func() {
				var sum, k int64
				for ; k < 1000000000; k ++ {
					sum += k
				}
				fmt.Println(region, sum)
			})
		}(fmt.Sprintf("region_%02d", i))
	}
	wg.Wait()
}

首先，代碼的功能非常簡單，只是啟動10個協程，每個協程處理的工作都是一樣的，即把0 … 1000000000 做了sum 運算。
其次，代碼中，添加了Task 和 Task 的Region，是我們更好的發現我們協程的位置(當然，我這裡都捕獲了，只是用Region 做了標識)，並將記錄的 trace 數據寫入trace.dat 文件中。
最後，為了更好的看到協程對cpu的搶佔，所以把cpu的個數限制為1個。

編譯並運行,會得到如下結果：

# go build trace_example.go
# ./trace_example 
region_09 499999999500000000
region_00 499999999500000000
region_01 499999999500000000
region_02 499999999500000000
region_03 499999999500000000
region_04 499999999500000000
region_05 499999999500000000
region_06 499999999500000000
region_07 499999999500000000
region_08 499999999500000000

從結果中，我們可以看出，協程執行的順序不是那麼有序。但是真實是怎麼執行的呢？我們從 trace.dat 中獲取答案。

Trace 分析

執行下面命令，打開trace 的web服務：

# go tool trace trace.dat
2020/04/16 17:34:09 Parsing trace...
2020/04/16 17:34:10 Splitting trace...
2020/04/16 17:34:10 Opening browser. Trace viewer is listening on //127.0.0.1:53426

我們先從分析整個協程入手, 從這裡可以看出，我們的協程其實沒有按照時間片輪詢的方式跑（畢竟這是一個純計算性的工作）

而從Task中，我們觀察所有自定義的Region 和goroutine.

從圖中可以看出，task 任務所關注的region 是一個一個跑的，region_09 先執行了，這個也從我們的輸出中得到了驗證。從圖中也可以看到，我們的goroutineid(G1, G10, G12 等, 雖然我們在go編寫代碼時並不能拿到這個goroutineid).

總結與反思

除了實操了一次 task 和 region 的自定義做trace 分析外，我們還能從這個例子中找到些什麼信息。

goroutine 肯定是存在的
goroutine 的啟動肯定不是有序的, 這一點從task 的圖中就可以明顯看出來
goroutine 如果沒有阻塞的服務的話，會一直佔用cpu的（所以有了 runtime.Gosched() 的存在）

所以，對於一些佔用高頻cpu的服務（比如說加解密，編解碼服務等）如果有別的優先級比較高的goroutine在工作，可以適當的讓出CPU, 保證服務正常有序工作。

Tags: golang