你不知道的 Go 之 pprof

時間  2021-06-10
標籤 git github golang 瀏覽器 安全 服務器 微信 函數 工具 性能 欄目 Git 简体版
原文   原文鏈接

簡介

Go 有很是多好用的工具，pprof 能夠用來分析一個程序的性能。pprof 有如下 4 種類型：git

  • CPU profiling（CPU 性能分析）：這是最常使用的一種類型。用於分析函數或方法的執行耗時；
  • Memory profiling：這種類型也常使用。用於分析程序的內存佔用狀況；
  • Block profiling：這是 Go 獨有的，用於記錄 goroutine 在等待共享資源花費的時間；
  • Mutex profiling：與 Block profiling 相似，可是隻記錄由於鎖競爭致使的等待或延遲。

咱們主要介紹前兩種類型。Go 中 pprof 相關的功能在包runtime/pprof中。github

CPU profiling

pprof 使用很是簡單。首先調用pprof.StartCPUProfile()啓用 CPU profiling。它接受一個io.Writer類型的參數，pprof會將分析結果寫入這個io.Writer中。爲了方便過後分析，咱們寫到一個文件中。golang

在要分析的代碼後調用pprof.StopCPUProfile()。那麼StartCPUProfile()和StopCPUProfile()之間的代碼執行狀況都會被分析。方便起見能夠直接在StartCPUProfile()後，用defer調用StopCPUProfile()，即分析這以後的全部代碼。瀏覽器

咱們如今實現一個計算斐波那契數列的第n數的函數：安全

func fib(n int) int {
  if n <= 1 {
    return 1
  }

  return fib(n-1) + fib(n-2)
}

而後使用 pprof 分析一下運行狀況：服務器

func main() {
  f, _ := os.OpenFile("cpu.profile", os.O_CREATE|os.O_RDWR, 0644)
  defer f.Close()
  pprof.StartCPUProfile(f)
  defer pprof.StopCPUProfile()

  n := 10
  for i := 1; i <= 5; i++ {
    fmt.Printf("fib(%d)=%d\n", n, fib(n))
    n += 3 * i
  }
}

執行go run main.go，會生成一個cpu.profile文件。這個文件記錄了程序的運行狀態。使用go tool pprof命令分析這個文件：微信

上面用top命令查看耗時最高的 10 個函數。能夠看到fib函數耗時最高，累計耗時 390ms，佔了總耗時的 90.70%。咱們也可使用top5和top20分別查看耗時最高的 5 個 和 20 個函數。函數

當找到耗時較多的函數，咱們還可使用list命令查看該函數是怎麼被調用的，各個調用路徑上的耗時是怎樣的。list命令後跟一個表示方法名的模式：工具

咱們知道使用遞歸求解斐波那契數存在大量重複的計算。下面咱們來優化一下這個函數：性能

func fib2(n int) int {
  if n <= 1 {
    return 1
  }

  f1, f2 := 1, 1
  for i := 2; i <= n; i++ {
    f1, f2 = f2, f1+f2
  }

  return f2
}

改用迭代以後耗時如何呢？咱們來測一下。首先執行go run main.go生成cpu.profile文件，而後使用go tool pprof分析：

這裏 top 看到的列表是空的。由於啓用 CPU profiling 以後，運行時每隔 10ms 會中斷一次，記錄每一個 goroutine 當前執行的堆棧，以此來分析耗時。咱們優化以後的代碼，在運行時還沒來得及中斷就執行完了，所以沒有信息。

go tool pprof 執行的全部命令能夠經過help查看：

Memory profiling

內存分析有所不一樣，咱們能夠在程序運行過程當中隨時查看堆內存狀況。下面咱們編寫一個生成隨機字符串，和將字符串重複n次的函數：

const Letters = "abcdefghijklmnopqrstuvwxyzABCDEFGHIJKLMNOPQRSTUVWXYZ"

func generate(n int) string {
  var buf bytes.Buffer
  for i := 0; i < n; i++ {
    buf.WriteByte(Letters[rand.Intn(len(Letters))])
  }
  return buf.String()
}

