Go的代碼調優一例

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

用tcpcopy導的線上流量，活動資料庫也是真實的資料，這是我抓的一份pprof：

genius@geniuss-Macbook-air:~/project/src/dsp_masky $go tool pprof ls.prof Welcome to pprof!  For help, type 'help'.(pprof) topTotal: 14413 samples    1342   9.3%   9.3%     1342   9.3% strconv.ParseUint    1243   8.6%  17.9%     1243   8.6% runtime.duffcopy    1082   7.5%  25.4%     5067  35.2% dsp_masky/model/bid.(*BidServer).FilterByCampaign    1073   7.4%  32.9%     1824  12.7% runtime.mallocgc     638   4.4%  37.3%      638   4.4% runtime.MSpan_Sweep     555   3.9%  41.2%      555   3.9% settype     547   3.8%  45.0%      547   3.8% runtime.mapaccess2_fast64     513   3.6%  48.5%     1855  12.9% strconv.ParseInt     376   2.6%  51.1%      452   3.1% regexp.(*machine).add     337   2.3%  53.5%     2418  16.8% dsp_masky/model.regionQuery

消耗排前三的函數分別是ParseUint，duffcopy，FilterByCampaign。下面一條一條的分析。

最佳化duffcopy

我查了一下duffcopy這個函數，是一個類似memcopy的函數，將記憶體從一塊複製到另一塊。這個函數並沒有由runtime中的任何庫函數調用到，它是編譯器產生的程式碼直接調用的。 為什麼duffcopy如此之高？我在看mentor的編程習慣的時候找到了原因：

var RCampaign map[int64]Campaign

RCampaign是一個全記憶體的活動資料庫，注意到它使用的儲存是Campaign而不是*Campaign，其中Campaign的定義是這樣子的，很大的一個結構體：

type Campaign struct {    Id                int64    Plan              CPlan    PublisherId       int    CreateUserId      int64    WardenStatus      int    Zone              []Zone    IpSections        []IpSection    ChannelId         int64    AdxId             int64    CategoryId        []int    TopPrice          float64    SubPrice          SubCharge    PositionPrice     map[int64]ChargePrice    ChargePrice       float64    ChargeType        int    Gaga              FilterGaga    MediaFilter       MediaFilter    OType             int    FrequencyFilters  []model.FrequencyFilter    AMonit            []string    Character         []model.ActionTerm    ...}

mentor平素是這樣子寫代碼的：

