在計算機性能除錯領域里,profiling 是指對應用程式的畫像,畫像就是應用程式使用 CPU 和記憶體的情況, Go語言是一個對性能特別看重的語言,因此語言中自帶了 profiling 的庫,這篇文章就要講解怎么在 golang 中做 profiling,
Go性能優化
Go語言專案中的性能優化主要有以下幾個方面:
- CPU profile:報告程式的 CPU 使用情況,按照一定頻率去采集應用程式在 CPU 和暫存器上面的資料
- Memory Profile(Heap Profile):報告程式的記憶體使用情況
- Block Profiling:報告 goroutines 不在運行狀態的情況,可以用來分析和查找死鎖等性能瓶頸
- Goroutine Profiling:報告 goroutines 的使用情況,有哪些 goroutine,它們的呼叫關系是怎樣的
采集性能資料
Go語言內置了獲取程式的運行資料的工具,包括以下兩個標準庫:
- runtime/pprof:采集工具型應用運行資料進行分析
- net/http/pprof:采集服務型應用運行時資料進行分析
pprof開啟后,每隔一段時間(10ms)就會收集下當前的堆疊資訊,獲取各個函式占用的CPU以及記憶體資源;最后通過對這些采樣資料進行分析,形成一個性能分析報告,
注意,我們只應該在性能測驗的時候才在代碼中引入pprof,
工具型應用
如果你的應用程式是運行一段時間就結束退出型別,那么最好的辦法是在應用退出的時候把 profiling 的報告保存到檔案中,進行分析,對于這種情況,可以使用runtime/pprof庫, 首先在代碼中匯入runtime/pprof工具:
import "runtime/pprof"
CPU性能分析
開啟CPU性能分析:
pprof.StartCPUProfile(w io.Writer)
停止CPU性能分析:
pprof.StopCPUProfile()
應用執行結束后,就會生成一個檔案,保存了我們的 CPU profiling 資料,得到采樣資料之后,使用go tool pprof工具進行CPU性能分析,
記憶體性能優化
記錄程式的堆疊資訊
pprof.WriteHeapProfile(w io.Writer)
得到采樣資料之后,使用go tool pprof工具進行記憶體性能分析,
go tool pprof默認是使用-inuse_space進行統計,還可以使用-inuse-objects查看分配物件的數量,
服務型應用
如果你的應用程式是一直運行的,比如 web 應用,那么可以使用net/http/pprof庫,它能夠在提供 HTTP 服務進行分析,
如果使用了默認的http.DefaultServeMux(通常是代碼直接使用 http.ListenAndServe(“0.0.0.0:8000”, nil)),只需要在你的web server端代碼中按如下方式匯入net/http/pprof
import _ "net/http/pprof"
如果你使用自定義的 Mux,則需要手動注冊一些路由規則:
r.HandleFunc("/debug/pprof/", pprof.Index)
r.HandleFunc("/debug/pprof/cmdline", pprof.Cmdline)
r.HandleFunc("/debug/pprof/profile", pprof.Profile)
r.HandleFunc("/debug/pprof/symbol", pprof.Symbol)
r.HandleFunc("/debug/pprof/trace", pprof.Trace)
如果你使用的是gin框架,那么推薦使用github.com/gin-contrib/pprof,在代碼中通過以下命令注冊pprof相關路由,
pprof.Register(router)
不管哪種方式,你的 HTTP 服務都會多出/debug/pprof endpoint,訪問它會得到類似下面的內容:

