背景
公司有一個使用golang開發的采集模塊,負責調用多個外部系統采集數據;最近做了一次架構上的調整,將采集模塊分成api、job兩個子模塊,並部署到容器中,拆分前部署在虛機上。
現象
部分采集任務在容器中的執行時間比虛機中執行時間要長,8倍左右,本地測試無異常
排查思路
調用外部接口耗時過長?
只有部分任務執行時間長,懷疑容器調用那部分系統接口比較慢,於是在容器中curl外部接口接口,發現並不慢,排除這個可能。
程序問題?
將現有部署在虛機中的正常運行的應用,部署到容器中發現部分任務也會慢; 將部署在容器中的應用部署到虛機后恢復了正常;懷疑是容器本身或容器網絡的問題,一時想不到是什么原因,於是開始了漫長的定位
pprof
pprof是golang提供的性能分析工具之一,采集模塊已經引入pprof,首先使用它進行排查;
(1). 在容器中安裝pprof/flamegraph1
(2). 在容器中執行如下命令,開啟pprof的http服務
(3).輸入上述http地址
- 查看cpu profiler
沒有什么太大異常,只有少許執行邏輯消耗一秒多
- 查看了top/flame graph都沒有查看到什么異常
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
主要有以下幾塊:Goroutine、網絡阻塞、同步鎖、同步阻塞等
(2) 觀察網絡IO
一下子看到了60多秒,心里一陣竊喜,但從第一個節點開始已經是50多秒了,仍然不知道是什么原因造成的。又看了gorouting部分
看到network wait那一列耗時占比非常大,心里又是一陣竊喜,基本確定是網絡的問題了,點擊某一個gorouting進入grouting頁面,再根據慢的任務名稱找到相應gorouting,點擊進入到trace頁面
由於network占用大多數時間,連續點了靠后的幾個綠條,發現最后一條語句一樣,到代碼中查看,發現是調用redis的代碼,於是在容器中ping redis服務器,又在虛機中ping,發現容器ping的響應時間是虛機的26倍左右;想到公司的服務器分多地部署,於是又查虛機、redis、容器的部署地域,發現虛機和redis在同一地域,而容器和redis服務器不在同一地域,這時才恍然大悟,后面的解決辦法就簡單了,不在此贅述了;
總結
分析問題要從大到小,逐漸縮小范圍,不能一上來就進入細節,這樣會耗時較長。開始我懷疑是虛機網絡問題,排查了外部系統接口,但遺漏了redis,造成后面花了幾個小時仔細排查。其實也是情有可原吧,這個采集模塊代碼細節我並不熟悉,我的語言技術棧主要是Java,對golang語言不太熟悉,只因負責這個模塊開發的同學束手無策,我是這個項目的負責人,只能趕鴨子上架了😃。一遇到問題,我就有一種莫名的小激動,因為遇到了我未知的領域,又有機會對技術有更深入的了解了。喜歡我文章的同學歡迎關注公眾號哦,不定期分享干貨!