Go 学习笔记（81）— Go 性能分析工具 pprof

wohu007

已于 2022-04-25 16:15:50 修改

阅读量1.2k

点赞数

分类专栏： Go 文章标签： pprof 性能分析工具

于 2021-10-15 20:11:42 首次发布

本文链接：https://blog.csdn.net/wohu1104/article/details/120725413

版权

Go 专栏收录该内容

90 篇文章 210 订阅

订阅专栏

1. 性能分析工具包

Go 语言为程序开发者们提供了丰富的性能分析 API，和非常好用的标准工具。这些 API 主要存在于：

runtime/pprof
net/http/pprof
runtime/trace

runtime 代码包中还包含了一些更底层的 API。它们可以被用来收集或输出 Go 程序运行过程中的一些关键指标，并帮助我们生成相应的概要文件以供后续分析时使用。

至于标准工具，主要有 go tool pprof 和 go tool trace 这两个。它们可以解析概要文件中的信息，并以人类易读的方式把这些信息展示出来。

2. 性能分析文件

在 Go 语言中，用于分析程序性能的概要文件有三种，分别是：

CPU 概要文件（CPU Profile）

对于 CPU 概要文件来说，其中的每一段独立的概要信息都记录着，在进行某一次采样的那个时刻，CPU 上正在执行的 Go 代码。

内存概要文件（Mem Profile）

对于内存概要文件，其中的每一段概要信息都记载着，在某个采样时刻，正在执行的 Go 代码以及堆内存的使用情况，这里包含已分配和已释放的字节数量和对象数量

阻塞概要文件（Block Profile）

阻塞概要文件，其中的每一段概要信息，都代表着 Go 程序中的一个 goroutine 阻塞事件

这些概要文件中包含的都是：在某一段时间内，对 Go 程序的相关指标进行多次采样后得到的概要信息。

在默认情况下，这些概要文件中的信息并不是普通的文本，它们都是以二进制的形式展现的。如果你使用一个常规的文本编辑器查看它们的话，那么肯定会看到一堆“乱码”。

这时就可以显现出 go tool pprof 这个工具的作用了。我们可以通过它进入一个基于命令行的交互式界面，并对指定的概要文件进行查阅。就像下面这样：

$ go tool pprof cpuprofile.out
Type: cpu
Time: Nov 9, 2018 at 4:31pm (CST)
Duration: 7.96s, Total samples = 6.88s (86.38%)
Entering interactive mode (type "help" for commands, "o" for options)
(pprof)

在进入这个工具的交互式界面之后，我们只要输入指令 help 并按下回车键，就可以看到很详细的帮助文档。

概要文件是通过 protocol buffers 生成的二进制数据流，或者说字节流。概括来讲，protocol buffers 是一种数据序列化协议，同时也是一个序列化工具。它可以把一个值，比如一个结构体或者一个字典，转换成一段字节流。也可以反过来，把经过它生成的字节流反向转换为程序中的一个值。前者就被叫做序列化，而后者则被称为反序列化。

Protocol buffers 的优势有不少。比如，它可以在序列化数据的同时对数据进行压缩，所以它生成的字节流，通常都要比相同数据的其他格式（例如 XML 和 JSON）占用的空间明显小很多。

Go 语言工具链中的 go pprof 可以帮助开发者快速分析及定位各种性能问题，如 CPU消耗、内存分配及阻塞分析。具体作用如下：
pprof

3. 性能分析原理

runtime/pprof 包中的 API 。可以在我们想让程序开始对 CPU 概要信息进行采样的时候，需要调用这个代码包中的 StartCPUProfile 函数，而在停止采样的时候则需要调用该包中的 StopCPUProfile 函数。

runtime/pprof.StartCPUProfile 函数在被调用的时候，先会去设定 CPU 概要信息的采样频率，并会在单独的 goroutine 中进行 CPU 概要信息的收集和输出。

性能分析首先需要使用 runtime.pprof 包嵌入到待分析程序的入口和结束处。StartCPUProfile函数设定的采样频率总是固定的，即：100 赫兹。也就是说，每秒采样 100 次，或者说每 10 毫秒采样一次。

