【譯】最佳化Go的模式

這是一個建立於 的文章，其中的資訊可能已經有所發展或是發生改變。

之前寫過一篇文章《為什麼SignalFx metric proxy通過Go語言開發》，這篇文章將會關注以我們的ingest服務為例，來講述我們是如何最佳化Go代碼的。

SingalFx基於串流分析和時間警示序列，例如應用程式指標，可以為時間序列資料的現代應用開發的進階監控平台（“我的應用程式收到了多少請求？”），還有系統級指標（“我的Linux伺服器使用了多少網路流量？”）。我們使用者流量很大並且粒度很高，每次使用者的流量都要先通過我們的ingest服務才能訪問其它的SignalFx服務。

第一步：啟用pprof

啥是pprof？

pprof是Go語言內建的標準方法用來調試Go程式效能。可以通過HTTP的方式調用pprof包，它能提取出來應用程式的CPU和記憶體資料，此外還有啟動並執行程式碼數和內容資訊。

如何啟用pprof？

你可以通過在你的應用增加一行代碼 import _ "net/http/pprof"，然後啟動你的應用伺服器，pprof就算是啟動了。還有一種方式，就是我們在做SignalFx的時候，為了在外部控制pprof，我們附加了一些處理常式，可以用過路由設定暴露出去，代碼如下：

import "github.com/gorilla/mux"import "net/http/pprof"var handler *mux.Router// ...handler.PathPrefix("/debug/pprof/profile").HandlerFunc(pprof.Profile)handler.PathPrefix("/debug/pprof/heap").HandlerFunc(pprof.Heap)

第二步：找到可以最佳化的代碼

要執行什嗎？

curl http://ingest58:6060/debug/pprof/profile > /tmp/ingest.profilego tool pprof ingest /tmp/ingest.profile(pprof) top7

這是幹嘛的？

Go語言套件含了一個本地的pprof工具來可視化輸出pprof的結果。我們配置的路由/debug/pprof/profile可以收集30秒資料。我上面的操作，第一步是儲存輸出到本地檔案，然後運行儲存後的檔案。值得一提的是，最後一個參數可以直接輸入一個URL來取代檔案（譯者註：go tool pprof ingest http://ingest58:6060/debug/pprof/profile）。 命令top7可以展示消耗CPU最好的7個函數。

結果

12910ms of 24020ms total (53.75%)Dropped 481 nodes (cum <= 120.10ms)Showing top 30 nodes out of 275 (cum >= 160ms)     flat  flat%   sum%        cum   cum%   1110ms  4.62%  4.62%     2360ms  9.83%  runtime.mallocgc    940ms  3.91%  8.53%     1450ms  6.04%  runtime.scanobject    830ms  3.46% 11.99%      830ms  3.46%  runtime.futex    800ms  3.33% 15.32%      800ms  3.33%  runtime.mSpan_Sweep.func1    750ms  3.12% 18.44%      750ms  3.12%  runtime.cmpbody    720ms  3.00% 21.44%      720ms  3.00%  runtime.xchg    580ms  2.41% 23.86%      580ms  2.41%  runtime._ExternalCode

為啥是這個結果

我們可以發現，這些函數我們都沒有直接調用過。然而，mallocgc、sacnobject還有mSpan_Sweep全部都會導致是記憶體回收的時候CPU佔用高。我們可以深入瞭解這些函數，而不是去最佳化Go語言的記憶體回收行程本身，更好的最佳化辦法是我們來最佳化我們代碼裡面使用Go語言的記憶體回收行程的方法。在這個例子中，我們可以最佳化的是減少在堆上面建立對象。

第三步：探究GC的原因

執行啥？

curl http://ingest58:6060/debug/pprof/heap > /tmp/heap.profilego tool pprof -alloc_objects /tmp/ingest /tmp/heap.profile(pprof) top3

做了啥？

可以注意到這次下載的URL和之前的有點像，但是是以/heap結尾的。這個將會給我們提供機器上面堆的使用總結的資料。我再一次儲存成檔案使用者後面的比較。參數-alloc_objects將會可視化應用程式在執行過程中分配的對象數量。

結果

