先来一段性能分析案例
package main
import (
"log"
"runtime"
"time"
)
// 输出当前内存情况
func readMemStats() {
// MemStats 结构体定义了一些内存信息静态变量
var ms runtime.MemStats
// 将当前内存申请和分配的统计信息填写进ms结构体中
runtime.ReadMemStats(&ms)
// alloc占用内存情况、堆空闲情况、堆释放情况
log.Printf("========> 已申请且仍在使用的字节数:%d(bytes) 闲置span中的字节数:%d(bytes) 释放到系统的字节数:%d(bytes)", ms.Alloc, ms.HeapIdle, ms.HeapReleased)
}
/**
* append 性能分析
* append 操作切片是比较常规的操作,当初始cap设置的比较小,而实际要存储的元素非常多时,性能损耗就会比较突出。
* 当 for 循环的次数足够多时,就会触发到性能瓶颈
*/
func test() {
container := make([]int, 8)
log.Println("========> test begin ……")
// 追加元素
for i := 0; i < 32*1000*1000; i++ {
container = append(container, i)
if i == 16*1000*1000 {
readMemStats()
}
}
log.Println("==========> test end ……")
}
func main() {
log.Println("============> 主程序开始时候的内存占用情况")
readMemStats()
test() // 调用append
log.Println("============> test 程序结束时候的内存占用情况")
readMemStats()
// 手动执行垃圾回收
runtime.GC()
log.Println("============> 垃圾回收结束时候的内存占用情况")
readMemStats()
log.Println("============> 开始启动另一个子程序")
go func() {
for {
readMemStats()
time.Sleep(5 * time.Second)
}
}()
time.Sleep(7 * time.Second)
}
命令行运行
go run pf.go
2023/04/04 15:47:36 ============> 主程序开始时候的内存占用情况
2023/04/04 15:47:36 ========> 已申请且仍在使用的字节数:223944(bytes) 闲置span中的字节数:3522560(bytes) 释放到系统的字节
数:3522560(bytes)
2023/04/04 15:47:36 ========> test begin ……
2023/04/04 15:47:36 ========> 已申请且仍在使用的字节数:154175528(bytes) 闲置span中的字节数:164093952(bytes) 释放到系统的字节数:40468480(bytes)
2023/04/04 15:47:36 ==========> test end ……
2023/04/04 15:47:36 ============> test 程序结束时候的内存占用情况
2023/04/04 15:47:36 ========> 已申请且仍在使用的字节数:178176(bytes) 闲置span中的字节数:1056284672(bytes) 释放到系统的字节数:44646400(bytes)
2023/04/04 15:47:36 ============> 垃圾回收结束时候的内存占用情况
2023/04/04 15:47:36 ========> 已申请且仍在使用的字节数:180072(bytes) 闲置span中的字节数:1056284672(bytes) 释放到系统的字节数:45056000(bytes)
2023/04/04 15:47:36 ============> 开始启动另一个次程序
2023/04/04 15:47:36 ========> 已申请且仍在使用的字节数:181536(bytes) 闲置span中的字节数:1056268288(bytes) 释放到系统的字节数:45039616(bytes)
2023/04/04 15:47:41 ========> 已申请且仍在使用的字节数:182096(bytes) 闲置span中的字节数:1056268288(bytes) 释放到系统的字节数:127221760(bytes)
这是段简单的代码示例,通过runtime
分析出程序运行过程中内存的变化情况,分别对应着内存的分配、空闲、释放
如果能web页面展示,或者生成一个文件、测试图表、命令行交互分析更为方便
下面介绍pprof使用方式
pprof是go语言内置 的分析性能,运维分析数据的工具
标准库支持
- runtime/pprof 采集程序 (非server)指定区块的运行数据进行分析
- net/http/pprof 基于 http server 运行,并且可以采集运行时的数据进行分析 (其实net/http/pprof中只是使用runtime/pprof包来进行封装了一下,并在http端口上暴露出来)
运行模式
- Report Generation 报告生成(需安装Graphviz)
- Terminal交互式终端使用
- web界面
可分析内容
- CPU profiling cpu分析,按照一定的频率采集所监听的应用程序cpu(含寄存器)的使用情况,确定应用程序在主动消耗cpu周期时花费时间的位置
- Memory Profiling 内存分析,在应用程序进行堆分配记录堆栈跟踪,用于监听当前和历史内存使用情况,以及检查内存泄漏。
- Block Profiling 阻塞分析,记录goroutine 阻塞等待同步(包含定时器通道)的位置,默认不开启,需要调用 runtime.SetBlockProfileRate 进行设置
- Mutex Profiling 互斥锁分析。报告互斥锁的竞争情况,默认不开启,需要调用 runtime.SetMutexProfileFraction 进行设置
注意,头部要引入 _ “net/http/pprof” 否则pprof包无法初始化
使用示例
package main
import (
"log"
"net/http"
_ "net/http/pprof" // pprof包的init方法会注册5个uri pattern方法到runtime包中
"time"
)
var datas int
func main() {
go func() {
for {
Add()
log.Printf("number:%d", datas)
time.Sleep(time.Second * 5)
}
}()
// 也可手动注册,可选择自定义的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)
_ = http.ListenAndServe(":6060", nil)
}
func Add() {
for i := 0; i < 3000; i++ {
datas = datas + 1
}
}
运行程序,浏览器访问 http://127.0.0.1:6060/debug/pprof/?debug=1
pprof web主页面(有堆栈、内存、CPU各项参数)
以我们文章开头的代码再做个示例,修改一下main
方法
func main() {
// 启动 pprof,这种是采用网络监听的方式,可以通过访问界面显示出测试的数据
go func() {
log.Println(http.ListenAndServe(":6060", nil))
}()
log.Println("============> [start].")
readMemStats()
test()
readMemStats()
log.Println("============> [force.gc].")
// 强制开启gc
runtime.GC()
log.Println("===========>[Done] .")
readMemStats()
go func() {
for {
readMemStats()
time.Sleep(10 * time.Second)
}
}()
time.Sleep(3600 * time.Second)
}
运行,并访问
访问上面路径的时候可以加上 /debug/pprof。这个是pprof默认的网页地址,当然不止这一个,其他的维度分析自行查看
点击profile
下载文件到本地
使用go tool pprof profile
命令打开
D:\www>go tool pprof profile
File: pf.exe
Build ID: C:\Users\39834\AppData\Local\Temp\go-build3168156067\b001\exe\pf.exe2023-04-04 16:54:58.262358 +0800 CST
Type: cpu
Time: Apr 4, 2023 at 4:59pm (CST)
Duration: 30.01s, Total samples = 50ms ( 0.17%)
Entering interactive mode (type "help" for commands, "o" for options)
(pprof)
输入 top 查看当前程序的执行情况
(pprof) top
Showing nodes accounting for 50ms, 100% of 50ms total
Showing top 10 nodes out of 29
flat flat% sum% cum cum%
30ms 60.00% 60.00% 30ms 60.00% runtime.stdcall1
10ms 20.00% 80.00% 10ms 20.00% runtime.stdcall4
10ms 20.00% 100% 40ms 80.00% runtime.wakep
0 0% 100% 10ms 20.00% runtime.(*mheap).allocManual
0 0% 100% 10ms 20.00% runtime.(*mheap).allocSpan
0 0% 100% 10ms 20.00% runtime.checkTimers
0 0% 100% 10ms 20.00% runtime.copystack
0 0% 100% 10ms 20.00% runtime.findRunnable
0 0% 100% 10ms 20.00% runtime.goready
0 0% 100% 10ms 20.00% runtime.goready.func1
(pprof)
输入web会以图形化的方式展示(web命令需要安装 Graphviz)
(pprof) web
(pprof)
输出到电脑系统临时目录file:///C:/Users/39834/AppData/Local/Temp/pprof003.svg
,并默认打开(关闭后,临时目录中文件会自动删除)
再来个示例
code
package main
import (
"os"
"runtime/pprof"
"strings"
)
func main() {
ff, _ := os.Create("mem.pprof")
defer ff.Close()
i := 1
for {
Opera()
if i > 30000 {
break
}
i++
}
_ = pprof.WriteHeapProfile(ff)
}
var cacheBuf []string
func Opera() {
cacheBuf = append(cacheBuf, strings.Repeat("caller", 100))
}
这段代码,我们把pprof结果保存到mem.pprof
文件中,然后用go tool
启动http窗口来查看结果
D:\www\peak\etc>go tool pprof -http=:1212 mem.pprof
Serving web UI on http://localhost:1212