1. 程式人生 > >Golang應用效能問題排查分析

Golang應用效能問題排查分析

## 背景 公司有一個使用golang開發的採集模組,負責呼叫多個外部系統採集資料;最近做了一次架構上的調整,將採集模組分成api、job兩個子模組,並部署到容器中,拆分前部署在虛機上。 ## 現象 部分採集任務在容器中的執行時間比虛機中執行時間要長,8倍左右,本地測試無異常 ## 排查思路 ### 呼叫外部介面耗時過長? 只有部分任務執行時間長,懷疑容器呼叫那部分系統介面比較慢,於是在容器中curl外部介面介面,發現並不慢,排除這個可能。 ### 程式問題? 將現有部署在虛機中的正常執行的應用,部署到容器中發現部分任務也會慢; 將部署在容器中的應用部署到虛機後恢復了正常;懷疑是容器本身或容器網路的問題,一時想不到是什麼原因,於是開始了漫長的定位 ### pprof > pprof是golang提供的效能分析工具之一,採集模組已經引入pprof,首先使用它進行排查; (1). 在容器中安裝pprof/flamegraph1 (2). 在容器中執行如下命令,開啟pprof的http服務 ![](https://img2020.cnblogs.com/blog/1352870/202101/1352870-20210120220133610-789115542.png) (3).輸入上述http地址 * 檢視cpu profiler ![](https://img2020.cnblogs.com/blog/1352870/202101/1352870-20210120220142242-909155082.png) >
沒有什麼太大異常,只有少許執行邏輯消耗一秒多 * 查看了top/flame graph都沒有檢視到什麼異常 ![](https://img2020.cnblogs.com/blog/1352870/202101/1352870-20210120220147657-1478735766.png) ![](https://img2020.cnblogs.com/blog/1352870/202101/1352870-20210120220151609-1264039031.png) > pprof中可以檢視以下幾類資訊 > - cpu(CPU Profiling): \$HOST/debug/pprof/profile,預設進行 30s 的 CPU Profiling,得到一個分析用的 profile 檔案 >
- block(Block Profiling):\$HOST/debug/pprof/block,檢視導致阻塞同步的堆疊跟蹤 > - goroutine:\$HOST/debug/pprof/goroutine,檢視當前所有執行的 goroutines 堆疊跟蹤 > - heap(Memory Profiling): \$HOST/debug/pprof/heap,檢視活動物件的記憶體分配情況 > - mutex(Mutex Profiling):\$HOST/debug/pprof/mutex,檢視導致互斥鎖的競爭持有者的堆疊跟蹤 > - threadcreate:\$HOST/debug/pprof/threadcreate,檢視建立新OS執行緒的堆疊跟蹤 由於跟網路有關係,所以想檢視下io耗時,pprof無法實現我的需求,想到可以使用trace觀察 >
期間又使用go-torch採集火焰圖資料並檢視,與pprof類似,感興趣的同學可自行嘗試 ### trace > trace也是go tool效能問題分析工具之一 (1) 開啟trace ![](https://img2020.cnblogs.com/blog/1352870/202101/1352870-20210120220212474-415373834.png) ![](https://img2020.cnblogs.com/blog/1352870/202101/1352870-20210120220243927-710451425.png) 主要有以下幾塊:Goroutine、網路阻塞、同步鎖、同步阻塞等 ![](https://img2020.cnblogs.com/blog/1352870/202101/1352870-20210120223052691-1729711601.png) (2) 觀察網路IO ![](https://img2020.cnblogs.com/blog/1352870/202101/1352870-20210120220250768-387145236.png) 一下子看到了60多秒,心裡一陣竊喜,但從第一個節點開始已經是50多秒了,仍然不知道是什麼原因造成的。又看了gorouting部分 ![](https://img2020.cnblogs.com/blog/1352870/202101/1352870-20210120220304276-1003371504.png) 看到network wait那一列耗時佔比非常大,心裡又是一陣竊喜,基本確定是網路的問題了,點選某一個gorouting進入grouting頁面,再根據慢的任務名稱找到相應gorouting,點選進入到trace頁面 ![](https://img2020.cnblogs.com/blog/1352870/202101/1352870-20210120220316596-124478263.png) 由於network佔用大多數時間,連續點了靠後的幾個綠條,發現最後一條語句一樣,到程式碼中檢視,發現是呼叫redis的程式碼,於是在容器中ping redis伺服器,又在虛機中ping,發現容器ping的響應時間是虛機的26倍左右;想到公司的伺服器分多地部署,於是又查虛機、redis、容器的部署地域,發現虛機和redis在同一地域,而容器和redis伺服器不在同一地域,這時才恍然大悟,後面的解決辦法就簡單了,不在此贅述了; ## 總結 分析問題要從大到小,逐漸縮小範圍,不能一上來就進入細節,這樣會耗時較長。開始我懷疑是虛機網路問題,排查了外部系統介面,但遺漏了redis,造成後面花了幾個小時仔細排查。其實也是情有可原吧,這個採集模組程式碼細節我並不熟悉,我的語言技術棧主要是Java,對golang語言不太熟悉,只因負責這個模組開發的同學束手無策,我是這個專案的負責人,只能趕鴨子上架了