用途
对程序性能进行剖析,可以找到性能的瓶颈、bug、以及对程序进行有目标的优化,从而提高程序的性能,解决程序中存在的问题。
如何对程序进行剖析
- 设置要分析的指标,利用
工具 (go test)
或性能指标API
对指标进行剖析,生成对应的概要文件(二进制文件)
- 使用分析工具(go tool pprof/ go tool trace)对概要文件进行解析,得到性能指标值的具体信息,这些信息可以以文本,图形的形式展示。
- 根据得到性能指标值的具体信息,分析程序性能,查找程序瓶颈或对程序进行优化
要对一个程序进行剖析,必须先生成对应指标的概要文件
,然后再用分析工具
去解析这个概要文件
概要文件
是Go程序在某一段时间内,对相关指标采样后,得到的概要信息。剖析时,会在程序执行期间进行一些自动抽样,在结束时进行推断,最后把统计结果保存为概要文件,供分析工具使用。
概要文件的格式
概要文件其实就是 由 protocol buffers
生成的二进制数据流,protocol buffers
是一种数据序列化协议,它定义了程序对象如 map
,结构体,数组等与字节之间如何相互转化。同时 protocol buffers
不仅仅是协议,也可以作为转化工具来使用,它可以把字节流转化为对象,也可以把对象转化为字节流。protocol buffers
会对生成的字节流进行压缩,它的体积比(JSON,XML
)都要更小,所以也更适合用于数据在网上传输
生成概要文件的方法
Go 语言支持多种类型的性能分析,可以通过
- 使用 go test 配合对应的标识符
- 使用性能指标API
这两种方式,都可以生成概要文件
有关性能的概要文件
CPU概要文件,内存概要文件,阻塞概要文件,它们可以通过 go test 配合对应的标识符生成,对CPU,内存,阻塞这三个指标进行分析。
Go test 标识生成概要文件
可以使用 go test
工具提供的剖析标识对程序进行分析,生成概要文件。不要让多个剖析标识同时运行,它们之间会相互影响,导致分析结果不准确
Cpu 剖析标识
记录占用CPU时间最长的函数,每个运行在CPU上的函数每几毫秒都会遇到系统中断事件,每次中断时,都会记录一个剖析数据
go test gott/fib -cpuprofile=cpu.log -run=None -bench=FibWithMap
堆剖析标识
记录最耗内容的语句,平均每申请512K的内存,就会记录一个剖析数据
go test gott/fib -memprofile=mem.log -run=None -bench=FibWithMap
阻塞剖解标识
记录阻塞goroutine最久的操作,如系统调用,等待锁,管道收发等,每当这些操作阻塞goroutine时,就会记录一个剖析数据
go test gott/fib -blockprofile=block.log -run=None -bench=FibWithMap
解析概要文件
可执行文件
使用以上标识符,除了生成了剖析数据日志(cpu.log/mem.log/block.log),go test 还会生成对应的可执行程序(fib.test),以包名做为前缀,后面为.test
的文件。为了减少剖析数据日志占用的空间和提高分析效率,分析日志本身并没有记录函数的名称,而是函数的地址,所以需要与之对应的可执行文件,才可以对剖析日志进行数据分析
pprof 分析工具
go tool pprof
命令可以用来分析剖析日志,它需要两个基本的参数
go tool pprof -text -nodecount=10 ./fib.test cpu.log
File: fib.test
Type: cpu
Time: Aug 9, 2021 at 11:30am (CST)
Duration: 1.43s, Total samples = 1.09s (76.02%)
Showing nodes accounting for 1.09s, 100% of 1.09s total
Showing top 10 nodes out of 17
flat flat% sum% cum cum%
0.49s 44.95% 44.95% 0.94s 86.24% runtime.mapaccess2_fast64
0.36s 33.03% 77.98% 0.36s 33.03% runtime.memhash64
0.12s 11.01% 88.99% 1.06s 97.25% gott/fib.fibWithMap
0.06s 5.50% 94.50% 0.06s 5.50% runtime.add (partial-inline)
0.03s 2.75% 97.25% 0.03s 2.75% runtime.bucketShift (inline)
0.02s 1.83% 99.08% 1.08s 99.08% gott/fib.BenchmarkFibWithMap
0.01s 0.92% 100% 0.01s 0.92% runtime.wbBufFlush1
0 0% 100% 0.01s 0.92% runtime.(*bmap).overflow (inline)
0 0% 100% 0.03s 2.75% runtime.bucketMask (inline)
0 0% 100% 0.01s 0.92% runtime.findrunnable
./fib.test
:测试生成的可执行文件,在一般的测试中,当测试完成后,文件就会被丢弃,但在启用剖析标识后,这个文件会被保留,供之后的分析使用
-nodecount
:限制分析结果输出的行数
-text
:指定输出的格式
还可以使用-web选项,用于生成函数的有向图,标注有CPU的使用和最热点的函数等信息
go tool pprof -web -nodecount=10 ./fib.test cpu.log
brew install graphviz
还可以不加任何选项进入交互界面
go tool pprof cpu.log
Type: cpu
Time: Aug 9, 2021 at 11:30am (CST)
Duration: 1.43s, Total samples = 1.09s (76.02%)
Entering interactive mode (type "help" for commands, "o" for options)
(pprof)
这里只用到了概要文件,没有用到测试生成的可执行文件
性能指标API生成概要文件
除了使用 go test 标识对程序进行性能分析,还可以使用标准库中的 runtime/pprof
,runtime/trace
,net/http/pprof
这三个包中提供的API来对Go程序进行性能分析,生成概要文件。
生成CPU概要文件
StartCPUProfile函数
StartCPUProfile()
函数对CPU信息进行定时采样生成概要文件,默认采样频率是100Hz,即每秒采样100次,调用pprof.StartCPUProfile()
函数开始进行采样。
StopCPUProfile函数
调用pprof.StopCPUProfile()
停止采样。当调用pprof.StartCPUProfile()
时,会启用一个新的goroutine,并在其中进行CPU信息的收集
func StopCPUProfile() {
cpu.Lock()
defer cpu.Unlock()
if !cpu.profiling {
return
}
cpu.profiling = false
runtime.SetCPUProfileRate(0)
<-cpu.done
}
StopCPUProfile
是通过设置SetCPUProfileRate(0)
为0,来停止采样的,而pprof.StartCPUProfile
是把runtime.SetCPUProfileRate(100)
设置为100来开始采样的
func main() {
profileName := "cpu_api.log"
f, err := common.CreateFile("", profileName)
if err != nil {
fmt.Printf("CPU profile creation error: %v\n", err)
return
}
defer f.Close()
pprof.StartCPUProfile(f)
op.CPULoad()
pprof.StopCPUProfile()
}
pprof.StartCPUProfile(f)
:把概要文件写入 cpu_api.log 文件
生成概要文件
go run pprof/cpu/cpu.go
go tool pprof 查看概要文件内容
go tool pprof -text -nodecount=15 cpu_api.log
Type: cpu
Time: Aug 17, 2021 at 3:56pm (CST)
Duration: 1.62s, Total samples = 1.47s (90.66%)
Showing nodes accounting for 1.47s, 100% of 1.47s total
Showing top 15 nodes out of 49
flat flat% sum% cum cum%
1.29s 87.76% 87.76% 1.29s 87.76% runtime.memmove
0.06s 4.08% 91.84% 0.06s 4.08% runtime.usleep
0.02s 1.36% 93.20% 0.02s 1.36% runtime.madvise
0.02s 1.36% 94.56% 0.02s 1.36% runtime.pthread_kill
0.02s 1.36% 95.92% 0.10s 6.80% runtime.slicebytetostring
0.01s 0.68% 96.60% 1.25s 85.03% bytes.(*Buffer).WriteString
0.01s 0.68% 97.28% 0.01s 0.68% runtime.(*mspan).init (inline)
0.01s 0.68% 97.96% 0.01s 0.68% runtime.memclrNoHeapPointers
0.01s 0.68% 98.64% 0.01s 0.68% runtime.newArenaMayUnlock
0.01s 0.68% 99.32% 0.01s 0.68% runtime.pthread_cond_wait
0.01s 0.68% 100% 0.05s 3.40% strconv.FormatInt
0 0% 100% 0.06s 4.08% bytes.(*Buffer).String (inline)
0 0% 100% 0.10s 6.80% bytes.(*Buffer).grow
0 0% 100% 0.01s 0.68% bytes.makeSlice
0 0% 100% 1.36s 92.52% gott/common/op.CPULoad
生成内存概要文件
对堆内存的使用进行采样,会按照平均每分配多少个字节(默认为512B),就对堆内存的使用情况进行一次采样。
MemProfileRate
为 runtime.MemProfileRate 设置采样频率(默认值是512KB),对其赋0值表示停止采样。
WriteHeapProfile 函数
调用WriteHeapProfile 函数,根据采样频率进行采样,并把收集到的采样信息写入指定文件。
func WriteHeapProfile(w io.Writer) error {
return writeHeap(w, 0)
}
ReadMemStats 函数
WriteHeapProfile(f)
函数记录的并不是实时的内存概要信息,而是最近一次内存垃圾工作完成后产生的。要得到实时信息可以使用runtime.ReadMemStats()
函数
func main() {
profileName := "mem_api.log"
f, err := common.CreateFile("", profileName)
if err != nil {
fmt.Printf("memory profile creation error: %v\n", err)
return
}
defer f.Close()
startMemProfile()
fib.FibMap(60)
endMemProfile(f)
}
func startMemProfile() {
runtime.MemProfileRate = 1
}
func endMemProfile(f *os.File) {
pprof.WriteHeapProfile(f)
}
调用runtime.MemProfileRate
设置每申请1B的内存,就进行采样,调用pprof.WriteHeapProfile(f)
把采样信息写入指定的文件mem_api.log
中
生成阻塞概要文件
SetBlockProfileRate函数
它在runtime
包中,用来设置采样频率,其参数rate
的值表示,当阻塞持续多少纳秒后对其进行进行采样。如果这个值小于等于0,则停止采样。
blockprofilerate变量
参数rate
的值会被转换为CPU的时钟周期,然后赋值给blockprofilerate
,即:实际采样频率为当一个阻塞持续了多少个CPU时钟周期,就对这个事件进行采样
func SetBlockProfileRate(rate int) {
var r int64
if rate <= 0 {
r = 0
} else if rate == 1 {
r = 1
} else {
r = int64(float64(rate) * float64(tickspersecond()) / (1000 * 1000 * 1000))
if r == 0 {
r = 1
}
}
atomic.Store64(&blockprofilerate, uint64(r))
}
pprof.Lookup(“block”)
用来获取阻塞概要信息,获取信息要调用pprof.Lookup("block")
,block
做为参数传入,函数会返回一个*pprof.Profile
类型的值,对这个值调用WriteTo(w io.Writer, debug int)
方法,可以把概要信息写入文件。这个方法的第一个参数传入要写入概要信息的文件,第二个参数debug表示概要信息详细程度
func main() {
profileName := "block_api.log"
f, err := common.CreateFile("", profileName)
if err != nil {
fmt.Printf("block profile creation error: %v\n", err)
return
}
defer f.Close()
startBlockProfile()
fib.FibMap(45)
stopBlockProfile(f)
}
func startBlockProfile() {
runtime.SetBlockProfileRate(blockProfileRate)
}
func stopBlockProfile(f *os.File) {
pprof.Lookup("block").WriteTo(f, debug)
}
debug参数的值
- 0:生成protocol buffers字节流
- 1:生成内容可读的普通文本的概要文件,且函数名,包名,源码文件等信息会被做为注释加入进概要文件
- 2:生成内容可读的普通文本的概要文件,且包括更详细的信息
对于使用参数值1、2
生成的概要文件,不能使用 go tool pprof
查看,因为文件不是 protocol
格式
pprof.Lookup函数的使用
Lookup(name string)
通过给定的name
的值,返回对应的概要信息。如果返回值是 nil,表示不存在与给定名称对应的概要信息。预定义了6个概要名称,分别是goroutine, threadcreate, heap, allocs, block, mutex
函数的返回值是*Profile
类型的值,可以通过调用WriteTo(w io.Writer, debug int)
方法,把采样的概要信息写入指定的文件中(通过第一个参数设置),第二个参数表示了写入信息的详细细节程序,值可以是0,1,2
(具体代表的内容就是上面小节讲的)。
预定义概要名称的使用
goroutine
此指标可以收集正在使用的所有 goroutine 的堆栈跟踪信息,在调用WriteTo方法时,如果debug的值大于等于2,会把这些信息写入概要文件,文件可能会非常大
heap、allocs
此指标会收集与堆内存的分配和释放有关的采样信息,可以看成是内存概要信息,heap 与 allocs 仅在debug为0的时候会有区别,heap统计的是已经分配但还没有释放的内存空间,allocs展示的是已分配的内存空间。当debug的值大于0时,这两个指标值输出的内容是相同的
threadcreate
此指标会收集堆栈跟踪信息。这些堆栈跟踪信息中的每一个都会描绘出一个代码调用链,这些调用链上的代码都导致新的操作系统线程产生
block
此指标会收集因争用同步原语而被阻塞的那些代码的堆栈跟踪信息
mutex
此指标会收集曾经作为同步原语持有者的那些代码,它们的堆栈跟踪信息
同步原语可以理解为:通道、互斥锁、条件变量、”WaitGroup”
对于除了 CPU 概要信息之外的其他概要信息,我们都可以通过调用这个函数获取到。
为基于 HTTP 协议的网络服务添加性能分析接口
在我们编写网络服务程序的时候,使用net/http/pprof
包要比直接使用runtime/pprof
包方便和实用很多,这个代码包可以为网络服务的监测提供有力的支撑
package main
import (
"log"
"net/http"
_ "net/http/pprof"
)
func main() {
log.Println(http.ListenAndServe("localhost:8082", nil))
}
直接访问http://localhost:8082/debug/pprof 可以看到goroutine,threadcreate,heap, allocs,block,mutex
这6个指标的概要信息。它们都配有debug参数,默认值为0,可以通过改变debug的值改变概要信息的详细程度,如 gotroutine
的URL是http://localhost:8082/debug/pprof/goroutine?debug=1
当访问http://localhost:8082/debug/pprof/profile 时,程序会执行对 CPU 概要信息的采样,可以通过加入参数seconds
来控制对cpu的访问时间(默认是30秒),当采样结束后,会提示你下载概要文件。你也可以执行下面命令,直接读取概要文件
go tool pprof http://localhost:6060/debug/pprof/profile?seconds=60
要回答的问题
先写结论,便于接下来的阅读与理解
基准测试与剖析的区别
基准测试可以用来衡量一个程序的性能,如果想让程序运行的更快,或对性能不理想的程序进行提升,基准测试无法给出从哪里可以进行优化。
通过剖析,可以找出程序性能瓶颈所在,从而有针对性的对程序进行优化,提高性能。不要过早的进行优化,97%的场景,都不需要过早优化或根本就不需要优化,我们要做的仅是让程序可以正常运行即可。
剖析是如何进行的
剖析就是在程序执行期间进行一些自动抽样,在结束时进行推断,最后把统计结果保存为剖析数据文件,供剖析工具使用。Go 语言支持多种类型的剖析性能分析,可以通过go test 工具或调用Go的runtime 性能分析API(启用运行时剖析),对程序进行剖析。
需要对哪些代码进行剖析
要对程序的主要功能,关键部分进行基准测试,然后对其进行剖析,功能测试不应该参与进来,使用 -run=None
,禁止功能测试的运行