赫兹，也称 Hz，是 CPU 主频的基本单位。CPU 的主频指的是，CPU 内核工作的时钟频率，这个时钟频率的倒数即为时钟周期（clock cycle），也就是一个 CPU 内核执行一条运算指令所需的时间，单位是秒。例如，主频为 1000Hz 的 CPU，它的单个内核执行一条运算指令所需的时间为 0.001秒，即 1 毫秒。又例如，我们现在常用的 3.2GHz 的多核 CPU，其单个内核在 1 个纳秒的时间里就可以至少执行三条运算指令。

StartCPUProfile 函数设定的 CPU 概要信息采样频率，相对于现代的 CPU 主频来说是非常低的。这主要有两个方面的原因。

一方面，过高的采样频率会对 Go 程序的运行效率造成很明显的负面影响。因此，runtime 包中SetCPUProfileRate 函数在被调用的时候，会保证采样频率不超过 1MHz（兆赫），也就是说，它只允许每 1 微秒最多采样一次。StartCPUProfile 函数正是通过调用这个函数来设定 CPU 概要信息的采样频率的。
另一方面，经过大量的实验，Go 语言团队发现 100Hz 是一个比较合适的设定。因为这样做既可以得到足够多、足够有用的概要信息，又不至于让程序的运行出现停滞。另外，操作系统对高频采样的处理能力也是有限的，一般情况下，超过 500Hz 就很可能得不到及时的响应了。

在 StartCPUProfile 函数执行之后，一个新启用的 goroutine 将会负责执行 CPU 概要信息的收集和输出，直到 runtime/pprof 包中的 StopCPUProfile 函数被成功调用。StopCPUProfile 函数也会调用runtime.SetCPUProfileRate 函数，并把参数值（也就是采样频率）设为 0。这会让针对 CPU 概要信息的采样工作停止。同时，它也会给负责收集 CPU 概要信息的代码一个“信号”，以告知收集工作也需要停止了。

在接到这样的“信号”之后，那部分程序将会把这段时间内收集到的所有 CPU 概要信息，全部写入到我们在调用 StartCPUProfile 函数的时候指定的写入器中。只有在上述操作全部完成之后，StopCPUProfile 函数才会返回。

4. 代码实战

package main

import (
	"errors"
	"os"
	"path/filepath"
	"runtime/pprof"
)

var (
	profileName = "cpuprofile.out"
)

// CreateFile 用于在当前目录下创建一个指定名称的文件。
// 若同名文件已存在，则清空并复用。
func CreateFile(dir, name string) (*os.File, error) {
	if dir == "" {
		var err error
		dir, err = os.Getwd()
		if err != nil {
			return nil, err
		}
	}
	path := filepath.Join(dir, name)
	return os.Create(path)
}

func joinSlice() []string {
	var arr []string
	// 为了进行性能分析,这里在己知元素大小的情况下,还是使用 append()
	// 函数不断地添加切片。性能较低,在实际中应该避免,这里为了性能分析,故意这样写。
	for i := 0; i < 1000000; i++ {
		arr = append(arr, "arr")
	}

	return arr
}

func main() {
	f, _ := CreateFile("", profileName)

	defer f.Close()
	startCPUProfile(f)

	joinSlice()

	stopCPUProfile()
}

func startCPUProfile(f *os.File) error {
	if f == nil {
		return errors.New("nil file")
	}
	return pprof.StartCPUProfile(f)
}

func stopCPUProfile() {
	pprof.StopCPUProfile()
}

运行后输出结果：

cpuprofile.out

使用命令

$ go tool pprof cpuprofile.out 
File: q1
Type: cpu
Time: Apr 25, 2022 at 3:58pm (CST)
Duration: 300.85ms, Total samples = 150ms (49.86%)
Entering interactive mode (type "help" for commands, "o" for options)
(pprof)

输入 help