func repeat(s string, n int) string {
  var result string
  for i := 0; i < n; i++ {
    result += s
  }

  return result
}

編寫程序，調用上面的函數，記錄內存佔用狀況：

func main() {
  f, _ := os.OpenFile("mem.profile", os.O_CREATE|os.O_RDWR, 0644)
  defer f.Close()
  for i := 0; i < 100; i++ {
    repeat(generate(100), 100)
  }

  pprof.Lookup("heap").WriteTo(f, 0)
}

這裏在循環結束後，經過pprof.Lookup("heap")查看堆內存的佔用狀況，並將結果寫到文件mem.profile中。

運行go run main.go生成mem.profile文件，而後使用go tool pprof mem.profile來分析：

固然也可使用list命令查看，內存在哪一行分配的：

結果在預期之中，由於字符串拼接要會佔用很多臨時空間。

pkg/profile

runtime/pprof使用起來有些不便，由於要重複編寫打開文件，開啓分析，結束分析的代碼。因此出現了包裝了runtime/pprof的庫：pkg/profile。pkg/profile的 GitHub 倉庫地址爲：https://github.com/pkg/profile。pkg/profile只是對runtime/pprof作了一層封裝，讓它更好用。使用pkg/profile能夠將代碼簡化爲一行。使用前須要使用go get github.com/pkg/profile獲取這個庫。

defer profile.Start().Stop()

默認啓用的是 CPU profiling，數據寫入文件cpu.pprof。使用它來分析咱們的fib程序性能：

$ go run main.go 
2021/06/09 21:10:36 profile: cpu profiling enabled, C:\Users\ADMINI~1\AppData\Local\Temp\profile594431395\cpu.pprof
fib(10)=89
fib(13)=377
fib(19)=6765
fib(28)=514229
fib(40)=165580141
2021/06/09 21:10:37 profile: cpu profiling disabled, C:\Users\ADMINI~1\AppData\Local\Temp\profile594431395\cpu.pprof

控制檯會輸出分析結果寫入的文件路徑。

若是要啓用 Memory profiling，能夠傳入函數選項MemProfile：

defer profile.Start(profile.MemProfile).Stop()

另外還能夠經過函數選項控制內存採樣率，默認爲 4096。咱們能夠改成 1：

defer profile.Start(profile.MemProfile, profile.MemProfileRate(1)).Stop()

火焰圖

經過命令行查看 CPU 或內存狀況不夠直觀。Bredan Gregg 大神發明了火焰圖（Flame Graph）能夠很直觀地看到內存和 CPU 消耗狀況。新版本的 go tool pprof 工具已經集成了火焰圖（我使用的是 Go1.16）。想要生成火焰圖，必須安裝 graphviz。

在 Mac 上：

brew install graphviz

在 Ubuntu 上：

apt install graphviz

在 Windows 上，官網下載頁http://www.graphviz.org/download/有可執行安裝文件，下載安裝便可。注意設置 PATH 路徑。

上面程序生成的 cpu.profile 和 mem.profile 咱們能夠直接在網頁上查看火焰圖。執行下面命令：

go tool pprof -http :8080 cpu.profile

默認會打開瀏覽器窗口，顯示下面的頁面：

咱們能夠在 VIEW 菜單欄中切換顯示火焰圖：

能夠用鼠標在火焰圖上懸停、點擊，來查看具體的某個調用。

net/http/pprof

若是線上遇到 CPU 或內存佔用太高，該怎麼辦呢？總不能將上面的 Profile 代碼編譯到生產環境吧，這無疑會極大地影響性能。net/http/pprof提供了一個方法，不使用時不會形成任何影響，遇到問題時能夠開啓 profiling 幫助咱們排查問題。咱們只須要使用import這個包，而後在一個新的 goroutine 中調用http.ListenAndServe()在某個端口啓動一個默認的 HTTP 服務器便可：

import (
  _ "net/http/pprof"
)

func NewProfileHttpServer(addr string) {
  go func() {
    log.Fatalln(http.ListenAndServe(addr, nil))
  }()
}

