我們使用golang編寫的線上服務(wù)良姆，通常會(huì)設(shè)置一個(gè)golang runtime指標(biāo)監(jiān)控肠虽，包括goroutine num、gc num玛追、gc pause 等等税课。最近的一次上線，發(fā)現(xiàn) gc 相關(guān)的指標(biāo)出現(xiàn)異常痊剖，gc num 和 gc pause 大幅升高韩玩。由于 golang 的 gc 是 stop the world 來做， gc 過多會(huì)搶占程序的正常執(zhí)行時(shí)間陆馁，甚至影響對(duì)外提供的服務(wù)找颓，因此暫停了上線，準(zhǔn)備先把 gc 的問題修復(fù)下叮贩。
出問題時(shí)的 gc 監(jiān)控如下：
其中藍(lán)色曲線表示 gc num叮雳，黃色曲線表示 gc pause（單位ms），兩個(gè)指標(biāo)都是30s的累計(jì)數(shù)據(jù)妇汗×辈唬可以看到每30s的pause達(dá)到了秒級(jí)別。
登錄到線上機(jī)器杨箭，通過 go tool pprof --alloc_objects http://localhost:xxxx/debug/pprof/heap 命令寞焙，查看對(duì)象分配的采樣記錄。發(fā)現(xiàn)比較大頭的有reflect.Value互婿、encoding/json捣郊、fmt.Sprint〈炔危考慮到程序中為了更好地做抽象呛牲，使用了反射操作，而 reflect.Value 會(huì)將對(duì)象拷貝并分配到堆上驮配，程序中的對(duì)象都是消息體娘扩，有的消息體會(huì)超大，因此會(huì)分配較多的堆內(nèi)存壮锻。對(duì)程序做了一版優(yōu)化琐旁，去掉這個(gè)反射邏輯，改為switch case?猜绣，重新上線灰殴，發(fā)現(xiàn) gc 略有下降，但效果還是不夠掰邢。
?繼續(xù)做 profile牺陶，已經(jīng)沒有了 reflect.Value伟阔，于是只能再從另外兩項(xiàng)入手。
這個(gè)程序是一個(gè)老程序的重構(gòu)版掰伸，當(dāng)時(shí)為了做diff測(cè)試皱炉，加了大量的日志，包括debug日志碱工，甚至有些用來做diff的日志是marshal成json的娃承。我們用的日志庫沒有做特殊處理奏夫，每條日志都會(huì)先調(diào)用 fmt.Sprint怕篷，這個(gè)函數(shù)會(huì)把對(duì)象分配到堆上。針對(duì)上述情況酗昼，做了大量的日志刪減廊谓，gc 略有下降但效果不夠。
繼續(xù)做性能分析麻削，發(fā)現(xiàn)gc大頭還是json相關(guān)操作蒸痹。這個(gè)應(yīng)用程序的主要功能就是處理json格式傳入的消息，因此除非從 json 庫著手改善呛哟，否則似乎解決不了問題叠荠。BTW，在處理的諸多消息中扫责，有一類消息體占用字節(jié)數(shù)巨大榛鼎，是其他消息的十倍以上。嘗試取消訂閱這類消息鳖孤，發(fā)現(xiàn)gc立即好轉(zhuǎn)者娱，恢復(fù)到正常水平。不過苏揣，這條路徑走不通黄鳍。
分析本程序的特點(diǎn)，它基于消息觸發(fā)的模式平匈，每次消息到來就會(huì)處理框沟，處理就會(huì)有堆對(duì)象產(chǎn)生。golang 的 gc 時(shí)機(jī)是根據(jù)當(dāng)前與上次的 heap size 的比例來決定增炭，默認(rèn)情況下是100街望，即新增一倍就會(huì)觸發(fā)。嘗試把這個(gè)比例調(diào)大 export GOGC=400弟跑，試圖降低 gc 觸發(fā)頻率灾前，發(fā)現(xiàn)效果還是不錯(cuò)的，兩個(gè)指標(biāo)均有明顯下降孟辑，其他指標(biāo)無明顯異常哎甲，暫時(shí)先這樣解決蔫敲，以后有余力再做程序?qū)用鎯?yōu)化。
