使用pprof和go-torch排查golang的性能問題

2022-01-29 felix021


最近線上服務壓力很大,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

相關焦點

  • Golang程序性能分析(一)pprof和go-torch
    使用go tool pprof通過上面的設置可以獲取服務的性能數據後,接下來就可以使用go tool pprof工具對這些數據進行分析和保存了,一般都是使用pprof通過HTTP訪問上面列的那些路由端點直接獲取到數據後再進行分析,獲取到數據後pprof會自動讓終端進入交互模式。
  • Golang程序性能分析(二)在Echo和Gin框架中使用pprof
    前言今天繼續分享使用Go官方庫pprof做性能分析相關的內容,上一篇文章:Golang程序性能分析(一)pprof和go-torch中我花了很大的篇幅介紹了如何使用pprof採集Go應用程式的性能指標,如何找到運行緩慢的函數,以及函數中每一部的性能消耗細節。
  • 深度解密Go語言之pprof
    性能優化這件事也一樣,識別出性能瓶頸,會讓我們付出最小的努力,而得到最大的回報。Go 語言裡,pprof 就是這樣一個工具,幫助我們快速找到性能瓶頸,進而進行有針對性地優化。上圖來自參考資料【wolfogre】的一篇 pprof 實戰的文章,提供了一個樣例程序,通過 pprof 來排查、分析、解決性能問題,非常精彩。當 CPU 性能分析啟用後,Go runtime 會每 10ms 就暫停一下,記錄當前運行的 goroutine 的調用堆棧及相關數據。當性能分析數據保存到硬碟後,我們就可以分析代碼中的熱點了。
  • gin使用pprof性能分析
    pprof// 導入包import (  "github.com/DeanThompson/ginpprof")// gin框架直接集成router := gin.New()ginpprof.Wrapper(router)命令行分析$ go
  • golang 性能診斷看這篇就夠了
    ,一般分為兩種情況,一是線上應用真的出現性能問題;二是我們需要對準備上線的系統進行性能預估;後者需要壓力測試輔助進行,此處不表。go生態已經為我們提供了大量的API和診斷工具幫助我們解決go應用的性能問題。我們常用的大致可以分為兩類:profile一般被稱為性能分析,對程序而言,就是程序運行時的各種概況信息,包括cpu佔用情況、內存情況、線程情況等。
  • Golang程序性能分析(三)用pprof分析gRPC服務的性能
    ,這次我們的主要內容是如何使用pprof工具對gRPC服務的程序性能進行分析。但是我們可以換個角度來看這個問題,pprof做CPU分析原理是按照一定的頻率採集程序CPU(包括寄存器)的使用情況,確定Golang程序性能分析(二)在Echo和Gin框架中使用pprof應用程式在主動消耗 CPU 周期時花費時間的位置。所以我們可以在gRPC服務啟動時,異步啟動一個監聽其他埠的HTTP服務,通過這個HTTP服務間接獲取gRPC服務的分析數據。
  • Golang 性能分析工具簡要介紹
    Go 提供了 pprof 以及 trace 工具,本文分別介紹這兩個工具的簡要用法,希望大家能夠快速了解以及快速入門 Go 的性能調優。先來一段演練在給大家介紹枯燥的基礎知識之前,先來看看一個簡單的例子,這個例子簡單粗暴,可以通過 pprof 快速定位協程阻塞問題。
  • golang pprof label 使用
    trace vs   pprof      go tool trace 和go tool pprof 兩個工具的使用方法類似,但是兩者的原理和側重點不同
  • 使用 pprof 和 Flame-Graph 調試 Golang 應用
    pprofpprof 我理解是 program profile(即程序性能剖析之意),Golang 提供的兩個官方包 runtime/pprof,net/http/pprof 能方便的採集程序運行的堆棧、goroutine、內存分配和佔用、io 等信息的 .prof 文件,然後可以使用 go tool pprof 分析 .prof 文件。
  • golang 調試分析的高階技巧
    你安裝好 golang 之後,執行 go tool 就能看到內置支持的所有工具了。再者,線上不可能讓你隨意 attach 進程,很多時候都是出 core 了,你就只有一個 core 文件去排查。pprofpprof 支持四種類型的分析:CPU :CPU 分析,採樣消耗 cpu 的調用,這個一般用來定位排查程序裡耗費計算資源的地方;Memroy :內存分析,一般用來排查內存佔用,內存洩露等問題;Block :阻塞分析,會採樣程序裡阻塞的調用情況;我們這裡詳細以內存佔用分析舉例(
  • Golang 調試分析的高階技巧
    你安裝好 golang 之後,執行 go tool 就能看到內置支持的所有工具了。再者,線上不可能讓你隨意 attach 進程,很多時候都是出 core 了,你就只有一個 core 文件去排查。pprofpprof 支持四種類型的分析:CPU :CPU 分析,採樣消耗 cpu 的調用,這個一般用來定位排查程序裡耗費計算資源的地方;Memroy :內存分析,一般用來排查內存佔用,內存洩露等問題;Block :阻塞分析,會採樣程序裡阻塞的調用情況;我們這裡詳細以內存佔用分析舉例(
  • Go語言使用benchmark進行性能測試
    在日常開發中,基準測試是必不可少的,基準測試主要是通過測試CPU和內存的效率問題,來評估被測試代碼的性能,進而找到更好的解決方案。而Go語言中自帶的benchmark則是一件非常神奇的測試利器。有了它,開發者可以方便快捷地在測試一個函數方法在串行或並行環境下的基準表現。
  • Go 調試分析的高階技巧
    pprofpprof 支持四種類型的分析:CPU :CPU 分析,採樣消耗 cpu 的調用,這個一般用來定位排查程序裡耗費計算資源的地方;Memroy :內存分析,一般用來排查內存佔用,內存洩露等問題;Block :阻塞分析,會採樣程序裡阻塞的調用情況;我們這裡詳細以內存佔用分析舉例(
  • Golang 大殺器之性能剖析 PProf
    😭想做性能分析PProf想要進行性能優化,首先矚目在 Go 自身提供的工具鏈來作為分析依據,本文將帶你學習、使用 Go 後花園,涉及如下:是什麼pprof 是用於可視化和分析性能分析數據的工具pprof 以 profile.proto 讀取分析樣本的集合,並生成報告以可視化並幫助分析數據(支持文本和圖形報告)profile.proto 是一個
  • Go 性能分析工具 pprof 入門
    /【導讀】pprof是golang用於性能分析的工具、可以生成圖形和文本報告。在實際項目中對高並發場景下的服務上線前必須經過pprof驗證,本文介紹了pprof的用法。0x18d067f+0x17933e7trace: 對應用程式進行執行追蹤,參數: seconds, 默認值1s這幾個 CMD 因為各種原因沒有整合到 Profile 結構中去,但就使用上而言,是沒有區別的,URL格式是一致的,因此可以看做一個整體,從各個角度對系統進行數據採樣和分析。
  • 如何使用pprof分析應用
    web 分析10、runtime.pprof編程如何開始在主mian中引入分析準備工具brew install graphvizgo tool pprof參數分析-inuse_space 正在使用的內存-inuse_objects 正在使用的分配的的對象-alloc_space 從程序開始到現在總共分配的內存
  • Go test基礎用法大全
    語言的 test 命令有很多參數,怎麼利用 test 命令和它提供的參數,又能做到什麼?性能測試涉及如下方面:CPU Profiling:CPU分析,按照一定的頻率採集所監聽的應用程式CPU(含寄存器)的使用情況,可確定應用程式在主動消耗CPU 周期時花費時間的位置Memory Profiling:內存分析,在應用程式進行堆分配時記錄堆棧跟蹤,用於監視當前和歷史內存使用情況,以及檢查內存洩漏Block Profiling
  • Go語言 CPU 性能、內存分析調試方法大匯總:你要的都在這
    $ time go run test2.go&{{0 0} 張三 0}real 0m0.843suser 0m0.216ssys 0m0.389s上面是使用time對 go run test2.go對執行程序做了性能分析,得到3個指標。
  • Golang 性能測試 (3) 協程追蹤術
    本文簡單介紹 gola
  • Golang 性能測試 (1)
    Golang 語言在提供了功能測試的基礎上,提供了豐富的性能測試功能。SHOW CODE首先,從一個例子來講起。寫一個簡單的快速排序,然後和系統自帶的排序做性能比較。上述命令指定了每個benchmark方法執行3次,並顯示內存和代碼覆蓋率。從基準測試的結果可以分析出:對於1w數據量的排序,自帶的排序比我的排序算法要快20倍左右;100數據量的排序,手擼的排序略勝一籌。從內存分析來講,系統自帶的會使用4B的數據,而我的算法無內存分配。