大家好,我是煎鱼。
这次分享《Go 语言编程之旅》中的性能剖析大杀器 PProf,文章字数有 1w3+ 字,我想应该是目前业界比拟全的 PProf 文章了。
心愿借此让更多的 Go 语言爱好者搞懂 PProf 的应用,以便在成为救火队长时,都可能怀才不遇,成为团队外围主力,实现早晨 7 点上班。
本文目录如下:
感觉不错的话,欢送点赞和转发给更多小伙伴们看到,感激。
前言
应用程序在运行时,总是会呈现一些你所意料不到的问题,像是跑着跑着忽然报警,监控提醒你过程 CPU 使用率过高、内存占用一直增大(疑似泄露)、长期内存大量申请后长时间内不滑,又或是 Goroutine 泄露、呈现 Goroutine 数量暴涨,并且持续保持,甚至是莫名其妙在某次迭代公布后的数小时内呈现了应用程序无奈提供服务的问题 …
这产生起来的话,是如许的让人感到担心,那么除了在咱们平时要做好各类防护以外,在问题正在产生时,咱们又有什么方法排查呢,因而在这个章节,咱们将介绍排查方法之一,也就是 Go 语言的性能分析大杀器 PProf 工具链,它是 Go 语言中必知必会的技能点。
PProf 是什么
在 Go 语言中,PProf 是用于可视化和剖析性能剖析数据的工具,PProf 以 profile.proto 读取剖析样本的汇合,并生成报告以可视化并帮忙剖析数据(反对文本和图形报告)。
而刚刚提到的 profile.proto 是一个 Protobuf v3 的形容文件,它形容了一组 callstack 和 symbolization 信息,作用是统计分析的一组采样的调用栈,是很常见的 stacktrace 配置文件格式。
有哪几种采样形式
- runtime/pprof:采集程序(非 Server)的指定区块的运行数据进行剖析。
- net/http/pprof:基于 HTTP Server 运行,并且能够采集运行时数据进行剖析。
- go test:通过运行测试用例,并指定所需标识来进行采集。
反对什么应用模式
- Report generation:报告生成。
- Interactive terminal use:交互式终端应用。
- Web interface:Web 界面。
能够做什么
- CPU Profiling:CPU 剖析,依照肯定的频率采集所监听的应用程序 CPU(含寄存器)的应用状况,可确定应用程序在被动耗费 CPU 周期时破费工夫的地位。
- Memory Profiling:内存剖析,在应用程序进行堆调配时记录堆栈跟踪,用于监督以后和历史内存应用状况,以及查看内存透露。
- Block Profiling:阻塞剖析,记录 Goroutine 阻塞期待同步(包含定时器通道)的地位,默认不开启,须要调用
runtime.SetBlockProfileRate
进行设置。 - Mutex Profiling:互斥锁剖析,报告互斥锁的竞争状况,默认不开启,须要调用
runtime.SetMutexProfileFraction
进行设置。 - Goroutine Profiling:Goroutine 剖析,能够对以后应用程序正在运行的 Goroutine 进行堆栈跟踪和剖析。
其中像是 Goroutine Profiling 这项性能会在理论排查中会常常用到。
因为很多问题呈现时的表象就是 Goroutine 暴增,而这时候咱们要做的事件之一就是查看应用程序中的 Goroutine 正在做什么事件,因为什么阻塞了,而后再进行下一步。
介绍和应用
一个简略的例子
咱们新建一个 main.go 文件,用于后续的应用程序剖析和示例展现,写入如下代码:
var datas []string
func main() {go func() {
for {log.Printf("len: %d", Add("go-programming-tour-book"))
time.Sleep(time.Millisecond * 10)
}
}()
_ = http.ListenAndServe("0.0.0.0:6060", nil)
}
func Add(str string) int {data := []byte(str)
datas = append(datas, string(data))
return len(datas)
}
接下来最重要的一步,就是在 import 中增加 _ "net/http/pprof"
的援用,如下:
import (
_ "net/http/pprof"
...
)
接下来咱们运行这个程序,拜访 http://127.0.0.1:6060/debug/pprof/
地址,查看是否失常响应。
通过浏览器拜访
第一种形式,咱们能够间接通过浏览器,进行查看,那么在第一步咱们能够先查看总览页面,也就是拜访 http://127.0.0.1:6060/debug/pprof/
,如下:
/debug/pprof/
Types of profiles available:
Count Profile
3 allocs
0 block
0 cmdline
8 goroutine
3 heap
0 mutex
0 profile
11 threadcreate
0 trace
full goroutine stack dump
- allocs:查看过来所有内存调配的样本,拜访门路为
$HOST/debug/pprof/allocs
。 - block:查看导致阻塞同步的堆栈跟踪,拜访门路为
$HOST/debug/pprof/block
。 - cmdline:以后程序的命令行的残缺调用门路。
- goroutine:查看以后所有运行的 goroutines 堆栈跟踪,拜访门路为
$HOST/debug/pprof/goroutine
。 - heap:查看流动对象的内存分配情况,拜访门路为
$HOST/debug/pprof/heap
。 - mutex:查看导致互斥锁的竞争持有者的堆栈跟踪,拜访门路为
$HOST/debug/pprof/mutex
。 - profile:默认进行 30s 的 CPU Profiling,失去一个剖析用的 profile 文件,拜访门路为
$HOST/debug/pprof/profile
。 - threadcreate:查看创立新 OS 线程的堆栈跟踪,拜访门路为
$HOST/debug/pprof/threadcreate
。
如果你在对应的拜访门路上新增 ?debug=1
的话,就能够间接在浏览器拜访,如下:
debug 模式
若不新增 debug
参数,那么将会间接下载对应的 profile 文件。
再开展来讲,在部署环境中,咱们为了网络安全,通常不会间接对外网裸露 pprof 的相干端口,因而会通过 curl
、wget
等形式进行 profile 文件的间接拉取。
另外还有一点须要留神,debug 的拜访形式是具备时效性的,在理论场景中,咱们经常须要及时将以后状态下的 profile 文件给存储下来,便于二次剖析。
通过交互式终端应用
第二种形式,咱们能够间接通过命令行,来实现对正在运行的应用程序 pprof 的抓取和剖析。
CPU Profiling
$ 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/eddycjy/pprof/pprof.samples.cpu.002.pb.gz
Type: cpu
Duration: 1mins, Total samples = 37.25s (61.97%)
Entering interactive mode (type "help" for commands, "o" for options)
(pprof)
执行该命令后,需期待 60 秒(可调整 seconds 的值),pprof 会进行 CPU Profiling,完结后将默认进入 pprof 的命令行交互式模式,能够对剖析的后果进行查看或导出。另外如果你所启动的 HTTP Server 是 TLS 的形式,那么在调用 go tool pprof
时,须要将调用门路改为:go tool pprof https+insecure://localhost:6060/debug/pprof/profile\?seconds\=60
。
接下来咱们输出查问命令 top10
,以此查看对应资源开销(例如:CPU 就是执行耗时 / 开销、Memory 就是内存占用大小)排名前十的函数,如下:
(pprof) top10
Showing nodes accounting for 36.23s, 97.26% of 37.25s total
Dropped 80 nodes (cum <= 0.19s)
Showing top 10 nodes out of 34
flat flat% sum% cum cum% Name
32.63s 87.60% 87.60% 32.70s 87.79% syscall.syscall
0.87s 2.34% 89.93% 0.88s 2.36% runtime.stringtoslicebyte
0.69s 1.85% 91.79% 0.69s 1.85% runtime.memmove
0.52s 1.40% 93.18% 0.52s 1.40% runtime.nanotime
...
(pprof)
- flat:函数本身的运行耗时。
- flat%:函数本身在 CPU 运行耗时总比例。
- sum%:函数本身累积应用 CPU 总比例。
- cum:函数本身及其调用函数的运行总耗时。
- cum%:函数本身及其调用函数的运行耗时总比例。
- Name:函数名。
在大多数的状况下,咱们能够通过这五列得出一个应用程序的运行状况,晓得以后是什么函数,正在做什么事件,占用了多少资源,谁又是占用资源的大头,以此来失去一个初步的剖析方向。
另外在交互命令行中,pprof 还反对了大量的其它命令,具体可执行 pprof help
查看帮忙阐明。
Heap Profiling
$ go tool pprof http://localhost:6060/debug/pprof/heap
Fetching profile over HTTP from http://localhost:6060/debug/pprof/heap
Saved profile in /Users/eddycjy/pprof/pprof.alloc_objects.alloc_space.inuse_objects.inuse_space.011.pb.gz
Type: inuse_space
Entering interactive mode (type "help" for commands, "o" for options)
(pprof)
执行该命令后,可能很快的拉取到其后果,因为它不须要像 CPU Profiling 做采样期待,这里须要留神的一点是 Type
这一个选项,你能够看到它默认显示的是 inuse_space
,实际上能够针对多种内存详情进行剖析,罕用的类别如下:
- inuse\_space:剖析应用程序的常驻内存占用状况。
$ go tool pprof -inuse_space http://localhost:6060/debug/pprof/heap
(pprof) top
Showing nodes accounting for 4.01GB, 100% of 4.01GB total
flat flat% sum% cum cum%
4.01GB 100% 100% 4.01GB 100% main.Add
0 0% 100% 4.01GB 100% main.main.func1
- alloc\_objects:剖析应用程序的内存长期分配情况。
$ go tool pprof -alloc_objects http://localhost:6060/debug/pprof/heap
(pprof) top
Showing nodes accounting for 215552550, 100% of 215560746 total
Dropped 14 nodes (cum <= 1077803)
flat flat% sum% cum cum%
86510197 40.13% 40.13% 86510197 40.13% main.Add
85984544 39.89% 80.02% 85984544 39.89% fmt.Sprintf
43057809 19.97% 100% 215552550 100% main.main.func1
0 0% 100% 85984544 39.89% log.Printf
另外还有 inuse\_objects 和 alloc\_space 类别,别离对应查看每个函数所别离的对象数量和查看调配的内存空间大小,具体可依据状况选用。
Goroutine Profiling
$ go tool pprof http://localhost:6060/debug/pprof/goroutine
Fetching profile over HTTP from http://localhost:6060/debug/pprof/goroutine
Saved profile in /Users/eddycjy/pprof/pprof.goroutine.003.pb.gz
Type: goroutine
Entering interactive mode (type "help" for commands, "o" for options)
(pprof)
在查看 goroutine 时,咱们能够应用 traces
命令,这个命令会打印出对应的所有调用栈,以及指标信息,能够让咱们很便捷的查看到整个调用链路有什么,别离在哪里应用了多少个 goroutine,并且可能通过剖析查看到谁才是真正的调用方,输入后果如下:
(pprof) traces
Type: goroutine
-----------+-------------------------------------------------------
2 runtime.gopark
runtime.netpollblock
internal/poll.runtime_pollWait
...
-----------+-------------------------------------------------------
1 runtime.gopark
runtime.netpollblock
...
net/http.ListenAndServe
main.main
runtime.main
在调用栈上来讲,其展现程序是自下而上的,也就是 runtime.main
办法调用了 main.main
办法,main.main
办法又调用了 net/http.ListenAndServe
办法,这里对应的也就是咱们所应用的示例代码了,排查起来会十分不便。
每个调用堆栈信息用 -----------
宰割,函数办法前的就是指标数据,像 Goroutine Profiling 展现是就是该办法占用的 goroutine 的数量。而 Heap Profiling 展现的就是占用的内存大小,如下:
$ go tool pprof http://localhost:6060/debug/pprof/heap
...
Type: inuse_space
Entering interactive mode (type "help" for commands, "o" for options)
(pprof) traces
Type: inuse_space
-----------+-------------------------------------------------------
bytes: 13.55MB
13.55MB main.Add
main.main.func1
-----------+-------------------------------------------------------
实际上 pprof 中的所有性能都会依据不同的 Profile 类型展现不同的对应后果。
Mutex Profiling
怎么样的状况下会造成阻塞呢,个别有如下形式:调用 chan
(通道)、调用 sync.Mutex
(同步锁)、调用 time.Sleep()
等等。那么为了验证互斥锁的竞争持有者的堆栈跟踪,咱们能够依据以上的 sync.Mutex
形式,来调整先前的示例代码,代码如下:
func init() {runtime.SetMutexProfileFraction(1)
}
func main() {
var m sync.Mutex
var datas = make(map[int]struct{})
for i := 0; i < 999; i++ {go func(i int) {m.Lock()
defer m.Unlock()
datas[i] = struct{}{}
}(i)
}
_ = http.ListenAndServe(":6061", nil)
}
须要特地留神的是 runtime.SetMutexProfileFraction
语句,如果将来心愿进行互斥锁的采集,那么须要通过调用该办法来设置采集频率,若不设置或没有设置大于 0 的数值,默认是不进行采集的。
接下来咱们进行调用 go tool pprof
进行剖析,如下:
$ go tool pprof http://localhost:6061/debug/pprof/mutex
Fetching profile over HTTP from http://localhost:6061/debug/pprof/mutex
Saved profile in /Users/eddycjy/pprof/pprof.contentions.delay.010.pb.gz
Type: delay
Entering interactive mode (type "help" for commands, "o" for options)
咱们查看调用 top
命令,查看互斥量的排名:
(pprof) top
Showing nodes accounting for 653.79us, 100% of 653.79us total
flat flat% sum% cum cum%
653.79us 100% 100% 653.79us 100% sync.(*Mutex).Unlock
0 0% 100% 653.79us 100% main.main.func1
接下来咱们能够调用 list
命令,看到指定函数的代码状况(蕴含特定的指标信息,例如:耗时),若函数名不明确,默认会对函数名进行含糊匹配,如下:
(pprof) list main
Total: 653.79us
ROUTINE ======================== main.main.func1 in /eddycjy/main.go
0 653.79us (flat, cum) 100% of Total
. . 40: go func(i int) {. . 41: m.Lock()
. . 42: defer m.Unlock()
. . 43:
. . 44: datas[i] = struct{}{}
. 653.79us 45: }(i)
. . 46: }
. . 47:
. . 48: err := http.ListenAndServe(":6061", nil)
. . 49: if err != nil {. . 50: log.Fatalf("http.ListenAndServe err: %v", err)
(pprof)
咱们能够在输入的剖析中比拟精确的看到引起互斥锁的函数在哪里,锁开销在哪里,在本例中是第 45 行。
Block Profiling
与 Mutex 的 runtime.SetMutexProfileFraction
类似,Block 也须要调用 runtime.SetBlockProfileRate()
进行采集量的设置,否则默认敞开,若设置的值小于等于 0 也会认为是敞开。
与上大节 Mutex 相比,主体代码不变,仅是新增 runtime.SetBlockProfileRate()
的调用,如下:
func init() {runtime.SetBlockProfileRate(1)
...
}
咱们查看调用 top
命令,查看阻塞状况的排名:
$ go tool pprof http://localhost:6061/debug/pprof/block
Fetching profile over HTTP from http://localhost:6061/debug/pprof/block
Saved profile in /Users/eddycjy/pprof/pprof.contentions.delay.017.pb.gz
Type: delay
Entering interactive mode (type "help" for commands, "o" for options)
(pprof) top
Showing nodes accounting for 74.54ms, 100% of 74.54ms total
flat flat% sum% cum cum%
74.54ms 100% 100% 74.54ms 100% sync.(*Mutex).Lock
0 0% 100% 74.54ms 100% main.main.func1
同样的,咱们也能够调用 list
命令查看具体的阻塞状况,执行形式和排查模式与先前概述的统一。
查看可视化界面
接下来咱们持续应用后面的示例程序,将其从新运行起来,而后在其它窗口执行下述命令:
$ wget http://127.0.0.1:6060/debug/pprof/profile
默认须要期待 30 秒,执行结束后可在当前目录下发现采集的文件 profile,针对可视化界面咱们有两种形式可进行下一步剖析:
- 办法一(举荐):该命令将在所指定的端口号运行一个 PProf 的剖析用的站点。
$ go tool pprof -http=:6001 profile
- 办法二:通过 web 命令将以 svg 的文件格式写入图形,而后在 Web 浏览器中将其关上。
$ go tool pprof profile
Type: cpu
Time: Feb 1, 2020 at 12:09pm (CST)
Duration: 30s, Total samples = 60ms (0.2%)
Entering interactive mode (type "help" for commands, "o" for options)
(pprof) web
如果呈现谬误提醒 Could not execute dot; may need to install graphviz.
,那么意味着你须要装置 graphviz
组件。
另外办法一所运行的站点,实际上蕴含了办法二的内容(svg 图片),并且更灵便,因而非非凡状况,咱们会间接应用办法一的形式运行站点来做察看和剖析。
分析内容
通过 PProf 所提供的可视化界面,咱们可能更不便、更直观的看到 Go 应用程序的调用链、应用状况等。另外在 View 菜单栏中,PProf 还反对多种剖析形式的切换,如下:
view 菜单栏
接下来咱们将基于 CPU Profiling 所抓取的 Profile 进行一一介绍,而其它 Profile 类型的剖析模式也是互通的,只有咱们理解了一种,其余的也就会了。
Top
top 栏目
该视图与后面所解说的 top
子命令的作用和含意是一样的,因而不再赘述。
Graph
graph 栏目
该视图展现的为整体的函数调用流程,框越大、线越粗、框色彩越娇艳(红色)就代表它占用的工夫越久,开销越大。相同若框色彩越淡,越小则代表在整体的函数调用流程中,它的开销是绝对较小的。
因而咱们能够用此视图去剖析谁才是开销大头,它又是因为什么调用流程而被调用的。
Peek
peek 栏目
此视图相较于 Top 视图,减少了所属的上下文信息的展现,也就是函数的输入调用者 / 被调用者。
Source
source 栏目
该视图次要是减少了面向源代码的追踪和剖析,能够看到其开销次要耗费在哪里。
Flame Graph
flame graph 概览
Flame Graph(火焰图)它是可动静的,调用程序由上到下(A -> B -> C -> D),每一块代表一个函数、色彩越娇艳(红)、区块越大代表占用 CPU 的工夫更长。同时它也反对点击块深刻进行剖析。
咱们抉择页面上的 main.main.func1
区块,将会进入到其属下的下一层级,如下:
进一步查看 flame graph
这样子咱们就能够依据不同函数的多维度层级进行剖析,可能更好的察看其流转并发现问题。
通过测试用例做分析
在上述章节中,咱们是通过在应用程序中埋入办法进行采集的,那么还有一种形式,可能更精准的分析到你所想要剖析的流程或函数。
首先咱们将先前所编写的 Add 办法挪到独立的 package 中,命名为 add.go 文件,而后新建 add\_test.go 文件,写入如下测试用例代码:
func TestAdd(t *testing.T) {_ = Add("go-programming-tour-book")
}
func BenchmarkAdd(b *testing.B) {
for i := 0; i < b.N; i++ {Add("go-programming-tour-book")
}
}
在实现代码编写后,咱们回到命令行窗口执行如下采集命令:
$ go test -bench=. -cpuprofile=cpu.profile
执行结束后会在以后命令生成 cpu.profile 文件,而后只需执行 go tool pprof
命令就能够进行查看了,如下图:
cpu profile
另外除了对 CPU 进行分析以外,咱们还能够调整选项,对内存状况进行剖析,如下采集命令:
$ go test -bench=. -memprofile=mem.profile
接下来和下面一样,执行 go tool pprof
命令进行查看,如下图:
进一步查看
通过 Lookup 写入文件做分析
除了注入 http handler 和 go test 以外,咱们还能够在程序中通过 pprof 所提供的 Lookup 办法来进行相干内容的采集和调用。
其一共反对六种类型,别离是:
- goroutine。
- threadcreate。
- heap。
- block。
- mutex。
具体代码如下:
type LookupType int8
const (
LookupGoroutine LookupType = iota
LookupThreadcreate
LookupHeap
LookupAllocs
LookupBlock
LookupMutex
)
func pprofLookup(lookupType LookupType, w io.Writer) error {
var err error
switch lookupType {
case LookupGoroutine:
p := pprof.Lookup("goroutine")
err = p.WriteTo(w, 2)
case LookupThreadcreate:
p := pprof.Lookup("threadcreate")
err = p.WriteTo(w, 2)
case LookupHeap:
p := pprof.Lookup("heap")
err = p.WriteTo(w, 2)
case LookupAllocs:
p := pprof.Lookup("allocs")
err = p.WriteTo(w, 2)
case LookupBlock:
p := pprof.Lookup("block")
err = p.WriteTo(w, 2)
case LookupMutex:
p := pprof.Lookup("mutex")
err = p.WriteTo(w, 2)
}
return err
}
接下来咱们只须要对该办法进行调用就好了,其提供了 io.Writer
接口,也就是只有实现了对应的 Write 办法,咱们能够将其写到任何反对中央去,如下:
...
func init() {runtime.SetMutexProfileFraction(1)
runtime.SetBlockProfileRate(1)
}
func main() {http.HandleFunc("/lookup/heap", func(w http.ResponseWriter, r *http.Request) {_ = pprofLookup(LookupHeap, os.Stdout)
})
http.HandleFunc("/lookup/threadcreate", func(w http.ResponseWriter, r *http.Request) {_ = pprofLookup(LookupThreadcreate, os.Stdout)
})
http.HandleFunc("/lookup/block", func(w http.ResponseWriter, r *http.Request) {_ = pprofLookup(LookupBlock, os.Stdout)
})
http.HandleFunc("/lookup/goroutine", func(w http.ResponseWriter, r *http.Request) {_ = pprofLookup(LookupGoroutine, os.Stdout)
})
_ = http.ListenAndServe("0.0.0.0:6060", nil)
}
在上述代码中,咱们将采集后果写入到了管制台上,咱们能够进行一下验证,调用 http://127.0.0.1:6060/lookup/heap
,控制台输入后果如下:
$ go run main.go
heap profile: 0: 0 [0: 0] @ heap/1048576
# runtime.MemStats
# Alloc = 180632
# TotalAlloc = 180632
# Sys = 69928960
# Lookups = 0
...
为什么要初始化 net/http/pprof
在咱们的例子中,你会发现咱们在援用上对 net/http/pprof
包进行了默认的初始化(也就是 _
),如果你已经漏了,或者没加,你会发现压根调用不了 pprof 的相干接口,这是为什么呢,咱们一起看看上面该包的初始化办法,如下:
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)
}
实际上 net/http/pprof
会在初始化函数中对规范库中 net/http
所默认提供的 DefaultServeMux 进行路由注册,源码如下:
var DefaultServeMux = &defaultServeMux
var defaultServeMux ServeMux
func HandleFunc(pattern string, handler func(ResponseWriter, *Request)) {DefaultServeMux.HandleFunc(pattern, handler)
}
而咱们在例子中应用的 HTTP Server,也是应用的规范库中默认提供的,因而便完满的联合在了一起,这也恰好也是最小示例的模式。
这时候你可能会留神到另外一个问题,那就是咱们的理论我的项目中,都是有绝对独立的 ServeMux 的,这时候咱们只有仿照着将 pprof 对应的路由注册进去就好了,如下:
mux := http.NewServeMux()
mux.HandleFunc("/debug/pprof/", pprof.Index)
mux.HandleFunc("/debug/pprof/cmdline", pprof.Cmdline)
mux.HandleFunc("/debug/pprof/profile", pprof.Profile)
mux.HandleFunc("/debug/pprof/symbol", pprof.Symbol)
mux.HandleFunc("/debug/pprof/trace", pprof.Trace)
总结
在本文中咱们具体的介绍了 Go 语言中 pprof 的应用,针对一些罕用的套件均进行了阐明。而 pprof 在咱们平时的性能分析,问题排查上都占据着十分重要的角色。
在日常只须要依据正当的排查思路,置信你肯定可能依据在 pprof 中的蛛丝马迹,解决那些或大或小的问题,实现准点上班!
我是煎鱼,咱们下期见:)
若有任何疑难欢送评论区反馈和交换,最好的关系是相互成就 ,各位的 点赞 就是煎鱼创作的最大能源,感激反对。
文章继续更新,能够微信搜【脑子进煎鱼了】浏览,回复【000】有我筹备的一线大厂面试算法题解和材料。
本文 GitHub github.com/eddycjy/blog 已收录,欢送 Star 催更。