先把結(jié)論列在前面：

1. Golang的性能可以做到非常好幢痘，但是一些native包的性能很可能會拖后腿，比如regexp和encoding/json掀泳。如果在性能要求較高的場合使用雪隧，要根據(jù)實際情況做相應(yīng)優(yōu)化。
2. on-cpu/off-cpu火焰圖的使用是程序性能分析的利器员舵，往往一針見血脑沿。雖然生成一張火焰圖比較繁瑣（尤其是off-cpu圖），但絕對值得擁有马僻！

之前一直使用Logstash作為日志文件采集客戶端程序庄拇。Logstash功能強大，有豐富的數(shù)據(jù)處理插件及很好的擴展能力，但由于使用JRuby實現(xiàn)措近，性能堪憂溶弟。而Filebeat是后來出現(xiàn)的一個用go語言實現(xiàn)的，更輕量級的日志文件采集客戶端瞭郑。性能不錯辜御、資源占用少，但幾乎沒有任何解析處理能力屈张。通常的使用場景是使用Filebeat采集到Logstash解析處理擒权，然后再上傳到Kafka或Elasticsearch。值得注意的是阁谆，Logstash和Filebeat都是Elastic公司的優(yōu)秀開源產(chǎn)品碳抄。

為了提高客戶端的日志采集性能，又減少數(shù)據(jù)傳輸環(huán)節(jié)和部署復(fù)雜度场绿，并更充分的將go語言的性能優(yōu)勢利用于日志解析剖效，于是決定在Filebeat上通過開發(fā)插件的方式，實現(xiàn)針對公司日志格式規(guī)范的解析焰盗，直接作為Logstash的替代品璧尸。

背景介紹完畢，下面是實現(xiàn)和優(yōu)化的過程姨谷。

Version 1

先做一個最簡單的實現(xiàn)逗宁，即用go自帶的正則表達式包regexp做日志解析映九。性能已經(jīng)比Logstash（也是通過開發(fā)插件做規(guī)范日志解析）高出30%梦湘。

這里的性能測試著眼于日志采集的瓶頸——解析處理環(huán)節(jié)，指標(biāo)是在限制只使用一個cpu core的條件下（在服務(wù)器上要盡量減少對業(yè)務(wù)應(yīng)用的資源占用）件甥，采集并解析1百萬條指定格式和長度的日志所花費的時間捌议。測試環(huán)境是1臺主頻為3.2GHz的PC。為了避免disk IO及page cache的影響引有，將輸入文件和輸出文件都放在/dev/shm中瓣颅。對于Filebeat的CPU限制，是通過啟動時指定環(huán)境變量GOMAXPROCS=1實現(xiàn)譬正。

這一版本處理1百萬條日志花費的時間為122秒宫补，即每秒8200條日志。

Version 2

接下來嘗試做一些優(yōu)化曾我，看看這個go插件的性能還可不可以有些提升粉怕。首先想到的是替換regexp包。Linux下有一個C實現(xiàn)的PCRE庫抒巢，github.com/glenn-brown/golang-pkg-pcre/src/pkg/pcre這個第三方包正是將PCRE庫應(yīng)用到golang中贫贝。CentOS下需要先安裝pcre-devel這個包。
這個版本的處理時間為97秒，結(jié)果顯示比第一個版本的處理性能提升了25%稚晚。

Version 3

第三個版本崇堵，是完全不使用正則表達式，而是針對固定的日志格式規(guī)則客燕，利用strings.Index()做字符串分解和提取操作鸳劳。這個版本的處理時間為70秒，性能又大大的提升了將近40%也搓。

Version 4

那還有沒有進一步提升的空間呢棍辕。有，就是Filebeat用作序列化輸出的json包还绘。我們的日志上傳使用json格式楚昭，而Filebeat使用go自帶的encoding/json包是基于反射實現(xiàn)的，性能一直廣受詬病拍顷。如果對json解析有優(yōu)化的話抚太，性能提高會是很可觀的。既然我們的日志格式是固定的昔案，解析出來的字段也是固定的尿贫，這時就可以基于固定的日志結(jié)構(gòu)體做json的序列化，而不必用低效率的反射來實現(xiàn)踏揣。go有多個針對給定結(jié)構(gòu)體做json序列化/反序列化的第三方包庆亡，我們這里使用的是easyjson。在安裝完easyjson包后捞稿，對我們包含了日志格式結(jié)構(gòu)體定義的程序文件執(zhí)行easyjson命令又谋，會生成一個xxx_easyjson.go的文件，里面包含了這個結(jié)構(gòu)體專用的Marshal/Unmarshal方法娱局。這樣一來彰亥，處理時間又縮短為61秒，性能提高15%衰齐。

這時任斋，代碼在我面前，已經(jīng)想不出有什么大的方面還可以優(yōu)化的了耻涛。是時候該本文的另一個主角废酷，火焰圖出場了。

火焰圖是性能分析的一個有效工具抹缕，這里是它的說明澈蟆。通常看到的火焰圖歉嗓，是指on-cpu火焰圖丰介，用來分析cpu都消耗在哪些函數(shù)調(diào)用上。

安裝完FlameGraph工具后，先對目前版本的程序運行一次性能測試哮幢，按照說明抓取數(shù)據(jù)生成火焰圖如下带膀。

FlameGraph對于c/go程序是通用的。對于go程序橙垢，也可以使用自帶的net/http/pprof包作為數(shù)據(jù)源垛叨，然后安裝uber的go-torch工具來自動調(diào)用FlameGraph腳本生成on-cpu火焰圖，執(zhí)行會稍為簡便一些柜某。參見go-torch說明嗽元。