(pprof) help
  Commands:
    callgrind        Outputs a graph in callgrind format
    comments         Output all profile comments
    disasm           Output assembly listings annotated with samples
    dot              Outputs a graph in DOT format
    eog              Visualize graph through eog
    evince           Visualize graph through evince
    gif              Outputs a graph image in GIF format
    gv               Visualize graph through gv
    kcachegrind      Visualize report in KCachegrind
    list             Output annotated source for functions matching regexp
    pdf              Outputs a graph in PDF format
    peek             Output callers/callees of functions matching regexp
    png              Outputs a graph image in PNG format
    proto            Outputs the profile in compressed protobuf format
    ps               Outputs a graph in PS format
    raw              Outputs a text representation of the raw profile
    svg              Outputs a graph in SVG format
    tags             Outputs all tags in the profile
    text             Outputs top entries in text form
    top              Outputs top entries in text form
    topproto         Outputs top entries in compressed protobuf format
    traces           Outputs all profile samples in text form
    tree             Outputs a text rendering of call graph
    web              Visualize graph through web browser
    weblist          Display annotated source in a web browser
    o/options        List options and their current values
    quit/exit/^D     Exit pprof

  Options:
    call_tree        Create a context-sensitive call tree
    compact_labels   Show minimal headers
    divide_by        Ratio to divide all samples before visualization
    drop_negative    Ignore negative differences
    edgefraction     Hide edges below <f>*total
    focus            Restricts to samples going through a node matching regexp
    hide             Skips nodes matching regexp
    ignore           Skips paths going through any nodes matching regexp
    mean             Average sample value over first value (count)
    nodecount        Max number of nodes to show
    nodefraction     Hide nodes below <f>*total
    noinlines        Ignore inlines.
    normalize        Scales profile based on the base profile.
    output           Output filename for file-based outputs
    prune_from       Drops any functions below the matched frame.
    relative_percentages Show percentages relative to focused subgraph
    sample_index     Sample value to report (0-based index or name)
    show             Only show nodes matching regexp
    show_from        Drops functions above the highest matched frame.
    source_path      Search path for source files
    tagfocus         Restricts to samples with tags in range or matched by regexp
    taghide          Skip tags matching this regexp
    tagignore        Discard samples with tags in range or matched by regexp
    tagshow          Only consider tags matching this regexp
    trim             Honor nodefraction/edgefraction/nodecount defaults
    trim_path        Path to trim from source paths before search
    unit             Measurement units to display

  Option groups (only set one per group):
    cumulative       
      cum              Sort entries based on cumulative weight
      flat             Sort entries based on own weight
    granularity      
      addresses        Aggregate at the address level.
      filefunctions    Aggregate at the function level.
      files            Aggregate at the file level.
      functions        Aggregate at the function level.
      lines            Aggregate at the source code line level.
  :   Clear focus/ignore/hide/tagfocus/tagignore

  type "help <cmd|option>" for more information
(pprof)

再输入 top 可以看到

(pprof) top
Showing nodes accounting for 150ms, 100% of 150ms total
Showing top 10 nodes out of 29
      flat  flat%   sum%        cum   cum%
      50ms 33.33% 33.33%       50ms 33.33%  runtime.memclrNoHeapPointers
      40ms 26.67% 60.00%       40ms 26.67%  runtime.procyield
      20ms 13.33% 73.33%       30ms 20.00%  runtime.scanobject
      10ms  6.67% 80.00%       20ms 13.33%  runtime.findObject
      10ms  6.67% 86.67%       10ms  6.67%  runtime.heapBits.next
      10ms  6.67% 93.33%       10ms  6.67%  runtime.spanOf
      10ms  6.67%   100%       20ms 13.33%  runtime.wbBufFlush1
         0     0%   100%      100ms 66.67%  main.joinSlice
         0     0%   100%      100ms 66.67%  main.main
         0     0%   100%       50ms 33.33%  runtime.(*mheap).alloc
(pprof) list joinSlice
Total: 150ms
ROUTINE ======================== main.joinSlice in /home/wohu/goProject/Golang_Puzzlers/src/puzzlers/article37/q1/demo96.go
         0      100ms (flat, cum) 66.67% of Total
         .          .     28:func joinSlice() []string {
         .          .     29:	var arr []string
         .          .     30:	// 为了进行性能分析,这里在己知元素大小的情况下,还是使用 append()
         .          .     31:	// 函数不断地添加切片。性能较低,在实际中应该避免,这里为了性能分析,故意这样写。
         .          .     32:	for i := 0; i < 1000000; i++ {
         .      100ms     33:		arr = append(arr, "arr")
         .          .     34:	}
         .          .     35:
         .          .     36:	return arr
         .          .     37:}
         .          .     38:
