Go 程序的性能监控与分析 pprof

Go 开箱就提供了一系列的性能监控 API 以及用于分析的工具, 可以快捷而有效地观察应用程序各个细节的 CPU 与内存使用情况, 包括生成一些可视化的数据.

pprof 数据采样

pprof 采样数据主要有如下方式:

  • runtime/pprof: 采集程序(非 Server)的运行数据进行分析。手动调用runtime.StartCPUProfile或者runtime.StopCPUProfile等 API来生成和写入采样文件,灵活性高
  • net/http/pprof: 采集 HTTP Server 的运行时数据进行分析。通过 http 服务获取Profile采样文件,简单易用,适用于对应用程序的整体监控。通过 runtime/pprof 实现
net/http/pprof

在应用程序中导入import _ “net/http/pprof”,并启动 http server即可:

import _ "net/http/pprof" //执行init函数

net/http/pprof 已经在 init()函数中通过 import 副作用(side effect)完成默认 Handler 的注册

go func() {
    log.Println(http.ListenAndServe("localhost:6060", nil))
}()

1个简单的例子:

main.go

package main

import (
    "log"
    "net/http"
    _ "net/http/pprof"
    "gitlab.pri.ibanyu.com/devops/go-pprof-example/data"
)

func main() {
    go func() {
        for {
            log.Println(data.Add("https://github.com/devops"))
        }
    }()

    http.ListenAndServe("0.0.0.0:6060", nil)
}

data/d.go,文件内容:

package data

var datas []string

func Add(str string) string {
    data := []byte(str)
    sData := string(data)
    datas = append(datas, sData)

    return sData
}

接着我们需要编译一下这个程序并运行

$ go build .
$ ./go-pprof-example
2019/07/31 21:14:47 https://github.com/devops
2019/07/31 21:14:47 https://github.com/devops
2019/07/31 21:14:47 https://github.com/devops
2019/07/31 21:14:47 https://github.com/devops
2019/07/31 21:14:47 https://github.com/devops
2019/07/31 21:14:47 https://github.com/devops
2019/07/31 21:14:47 https://github.com/devops
2019/07/31 21:14:47 https://github.com/devops
2019/07/31 21:14:47 https://github.com/devops

之后可通过 http://localhost:6060/debug/pprof 可以看到如下页面:

页面上展示了可用的程序CMD运行采样数据:

  • allocs: 内存分配情况的采样信息
  • goroutine: /debug/pprof/goroutine,获取程序当前所有 goroutine 的堆栈信息
  • heap: /debug/pprof/heap,查看活动对象的内存分配情况。
  • threadcreate: /debug/pprof/threadcreate,查看创建新OS线程的堆栈跟踪
  • block: /debug/pprof/block,阻塞操作情况的采样信息
  • mutex: /debug/pprof/mutex,查看导致互斥锁的竞争持有者的堆栈跟踪
  • cmdline: /debug/pprof/cmdline,获取程序的命令行启动参数
  • profile: /debug/pprof/profile,默认进行 30s 的 CPU Profiling,得到一个分析用的 profile 文件
  • trace: /debug/pprof/trace 程序运行跟踪信息
runtime/pprof

runtime/pprof提供各种相对底层的 API 用于生成采样数据,一般应用程序更推荐使用net/http/pprof,runtime/pprof 的 API 参考runtime/pprof或 http pprof 实现

通过交互式终端使用

1. profile
$ go tool pprof http://localhost:6060/debug/pprof/profile?seconds=60
Fetching profile over HTTP from http://localhost:6060/debug/pprof/profile?seconds=60
Saved profile in /Users/wangyichen/pprof/pprof.samples.cpu.002.pb.gz
Type: cpu
Time: Jul 31, 2019 at 9:26pm (CST)
Duration: 1mins, Total samples = 8.02s (13.33%)
Entering interactive mode (type "help" for commands, "o" for options)
(pprof)

执行该命令后,需等待 60 秒(可调整 seconds 的值),pprof 会进行 CPU Profiling。结束后将默认进入 pprof 的交互式命令模式,可以对分析的结果进行查看或导出。具体可执行 pprof help 查看命令说明.

