這是一個建立於 的文章,其中的資訊可能已經有所發展或是發生改變。
最近看了一篇文章,如何定位 golang 進程 hang 死的 bug,裡面有這樣一段代碼:
package mainimport ( "fmt" "io" "log" "net/http" "runtime" "time")func main() { runtime.GOMAXPROCS(runtime.NumCPU()) go server() go printNum() var i = 1 for { // will block here, and never go out i++ } fmt.Println("for loop end") time.Sleep(time.Second * 3600)}func printNum() { i := 0 for { fmt.Println(i) i++ }}func HelloServer(w http.ResponseWriter, req *http.Request) { fmt.Println("hello world") io.WriteString(w, "hello, world!\n")}func server() { http.HandleFunc("/", HelloServer) err := http.ListenAndServe(":12345", nil) if err != nil { log.Fatal("ListenAndServe: ", err) }}
運行,會發現列印一會兒數字後停了,我們執行
curl localhost:12345
程式卡死。關於程式掛在哪裡藉助dlv
是很好定位的:
dlv debug hang.go
進去之後運行程式,列印停止進入卡死狀態,我們執行ctrl C
,dlv
會顯示斷開的地方:
received SIGINT, stopping process (will not forward signal)> main.main() ./hang.go:17 (PC: 0x12dd7c8) 12: func main() { 13: runtime.GOMAXPROCS(runtime.NumCPU()) 14: go server() 15: go printNum() 16: var i = 1=> 17: for { 18: // will block here, and never go out 19: i++ 20: } 21: fmt.Println("for loop end") 22: time.Sleep(time.Second * 3600)(dlv)
但是我還是不明白,不明白的地方主要是因為:
- 我又看了兩篇文章Goroutine調度執行個體簡要分析和也談goroutine調度器,是同一位作者Tony Bai寫的,寫得非常好。第二篇文章解釋了goroutine的調度和cpu數量的關係(不多加解釋,建議大家看看),我的mac是雙核四線程(這裡不明白的同學自行google cpu 超執行緒),go版本是1.9,理論上講可以跑4個goroutine而不用考慮死迴圈,一個死迴圈最多把一個cpu打死,上面的代碼中只有3個goroutine,而且他們看上去都掛住了。
- 上面說的理論上講,不是我主觀臆測的,我跑了
1
中第一篇文章中的一個例子:
package mainimport ( "fmt" "time")func deadloop() { for { }}func main() { go deadloop() for { time.Sleep(time.Second * 1) fmt.Println("I got scheduled!") }}
上面代碼有兩個goroutine,一個是main goroutine
,一個是deadloop goroutine
,跑得時候deadloop gouroutine
不會對main goroutine
造成影響,列印一直在持續,作者的文章解釋了原因。
- 如何定位 golang 進程 hang 死的 bug這篇文章提到了
gcwaiting
,然而沒有解釋。
在如何定位 golang 進程 hang 死的 bug有這樣一段話:
因為在 for 迴圈中沒有函數調用的話,編譯器不會插入調度代碼,所以這個執行 for 迴圈的 goroutine 沒有辦法被調出,而在迴圈期間碰到 gc,那麼就會卡在 gcwaiting 階段,並且整個進程永遠 hang 死在這個迴圈上。並不再對外響應。
這個其實就是我們的第一段代碼卡死的原因,也是我們第二段代碼沒有卡死的原因,就是在gc
上!
我們再看一篇文章,golang的記憶體回收(GC)機制,這篇文章很短,但每句話都很重要:
- 設定gcwaiting=1,這個在每一個G任務之前會檢查一次這個狀態,如是,則會將當前M 休眠;
- 如果這個M裡面正在運行一個長時間的G任務,咋辦呢,難道會等待這個G任務自己切換嗎?這樣的話可要等10ms啊,不能等!堅決不能等!
所以會主動發出搶佔標記(類似於上一篇),讓當前G任務中斷,再運行下一個G任務的時候,就會走到第1步
那麼如果這時候啟動並執行是沒有函數調用的死迴圈呢,gc也發出了搶佔標記,但是如果死迴圈沒有函數調用,就沒有地方被標記,無法被搶佔,那就只能設定gcwaiting=1
,而M沒有休眠,stop the world
卡住了(死結),gcwaiting
一直是1,整個程式都卡住了!
這裡其實已經解釋了第一份代碼的現象,第二份代碼為什麼沒有hang住相信大家也能猜到了:代碼裡沒有觸發gc!我們來手動觸發一下:
package mainimport ( "fmt" "log" "net/http" _ "net/http/pprof" // "runtime" "time")func deadloop() { for { }}func main() { go func() { log.Println(http.ListenAndServe("localhost:6060", nil)) }() go deadloop() i := 3 for { time.Sleep(time.Second * 1) i-- fmt.Println("I got scheduled!") if i == 0 { runtime.GC() } }}
會發現列印了3行之後,程式也卡死了,bingo?
我們來看看gcwaiting
是不是等於1:
$ go build hang2.go$ GODEBUG="schedtrace=300,scheddetail=1" ./hang2SCHED 2443ms: gomaxprocs=4 idleprocs=3 threads=7 spinningthreads=0 idlethreads=2 runqueue=0 gcwaiting=0 nmidlelocked=0 stopwait=0 sysmonwait=0 P0: status=1 schedtick=4 syscalltick=5 m=5 runqsize=0 gfreecnt=1 P1: status=0 schedtick=14 syscalltick=0 m=-1 runqsize=0 gfreecnt=0 P2: status=0 schedtick=3 syscalltick=4 m=-1 runqsize=0 gfreecnt=0...... SCHED 2751ms: gomaxprocs=4 idleprocs=0 threads=7 spinningthreads=0 idlethreads=2 runqueue=0 gcwaiting=1 nmidlelocked=0 stopwait=1 sysmonwait=0 P0: status=1 schedtick=4 syscalltick=5 m=5 runqsize=0 gfreecnt=1 P1: status=3 schedtick=14 syscalltick=0 m=-1 runqsize=0 gfreecnt=0 P2: status=3 schedtick=3 syscalltick=10 m=-1 runqsize=0 gfreecnt=0 P3: status=3 schedtick=1 syscalltick=26 m=0 runqsize=0 gfreecnt=0 M6: p=-1 curg=-1 mallocing=0 throwing=0 preemptoff= locks=0 dying=0 helpgc=0 spinning=false blocked=false lockedg=-1 M5: p=0 curg=19 mallocing=0 throwing=0 preemptoff= locks=0 dying=0 helpg
代碼誠不欺我也!
參考資料
- 如何定位 golang 進程 hang 死的 bug
- Goroutine調度執行個體簡要分析
- 也談goroutine調度器
- golang的記憶體回收(GC)機制