這個路徑下還有幾個子頁面:
/debug/pprof/profile:訪問這個鏈接會自動進行 CPU profiling,持續 30s,并生成一個檔案供下載/debug/pprof/heap: Memory Profiling 的路徑,訪問這個鏈接會得到一個記憶體 Profiling 結果的檔案/debug/pprof/block:block Profiling 的路徑/debug/pprof/goroutines:運行的 goroutines 串列,以及呼叫關系 go tool pprof命令
不管是工具型應用還是服務型應用,我們使用相應的pprof庫獲取資料之后,下一步的都要對這些資料進行分析,我們可以使用go tool pprof命令列工具,
go tool pprof最簡單的使用方式為:
go tool pprof [binary] [source]
其中:
- binary 是應用的二進制檔案,用來決議各種符號;
- source 表示 profile 資料的來源,可以是本地的檔案,也可以是 http 地址,
注意事項: 獲取的 Profiling 資料是動態的,要想獲得有效的資料,請保證應用處于較大的負載(比如正在生成中運行的服務,或者通過其他工具模擬訪問壓力),否則如果應用處于空閑狀態,得到的結果可能沒有任何意義,
具體示例
首先我們來寫一段有問題的代碼:
package main
import (
"flag"
"fmt"
"os"
"runtime/pprof"
"time"
)
// 一段有問題的代碼
func logicCode() {
var c chan int
for {
select {
case v := <-c:
fmt.Printf("recv from chan, value:%v\n", v)
default:
//修正讓出CPU
//time.Sleep(time.Millisecond)
}
}
}
func main() {
var isCPUPprof bool
var isMemPprof bool
flag.BoolVar(&isCPUPprof, "cpu", false, "turn cpu pprof on")
flag.BoolVar(&isMemPprof, "mem", false, "turn mem pprof on")
flag.Parse()
if isCPUPprof {
f1, err := os.Create("./cpu.pprof")
if err != nil {
fmt.Printf("create cpu pprof failed, err:%v\n", err)
return
}
_ = pprof.StartCPUProfile(f1)
defer func() {
pprof.StopCPUProfile()
_ = f1.Close()
}()
}
for i := 0; i < 6; i++ {
go logicCode()
}
time.Sleep(10 * time.Second)
if isMemPprof {
f2, err := os.Create("./mem.pprof")
if err != nil {
fmt.Printf("create mem pprof failed, err:%v\n", err)
return
}
defer func() {
_ = pprof.WriteHeapProfile(f2)
_ = f2.Close()
}()
}
}
通過flag我們可以在命令列控制是否開啟CPU和Mem的性能分析, 將上面的代碼保存并編譯成runtime_pprof可執行檔案,執行時加上-cpu命令列引數如下:
./runtime_pprof -cpu
等待30秒后會在當前目錄下生成一個cpu.pprof檔案,
命令列互動界面
我們使用go工具鏈里的pprof來分析一下,
go tool pprof cpu.pprof
執行上面的代碼會進入互動界面如下:
runtime_pprof $ go tool pprof cpu.pprof
Type: cpu
Time: Jun 28, 2019 at 11:28am (CST)
Duration: 20.13s, Total samples = 1.91mins (568.60%)
Entering interactive mode (type "help" for commands, "o" for options)
(pprof)
我們可以在互動界面輸入top3來查看程式中占用CPU前3位的函式:
(pprof) top3
Showing nodes accounting for 100.37s, 87.68% of 114.47s total
Dropped 17 nodes (cum <= 0.57s)
Showing top 3 nodes out of 4
flat flat% sum% cum cum%
42.52s 37.15% 37.15% 91.73s 80.13% runtime.selectnbrecv
35.21s 30.76% 67.90% 39.49s 34.50% runtime.chanrecv
22.64s 19.78% 87.68% 114.37s 99.91% main.logicCode
其中:
- flat:當前函式占用CPU的耗時
- flat::當前函式占用CPU的耗時百分比
- sun%:函式占用CPU的耗時累計百分比
- cum:當前函式加上呼叫當前函式的函式占用CPU的總耗時
- cum%:當前函式加上呼叫當前函式的函式占用CPU的總耗時百分比
- 最后一列:函式名稱
在大多數的情況下,我們可以通過分析這五列得出一個應用程式的運行情況,并對程式進行優化,
我們還可以使用list 函式名命令查看具體的函式分析,例如執行list logicCode查看我們撰寫的函式的詳細分析,
(pprof) list logicCode
Total: 1.91mins
ROUTINE ================ main.logicCode in .../runtime_pprof/main.go
22.64s 1.91mins (flat, cum) 99.91% of Total
. . 12:func logicCode() {
. . 13: var c chan int
. . 14: for {
. . 15: select {
. . 16: case v := <-c:
22.64s 1.91mins 17: fmt.Printf("recv from chan, value:%v\n", v)
. . 18: default:
. . 19:
. . 20: }
. . 21: }
. . 22:}
通過分析發現大部分CPU資源被17行占用,我們分析出select陳述句中的default沒有內容會導致上面的case v:=<-c:一直執行,我們在default分支添加一行time.Sleep(time.Second)即可,
圖形化
或者可以直接輸入web,通過svg圖的方式查看程式中詳細的CPU占用情況, 想要查看圖形化的界面首先需要安裝graphviz圖形化工具,
Mac:
brew install graphviz
Windows: 下載graphviz 將graphviz安裝目錄下的bin檔案夾添加到Path環境變數中, 在終端輸入dot -version查看是否安裝成功,