func ConvertCampaign(campaignInfo model.Campaign) (campaign Campaign, err error) {  //直接返回這麼大的結構體campaigns[Id] = campaign    //直接整個結構體賦值到map中

類似的例子還有很多，這些都會造成整份的資料拷貝，正是這樣的編程習慣導致了duffcopy函數消耗了8.6%的CPU！

推薦的一個好的習慣是，稍大的類型存到map都儲存指標而不是值。

下面是優掉掉duffcopy之後抓的一份pprof：

Total: 12507 samples    1739  13.9%  13.9%     1739  13.9% strconv.ParseUint    1290  10.3%  24.2%     8282  66.2% dsp_masky/model/bid.(*BidServer).FilterByCampaign     813   6.5%  30.7%      906   7.2% runtime.mapaccess2_fast64     705   5.6%  36.4%     2444  19.5% strconv.ParseInt     440   3.5%  39.9%      523   4.2% regexp.(*machine).add     402   3.2%  43.1%     1202   9.6% hash_insert     394   3.2%  46.2%     3136  25.1% dsp_masky/model.regionQuery     305   2.4%  48.7%     2737  21.9% strconv.Atoi     305   2.4%  51.1%      316   2.5% syscall.Syscall     288   2.3%  53.4%     1027   8.2% runtime.mallocgc

最佳化ParseUint

這是我們即時競價服務，每秒會有大量的請求到達。在每一次請求中，需要遍曆所有活動，挑選出跟這次曝光機會相匹配的，參與競價。其中有一項是地區資訊，請求中會包含IP來源。而活動中是有地區資訊，通過IP查詢到使用者所屬地區，然後跟活動中地區進行比較。

問題出在地區使用的結構體上，活動中儲存是用string表示的：

type Zone struct {    CountryId string    RegionId  string    CityId    string}

而由IP得到的地區是用int表示的。所以比較兩者是否匹配時，會用strconv.Atoi進行轉換，這個函數調用了ParseUint。

當前的活動數量是2000，其中實際參與比較的是400個，然後每次比較會調用三次字串轉換操作，假設QPS當前是1500，那麼400*3*1500將產生1,800,000次的ParseUint調用。這就是ParseUint函數會佔用這麼高CPU的原因了。

所以，我將Zone的儲存結構調整為int後，避免了ParseUint函數。最佳化掉ParseUint之後，得到的pprof是這樣子的：

(pprof) topTotal: 4554 samples     426   9.4%   9.4%      480  10.5% runtime.mapaccess2_fast64     232   5.1%  14.4%     1768  38.8% dsp_masky/model/bid.(*BidServer).FilterByCampaign     216   4.7%  19.2%      216   4.7% syscall.Syscall     183   4.0%  23.2%      213   4.7% hash_insert     167   3.7%  26.9%      167   3.7% ExternalCode     141   3.1%  30.0%      222   4.9% runtime.mallocgc     121   2.7%  32.6%      121   2.7% runtime.futex     115   2.5%  35.2%      136   3.0% evacuate     112   2.5%  37.6%      112   2.5% runtime.MSpan_Sweep     103   2.3%  39.9%      103   2.3% runtime.aeshash64

剛拿到代碼的時候觀察，極限的時候大概會有2000多一點的QPS，在最高的流量壓力下CPU佔用甚至會超過700%，而做完這兩個做化之後，再也沒看到過CPU跑到500%以上。

幹掉defer

mapaccess2_fast64是由於v, ok := m[key]這種形式的map訪問產生的。當前代碼中非常大量地使用了map資料結構，而我看了一下相應的代碼，大多使用都屬於合理的範疇，所以這個方向很難最佳化下去。也許換成自己實現的hash會帶來一定的提升，但是吃力不討好的事情，暫時放著。

至於FilterByCampaign，對於每個曝光機會，需要與所有的活動的設定進行匹配，進行過濾，裡面有一個大的for range迴圈很耗效能。除非演算法層級的最佳化，否則這個大迴圈都避不開。但我暫時還沒想到一個好的演算法。

有點進展不順了，於是去與mentor討論。mentor提到，在加入了調價的一個更新之後，系統的CPU從原來的200%升到了400%的樣子，讓我可以去查一下這條路徑的代碼。然後我看到了defer，立馬眼睛亮了：

 func (this *Campaign) GetPrice(positionId, size, host int64, b *BidServer) (price float64, err error) {     ...     defer func() {         ...     }()     ...     if err != nil {         return     }     return }

這裡有個明顯的使用不當：如果返回err不為空白，直接返回就可了，完全不需要執行defer函數，所以代碼不應該這麼寫。而且，defer調用會有一定的開銷。簡要地說一下，首先defer需要把參數之類的東西先封裝進一下結構體，跟函數一起，成為一個閉包，儲存到defer鏈中。然後在函數返回時還會有一個defer鏈表的處理，以棧的順序調用執行閉包函數。對於defer的記憶體回收等，也會有特殊的一些處理，總之，影響挺大。

GetPrice函數是代碼路徑中一個必然調用的函數，雖然沒有迴圈，但是QPS上去之後，效能影響不可小噓。最佳化完這裡後觀察，在大概1000左右QPS環境下，CPU使用率從最佳化前的200%左右，下降到了120%左右。

defer是效能殺手，我的原則是能不用盡量避開。

time.Date

現在看pprof是這樣的：

(pprof) topTotal: 3348 samples     254   7.6%   7.6%      266   7.9% syscall.Syscall     177   5.3%  12.9%      221   6.6% hash_next     168   5.0%  17.9%     1320  39.4% dsp_masky/model/bid.(*BidServer).FilterByCampaign     153   4.6%  22.5%      369  11.0% runtime.mallocgc     153   4.6%  27.0%      194   5.8% runtime.mapaccess2_fast64     113   3.4%  30.4%      113   3.4% time.absDate     102   3.0%  33.5%      102   3.0% runtime.futex      90   2.7%  36.1%      106   3.2% runtime.MSpan_Sweep      83   2.5%  38.6%       83   2.5% runtime.aeshash64      74   2.2%  40.8%       86   2.6% syscall.Syscall6

呐呢？time.absDate這個函數能佔用到3.4%的效能？趕緊看代碼：

 for _, campaignId := range campaignIds {     //擷取活動     campaign, ok := RCampaign[campaignId]     //排期    now := time.Now()    year, month, day := now.Date()    day = year*10000 + int(month)*100 + day

改掉，移到for迴圈外面去，又找了一個問題，好happy。最佳化完之後的pprof：

(pprof) topTotal: 3310 samples     272   8.2%   8.2%      278   8.4% syscall.Syscall     213   6.4%  14.7%      264   8.0% hash_next     172   5.2%  19.8%      385  11.6% runtime.mallocgc     163   4.9%  24.8%      215   6.5% runtime.mapaccess2_fast64     155   4.7%  29.5%     1045  31.6% dsp_masky/model/bid.(*BidServer).FilterByCampaign     143   4.3%  33.8%      143   4.3% runtime.futex      90   2.7%  36.5%       90   2.7% runtime.aeshash64      87   2.6%  39.1%      116   3.5% runtime.MSpan_Sweep      67   2.0%  41.1%       82   2.5% settype      66   2.0%  43.1%       66   2.0% runtime.findfunc

這個做完之後，1000QPS左右，CPU的使用率大概到了100%以內，相對上一次大概有個20%的情況最佳化。

最佳化mallocgc

mallocgc佔了5.2%，這個是由於頻繁記憶體配置導致的。跟著svg找到了mallocgc的來源，是由這個函數產生的：

func (this *Campaign) GetPrice(positionId, size, host int64, b *BidServer) (price float64, err error) {        offer = &Offer{            CampaignId: this.Id,            UserId:     this.CreateUserId,            Ctype:      this.ChargeType,        }        malloced = true    }    ...}

每秒會來許多的請求，每來一條請求，都會對每個活動調用GetPrice進行價格方面的過濾，正是offer這個出價對象導致了大量的mallocgc。

既然找到了問題，就開始動手改。想法是，專門做一個Offer對象的分配池。

Go1.3提供了sync.Pool，我先用這個去實現，做了一個全域的var OfferPool *sync.Pool，然後每次分配從pool中去取。但...這是一次不成功的嘗試。修改之後，我發現CPU利用率暴漲近一倍，pprof顯示，大量的CPU時間耗在了Pool.Get函數中。

怎麼可能做了對象的分配池，效能反而不如每次直接分配了呢？？？

思考之後，找到了原因。大量的CPU耗在Pool.Get中，裡面是調用的CAP操作，搶‘鎖’的狀況很嚴重。原來，我做的是一個全域的pool，而每個請求都是在不同goroutine中，所以從pool中取對象時，搶鎖浪費了大量的CPU，導致最佳化以後CPU反而暴增了。那麼為什麼mallocgc卻沒事呢？是因為它的鎖的粒度小得多。mallocgc分配時，goroutine會先從本地的MCache中取記憶體，取不到時會到結體體M中取記憶體塊，只有當M中出取不到時，才會去全域的記憶體配置池中取，所以不存在嚴重的競爭問題。

為了避開全域鎖的問題，我改成了每個請求中附帶一點Offer緩衝，然後分配改成了下面的樣子：

var offer *Offerif b.OfferPoolIndex < len(b.OfferPool) {    offer = &b.OfferPool[b.OfferPoolIndex]    b.OfferPoolIndex++} else {    offer = &Offer{        CampaignId: this.Id,        UserId:     this.CreateUserId,        Ctype:      this.ChargeType,    }}

由於之前已經最佳化過許多了，這個最佳化帶來的提升不是很大了，大概在10%吧。目前觀察到的1000QPS左右的CPU使用率大概在70-80%。再做下去已經性價比不高了，於是這次的最佳化工作到此結束！

更新：

後面測試發現，在最佳化ParseUint的時候修改代碼引入了錯誤，導致過濾了很多的計算量。之後的繼續最佳化中，相關資料失效，pprof不再能體現正確的方向。憂鬱了~_~

最佳化前後對比

實驗環境是開兩個進程，一個跑最佳化前的代碼，一個跑最佳化後的代碼。用tcpcopy同時給兩個進程匯入線上真實流量觀察。

CPU利用率

觀察一段時間的兩者CPU利用率，這是取樣的一小段資料：

最佳化前：473 473 450 476 469 579 495

最佳化後：258 264 246 261 258 267 274

平均為原來的53.5%。

記憶體

使用比原來略有降低。

最佳化前：{"mem":"508.8MB","ver":"20140327~git-xxx","up_time":"2014-08-04 18:02:55","total_count":50208025,"last_10_second_qps":1119.800000}最佳化後：{"mem":"431.6MB","ver":"20140327~git-xxx","up_time":"2014-08-05 12:12:43","total_count":9974904,"last_10_second_qps":1056.700000}

回應時間

目前回應時間落在10ms以內是比較理想的。作為對比觀察，tail取100000條日誌記錄，比較回應時間落在10/20/30ms區間上的記錄條數

最佳化前：7309/1924/779

最佳化後：4220/1041/220

pprof效能最佳化golang

•