你不知道的 Go 之 pprof

简介

Go 有非常多好用的工具，pprof 可以用来分析一个程序的性能。pprof 有以下 4 种类型：

• CPU profiling（CPU 性能分析）：这是最常使用的一种类型。用于分析函数或方法的执行耗时；
• Memory profiling：这种类型也常使用。用于分析程序的内存占用情况；
• Block profiling：这是 Go 独有的，用于记录 goroutine 在等待共享资源花费的时间；
• Mutex profiling：与 Block profiling 类似，但是只记录因为锁竞争导致的等待或延迟。

runtime/pprof

CPU profiling

pprof.StartCPUProfile()io.Writerpprofio.Writer

pprof.StopCPUProfile()StartCPUProfile()StopCPUProfile()StartCPUProfile()deferStopCPUProfile()

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.gocpu.profilego tool pprof

topfibtop5top20

listlist

我们知道使用递归求解斐波那契数存在大量重复的计算。下面我们来优化一下这个函数：

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.gocpu.profilego tool pprof

这里 top 看到的列表是空的。因为启用 CPU profiling 之后，运行时每隔 10ms 会中断一次，记录每个 goroutine 当前执行的堆栈，以此来分析耗时。我们优化之后的代码，在运行时还没来得及中断就执行完了，因此没有信息。

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.gomem.profilego tool pprof mem.profile

list

结果在预期之中，因为字符串拼接要会占用不少临时空间。

pkg/profile

runtime/pprofruntime/pprofpkg/profilepkg/profilepkg/profileruntime/pprofpkg/profilego get github.com/pkg/profile

defer profile.Start().Stop()

cpu.pproffib

$ 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

控制台会输出分析结果写入的文件路径。

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

net/http/pprofimporthttp.ListenAndServe()

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.gohttp://localhost:9999/debug/pprof/

go tool pprof

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

seconds=120

fibHandlerrepeatHandler

go tool pprofC:\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/pprofnet/http/pprofinit()

// 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)
}

DefaultServeMuxnet/httpDefaultServeMuxhttp.NewServeMux()ServeMux

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/pprofStartCPUProfile(w)pprof.StopCPUProfile()StartCPUProfile()http.ResponseWriter

init()/debug/pprof/heapIndex()

// 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)handlerstringServeHTTP()

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

Benchmarkcpu.profilemem.profilebench_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

总结

pkg/profilenet/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