Go 環境變量 - GODEBUG 詳解
簡介
GODEBUG 環境變量可以控制程序運行時的調度信息輸出,方便開發者瞭解內部細節。
語法是通過逗號分割多個鍵值對,例如:
# 運行 main.go, 每秒輸出 1 次調度信息
$ GODEBUG=scheddetail=1,schedtrace=1000 go run main.go
常用參數
示例程序
本文後面的幾個用例,全部使用該程序演示。
package main
import (
"sync"
"time"
)
func main() {
var wg sync.WaitGroup
for i := 0; i < 10; i++ {
wg.Add(1)
go func() {
defer wg.Done()
time.Sleep(1 * time.Second)
}()
}
wg.Wait()
}
輸出調度基礎信息
執行命令
$ GODEBUG=schedtrace=1000 go run main.go
# 輸出如下
SCHED 0ms: gomaxprocs=8 idleprocs=6 threads=5 spinningthreads=1 idlethreads=0 runqueue=0 [1 0 0 0 0 0 0 0]
...
SCHED 0ms: gomaxprocs=8 idleprocs=6 threads=5 spinningthreads=1 idlethreads=2 runqueue=0 [0 0 0 0 0 0 0 0]
SCHED 0ms: gomaxprocs=8 idleprocs=6 threads=5 spinningthreads=1 idlethreads=2 runqueue=0 [9 0 0 0 0 0 0 0]
SCHED 1007ms: gomaxprocs=8 idleprocs=8 threads=13 spinningthreads=0 idlethreads=6 runqueue=0 [0 0 0 0 0 0 0 0]
輸出結果說明
輸出 GC 時內存示例
執行命令
$ GODEBUG=gctrace=1 go run main.go
# 輸出如下
gc 1 @0.028s 1%: 0.058+1.1+0.19 ms clock, 0.46+0/1.0/0.36+1.5 ms cpu, 3->4->0 MB, 4 MB goal, 0 MB stacks, 0 MB globals, 8 P
gc 2 @0.034s 1%: 0.083+0.63+0.005 ms clock, 0.66+0.094/0.51/0.27+0.044 ms cpu, 3->3->0 MB, 4 MB goal, 0 MB stacks, 0 MB globals, 8 P
gc 3 @0.039s 1%: 0.031+0.66+0.042 ms clock, 0.25+0.091/0.49/0.39+0.34 ms cpu, 3->4->0 MB, 4 MB goal, 0 MB stacks, 0 MB globals, 8 P
gc 4 @0.043s 2%: 0.027+0.70+0.14 ms clock, 0.22+0.039/0.50/0.34+1.1 ms cpu, 3->3->0 MB, 4 MB goal, 0 MB stacks, 0 MB globals, 8 P
...
gc 1 @0.002s 4%: 0.012+0.78+0.005 ms clock, 0.098+0.49/0.58/0.32+0.040 ms cpu, 4->6->5 MB, 4 MB goal, 0 MB stacks, 0 MB globals, 8 P
gc 2 @0.015s 2%: 0.016+1.3+0.034 ms clock, 0.12+0.022/1.1/0.90+0.27 ms cpu, 9->9->7 MB, 10 MB goal, 0 MB stacks, 0 MB globals, 8 P
輸出結果說明
下面以最後一行輸出爲例進行說明:
gc 2 @0.015s 2%: 0.016+1.3+0.034 ms clock, 0.12+0.022/1.1/0.90+0.27 ms cpu, 9->9->7 MB, 10 MB goal, 0 MB stacks, 0 MB globals, 8 P
輸出調度完整信息
執行命令
$ GODEBUG=scheddetail=1,schedtrace=1000 go run main.go
# 輸出如下
SCHED 0ms: gomaxprocs=8 idleprocs=6 threads=6 spinningthreads=1 idlethreads=2 runqueue=0 gcwaiting=0 nmidlelocked=0 stopwait=0 sysmonwait=0
P0: status=1 schedtick=1 syscalltick=0 m=0 runqsize=0 gfreecnt=0 timerslen=0
P1: status=0 schedtick=2 syscalltick=0 m=-1 runqsize=0 gfreecnt=0 timerslen=0
...
P7: status=0 schedtick=0 syscalltick=0 m=-1 runqsize=0 gfreecnt=0 timerslen=0
M5: p=2 curg=-1 mallocing=0 throwing=0 preemptoff= locks=1 dying=0 spinning=true blocked=false lockedg=-1
...
M0: p=0 curg=1 mallocing=0 throwing=0 preemptoff= locks=5 dying=0 spinning=false blocked=false lockedg=1
G1: status=2(chan receive) m=0 lockedm=0
...
G4: status=4(GC scavenge wait) m=-1 lockedm=-1
...
SCHED 1008ms: gomaxprocs=8 idleprocs=8 threads=14 spinningthreads=0 idlethreads=7 runqueue=0 gcwaiting=0 nmidlelocked=1 stopwait=0 sysmonwait=0
P0: status=0 schedtick=262 syscalltick=826 m=-1 runqsize=0 gfreecnt=0 timerslen=0
...
P7: status=0 schedtick=17 syscalltick=307 m=-1 runqsize=0 gfreecnt=3 timerslen=0
M13: p=-1 curg=-1 mallocing=0 throwing=0 preemptoff= locks=0 dying=0 spinning=false blocked=true lockedg=-1
...
M0: p=-1 curg=-1 mallocing=0 throwing=0 preemptoff= locks=0 dying=0 spinning=false blocked=true lockedg=-1
G1: status=4(semacquire) m=-1 lockedm=-1
G17: status=6() m=1 lockedm=1
G2: status=4(force gc (idle)) m=-1 lockedm=-1
G3: status=4(GC sweep wait) m=-1 lockedm=-1
G4: status=4(sleep) m=-1 lockedm=-1
G5: status=4(finalizer wait) m=-1 lockedm=-1
G12: status=6() m=-1 lockedm=-1
G22: status=6() m=-1 lockedm=-1
G10: status=4(GC worker (idle)) m=-1 lockedm=-1
...
G78: status=4(select) m=-1 lockedm=10
G146: status=4(chan receive) m=-1 lockedm=-1
輸出結果說明
P
的相關輸出說明,以下面這行輸出爲例:
P0: status=1 schedtick=1 syscalltick=0 m=0 runqsize=0 gfreecnt=0 timerslen=0
P
的狀態列表
const (
// 處理器沒有在執行代碼或者調度,位於空閒列表或者被可以改變其狀態的結構持有
_Pidle = iota
// 處理器被線程 M 持有,並且正在執行代碼或者調度
_Prunning
// 處理器沒有在執行代碼,線程陷入系統調用
_Psyscall
// 處理器被線程 M 持有,由於 GC 被停止
_Pgcstop
// 處理器不再被使用
_Pdead
)
M
的相關輸出說明,以下面這行輸出爲例:
M0: p=0 curg=1 mallocing=0 throwing=0 preemptoff= locks=5 dying=0 spinning=false blocked=false lockedg=1
G
的相關輸出說明,以下面這行輸出爲例:
G1: status=2(chan receive) m=0 lockedm=0
G
的狀態列表
const (
// goroutine 剛被分配並且還沒有被初始化
_Gidle = iota // 0
// goroutine 處於運行隊列中,沒有在執行代碼,沒有棧的所有權
_Grunnable // 1
// goroutine 可以執行代碼並且擁有有棧的所有權,M 和 P 已經設置並且有效
_Grunning // 2
// goroutine 正在執行系統調用,沒有在執行代碼,擁有棧的所有權但是不在運行隊列中,此外,M 已經設置
_Gsyscall // 3
// goroutine 處於阻塞中,沒有在執行代碼並且不在運行隊列中,但是可能存在於 Channel 的等待隊列上
_Gwaiting // 4
// 沒有使用這個狀態,但是被硬編碼到了 gbd 腳本中
_Gmoribund_unused // 5
// goroutine 沒有被使用 (可能已經退出或剛剛初始化),沒有在執行代碼,可能存在分配的棧
_Gdead // 6
// 沒有使用這個狀態
_Genqueue_unused // 7
// goroutine 的棧正在被移動,沒有在執行代碼並且不在運行隊列中
_Gcopystack // 8
// goroutine 由於搶佔而阻塞,等待喚醒
_Gpreempted // 9
// GC 正在掃描棧空間,沒有在執行代碼,可以與上述其他狀態同時存在
_Gscan = 0x1000
)
可視化
國外的大佬 Dave Cheney
開發了一個工具,可以實時可視化 GC trace
數據,項目地址 在這裏 [1]。
圖片來源: https://dave.cheney.net/2014/07/11/visualising-the-go-garbage-collector
Reference
-
runtime[3]
-
scheduler-trace[4]
-
GODEBUG[5]
-
Go Environment Variables[6]
-
Scheduler Tracing In Go[7]
參考資料
[1] 在這裏: https://github.com/davecheney/gcvis
[2] Go Hacking.md: hacking.md
[3] runtime: https://pkg.go.dev/runtime
[4] scheduler-trace: https://github.com/golang/go/wiki/Performance#scheduler-trace
[5] GODEBUG: https://ydkgo.netlify.app/docs/profiling/godebug/readme/
[6] Go Environment Variables: https://pkg.go.dev/runtime#hdr-Environment_Variables
[7] Scheduler Tracing In Go: https://www.ardanlabs.com/blog/2015/02/scheduler-tracing-in-go.html
本文由 Readfog 進行 AMP 轉碼,版權歸原作者所有。
來源:https://mp.weixin.qq.com/s/AunOvSWc0g-y5DgkxwP2AQ