Golang 大杀器之性能剖析 PProf

2019-08-28

加入收藏

前言

写了几吨代码，实现了几百个接口。功能测试也通过了，终于成功的部署上线了

结果，性能不佳，什么鬼？

想做性能分析？

PProf

想要进行性能优化，首先瞩目在 Go 自身提供的工具链来作为分析依据，本文将带你学习、使用 Go 后花园，涉及如下：

runtime/pprof：采集程序（非 Server）的运行数据进行分析
net/http/pprof：采集 HTTP Server 的运行时数据进行分析

是什么

pprof 是用于可视化和分析性能分析数据的工具

pprof 以 profile.proto 读取分析样本的集合，并生成报告以可视化并帮助分析数据（支持文本和图形报告）

profile.proto 是一个 Protocol Buffer v3 的描述文件，它描述了一组 callstack 和 symbolization 信息，作用是表示统计分析的一组采样的调用栈，是很常见的 stacktrace 配置文件格式

支持什么使用模式

Report generation：报告生成
Interactive terminal use：交互式终端使用
Web interface：Web 界面

可以做什么

CPU Profiling：CPU 分析，按照一定的频率采集所监听的应用程序 CPU（含寄存器）的使用情况，可确定应用程序在主动消耗 CPU 周期时花费时间的位置
Memory Profiling：内存分析，在应用程序进行堆分配时记录堆栈跟踪，用于监视当前和历史内存使用情况，以及检查内存泄漏
Block Profiling：阻塞分析，记录 goroutine 阻塞等待同步（包括定时器通道）的位置
Mutex Profiling：互斥锁分析，报告互斥锁的竞争情况

一个简单的例子

我们将编写一个简单且有点问题的例子，用于基本的程序初步分析

编写 demo 文件

（1）demo.go，文件内容：

（2）data/d.go，文件内容：

运行这个文件，你的 HTTP 服务会多出 /debug/pprof 的 endpoint 可用于观察应用程序的情况

分析

一、通过 Web 界面

这个页面中有许多子页面，咱们继续深究下去，看看可以得到什么？

cpu（CPU Profiling）: $HOST/debug/pprof/profile，默认进行 30s 的 CPU Profiling，得到一个分析用的 profile 文件
block（Block Profiling）：$HOST/debug/pprof/block，查看导致阻塞同步的堆栈跟踪
goroutine：$HOST/debug/pprof/goroutine，查看当前所有运行的 goroutines 堆栈跟踪
heap（Memory Profiling）: $HOST/debug/pprof/heap，查看活动对象的内存分配情况
mutex（Mutex Profiling）：$HOST/debug/pprof/mutex，查看导致互斥锁的竞争持有者的堆栈跟踪
threadcreate：$HOST/debug/pprof/threadcreate，查看创建新OS线程的堆栈跟踪

二、通过交互式终端使用

执行该命令后，需等待 60 秒（可调整 seconds 的值），pprof 会进行 CPU Profiling。结束后将默认进入 pprof 的交互式命令模式，可以对分析的结果进行查看或导出。具体可执行 pprof help 查看命令说明

(pprof) top10
Showing nodes accounting for 25.92s, 97.63% of 26.55s total
Dropped 85 nodes (cum <= 0.13s)
Showing top 10 nodes out of 21
 flat flat% sum% cum cum%
 23.28s 87.68% 87.68% 23.29s 87.72% syscall.Syscall
 0.77s 2.90% 90.58% 0.77s 2.90% runtime.memmove
 0.58s 2.18% 92.77% 0.58s 2.18% runtime.freedefer
 0.53s 2.00% 94.76% 1.42s 5.35% runtime.scanobject
 0.36s 1.36% 96.12% 0.39s 1.47% runtime.heapBitsForObject
 0.35s 1.32% 97.44% 0.45s 1.69% runtime.greyobject
 0.02s 0.075% 97.51% 24.96s 94.01% main.main.func1
 0.01s 0.038% 97.55% 23.91s 90.06% os.(*File).Write
 0.01s 0.038% 97.59% 0.19s 0.72% runtime.mallocgc
 0.01s 0.038% 97.63% 23.30s 87.76% syscall.Write