(pprof) top10
Showing nodes accounting for 7.88s, 98.25% of 8.02s total
Dropped 35 nodes (cum <= 0.04s)
Showing top 10 nodes out of 37
      flat  flat%   sum%        cum   cum%
     5.79s 72.19% 72.19%      6.15s 76.68%  syscall.syscall
     0.42s  5.24% 77.43%      0.75s  9.35%  runtime.notetsleep
     0.35s  4.36% 81.80%      0.36s  4.49%  runtime.exitsyscallfast
     0.34s  4.24% 86.03%      0.34s  4.24%  runtime.nanotime
     0.33s  4.11% 90.15%      0.33s  4.11%  runtime.pthread_cond_timedwait_relative_np
     0.33s  4.11% 94.26%      0.33s  4.11%  runtime.usleep
     0.15s  1.87% 96.13%      0.15s  1.87%  runtime.memmove
     0.09s  1.12% 97.26%      0.09s  1.12%  runtime.memclrNoHeapPointers
     0.07s  0.87% 98.13%      0.07s  0.87%  runtime.pthread_cond_signal
     0.01s  0.12% 98.25%      0.26s  3.24%  gitlab.pri.ibanyu.com/devops/go-pprof-example/data.Add
  • flat:给定函数上运行耗时
  • flat%:同上的 CPU 运行耗时总比例
  • sum%:给定函数累积使用 CPU 总比例
  • cum:当前函数加上它之上的调用运行总耗时
  • cum%:同上的 CPU 运行耗时总比例

最后一列为函数名称,在大多数的情况下,我们可以通过这五列得出一个应用程序的运行情况并优化.

2.heap
Fetching profile over HTTP from http://localhost:6060/debug/pprof/heap
Saved profile in /Users/wangyichen/pprof/pprof.alloc_objects.alloc_space.inuse_objects.inuse_space.002.pb.gz
Type: inuse_space
Time: Jul 31, 2019 at 9:34pm (CST)
Entering interactive mode (type "help" for commands, "o" for options)
(pprof) top
Showing nodes accounting for 1.27GB, 100% of 1.27GB total
      flat  flat%   sum%        cum   cum%
    1.27GB   100%   100%     1.27GB   100%  gitlab.pri.ibanyu.com/devops/go-pprof-example/data.Add
         0     0%   100%     1.27GB   100%  main.main.func1
(pprof) list data.Add
Total: 1.27GB
ROUTINE ======================== gitlab.pri.ibanyu.com/devops/go-pprof-example/data.Add in /tmp/example/data/d.go
    1.27GB     1.27GB (flat, cum)   100% of Total
         .          .      2:
         .          .      3:var datas []string
         .          .      4:
         .          .      5:func Add(str string) string {
         .          .      6:    data := []byte(str)
  823.03MB   823.03MB      7:    sData := string(data)
  481.98MB   481.98MB      8:    datas = append(datas, sData)
         .          .      9:
         .          .     10:    return sData
         .          .     11:}
  • -inuse_space:分析应用程序的常驻内存占用情况
  • -alloc_objects:分析应用程序的内存临时分配情况
3.allocs
go tool pprof http://localhost:6060/debug/pprof/allocs
Fetching profile over HTTP from http://localhost:6060/debug/pprof/allocs
Saved profile in /Users/wangyichen/pprof/pprof.alloc_objects.alloc_space.inuse_objects.inuse_space.003.pb.gz
Type: alloc_space
Time: Jul 31, 2019 at 9:37pm (CST)
Entering interactive mode (type "help" for commands, "o" for options)
(pprof) top
Showing nodes accounting for 5458.28MB, 99.86% of 5465.68MB total
Dropped 22 nodes (cum <= 27.33MB)
      flat  flat%   sum%        cum   cum%
 3987.74MB 72.96% 72.96%  3987.74MB 72.96%  gitlab.pri.ibanyu.com/devops/go-pprof-example/data.Add
  980.03MB 17.93% 90.89%   980.03MB 17.93%  fmt.Sprintln
  490.51MB  8.97% 99.86%  5458.28MB 99.86%  main.main.func1
         0     0% 99.86%   980.03MB 17.93%  log.Println
4. block

go tool pprof http://localhost:6060/debug/pprof/block

5. mutex

go tool pprof http://localhost:6060/debug/pprof/block

PProf 可视化界面

go-torch 在 Go 1.11 之前是作为非官方的可视化工具存在的, 它可以为监控数据生成火焰图,从 Go 1.11 开始, 火焰图被集成进入 Go 官方的 pprof 库.

go-torch is deprecated, use pprof instead

As of Go 1.11, flamegraph visualizations are available in go tool pprof directly!
$ go tool pprof -http=":8088" [binary] [profile]

在浏览器打开 http://localhost:8081/ui/flamegraph, 就可以看到下面这样的反过来的火焰图.如果出现 Could not execute dot; may need to install graphviz.,就是提示你要安装 graphviz 。谷歌安装即可.

火焰图最大优点是动态的,每一块代表一个函数,颜色的深浅是随机的 ,长度越长代表占用 CPU 时间越长,

然后, pprof 命令行的 top 以及 list 正则也可以在这里边完成, 还有 svg 图形.

通过 PProf 的可视化界面,我们能够更方便、更直观的看到 Go 应用程序的调用链、使用情况等,并且在 View 菜单栏中,还支持如上多种方式的切换。

本文粗略地介绍了 Go 的性能利器 PProf。在特定的场景中,PProf 给定位、剖析问题带了极大的帮助