10 年前，谷歌遇到一個(gè)由 C++ 編譯時(shí)間過長(zhǎng)造成的嚴(yán)重瓶頸，他們需要全新的解決方案。為應(yīng)對(duì)這一挑戰(zhàn)，谷歌工程師創(chuàng)建了一種叫 Go（又名 Golang）的新編程語言。Go 語言借鑒了 C++ 的優(yōu)點(diǎn)（比如其性能和安全特性），同時(shí)結(jié)合了 Python 的開發(fā)速度，這讓其能快速使用多個(gè)核心，實(shí)現(xiàn)并發(fā)計(jì)算。
在 Coralogix，我們解析客戶日志來為它們提供相應(yīng)的實(shí)時(shí)分析、警報(bào)和元數(shù)據(jù)等。為做到這一點(diǎn)，解析階段必須非常快，但解析階段卻又非常復(fù)雜，并需要為每一個(gè)日志行服務(wù)加載大量規(guī)則。這是我們覺得采用 Golang 的原因之一。
這項(xiàng)新服務(wù)全天候運(yùn)行在我們的生產(chǎn)環(huán)境中。雖然結(jié)果很不錯(cuò)，但是它仍然需要運(yùn)行在高性能的機(jī)器上。這個(gè) Go 服務(wù)運(yùn)行在一臺(tái) 8 核 CPU 和 36GB 內(nèi)存的 AWS m4.2xlarge 實(shí)例上，每天解析超過數(shù)百億的日志。
這個(gè)階段，一切運(yùn)行正常，可以將就，但這不是我們的風(fēng)格，我們希望用更少的 AWS 實(shí)例來提供更多的功能，比如性能等。為實(shí)現(xiàn)這一目標(biāo)，我們需要了解瓶頸的本質(zhì)，以及如何能減少或完全消除它們。
問題分析
我們決定在服務(wù)上運(yùn)行一些性能分析，并檢查是什么導(dǎo)致 CPU 的高消耗，看看是否可以做些優(yōu)化工作。
升級(jí)版本
首先，我們將 GO 升級(jí)到最新的穩(wěn)定版本（軟件生命周期中的關(guān)鍵一步）。此前，我們的版本是 1.12.4，現(xiàn)在用的是 1.13.8。
根據(jù)官方文檔，1.13 版本在 runtime library 和一些對(duì)內(nèi)存使用有很大影響的組件進(jìn)行了重大改進(jìn)。不管怎么說，使用最新的穩(wěn)定版本很有意義，并且為我們節(jié)省了很多工作。
因此，內(nèi)存消耗也從 800MB 左右優(yōu)化到 180MB 左右。
分析開始
其次，為更好地理解我們的工作流程，并了解我們?cè)谀睦锘ㄙM(fèi)時(shí)間和資源，我們開始進(jìn)行分析。
分析不同的服務(wù)和編程語言可能看起來非常復(fù)雜并令人生畏，但是在 Go 中，它實(shí)際上非常簡(jiǎn)單，僅用幾個(gè)命令就可以實(shí)現(xiàn)。Go 有一個(gè)叫 "pprof" 的專門工具，可以通過監(jiān)聽路由（默認(rèn)端口為 6060）在應(yīng)用程序中啟用該工具，并使用 Go 包來管理 HTTP 連接：
復(fù)制代碼
import _ "net/http/pprof"
然后，在主函數(shù)或者路由包中啟用如下操作:
復(fù)制代碼
go func() { log.Println(http.ListenAndServe("localhost:6060",nil))}()
現(xiàn)在我們可以啟動(dòng)服務(wù)并連接到
復(fù)制代碼
Http://localhost:6060/debug/pprof
完整的 Go 文檔可以參閱此處。
pprof 的默認(rèn)配置是每隔 30 秒對(duì) CPU 使用率進(jìn)行采樣。我們可以調(diào)整一些配置從而實(shí)現(xiàn)對(duì) CPU 使用率、heap usage 等參數(shù)的采樣。我們主要關(guān)注的是 CPU 的使用情況，因此在生產(chǎn)階段中，我們采取一個(gè) 30 秒間隔的性能采樣，并發(fā)現(xiàn)下圖中的顯示內(nèi)容（注意：這是在我們升級(jí)了 Go 版本并將 Go 的內(nèi)部組件降到最低之后的結(jié)果）：
Go profiling
如你所見，我們發(fā)現(xiàn)很多與運(yùn)行時(shí)庫(kù)（runtime package ）相關(guān)的活動(dòng)，其中需要特別指出是 GC（垃圾收集）：幾乎 29% 的 CPU 被 GC 使用，這還只是消耗最多的前 20 個(gè)對(duì)象。由于 Go 的 GC 已經(jīng)非?？觳⒆隽撕艽髢?yōu)化，最好的實(shí)踐就是不要去改變或修改它。由于我們的內(nèi)存消耗非常低（與前一個(gè) Go 版本相比），所以主要問題變成了高對(duì)象分配率。
如果是這樣的話，我們可以做兩件事情：
- 調(diào)整 Go GC 活動(dòng)來適應(yīng)我們的服務(wù)行為，也就是說，我們需要延遲 GC 的觸發(fā)來減少其運(yùn)行頻率。作為代價(jià)，我們將不得不消耗更多的內(nèi)存。
- 找出代碼中分配了太多對(duì)象的函數(shù)、區(qū)域或行。
觀察一下實(shí)例類型，我們有大量的空閑內(nèi)存，而 CPU 數(shù)量則被機(jī)器類型所限制。因此我們需要調(diào)整這個(gè)比率。從 Golang 早期開始，就有一個(gè)閥值（flag）被大多數(shù)開發(fā)人員所忽視：GOGC。該閥值的缺省值為 100，它的主要工作就是告訴系統(tǒng)何時(shí)觸發(fā) GC。當(dāng)堆達(dá)到其初始大小的 100% 時(shí)，默認(rèn)值將觸發(fā) GC 進(jìn)程。將默認(rèn)值更改為更高數(shù)字則延遲 GC 觸發(fā)，反之，將更快地觸發(fā) GC。我們開始針對(duì)不同的數(shù)值進(jìn)行基準(zhǔn)測(cè)試，最終發(fā)現(xiàn)當(dāng) GOGC=2000 時(shí)，我們能獲得最佳性能。
這將我們的內(nèi)存使用量從 200 MB 立刻增加到 2.7 GB（這還是在我們更新 Go 版本減少了內(nèi)存消耗之后），并將我們的 CPU 使用率降低 10%。
下面的截圖展示了這些基準(zhǔn)測(cè)試的結(jié)果:
Gogc=2000 的結(jié)果
CPU 使用率排名前 4 的函數(shù)變成了我們的服務(wù)函數(shù)，這才說得過去?，F(xiàn)在，總的 GC 使用量變成了約 13%，比之前的一半還少。
繼續(xù)深入
我們本可以就此打住，但我們還是決定繼續(xù)去調(diào)查分配這么多對(duì)象的位置以及原因。很多時(shí)候，分配對(duì)象都有一個(gè)很好的理由（例如在流處理的情況下，我們?yōu)槊織l消息都創(chuàng)建了很多新對(duì)象，因?yàn)樗c下一條消息無關(guān)，需要移除它），但在某些情況下，有一種簡(jiǎn)單的方法可以優(yōu)化并極大地減少對(duì)象創(chuàng)建。
首先，讓我們運(yùn)行一個(gè)和之前相同的命令，只做一個(gè)小小的變動(dòng)，采用 heap dump：
復(fù)制代碼
Http://localhost:6060/debug/pprof/heap
為了查詢結(jié)果文件，我們可以在代碼文件目錄中運(yùn)行如下命令來分析調(diào)試結(jié)果：
復(fù)制代碼
go tool pprof -allocobjects <HEAP.PROFILE.FILE>
我們的截圖看起來是這樣的:
除第三行外，一切似乎都很合理。第三行是一個(gè)監(jiān)控函數(shù)，在每個(gè) Coralogix 規(guī)則解析階段的末尾向我們的 Promethes 導(dǎo)出者（exporter）輸出報(bào)告。為獲取進(jìn)一步的信息，我們運(yùn)行以下命令:
復(fù)制代碼
list <FunctionName>
例如：
復(fù)制代碼
list reportRuleExecution
然后，我們得到以下結(jié)果：
這兩個(gè)對(duì) WithLabelValues 的調(diào)用其實(shí)是針對(duì)度量的 Prometheus 調(diào)用（我們讓產(chǎn)品來決定是否真的需要它）。此外，我們看到第一行創(chuàng)建了大量對(duì)象（占該函數(shù)總分配對(duì)象的 10%）。通過進(jìn)一步研究，我們發(fā)現(xiàn)這是一個(gè)將客戶 ID 從 int 轉(zhuǎn)換為 string 的過程。該過程非常重要，但考慮到數(shù)據(jù)庫(kù)中的客戶數(shù)量有限，我們不應(yīng)該為迎合 Prometheus 而將變量作為字符串接收。因此，我們沒有在每次創(chuàng)建一個(gè)新字符串并在函數(shù)結(jié)束時(shí)丟棄它（浪費(fèi)了分配時(shí)間和 GC 的更多工作），而是在對(duì)象初始化時(shí)定義了一個(gè)映射，映射了從 1 到 10 萬之間的所有數(shù)字以及一個(gè)相對(duì)應(yīng)的”get”操作。
我們運(yùn)行了一個(gè)新的性能分析會(huì)話來驗(yàn)證上述論點(diǎn)，結(jié)果證明它是正確的（我們可以看到這部分不再分配對(duì)象了）:
這并不是一個(gè)非常大的改動(dòng)，但總的來說，這為我們節(jié)省了另一個(gè) GC 活動(dòng)，更具體地說，大約 1% 的 CPU 使用率。
最終狀態(tài)顯示在下面的截圖中：
最終結(jié)果
內(nèi)存使用：~1.3GB -> ~2.7GB
CPU 使用：~2.55 均值和~5.05 峰值 -> ~2.13 均值和~2.9 峰值。
Golang 優(yōu)化之前的 CPU 使用率：
Golang 優(yōu)化之后的 CPU 使用率：
總的來說，我們的改進(jìn)主要體現(xiàn)在峰值時(shí)間段，每秒處理的日志數(shù)量提升了。這意味著我們的基礎(chǔ)設(shè)施不再需要針對(duì)異常值進(jìn)行調(diào)優(yōu)，而且變得更加穩(wěn)定。
總結(jié)
通過分析 Go 解析服務(wù)，我們能定位出問題區(qū)域，更好地理解我們的服務(wù)，并決定在哪里（如果有的話）投入時(shí)間來做改進(jìn)工作。大多數(shù)性能分析工作最終都會(huì)參照用戶使用情況對(duì)閥值或配置進(jìn)行調(diào)優(yōu)，從而獲得更好的性能。
