在計算機性能調試領域里,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/DeanThompson/ginpprof"

package main

import (
	"github.com/gin-gonic/gin"

	"github.com/DeanThompson/ginpprof"
)

func main() {
	router := gin.Default()

	router.GET("/ping", func(c *gin.Context) {
		c.String(200, "pong")
	})

	// automatically add routers for net/http/pprof
	// e.g. /debug/pprof, /debug/pprof/heap, etc.
	ginpprof.Wrap(router) // 將路由包起來

	// ginpprof also plays well with *gin.RouterGroup
	// group := router.Group("/debug/pprof")
	// ginpprof.WrapGroup(group)

	router.Run(":8080")
}

  

不管哪種方式,你的 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 數據是動態的,要想獲得有效的數據,請保證應用處於較大的負載(比如正在生成中運行的服務,或者通過其他工具模擬訪問壓力)。否則如果應用處於空閑狀態,得到的結果可能沒有任何意義。

具體示例

首先我們來寫一段有問題的代碼:

// runtime_pprof/main.go
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:

		}
	}
}

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 {
		file, err := os.Create("./cpu.pprof")
		if err != nil {
			fmt.Printf("create cpu pprof failed, err:%v\n", err)
			return
		}
		pprof.StartCPUProfile(file)
		defer pprof.StopCPUProfile()
	}
	for i := 0; i < 8; i++ {
		go logicCode()
	}
	time.Sleep(20 * time.Second)
	if isMemPprof {
		file, err := os.Create("./mem.pprof")
		if err != nil {
			fmt.Printf("create mem pprof failed, err:%v\n", err)
			return
		}
		pprof.WriteHeapProfile(file)
		file.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: 下載graphvizgraphviz安裝目錄下的bin文件夾添加到Path環境變量中。 在終端輸入dot -version查看是否安裝成功。

關於圖形的說明: 每個框代表一個函數,理論上框的越大表示占用的CPU資源越多。 方框之間的線條代表函數之間的調用關系。 線條上的數字表示函數調用的次數。 方框中的第一行數字表示當前函數占用CPU的百分比,第二行數字表示當前函數累計占用CPU的百分比

go-torch和火焰圖

火焰圖(Flame Graph)是 Bredan Gregg 創建的一種性能分析圖表,因為它的樣子近似 🔥而得名。上面的 profiling 結果也轉換成火焰圖,如果對火焰圖比較了解可以手動來操作,不過這里我們要介紹一個工具:go-torch。這是 uber 開源的一個工具,可以直接讀取 golang profiling 數據,並生成一個火焰圖的 svg 文件。

安裝go-torch

 go get -v github.com/uber/go-torch
  // 在下載好的包中執行 go install (windows的才后面操作)

火焰圖 svg 文件可以通過瀏覽器打開,它對於調用圖的最優點是它是動態的:可以通過點擊每個方塊來 zoom in 分析它上面的內容。

火焰圖的調用順序從下到上每個方塊代表一個函數它上面一層表示這個函數會調用哪些函數方塊的大小代表了占用 CPU 使用的長短。火焰圖的配色並沒有特殊的意義,默認的紅、黃配色是為了更像火焰而已。

go-torch 工具的使用非常簡單,沒有任何參數的話,它會嘗試從http://localhost:8080/debug/pprof/profile獲取 profiling 數據。它有三個常用的參數可以調整:

  • -u –url:要訪問的 URL,這里只是主機和端口部分
  • -s –suffix:pprof profile 的路徑,默認為 /debug/pprof/profile
  • –seconds:要執行 profiling 的時間長度,默認為 30s

安裝 FlameGraph

要生成火焰圖,需要事先安裝 FlameGraph工具,這個工具的安裝很簡單(需要perl環境支持),只要把對應的可執行文件加入到環境變量中即可。

  1. 下載安裝perl:https://www.perl.org/get.html
  2. 下載FlameGraph:git clone https://github.com/brendangregg/FlameGraph.git
  3. FlameGraph目錄加入到操作系統的環境變量中。
  4. Windows平台的同學,需要把go-torch/render/flamegraph.go文件中的GenerateFlameGraph按如下方式修改,然后在go-torch目錄下執行go install即可。
// GenerateFlameGraph runs the flamegraph script to generate a flame graph SVG. func GenerateFlameGraph(graphInput []byte, args ...string) ([]byte, error) {
flameGraph := findInPath(flameGraphScripts)
if flameGraph == "" {
	return nil, errNoPerlScript
}
if runtime.GOOS == "windows" {
	return runScript("perl", append([]string{flameGraph}, args...), graphInput)
}
  return runScript(flameGraph, args, graphInput)
}

壓測工具wrk

推薦使用https://github.com/wg/wrkhttps://github.com/adjust/go-wrk

使用go-torch (下載完后cd到目錄使用 go install) -- (需要在gin框架下demo示例)

使用wrk進行壓測:go-wrk -n 50000 http://127.0.0.1:8080/book/list 在上面壓測進行的同時,打開另一個終端執行go-torch,30秒之后終端會初夏如下提示:Writing svg to torch.svg

然后我們使用瀏覽器打開torch.svg就能看到如下火焰圖了。

 

火焰圖的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 才有意義。