記一次golang程式CPU高的排查過程
前言
事情的起因是某天CTO突然和我說,生產環境的程式CPU有點高,關鍵是現在也沒什麼負載,同樣的程式碼在開發環境上CPU就低的多了。
不用細說,那一定是有什麼地方出問題了。
CTO還說,他pprof過了,佔用CPU最高的runtime.futex,還發了一篇相關的文章誰佔了該CPU核的30% - 一個較意外的Go效能問題 ,打趣說沒準系統負載高了,這個問題就沒了。因為原文中寫到:
必須指出,本問題是因為系統空閒沒有goroutine可以排程造成的。顯然的,系統繁忙的時候,即CPU資源真正體現價值時,上述30%的%CPU的overhead並不存在,因為大概率下會有goroutine可供排程,無需去做讓M去sleep這個很重的操作。
然後就把這個鍋就“甩”給我了,讓我研究一下。畢竟開發環境的負載也沒有那麼高,但是CPU卻蠻正常的。
分析
一開始我是沒什麼頭緒,順著CTO提供的線索,搜尋了一些runtime.futex的文章,幾乎所有文章都會提到以下可能會使CPU佔用率高的示例程式碼:
var ticker = time.NewTicker(100 * time.Millisecond)
defer ticker.Stop()
var counter = 0
for {
select {
case <-serverDone:
return
case <-ticker.C:
counter += 1
}
}
複製程式碼
這段程式碼給我指明瞭一些方向,我開始全域性搜尋一些time.NewTicker的程式碼。
巧的是,還真讓我搜到了一些,其中一個ticker的時間設定的很有問題。
options = append(options,metrics.BatchInterval(time.Duration(conf.BatchInterval)))
複製程式碼
這裡的time.Duration(conf.BatchInterval)沒有指定單位,那可就是nano second(納秒)級別的,這ticker的協程跑起來,沒造成死鎖,只能說linux伺服器的效能好。
後來,順藤摸瓜,發現了這個interval其實是promethus的取樣interval,promethus只在生產開啟了,也可以解釋了為什麼同樣的程式碼只在生產上出問題。
解決方法
初步的解決方法很簡單,就是給這個interval加上單位,再略微調大一些就好,而且目前我們並沒有太重視promethus的效能資料,所以也不是很確定50ms的取樣間隔是不是有些過大。
總結
雖說找到了問題的root cause,但還是有值得改進的地方,比如說,如果一開始就先diff生產和開發的程式的配置有哪些不同,說不定可以更快的解決問題。