關于圖形的說明: 每個框代表一個函式,理論上框的越大表示占用的CPU資源越多, 方框之間的線條代表函式之間的呼叫關系, 線條上的數字表示函式呼叫的次數, 方框中的第一行數字表示當前函式占用CPU的百分比,第二行數字表示當前函式累計占用CPU的百分比,
除了分析CPU性能資料,pprof也支持分析記憶體性能資料,比如,使用下面的命令分析http服務的heap性能資料,查看當前程式的記憶體占用以及熱點記憶體物件使用的情況,
# 查看記憶體占用資料
go tool pprof -inuse_space http://127.0.0.1:8080/debug/pprof/heap
go tool pprof -inuse_objects http://127.0.0.1:8080/debug/pprof/heap
# 查看臨時記憶體分配資料
go tool pprof -alloc_space http://127.0.0.1:8080/debug/pprof/heap
go tool pprof -alloc_objects http://127.0.0.1:8080/debug/pprof/heap
火焰圖
火焰圖(Flame Graph)是 Bredan Gregg 創建的一種性能分析圖表,因為它的樣子近似 🔥而得名,上面的 profiling 結果也轉換成火焰圖,如果對火焰圖比較了解可以手動來操作,不過這里我們要介紹一個工具:go-torch,這是 uber 開源的一個工具,可以直接讀取 golang profiling 資料,并生成一個火焰圖的 svg 檔案,
新版的Go內置pprof已內置火焰圖插件, 網上大多數教程是獨立安裝
新版只需運行一下命令
go tool pprof -http=:8080 cpu.pprof
Serving web UI on http://localhost:8080
打開瀏覽器訪問: http://localhost:8080
點擊上方選單,切換視圖


