誰偷了1/3個CPU - 詭異Go性能問題追根問底

看到過很多文章介紹本身CPU佔用惡高甚至接近100%，其實那到反而清楚無遺漏了，無非哪一個busy loop卡住了。這裏爲你們描述一個近期遇到的Go程序在空閒時候依舊在top命令裏總報告30%左右CPU佔用的問題，這樣的性能問題更隱蔽更難琢磨。

問題發生在我本身作的高性能多組Raft庫Dragonboat裏，這是一個Apache2開源的Go實現的多組Raft庫，它的主打就是吞吐性能吊打竟品幾十倍。由於性能是核心賣點，所以每一個函數的CPU耗費都瞭如指掌，直到有一天忽然發現系統空載的時候佔用一個CPU核的30%的負載，以下圖：

服務器程序空閒的時候，top中看到的cpu負載一般應該是個位數低位。深刻分析之後發現是一個較深的Go調度實現的問題。

觀察

看到上述top的結果，strace -c 看了一下，不少futex。多啓動幾個這樣的空閒進程，抓個火焰圖看，它是這樣的：

必須得假設您對Go近期版本(如1.8-1.11)的調度有必定基本瞭解，瞭解M、P、G三者的意義和做用。如暫時不瞭解，可參考本文或者該文的中文翻譯。

火焰圖中能夠觀察到幾點：

• 讓當前M去sleep的操做挺重的，它由tickWorkerMain試圖去讀一個channel引起
• runtime.futex的數據和上面提到的strace所報告的狀況吻合

查看代碼，Dragonboat庫tickWorkerMain中有一個1khz的ticker，等於每秒讀ticker.C這個channel 1000次。當時第一感受是有些疑惑，由於常識告訴我，一個簡單的非嚴格1khz的低頻ticker，在3Ghz左右的服務器處理器上，cpu佔用應該在1-2%這樣極低的佔用才合理。只是但願程序某個函數被一秒調用1000次，怎麼就佔用掉近30%的cpu？

先無論成因，孤立出這個問題點來看看。爲了實現「程序某個函數被一秒調用1000次」這點，在Go中用ticker能夠這麼作：

package main

import (
    "time"
)

func main() {
    ticker := time.NewTicker(time.Millisecond)
    defer ticker.Stop()
    for range ticker.C {
    }
}

結果上述程序top報告25%的%CPU值。是Go的ticker實現的問題嗎？換sleep循環看看：

package main

import (
    "time"
)

func main() {
    for {
        time.Sleep(time.Millisecond)
    }
}

運行上述time.Sleep程序，top報告15%的%CPU。這和一樣一個sleep循環的C++在1%的%CPU有天壤之別。因而開始傾向因而Go的調度器的鍋。

分析

再回到上述火焰圖，park_m()後一連串操做很顯眼。咱們已經知道M表示Machine，一般認爲是一個OS Thread，park_m()後續stopm()顧名思義就是這個把當前M給停用掉，告訴系統這個M暫時不用。

一切彷佛開始明朗了。每次tickWorkerMain開始等下一個tick的時候，也就是去讀ticker.C這個channel的時候都由於時間沒到channel爲空，當前goroutine會被park掉，這個操做很輕，只須要更改一個標誌。而此時由於系統空閒，並無別的goroutine可供調度，Go的scheduler就必須讓這個M去sleep，而這個操做是較重的且有鎖，最終futex的syscall被調用。更具體的，這還和Go的後臺timer實現、system monitor實現有關（注意火焰圖中runtime.sysmon），這裏不展開。人人都會告訴你協程調度是很輕的操做，這固然沒錯。但他們都沒有告訴你更重要的一點：協程調度反覆高頻出現沒有goroutine可供調度的代價在Go的當前實現裏是顯著的。

必須指出，本問題是由於系統空閒沒有goroutine能夠調度形成的。顯然的，系統繁忙的時候，即CPU資源真正體現價值時，上述30%的%CPU的overhead並不存在，由於大機率下會有goroutine可供調度，無需去作讓M去sleep這個很重的操做。

而這一問題的影響是具體客觀的：

• 用戶會反覆提問爲什麼系統空閒時佔30%的%CPU，空閒時進程在top裏始終排頂部不是個好事
• 在一個慢速的用電池的ARM核上有這東西就麻煩了

cgo解決

咱們也已經知道，C/C++作一樣的事代價很輕。若是從不改業務邏輯出發，首先想到的就是不讓M去sleep，不發生無goroutine可調度的狀況。好比，能夠用一個OS線程經過cgo獨立於scheduler地去產生這個1kHz的tick，每秒從C代碼去調用1000次所需的Go函數。這個思路很容易實現，無非是從Go代碼裏調用一個C函數，這個C函數每秒1000次的從sleep中醒來去調用Go裏的1khz的tick的處理函數，具體就不貼具體代碼了。

用這個思路修改了Dragonboat的代碼一跑，空閒時的cpu負載大幅下降：

 

結果

上述workaround已經讓這一問題對本身軟件的影響極大下降了。去golang-nuts吐槽一下，再報golang的issue tracker，根本的問題仍是Go Scheduler的實現。用戶用1kHz的ticker不該該是這樣大費周章，標準庫、runtime上直接提供更高效的實現纔是真正解決方案。

 

在Dragonboat的開發中，這樣的performance regression幾乎每週都發生。從一秒十萬次吞吐到一秒一千萬吞吐的進化，是算法協議不斷理解的深刻，也是對Go runtime習性的不斷熟悉的一個過程。後面陸續會風向大量這樣的性能優化實踐知識，均以目前互聯網後臺最熱門Golang爲語言，素材均爲任何應用均會涉及的通用場景。做爲最好的教材，歡迎你們試用Dragonboat，也請你們點Star支持它的持續開發。