Go 中 trace 包的使用
Go 給我們提供了一個工具trace
,可以在運行時啓用trace
, 並獲得程序執行情況的詳細視圖。
應該怎麼使用trace
呢?一般有下面三種使用方式
-
運行
go test
的時候,帶上-trace
參數標記,go test -trace=trace.out
-
從
pprof
中獲取實時trace
,import _ "net/http/pprof"
-
在代碼中編碼嵌入
trace
,
代碼中使用, 我寫了一個簡單的例子:
package main
import (
"io/ioutil"
"log"
"os"
"runtime/trace"
"sync"
)
// 一個簡單的例子去演示如何在代碼中使用trace包
func main() {
// 1. 創建trace持久化的文件句柄
f, err := os.Create("trace.out")
if err != nil {
log.Fatalf("failed to create trace output file: %v", err)
}
defer func() {
if err := f.Close(); err != nil {
log.Fatalf("failed to close trace file: %v", err)
}
}()
// 2. trace綁定文件句柄
if err := trace.Start(f); err != nil {
log.Fatalf("failed to start trace: %v", err)
}
defer trace.Stop()
// 下面就是你的監控的程序
// 我簡單寫了一個文件讀寫
var wg sync.WaitGroup
wg.Add(2)
// 一個協程用來讀文件
go func() {
defer wg.Done()
ioutil.ReadFile(`mxc.txt`)
}()
// 寫文件協程
go func() {
defer wg.Done()
ioutil.WriteFile(`mxc_code.txt`, []byte(`碼小菜`), 0644)
}()
wg.Wait()
}
運行命令
會看到生成一個trace.out
的文件,打開命令
這時候會打開一個瀏覽器窗口,可以看到
工作原理
trace
的工作流程非常簡單, 標準庫會記錄 Go 運行期間的每個事件,例如內存分配, 垃圾收集器 (gc) 的所有階段, goroutine 何時運行,暫停等等,並將這些信息格式化以供以後顯示使用。
- 在開始記錄之前,
runtime
會STW
,並對當前goroutines
的狀態進行快照。
stw
後,收集的事件會放入trace
的一個緩衝區,在達到緩衝區最大容量時刷新。下面是整個流程圖
tracer
現在就可以將上面收集的信息dump
到輸出。所以,當trace
開始時,Go 會專門爲trace
啓動一個goroutine
。這個goroutine
會在數據可用時dump
記錄的數據到輸出,在沒有數據時 park 住。如下圖:
現在的流程就非常清晰了
一旦生成了跟蹤信息,就可以用命令go tool trace output.out
來完成可視化, 下圖是我剛開始那個簡單程序的一個trace
圖, 點擊圖一的View Trace
上面的代碼相對簡單,看不到更多的關於gc
的信息,下面我寫了一個觸發 gc 的程序
package main
import (
"log"
"os"
"runtime/trace"
"sync"
)
func main() {
// 1. 創建trace持久化的文件句柄
f, err := os.Create("trace.out")
if err != nil {
log.Fatalf("failed to create trace output file: %v", err)
}
defer func() {
if err := f.Close(); err != nil {
log.Fatalf("failed to close trace file: %v", err)
}
}()
// 2. trace綁定文件句柄
if err := trace.Start(f); err != nil {
log.Fatalf("failed to start trace: %v", err)
}
defer trace.Stop()
// 下面就是你的監控的程序
var wg sync.WaitGroup
wg.Add(2)
go func() {
defer wg.Done()
for i := 0; i < 100; i++ {
_ = make([]int, 0, 20000)
}
}()
go func() {
defer wg.Done()
for i := 0; i < 100; i++ {
_ = make([]int, 0, 10000)
}
}()
wg.Wait()
}
圖示很直接。與gc
相關的信息,如下圖
下面是一個大致的描述
- STW 是
gc
中的兩個 "停止世界" 的階段。在這兩個階段中,goroutine
會停止運行。
- GC(idle) 指沒有標記內存時的 goroutine。
- MARK ASSIST 在分配內存過程中重新標記內存 (mark the memory) 的 goroutine。
- SWEEP 垃圾清理
- GXX runtime.gcBgMarkWorker 是幫助標記內存的專用後臺 goroutine。
然而,有些 Trace 並不容易理解:
proc start
當一個邏輯處理器 § 與一個線程綁定時被調用。也就是啓動新線程或從系統調用恢復
proc stop
當線程與當前處理器 § 分離時,將調用proc stop
。當線程發生系統調用被阻塞或線程退出時,就會發生這種情況。
goroutine
進行系統調用時,將調用syscall
注意:Trace 既可以定義和可視化自己的 Trace 以及也可以追蹤標準庫中的 Trace
用戶 Traces
用戶級別可以定義的 Trace 具有兩個層次級別:
-
在任務的最高層,有開始和結束
-
在該區域的子級別上
這裏有一個簡單的例子:
package main
import (
"context"
"io/ioutil"
"log"
"os"
"runtime/trace"
"sync"
)
// 一個簡單的例子去演示如何在代碼中使用trace包
func main() {
// 1. 創建trace持久化的文件句柄
f, err := os.Create("trace.out")
if err != nil {
log.Fatalf("failed to create trace output file: %v", err)
}
defer func() {
if err := f.Close(); err != nil {
log.Fatalf("failed to close trace file: %v", err)
}
}()
// 2. trace綁定文件句柄
if err := trace.Start(f); err != nil {
log.Fatalf("failed to start trace: %v", err)
}
defer trace.Stop()
ctx, task := trace.NewTask(context.Background(), "main start")
var wg sync.WaitGroup
wg.Add(2)
go func() {
defer wg.Done()
r := trace.StartRegion(ctx, "reading file")
defer r.End()
ioutil.ReadFile(`n1.txt`)
}()
go func() {
defer wg.Done()
r := trace.StartRegion(ctx, "writing file")
defer r.End()
ioutil.WriteFile(`n2.txt`, []byte(`42`), 0644)
}()
wg.Wait()
defer task.End()
}
可以通過菜單中的用戶自定義任務直接從工具中可視化這些 Trace:
也可以記錄一些其他的信息到任務:
ctx, task := trace.NewTask(context.Background(), "main start")
trace.Log(ctx, "category", "I/O file")
trace.Log(ctx, "goroutine", "2")
這些日誌將在設置任務的goroutine
下找到:
一個簡單的性能測試,可以幫助理解Trace
對應用程序的影響。一個將帶有-trace
標誌,而另一個則不帶-trace
。以下是帶有ioutil.ReadFile()
函數的性能測試的結果,該函數會生成大量事件:
name time/op
ReadFiles-8 48.1µs ± 0%
name time/op
ReadFiles-8 63.5µs ± 0% // with tracing
在這種情況下,性能影響約爲 35%,並且可能和應用有關係, 你可以根據你的應用性能來決定要用不用
本文由 Readfog 進行 AMP 轉碼,版權歸原作者所有。
來源:https://mp.weixin.qq.com/s/I3eObBWhRUd7mWi0mP_aeg