pprof使用

1. 简介

pprof 是 golang 自带的性能分析工具，可以查看web应用的运行状态，分析程序CPU，内存，goroutine等使用情况。

golang 针对不同使用场景，提供了以下两种方式开启pprof性能分析

runtime/pprof：底层的pprof，可以直接通过代码调用
net/http/pprof：对runtime/pprof的封装，提供http接口和页面，更方便的调用，前提是应用有提供http服务

net/http/pprof是对runtime/pprof的封装，提供了

2. 直接使用runtime/pprof

直接使用 runtime/pprof 库，将画像数据写入文件中

package main

import (
	"fmt"
	"os"
	"runtime/pprof"
)

func main() {
	//CPU Profile
	f, err := os.Create("./cpuprofile")
	if err != nil {
		fmt.Println(err)
		return
	}
	defer f.Close()
	pprof.StartCPUProfile(f)
	defer pprof.StopCPUProfile()

	//Memory Profile
	fm, err := os.Create("./memoryprofile")
	if err != nil {
		fmt.Println(err)
		return
	}
	defer fm.Close()
	pprof.WriteHeapProfile(fm)

	for i := 0; i < 100; i++ {
		fmt.Println("程序员麻辣烫")
	}
}

执行完后，会发现cpuprofile、memoryprofile文件，里面包含cpu、内存的画像。 runtime/pprof 直接支持这两种画像

2.1. 生成文件解析

1. 使用 **pprof** 工具分析文件：

• • 查看分析数据：运行 go tool pprof 命令来加载文件。例如：

go tool pprof cpu.pprof

这将启动一个交互式的 pprof 命令行界面，你可以在这里运行命令来查看不同的性能数据。

• • 常用命令：
• • • top：显示最消耗 CPU 的函数。
    • list <function>：显示特定函数的源代码及其性能数据。
    • web：生成一个可视化的图形（需要 Graphviz）。
• • 生成图形：你可以通过 web 命令生成 HTML 格式的性能图：

go tool pprof -http=:8080 cpu.pprof

访问 http://localhost:8080 查看图形界面。

1. 使用可视化工具：如果 web 命令不可用，可以使用 dot 工具将生成的 .dot 文件转换为图形：

go tool pprof -dot cpu.pprof > cpu.dot
dot -Tpng cpu.dot -o cpu.png

3. 通过net/http/pprof使用

3.1. 开启pprof

举个栗子

package main

import (
    "net/http"
    _ "net/http/pprof"
)

func main () {
    // 通过协程开启pprof数据采集
    go func(){
        _ = http.ListenAndServe("0.0.0.0:6060", nil)
    }()

    // 业务代码doSomeThing
    ...
}

该方式会在默认的 http.DefaultServeMux 中插入debug pprof端点

// pprof.go:79
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)
}

如果自定义了NewServeMux，那么需要手动插入debug pprof端点

m := http.NewServeMux()
m.Handle("/debug/vars", expvar.Handler()) //用于查看exvar包中的存储的数据，由于一般无人使用该包，所以意义不大。
m.HandleFunc("/debug/pprof/", pprof.Index))
m.HandleFunc("/debug/pprof/cmdline", pprof.Cmdline)
m.HandleFunc("/debug/pprof/profile", pprof.Profile)
m.HandleFunc("/debug/pprof/symbol", pprof.Symbol)
m.HandleFunc("/debug/pprof/trace", pprof.Trace)

3.2. 结果查看

打开浏览器，访问http://127.0.0.1:6060/debug/pprof/

此url为net/http/pprof首页，不会执行startProfile(), 只有点击页面里具体的选项，才会触发默认的30s pprof收集

/debug/pprof/

Types of profiles available:
Count	Profile
10	allocs                 
0	block
0	cmdline
93	goroutine
10	heap
0	mutex
0	profile
12	threadcreate
0	trace
full goroutine stack dump

Profile Descriptions:
    allocs: 过去所有内存分配的采样
    block: 导致同步原语阻塞的堆栈跟踪
    cmdline: 当前程序的命令行调用
    goroutine: 所有当前goroutine的堆栈跟踪
    heap: 活动对象内存分配的采样
    mutex: 互斥锁的堆栈跟踪
    profile: CPU使用情况
    threadcreate: 导致创建新OS线程的堆栈跟踪 
    trace:当前程序的执行跟踪.

一般goroutine导致的内存泄露，goroutine 的count数值会异常偏大。

3.3. 查看当前正在执行的goroutine

览器中打开链接127.0.0.1:6060/debug/pprof/goroutine，会默认开启30秒pprof，执行结束后自动下载goroutine文件

下载后，在命令行下执行：

go tool pprof -http=":8081" goroutine

