最近線上服務壓力很大,api的p99有點扛不住。
廣告業務對延時的要求普遍比較嚴格,有些adx設置的超時時間低至100ms,因此亟需找出性能熱點。
根據對目前系統情況的估計(和metrics埋點數據),大致估計問題出在廣告的正排環節。
使用 pprof 也證明了這一塊確實是熱點:
$ go tool pprof http:...(pprof) top 10Showing nodes accounting for 25.50s, 32.63% of 78.14s totalDropped 1533 nodes (cum <= 0.39s)Showing top 10 nodes out of 284 flat flat% sum% cum cum% 4.56s 5.84% 5.84% 4.87s 6.23% syscall.Syscall 4.03s 5.16% 10.99% 4.03s 5.16% runtime.aeshashbody 3.50s 4.48% 15.47% 6.01s 7.69% git.xxx.org/xxx/target.NewFilter 2.78s 3.56% 19.03% 3.73s 4.77% runtime.mapaccess2_fast64 2.63s 3.37% 22.40% 4.52s 5.78% runtime.mapiternext 2.08s 2.66% 25.06% 2.16s 2.76% runtime.heapBitsForObject 1.65s 2.11% 27.17% 1.93s 2.47% runtime.mapaccess1_fast64 1.57s 2.01% 29.18% 2.96s 3.79% runtime.mapaccess2 1.43s 1.83% 31.01% 2.06s 2.64% runtime.runqgrab 1.27s 1.63% 32.63% 1.27s 1.63% runtime.epollwait(pprof) pngGenerating report in profile001.png (使用生成的線框圖查看耗時)其中第三行 NewFilter 就是正排過濾函數。因為一些歷史原因,系統裡不是所有定向條件都使用了倒排,正排實現起來畢竟簡單、容易理解,而一旦開了這個口子,就會有越來越多正排加進來,推測是這個原因導致了性能的逐漸衰退。
經過討論,D同學花了一周多的時間,逐個梳理重寫。在Libra(字節跳動內部的ABTest平臺,參考谷歌分層實驗框架方案)上開實驗,平均耗時 -9%,從統計數據上來說,實驗組比對照組有了顯著的改進,但從最終結果上,整體的p95、p99超時都出現了進一步惡化。
這說明真正的問題不在於正排的計算,優化的思路出現了偏差。
考慮到晚高峰期間的cpu佔用率也只是剛超過50%,也就是說有可能性能問題在於鎖,但pprof的 block 和 mutex 都是空的,沒有線索。
猜測問題有可能在日誌,代碼裡確實用得不少。日誌用的是 github.com/ngaut/logging 庫,每一次調用都會用到兩個全局mutex。但通過調整log level 為error級別,大幅減少了日誌量,並沒有看到性能的改善。
經過搜索,發現 uber 基於 pprof 開發了一個神器 go-torch,可以生成火焰圖。安裝好 go-torch 及依賴 FlameGraph 以後執行:$ go-torch -u http://$IP:$PORT -f cpu.svgINFO[14:52:23] Run pprof command: go tool pprof -raw -seconds 30 http://$IP:$PORT/debug/pprof/profileINFO[14:52:54] Writing svg to cpu.svg用 Chrome 打開 cpu.svg,人肉排查:
可以看到,在NewFilter旁邊竟然還有一個耗時接近的 runtime.growslice ,結合實際代碼(略作簡化),可以推測是 slice 的初始化長度不足。
matchAds := make([]*ad, 0, 4096)adsBitMap.GetList(func(seq int) { if NewFilter(ctx, ad) { matchAds = append(matchAds, adlist[seq]) }})實際上最終定向後得到的廣告往往在數萬甚至數十萬的級別,而 go 的 slice 擴容在超過1024個元素以後是1.25倍,可想而知會出現大量的內存分配和拷貝,導致性能隨著廣告數量的增加逐漸惡化。最近的廣告數量也確實有了大幅的上升 —— 邏輯上形成了閉環。
經過優化,使用更大的初始化長度,並且使用 sync.Pool 來進一步減少內存分配,最終上線後p95和p99都下降了超過50%,效果顯著。
參考文章:
golang 使用pprof和go-torch做性能分析https://www.cnblogs.com/li-peng/p/9391543.html