下面咱們編寫一個 HTTP 服務器，將前面示例中的求斐波那契數和重複字符串搬到 Web 上。爲了讓測試結果更明顯一點，我把原來執行一次的函數都執行了 1000 次：

func fibHandler(w http.ResponseWriter, r *http.Request) {
  n, err := strconv.Atoi(r.URL.Path[len("/fib/"):])
  if err != nil {
    responseError(w, err)
    return
  }

  var result int
  for i := 0; i < 1000; i++ {
    result = fib(n)
  }
  response(w, result)
}

func repeatHandler(w http.ResponseWriter, r *http.Request) {
  parts := strings.SplitN(r.URL.Path[len("/repeat/"):], "/", 2)
  if len(parts) != 2 {
    responseError(w, errors.New("invalid params"))
    return
  }

  s := parts[0]
  n, err := strconv.Atoi(parts[1])
  if err != nil {
    responseError(w, err)
    return
  }

  var result string
  for i := 0; i < 1000; i++ {
    result = repeat(s, n)
  }
  response(w, result)
}

建立 HTTP 服務器，註冊處理函數：

func main() {
  mux := http.NewServeMux()
  mux.HandleFunc("/fib/", fibHandler)
  mux.HandleFunc("/repeat/", repeatHandler)

  s := &http.Server{
    Addr:    ":8080",
    Handler: mux,
  }

  NewProfileHttpServer(":9999")

  if err := s.ListenAndServe(); err != nil {
    log.Fatal(err)
  }
}

咱們另外啓動了一個 HTTP 服務器用於處理 pprof 相關請求。

另外爲了測試，我編寫了一個程序，一直髮送 HTTP 請求給這個服務器：

func doHTTPRequest(url string) {
  resp, err := http.Get(url)
  if err != nil {
    fmt.Println("error:", err)
    return
  }

  data, _ := ioutil.ReadAll(resp.Body)
  fmt.Println("ret:", len(data))
  resp.Body.Close()
}

func main() {
  var wg sync.WaitGroup
  wg.Add(2)
  go func() {
    defer wg.Done()
    for {
      doHTTPRequest(fmt.Sprintf("http://localhost:8080/fib/%d", rand.Intn(30)))
      time.Sleep(500 * time.Millisecond)
    }
  }()

  go func() {
    defer wg.Done()
    for {
      doHTTPRequest(fmt.Sprintf("http://localhost:8080/repeat/%s/%d", generate(rand.Intn(200)), rand.Intn(200)))
      time.Sleep(500 * time.Millisecond)
    }
  }()
  wg.Wait()
}

使用命令go run main.go啓動服務器。運行上面的程序一直髮送請求給服務器。一段時間以後，咱們能夠用瀏覽器打開http://localhost:9999/debug/pprof/：

go tool pprof也支持遠程獲取 profile 文件：

$ go tool pprof -http :8080 localhost:9999/debug/pprof/profile?seconds=120

其中seconds=120表示採樣 120s，默認爲 30s。結果以下：

能夠看出這裏除了運行時的消耗，主要就是fibHandler和repeatHandler這個處理的消耗了。

固然通常線上不可能把這個端口開放出來，由於有很大的安全風險。因此，咱們通常在線上機器 profile 生成文件，將文件下載到本地分析。上面咱們看到go tool pprof會生成一個文件保存在本地，例如個人機器上是C:\Users\Administrator\pprof\pprof.samples.cpu.001.pb.gz。把這個文件下載到本地，而後：

$ go tool pprof -http :8888 pprof.samples.cpu.001.pb.gz

net/http/pprof 實現

net/http/pprof的實現也沒什麼神祕的地方，無非就是在net/http/pprof包的init()函數中，註冊了一些處理函數：

// src/net/http/pprof/pprof.go
func init() {
  http.HandleFunc("/debug/pprof/", Index)
  http.HandleFunc("/debug/pprof/cmdline", Cmdline)
  http.HandleFunc("/debug/pprof/profile", Profile)
  http.HandleFunc("/debug/pprof/symbol", Symbol)
  http.HandleFunc("/debug/pprof/trace", Trace)
}