浏览器中打开链接127.0.0.1:6060/debug/pprof/heap
会下载heap文件。

下载后，在命令行下执行：

go tool pprof -http=":8081" heap

3.4 内存分析

web中查看

浏览器中打开链接 127.0.0.1:6060/debug/pprof/heap

会下载heap文件。

下载后，在命令行下执行：

go tool pprof -http=":8081" heap

会自动打开浏览器页面如下图所示

从图中可以直观的发现内存占用最多的都是哪些部分

3.5 查看CPU使用情况

web方式查看

浏览器中打开链接http://127.0.0.1:6060/debug/pprof/profile?seconds=5，

会下载profile文件。

这里指定采样参数seconds为5s，意思是采用5s之内的cpu使用情况。

下载后，在命令行下执行：

go tool pprof -http=":8081" profile

会自动打开浏览器页面如下图所示。

从图中可以直观的发现CPU占用最多的都是哪些部分。

由于例子程序一直空闲，此处的图借用其他程序的图。：）

命令行中执行

# 执行CPU性能分析，会默认从当前开始执行30scpu采样。
$ go tool pprof http://localhost:6060/debug/pprof/profile
# 也可以通过参数 seconds 指定采样时间。
$ go tool pprof http://localhost:6060/debug/pprof/profile\?seconds=60
# 采样结束后默认进入命令行界面
Fetching profile over HTTP from http://localhost:6060/debug/pprof/profile
Saved profile in /home/user/pprof/pprof.-.samples.cpu.001.pb.gz
File: -
Type: cpu
Time: Dec 24, 2020 at 6:24pm (CST)
Duration: 30.06s, Total samples = 590ms ( 1.96%)
Entering interactive mode (type "help" for commands, "o" for options)
(pprof) 
(pprof) top
Showing nodes accounting for 250ms, 42.37% of 590ms total
Showing top 10 nodes out of 285
      flat  flat%   sum%        cum   cum%
      50ms  8.47%  8.47%       50ms  8.47%  runtime.futex
      30ms  5.08% 13.56%      100ms 16.95%  runtime.findrunnable
      30ms  5.08% 18.64%       30ms  5.08%  syscall.Syscall
      20ms  3.39% 22.03%       20ms  3.39%  aeshashbody
      20ms  3.39% 25.42%       20ms  3.39%  encoding/json.(*decodeState).rescanLiteral
      20ms  3.39% 28.81%       30ms  5.08%  encoding/json.checkValid
      20ms  3.39% 32.20%       20ms  3.39%  runtime.epollwait
      20ms  3.39% 35.59%       30ms  5.08%  runtime.gentraceback
      20ms  3.39% 38.98%       20ms  3.39%  runtime.memclrNoHeapPointers
      20ms  3.39% 42.37%       20ms  3.39%  runtime.memmove

3.6 跟踪当前程序的执行

浏览器中打开链接 http://127.0.0.1:6060/debug/pprof/trace?seconds=5

会下载trace文件。

通过trace文件，可以查看各个goroutine执行耗时情况，包括网络等待耗时、同步耗时、GC耗时等。

下载后，在命令行下执行：

go tool trace -http=":8081" trace

会自动打开浏览器页面如下图所示。

点击“Goroutine analysis” 打开页面如下所示。

图中列出所有goroutine

打开第一个，可以看到各阶段耗时情况表

打开图中graph链接，可以看到调用关系和耗时。

go tool trace主要用于解决两个棘手的问题：诊断延迟问题和诊断并发问题。

延迟问题，是指程序执行过程被意外阻塞住。例如，被系统调用阻塞，被channel、muext阻塞， 或者调度器问题， 或者GC问题等。

并发问题，是指程序没有充分利用CPU。可能的原因包括，串行化、资源竞争等。

3.7 通过go-zero使用pprof

go-zero signals.go中集成了pprof，如果在terminal中执行kill -user2 {pid}, signals.go会收到信号开始pprof，再次发送kill -user2 {pid}则会停止

收集的信息都在/tmp文件夹下，以这个服务名命名的如下：

xxxx-mq-cpu-xxx.pprof

xxxx-mq-memory-xxx.pprof

xxxx-mq-mutex-xxx.pprof

xxxx-mq-block-xxx.pprof

…

这时候就可以下载对应的pprof去本地分析，可以使用go tool pprof xxxx-mq-memory-xxx.pprof，也可以配合graphviz使用web ui查看

todo

go-zero pprof的这个开关是手动的，不能做到有问题自动开启pprof保留现场。后续可以运维配合实例监控一起做，比如内存、cpu连续超过80%指标3分钟的话，就调用这个开关收集，之后就可以根据这个文件来分析问题

同样net/http/pprof也是一样的道理，可以通过运维配合实例监控一起做