gin框架使用
main.go
package main
import (
"fmt"
"github.com/DeanThompson/ginpprof"
"github.com/gin-gonic/gin"
"io"
"os"
"pprof/controllers"
)
func main() {
gin.DisableConsoleColor() //關閉顏色
//gin.SetMode(gin.DebugMode)
gin.SetMode(gin.ReleaseMode)
logfile, err := os.OpenFile("logs/gin_http.log", os.O_CREATE|os.O_APPEND|os.O_RDWR, 0666)
if err != nil {
fmt.Println("Could not create log file")
}
gin.DefaultWriter = io.MultiWriter(logfile)
r := gin.Default()
//r.Use(middlewares.Cors())
Group := r.Group("user")
{
Group.GET("/reg", controllers.Reg)
}
ginpprof.Wrap(r)
// ginpprof also plays well with *gin.RouterGroup
// group := router.Group("/debug/pprof")
// ginpprof.WrapGroup(group)
_ = r.Run(":8880")
}
controllers/user.go
package controllers
import (
"github.com/gin-gonic/gin"
"net/http"
)
func Reg(context *gin.Context) {
uid := context.DefaultQuery("uid", "0")
context.JSON(http.StatusOK, gin.H{
"code": 1,
"msg": "Success",
"data": uid,
})
}
壓測工具wrk
推薦使用https://github.com/wg/wrk 或 https://github.com/adjust/go-wrk, 或者使用apache的ab進行壓測
啟動分析程式:
go tool pprof -http=:8080 http://localhost:8880/debug/pprof/profile
Fetching profile over HTTP from http://localhost:8880/debug/pprof/profile
Saved profile in C:\Users\soul\pprof\pprof.samples.cpu.004.pb.gz
Serving web UI on http://localhost:8080
啟動wrk進行壓測:
go-wrk -n 10000 http://localhost:8880/user/reg?uid=10000
我這里使用ab進行壓測:
ab -n100000 -c 200 http://localhost:8880/user/reg?uid=10000
This is ApacheBench, Version 2.3 <$Revision: 1843412 $>
Copyright 1996 Adam Twiss, Zeus Technology Ltd, http://www.zeustech.net/
Licensed to The Apache Software Foundation, http://www.apache.org/
Benchmarking localhost (be patient)
Completed 10000 requests
Completed 20000 requests
Completed 30000 requests
Completed 40000 requests
Completed 50000 requests
Completed 60000 requests
Completed 70000 requests
Completed 80000 requests
Completed 90000 requests
Completed 100000 requests
Finished 100000 requests
Server Software:
Server Hostname: localhost
Server Port: 8880
Document Path: /user/reg?uid=10000
Document Length: 41 bytes
Concurrency Level: 200
Time taken for tests: 40.115 seconds
Complete requests: 100000
Failed requests: 0
Total transferred: 16400000 bytes
HTML transferred: 4100000 bytes
Requests per second: 2492.85 [#/sec] (mean)
Time per request: 80.229 [ms] (mean)
Time per request: 0.401 [ms] (mean, across all concurrent requests)
Transfer rate: 399.25 [Kbytes/sec] received
Connection Times (ms)
min mean[+/-sd] median max
Connect: 0 0 0.4 0 3
Processing: 12 80 5.5 79 123
Waiting: 2 58 15.2 59 121
Total: 12 80 5.5 79 123
Percentage of the requests served within a certain time (ms)
50% 79
66% 81
75% 82
80% 84
90% 86
95% 88
98% 92
99% 94
100% 123 (longest request)
30秒之后會自動打開瀏覽器:http://localhost:8080

查看火焰圖

火焰圖的y軸表示cpu呼叫方法的先后,x軸表示在每個采樣呼叫時間內,方法所占的時間百分比,越寬代表占據cpu時間越多,通過火焰圖我們就可以更清楚的找出耗時長的函式呼叫,然后不斷的修正代碼,重新采樣,不斷優化,
pprof與性能測驗結合
go test命令有兩個引數和 pprof 相關,它們分別指定生成的 CPU 和 Memory profiling 保存的檔案:
- -cpuprofile:cpu profiling 資料要保存的檔案地址
- -memprofile:memory profiling 資料要報文的檔案地址
我們還可以選擇將pprof與性能測驗相結合,比如:
比如下面執行測驗的同時,也會執行 CPU profiling,并把結果保存在 cpu.prof 檔案中:
go test -bench . -cpuprofile=cpu.prof
比如下面執行測驗的同時,也會執行 Mem profiling,并把結果保存在 cpu.prof 檔案中:
go test -bench . -memprofile=./mem.prof
需要注意的是,Profiling 一般和性能測驗一起使用,這個原因在前文也提到過,只有應用在負載高的情況下 Profiling 才有意義,
參考文章:https://www.liwenzhou.com/posts/Go/performance_optimisation/
轉載請註明出處,本文鏈接:https://www.uj5u.com/qita/258651.html
標籤:AI
上一篇:種子度量值