http.HandleFunc()會將處理函數註冊到默認的ServeMux中：

// src/net/http/server.go
var DefaultServeMux = &defaultServeMux
var defaultServeMux ServeMux

func HandleFunc(pattern string, handler func(ResponseWriter, *Request)) {
  DefaultServeMux.HandleFunc(pattern, handler)
}

這個DefaultServeMux是net/http的包級變量，只有一個實例。爲了不路徑衝突，一般咱們不建議在本身編寫 HTTP 服務器的時候使用默認的DefaultServeMux。通常都是先調用http.NewServeMux()建立一個新的ServeMux，見上面的 HTTP 示例代碼。

再來看net/http/pprof包註冊的處理函數：

// src/net/http/pprof/pprof.go
func Profile(w http.ResponseWriter, r *http.Request) {
  // ...
  if err := pprof.StartCPUProfile(w); err != nil {
    serveError(w, http.StatusInternalServerError,
      fmt.Sprintf("Could not enable CPU profiling: %s", err))
    return
  }
  sleep(r, time.Duration(sec)*time.Second)
  pprof.StopCPUProfile()
}

刪掉前面無關的代碼，這個函數也是調用runtime/pprof的StartCPUProfile(w)方法開始 CPU profiling，而後睡眠一段時間（這個時間就是採樣間隔），最後調用pprof.StopCPUProfile()中止採用。StartCPUProfile()方法傳入的是http.ResponseWriter類型變量，因此採樣結果直接寫回到 HTTP 的客戶端。

內存 profiling 的實現用了一點技巧。首先，咱們在init()函數中沒有發現處理內存 profiling 的處理函數。實現上，/debug/pprof/heap路徑都會走到Index()函數中：

// src/net/http/pprof/pprof.go
func Index(w http.ResponseWriter, r *http.Request) {
  if strings.HasPrefix(r.URL.Path, "/debug/pprof/") {
    name := strings.TrimPrefix(r.URL.Path, "/debug/pprof/")
    if name != "" {
      handler(name).ServeHTTP(w, r)
      return
    }
  }
  // ...
}

最終會走到handler(name).ServeHTTP(w, r)。handler只是基於string類型定義的一個新類型，它定義了ServeHTTP()方法：

type handler string

func (name handler) ServeHTTP(w http.ResponseWriter, r *http.Request) {
  p := pprof.Lookup(string(name))
  // ...
  p.WriteTo(w, debug)
}

刪掉其餘無關的代碼，就剩下上面兩行。統計數據將會寫入http.ResponseWriter。

Benchmark

其實在Benchmark時也能夠生成cpu.profile、mem.profile這些分析文件。咱們在第一個示例的目錄下新建一個bench_test.go文件：

func BenchmarkFib(b *testing.B) {
  for i := 0; i < b.N; i++ {
    fib(30)
  }
}

而後執行命令go test -bench . -test.cpuprofile cpu.profile：

而後就能夠分析這個cpu.profile文件了。

總結

本文介紹了 pprof 工具的使用，以及更方便使用的庫pkg/profile，另外介紹如何使用net/http/pprof給線上程序加個保險，遇到問題隨時能夠診斷。沒有遇到問題不會對性能有任何影響。

參考

  1. pkg/profile GitHub：https://github.com/pkg/profile
  2. 你不知道的Go GitHub：https://github.com/darjun/you-dont-know-go

我

個人博客：https://darjun.github.io

歡迎關注個人微信公衆號【GoUpUp】，共同窗習，一塊兒進步~

相關文章
相關標籤/搜索
每日一句
    每一个你不满意的现在，都有一个你没有努力的曾经。
本站公眾號
   歡迎關注本站公眾號,獲取更多信息
聯繫我們 最近搜索 最新文章 沪ICP备13005482号-10 MyBatis教程 SQL 教程 MySQL教程 Java 教程 Thymeleaf 教程 Hibernate教程 Spring教程 Redis教程