1. 程式人生 > 程式設計 >記一次golang程式CPU高的排查過程

記一次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生產和開發的程式的配置有哪些不同,說不定可以更快的解決問題。

參考文章