4964437929 of 7534904879 total (65.89%)Dropped 541 nodes (cum <= 37674524)Showing top 10 nodes out of 133 (cum >= 321426216)     flat  flat%   sum%        cum   cum%853721355 11.33% 11.33%  859078341 11.40%  github.com/signalfuse/sfxgo/ingest/tsidcache/tsiddiskcache.(*DiskKey).EncodeOld702927011  9.33% 20.66%  702927011  9.33%  reflect.unsafe_New624715067  8.29% 28.95%  624715067  8.29%  github.com/signalfuse/sfxgo/ingest/bus/rawbus.(*Partitioner).Partition

啥意思？

可以看出，11.33%的對象分配都發生在對象DiskKey的函數EncodeOld裡面，我們預期也是這個結果。然而，沒有料到的是Partition函數佔用了全部記憶體配置的8.29%，因為這個函數只是一些基本的計算，我得著重研究一下這個問題。

第四步：找到為什麼partitioner使用如此多記憶體的原因

執行啥？

(pprof) list Partitioner.*Partition

做了啥？

這個命令可以列印出來我關注的原始碼行，還有就是函數內部哪些代碼引起了堆的記憶體申請。這是pprof裡面許多命令的其中一個。另一個非常有用的是查看調用方和被呼叫者。可以通過help命令查看完整的協助並且都試一試。

結果

Total: 11323262665ROUTINE ======================== github.com/signalfuse/sfxgo/ingest/bus/rawbus.(*Partitioner).Partition in /opt/jenkins/workspace/ingest/gopath/src/github.com/signalfuse/sfxgo/ingest/bus/rawbus/partitioner.go927405893  927405893 (flat, cum)  8.19% of Total        .          .     64: if ringSize == 0 {        .          .     65: return 0, ErrUnsetRingSize        .          .     66: }        .          .     67: var b [8]byte        .          .     68: binary.LittleEndian.PutUint64(b[:], uint64(message.Key.(*partitionPickingKey).tsid))239971917  239971917     69: logherd.Debug2(log, "key", message.Key, "numP", numPartitions, "Partitioning")        .          .     70: murmHash := murmur3.Sum32(b[:])        .          .     71:        .          .     72: // 34026 => 66        .          .     73: setBits := uint(16)        .          .     74: setSize := uint32(1 << setBits)        .          .     75: shortHash := murmHash & (setSize - 1)        .          .     76: smallIndex := int32(shortHash) * int32(k.ringSize) / int32(setSize)687433976  687433976     77: logherd.Debug3(log, "smallIndex", smallIndex, "murmHash", murmHash, "shortHash", shortHash, "Sending to partition")        .          .     78: return smallIndex, nil        .          .     79:}        .          .     80:

啥意思？

這個可以表示debug日誌是引起變數從棧逃逸到堆的原因。因為調試日誌並不是直接需要的，我能夠直接刪掉這些行。但是首先，還是讓我們來確認這個假設。logherd.Debug2函數看起來封裝了如下所示，如果記錄層級debug沒有符合條件，WithField對象並不會調用。

// Debug2 to logger 2 key/value pairs and message.  Intended to save the mem alloc that WithField createsfunc Debug2(l *logrus.Logger, key string, val interface{}, key2 string, val2 interface{}, msg string) {     if l.Level >= logrus.DebugLevel {          l.WithField(key, val).WithField(key2, val2).Debug(msg)     }}

從pprof檢測看起來是傳遞整數到Debug2函數引起的記憶體配置，讓我們進一步確認。

第五步：找到日誌語句引起記憶體配置的原因

執行什麼：

go build -gcflags='-m' . 2>&1 | grep partitioner.go

這個用來幹啥？

通過-m參數編譯可以讓編譯器列印內容到stderr。這包括編譯器是否能夠在棧上面分配記憶體還是一定得將變數放到堆上面申請。如果編譯器不能決定一個變數是否在外部繼續被調用，他會被Go語言放到堆上面。

結果

./partitioner.go:63: &k.ringSize escapes to heap./partitioner.go:62: leaking param: k./partitioner.go:70: message.Key escapes to heap./partitioner.go:62: leaking param content: message./partitioner.go:70: numPartitions escapes to heap./partitioner.go:77: smallIndex escapes to heap./partitioner.go:77: murmHash escapes to heap./partitioner.go:77: shortHash escapes to heap./partitioner.go:68: (*Partitioner).Partition b does not escape./partitioner.go:71: (*Partitioner).Partition b does not escape

注意第77行，smallIndex、murmHash還有shortHash全部逃逸到了堆上面。編譯器為短生命週期的變數在堆上面申請了空間，導致我們在對上建立了很多我們並不需要的對象。

