这是我参与「第五届青训营」伴学笔记创作活动的第 2 天

性能分析工具pprof

功能简介

常用source这个调用图查看具体问题代码，以及top以及火焰图来看每种数据资源占用

搭建pprof实战项目

package main

import (
	"log"
	"net/http"
	_ "net/http/pprof" //自动注册pprof的handler到http server
	"os"
	"runtime"
	"time"

	"github.com/wolfogre/go-pprof-practice/animal"
)

func main() {
	log.SetFlags(log.Lshortfile | log.LstdFlags)
	log.SetOutput(os.Stdout)

	runtime.GOMAXPROCS(1)              //限制cpu使用数
	runtime.SetMutexProfileFraction(1) //开启锁调用跟踪
	runtime.SetBlockProfileRate(1)     //开启阻塞调用跟踪

	go func() {
        //启动http server
		if err := http.ListenAndServe(":6060", nil); err != nil {
			log.Fatal(err)
		}
		os.Exit(0)
	}()

	for {
		for _, v := range animal.AllAnimals {
			v.Live()
		}
		time.Sleep(time.Second)
	}
}

浏览器查看指标

浏览器打开：/debug/pprof/，会进入pprof指标界面，下面也有简单说明

点进去可以看到界面展示不是很友好

cpu问题排查

可以先用资源管理器查看cpu占用

go tool pprof

ppro的采样结果是将一段时间内的信息汇总蝓出到文件中，所以首先需要拿到这个profile文件。你可以直接使用暴漏的接口链接下载文件后使用，也可以直接用pprof工具连接这个接口下载需要。如果浏览器打开暴漏的连接会启动一个60s的采样，用命令行可以通过seconds=10指定采样10s的数据

go tool pprof "http://localhost:6060/debug/pprof/profile?seconds=10"

执行命令后会进入特殊的命令行程序

top

top：查看函数耗费cpu情况

在该命令行调用top查看资源占用情况

Flat当前函数本身执行的耗时
Flat%:flat占cpu总时间的耗时
Sum%:上面每一行的flat%总和
Cum(Cumulative):指当前函数本身加上其调用函数的总耗时
Cum%:Cum占cpu总时间的比例

这里是更直观的一个图

表格前面描述了采样的总体信息。默认会展示资源占用最高的10个函数，如果只需要查看最高的N个函数，可以输入topN,例如查看最高的3个调用，输入top3

falt==0：也就是说这个函数里面光调用别的函数了

list

list：根据指定的正则表达式查找代码行

当我们找到小号资源最多的几个函数后，可以调用list来查看到底是该函数的那一部分耗费资源最多

这里发现for循环耗时最多

web

web：调用关系可视化

命令行有时候不是很直观，可以通过web命令可视化，注意需要先安装Graphviz

这里发现Tiger.Eat耗费cpu最多，查看view的source视图看看到底Tiger.Eat的那部分代码有问题。

此时我们可以依据定位的信息去代码里看看Tiger.Eat函数占用cpu的代码并进行相应优化

堆内存排查

除了web命令也可以通过-http=:8080开启pprof自带的web ui

go tool pprof -http=:8080 "http://localhost:6060/debug/pprof/heap"

进入web界面可以可视化看到性能信息，图片展示了调用关系，此时可以看到，mouse.steal占用的内存最多。

查看view的source视图看看到底mouse.steal的那部分代码有问题。

此时我们可以依据定位的信息去代码里看看mouse.steal占用内存的代码，并进行相应优化

goroutine排查

go tool pprof -http=:8080 "http://localhost:6060/debug/pprof/goroutine"

初始界面会展示调用关系，以及相关的协程情况

这里看到问题在于wolf.drink就创建了51个协程占94.44%，这个图太大不容看，可以点击view的flame graph看火焰图

由上到下表示调用顺序
每一块代表一个函数，越长代表占用CPU的时间更长
火焰图是动态的，支持点击块进行分析

接下来选择view的source查询wolf看看到底是那部分代码有问题

发现是time.Sleep导致go协程不能快速结束

mutex锁

同样可以通过source查看到底是那部分代码导致的耗时

block-阻塞

小结

基本所有调优都可以现根据flamegraph视图来判断谁占资源最猛，然后再通过source视图查看该函数到底那一部分代码占时间最多，再进行相应代码修改。cpu直接通过客户端的top和list进行查找代码就可以

实际分析排查过程
- 排查 CPU 问题
  - 命令行分析
    - go tool pprof "http://localhost:6060/debug/pprof/profile?seconds=10"
  - top 命令
  - list 命令
  - 熟悉 web 页面分析
  - 调用关系图，火焰图
  - go tool pprof -http=:8080 "http://localhost:6060/debug/pprof/cpu"
- 排查堆内存问题
  - go tool pprof -http=:8080 "http://localhost:6060/debug/pprof/heap"
- 排查协程问题
  - go tool pprof -http=:8080 "http://localhost:6060/debug/pprof/goroutine"
- 排查锁问题
  - go tool pprof -http=:8080 "http://localhost:6060/debug/pprof/mutex"
- 排查阻塞问题
  - go tool pprof -http=:8080 "http://localhost:6060/debug/pprof/block"

pprof采样过程与原理

CPU采样会记录所有的调用栈和它们的占用时间。在采样时，进程会每秒暂停一百次，每次会记录当前的调用栈信息。汇总之后，根据调用栈在采样中出现的次数来推断函数的运行时间。你需要手动地启动和停止采样。每秒100次的暂停领率也不能更改。这个定时暂停机制在unix或类unix系统上是依赖信号机制实现的。每次「暂停」都会接收到一个信号，通过系统计时器来保证这个信号是固定频率发送的。具体流程

一共有三个相关角色：进程本身、操作系统和写缓冲，启动采样时，进程向OS注册一个定时器，OS会每隔10ms向进程发送一个SIGPROF信号，进程接收到信号后就会对当前的调用栈进行记录。与此同时，进程会启动一个写缓冲的goroutine,它会每隔100ms从进程中读取已经记录的堆栈信息，并写入到输出流当采样停止时，进程向OS取消定时器，不再接收信号，写缓冲读取不到新的堆栈时，结束输出。

堆内存

内存采样在实现上依赖了内存分配器的记录，所以它只记录在堆上分配，且会参与GC的内存和一些其他的内存分配，例如调用结束就会回收的栈内存、一些更底层使用cgo调用分配的内存是不会被采样记录的。

内存的采样是一个持续的过程，它会记录从程序运行起的所有分配或释放的内存大小和对象数量，并在采样时遍历这些结果进行汇总，

协程

阻塞&锁

性能分析工具pprof | 青训营笔记