perf_on_cpu_orig.png

圖中縱向代表的是函數(shù)調(diào)用棧，橫向各個方塊的寬度代表的是占用cpu時間的比例喂击，需要留意的是靠近頂端的大長條剂癌。方塊的顏色是隨機的沒有實際意義。

從上圖可以看到cpu時間占用最多的主要有兩塊翰绊。一塊是Output處理部分佩谷，稍為大頭的是json處理，這塊已經(jīng)優(yōu)化過沒什么可以做的了监嗜。另一塊就比較奇怪了谐檀，是common.MapStr.Clone()方法，居然占了40%的cpu時間裁奇。再往上看桐猬，主要是Errorf的處理。一看代碼刽肠，馬上明白了溃肪。

func (m MapStr) Clone() MapStr {
    result := MapStr{}

    for k, v := range m {
        innerMap, err := toMapStr(v)
        if err == nil {
            result[k] = innerMap.Clone()
        } else {
            result[k] = v
        }
    }

    return result
}

common.MapStr是在pipeline中存放日志內(nèi)容的結(jié)構(gòu)體，它的Clone()方法實現(xiàn)里判斷一個子鍵值是否為嵌套的Mapstr結(jié)構(gòu)時五垮，是通過判斷toMapStr()方法是否返回error乍惊。從這里看杜秸，生成error對象的代價是非撤耪蹋可觀的。于是撬碟，一個顯然的fix诞挨，就是將toMapStr()中的判斷方法移到Clone()中并避免生成error。

Version 5

對修改后的代碼重新生成一張火焰圖如下呢蛤。

perf_on_cpu_opt.png

這時common.MapStr.Clone()從圖中已經(jīng)幾乎找不見了惶傻，證明花費的cpu時間已經(jīng)可以忽略不計。
測試時間一下子縮短到了46秒其障，節(jié)省了33%银室，非常大的改善！

到現(xiàn)在，還有一個之前未提到的問題沒有解決——在限制使用一個core之后蜈敢，測試運行時cpu利用率只能跑到82%左右辜荠。是不是由于有鎖存在影響了性能呢？

這時候抓狭，又該請off-cpu火焰圖出場了伯病。Off-cpu火焰圖，是用來分析程序沒有有效利用cpu的時候否过，消耗在什么地方了午笛，在這里有詳細(xì)的介紹。數(shù)據(jù)收集比on-cpu火焰圖要復(fù)雜苗桂，可以使用大名鼎鼎的春哥提供的openresty-systemtap-toolkit包药磺。春哥的項目頁面中沒有詳細(xì)說明的是kernel-devel和debuginfo包的安裝方法。在此也記錄一下煤伟。

# kernel-devel沒有問題与涡，直接yum安裝
sudo yum install -y kernel-devel

# debuginfo，在CentOS7中需要這樣裝
sudo vim /etc/yum.repos.d/CentOS-Debuginfo.repo
修改為enable=1
sudo debuginfo-install kernel

安裝時可能還會報錯：
Invalid GPG Key from file:///etc/pki/rpm-gpg/RPM-GPG-KEY-CentOS-Debug-7: No key found in given key data
需要從https://www.centos.org/keys/RPM-GPG-KEY-CentOS-Debug-7下載key寫入到/etc/pki/rpm-gpg/RPM-GPG-KEY-CentOS-Debug-7

安裝完后按照說明生成了off-cpu火焰圖如下：

perf_off_cpu_orig.png

我還不能完全解讀這張圖持偏，但是已經(jīng)可以明顯看到驼卖，對Registry文件（Filebeat用于記錄文件采集列表和offset數(shù)據(jù)）的寫操作占了一定比例。于是鸿秆，嘗試將Filebeat的spool_size（每完成這么多條日志更新一次Registry文件）設(shè)置為10240酌畜，默認(rèn)值的5倍，運行測試cpu已經(jīng)可以跑到95%以上卿叽。而將Registry設(shè)置到/dev/shm/下也同樣可以解決測試時cpu跑不滿的問題桥胞。

這就否定了上面對鎖使用不當(dāng)影響性能的猜測。在實際應(yīng)用時spool_size的設(shè)置應(yīng)當(dāng)依據(jù)結(jié)合了output端（如寫入到Kafka）的測試數(shù)據(jù)來決定考婴。

至此贩虾，優(yōu)化結(jié)束，達到了最初版本性能的3倍沥阱！
各個版本的具體運行性能數(shù)據(jù)如下圖所示缎罢。

performance_compare.png

需要稍作說明的是：

1. Filebeat開發(fā)是基于5.3.1版本，go版本是1.8
2. Logstash的測試通過-w 1參數(shù)配置使用一個工作進程考杉，并未限制使用一個core
3. 執(zhí)行時間包括了程序的啟動時間（Logstash的啟動時間有將近20秒）

最終的優(yōu)化結(jié)果是策精，針對特定格式和長度的日志解析能力在PC上達到了每秒25000條，即使在CPU主頻較低的生產(chǎn)服務(wù)器上崇棠，也可以達到每秒20000條咽袜。

Go的高性能真不是吹的，當(dāng)然是要在足夠的優(yōu)化后：）

附錄枕稀，關(guān)于go的性能有一篇這樣的討論询刹，有興趣可以看看：
http://stackoverflow.com/questions/20875341/why-golang-is-slower-than-scala