第六步：對partition函數壓測

寫什嗎？

func BenchmarkPartition(b *testing.B) {     r := rand.New(rand.NewSource(0))     k := partitionPickingKey{}     msg := sarama.ProducerMessage {          Key: &k,     }     p := Partitioner{          ringSize: 1024,          ringName: "quantizer.ring",     }     num_partitions := int32(1024)     for i := 0; i < b.N; i++ {          k.tsid = r.Int63()          part, err := p.Partition(&msg, num_partitions)          if err != nil {               panic("Error benchmarking")          }          if part < 0 || part >= num_partitions {               panic("Bench failure")          }     }}

壓測只是簡單的建立了B.N個對象，並且在返回的時候做了一個基本的檢查來確認對象不會被簡單的最佳化掉。我們推薦當程式員在最佳化代碼之前編寫壓測代碼來確保你在朝著正確的方向進行。

第七步：對partition函數壓測記憶體配置

執行啥？

go test -v -bench . -run=_NONE_ -benchmem BenchmarkPartition

做了啥？

壓測會按照正則匹配符合“.”條件的函數，-benchmen將會追蹤每次迴圈的堆使用平均情況。通過傳遞參數-run=_NONE_，我可以節約一些時間，這樣測試只會運行有“NONE”字串的單元測試。換句話說，不下運行任何一個單元測試，只運行全部的壓力測試。

結果

PASSBenchmarkPartition-8 10000000       202 ns/op      64 B/op       4 allocs/op

意味著啥？

每一次迴圈消耗平均202ns，最重要的是，每個操作有4次對象分配。

第八步：刪掉日誌語句

咋寫？

@@ -66,7 +65,6 @@ func (k *Partitioner) Partition(message *sarama.ProducerMessage, numPartitions i       }       var b [8]byte       binary.LittleEndian.PutUint64(b[:], uint64(message.Key.(*partitionPickingKey).tsid))-       logherd.Debug2(log, "key", message.Key, "numP", numPartitions, "Partitioning")       murmHash := murmur3.Sum32(b[:])       // 34026 => 66@@ -74,7 +72,6 @@ func (k *Partitioner) Partition(message *sarama.ProducerMessage, numPartitions i       setSize := uint32(1 << setBits)       shortHash := murmHash & (setSize - 1)       smallIndex := int32(shortHash) * int32(k.ringSize) / int32(setSize)-       logherd.Debug3(log, "smallIndex", smallIndex, "murmHash", murmHash, "shortHash", shortHash, "Sending to partition")       return smallIndex, nil}

幹了什嗎？

我的修複方式是刪除日誌代碼。測試期間/調試期間，我增加了這些調試代碼，但是一直沒有刪掉它們。這種情況下，刪掉這些代碼最簡單。

第九步：重新編譯評估是否變數逃逸到了堆

如何執行？

go build -gcflags='-m' . 2>&1 | grep partitioner.go

結果

./partitioner.go:62: &k.ringSize escapes to heap./partitioner.go:61: leaking param: k./partitioner.go:61: (*Partitioner).Partition message does not escape./partitioner.go:67: (*Partitioner).Partition b does not escape./partitioner.go:68: (*Partitioner).Partition b does not escape

意味著什嗎？

可以發現smallIndex、murmHash和shortHash變數不在有逃逸到堆的訊息。

第十步：重新壓測評估每個操作的記憶體配置情況

如何執行？

go test -v -bench . -run=_NONE_ -benchmem BenchmarkPartition

結果

PASSBenchmarkPartition-8 30000000        40.5 ns/op       0 B/op       0 allocs/opok   github.com/signalfuse/sfxgo/ingest/bus/rawbus 1.267s

啥意思？

注意到每個操作只消耗40ns，更重要的是，每個操作不再有記憶體配置。因為我是準備來最佳化堆，這對我來說很重要。

結束語

pprof是非常有用的工具來剖析Go代碼的效能問題。通過結合Go語言內建的壓測工具，你能夠得到關於代碼改變引起的變化的真正的數字。不幸的是，效能衰退會隨著時間而攀升。下一步，讀者可以練習，儲存benchmark的結果到資料庫，這樣你可以在每一次代碼提交之後查看代碼的效能。

原文連結：【譯】最佳化Go的模式，轉載請註明來源！