(pprof)

5. 安装 Graphviz

go pprof 工具链配合 Graphviz 图形化工具可以将 runtime.pprof 包生成的数据转换为 PDF格式，以图片的方式展示程序的性能分析结果。

Graphviz 是一套通过文本描述的方法生成图形的工具包。描述文本的语言叫做 DOT 。在 www.graphviz.org 网站可以获取到最新的 Graphviz 各平台的安装包。

CentOS下，可以使用 yum 指令直接安装：

yum install graphviz

Ubuntu 下

sudo apt-get install graphviz

其它平台安装方式可参考： https://www.graphviz.org/download/

6. 安装第三方包

runtime.pprof 提供基础的运行时分析的驱动，但是这套接口使用起来还不是太方便，例如：

输出数据使用 io.Writer 接口，虽然扩展性很强，但是对于实际使用不够方便，不支持写入文件；
默认配置项较为复杂；

很多第三方的包在系统包 runtime.pprof 的技术上进行便利性封装，让整个测试过程更为方便。这里使用 github.com/pkg/profile 包进行例子展示，使用下面代码安装这个包：

go get github.com/pkg/profile

7. 性能分析示例

cpu.go 代码内容：

package main

import (
	"time"

	"github.com/pkg/profile"
)

func joinSlice() []string {

	var arr []string

	// 为了进行性能分析,这里在己知元素大小的情况下,还是使用 append()
	// 函数不断地添加切片。性能较低,在实际中应该避免,这里为了性能分析,故意这样写。
	for i := 0; i < 1000000; i++ {
		arr = append(arr, "arr")
	}

	return arr
}

func main() {
	// 开始性能分析， Start 参数都是可选项，指定的分析项目是profile.CPUProfile
	// profile.ProfilePath(".") 指定输出的分析文件路径，
	// profile.Start 返回一个停止接口
	stopper := profile.Start(profile.CPUProfile, profile.ProfilePath("."))

	// 在main结束时停止性能分析
	defer stopper.Stop()

	// 分析的核心逻辑
	joinSlice()
	// 为了保证性能分析数据的合理性,分析的最短时间是 1 秒,使用 time.Sleep()
	//	在程序结束前等待 1 秒。如果你的程序默认可以运行 1 秒以上,这个等待可以去掉 。
	time.Sleep(time.Second)
}

性能分析需要可执行配合才能生成分析结果，因此使用命令行对程序进行编译，步骤如下：

go build  -o cpu cpu.go			
./cpu												# 运行可执行文件，在当前目录下生成 cpu.pprof
go tool pprof  --pdf cpu cpu.pprof > cpu.pdf

使用 go tool 工具链输入 cpu.pprof 和 cpu 可执行文件，生成 PDF 格式的输出文件，将输出文件重定向为 cpu.pdf 文件。这个过程中会调用 Graphviz 工具。

8. PDF 结果

每一个框为一个函数调用的路径，第 3 个方框中 joinSlice 函数耗费了 76% 的 CPU 时间，存在性能瓶颈。

重新优化代码，在己知切片元素数量的情况下直接分配内存，代码如下：

func joinSlice() []string {
	const count = 1000000
	var arr = make([]string, count)

	for i := 0; i < count; i++ {
		arr[i] = "arr"
	}

	return arr
}

9. 实战案例

https://github.com/wolfogre/go-pprof-practice
https://blog.wolfogre.com/posts/go-ppof-practice/

wohu007

关注

0
点赞
踩
1

收藏

觉得还不错? 一键收藏
0
评论
Go 学习笔记（81）— Go 性能分析工具 pprof

Go 语言工具链中的 go pprof 可以帮助开发者快速分析及定位各种性能问题，如 CPU消耗、内存分配及阻塞分析。性能分析首先需要使用 runtime.pprof 包嵌入到待分析程序的入口和结束处。runtime.pprof 包在运行时对程序进行每秒 100 次的采样，最少采样 1 秒。然后将生成的数据输出，让开发者写入文件或者其他媒介上进行分析。go pprof 工具链配合 Graphviz 图形化工具可以将 runtime.pprof 包生成的数据转换为 PDF格式，以图片的
复制链接

扫一扫