基准测试函数
// from fib.go
func Fib(n int) int {
if n < 2 {
return n
}
return Fib(n-1) + Fib(n-2)
}针对Fib函数写个基准测试函数
直接让gpt写就好了
// fib_test.go
package main
import (
"testing"
)
func Fib(n int) int {
if n < 2 {
return n
}
return Fib(n-1) + Fib(n-2)
}
func BenchmarkFib(b *testing.B) {
// Run the Fib function b.N times
for i := 0; i < b.N; i++ {
Fib(20) // You can change the input value here based on your requirement
}
}
![[Pasted image 20230801171846.png]] 点击这里即可
pprof
输入
go get github.com/wolfogre/go-pprof-practice/animal
获取文件,打开,运行 不用从GitHub上clone,但是需要能访问GitHub
页面上展示了可用的程序运行采样数据
| 类型 | 描述 | 备注 |
|---|---|---|
| allocs | 内存分配情况的采样信息 | 可以用浏览器打开,但可读性不高 |
| blocks | 阻塞操作情况的采样信息 | 可以用浏览器打开,但可读性不高 |
| cmdline | 显示程序启动命令及参数 | 可以用浏览器打开,这里会显示 ./go-pprof-practice |
| goroutine | 当前所有协程的堆栈信息 | 可以用浏览器打开,但可读性不高 |
| heap | 堆上内存使用情况的采样信息 | 可以用浏览器打开,但可读性不高 |
| mutex | 锁争用情况的采样信息 | 可以用浏览器打开,但可读性不高 |
| profile | CPU 占用情况的采样信息 | 浏览器打开会下载文件 |
| threadcreate | 系统线程创建情况的采样信息 | 可以用浏览器打开,但可读性不高 |
| trace | 程序运行跟踪信息 | 浏览器打开会下载文件,本文不涉及,可另行参阅《深入浅出 Go trace》 |
借助
go tool pprof命令来排查问题,这个命令是 go 原生自带的,所以不用额外安装
排查 CPU 占用过高
打开自己系统的任务管理器,![[Pasted image 20230802105630.png]] 可以看到cpu占比很高 (我是用vscode运行的,用着比较顺手,其实直接用cmd运行就可以,看到的就是一个项目名称go-pprof-practice的cpu占比很高)
输入
go tool pprof http://localhost:6060/debug/pprof/profile
进入交互式终端,而后,输入top
![[Pasted image 20230802110101.png]]
github.com/wolfogre/go-pprof-practice/animal/felidae/tiger.(*Tiger).Eat
flat: 9.29s,表示在Tiger类型的Eat方法中执行消耗的时间。flat%: 91.98%,表示Eat方法的执行时间占程序总执行时间的 91.98%。sum%: 91.98%,表示Eat方法以及在Eat方法中调用的其他函数的执行时间占程序总执行时间的 91.98%。cum: 9.30s,表示从程序开始到Eat方法执行结束的时间。cum%: 92.08%,表示从程序开始到Eat方法执行结束的时间占程序总执行时间的 92.08%。
可以定位到
github.com/wolfogre/go-pprof-practice/animal/felidae/tiger.(*Tiger).Eat这个命令占用cpu较多
![[Pasted image 20230802110505.png]] 可以看到,24行这里
9.29s 9.30s 24: for i := 0; i < loop; i++ {
占用时间更多
输入web,看到可视化的内容 ![[Pasted image 20230802164845.png]] eat占比很高
终端输入exit,退出,并终止程序 改eat的bug
排查内存占用过高
运行程序,输入
go tool pprof http://localhost:6060/debug/pprof/heap
进入交互式终端,而后,再一次使用 top、list 来定问问题代码
![[Pasted image 20230802165632.png]]
或者web ![[Pasted image 20230802165422.png]] 获得关于内存占用的情况
退出
排查频繁内存回收
你应该知道,频繁的 GC 对 golang 程序性能的影响也是非常严重的。虽然现在这个炸弹程序内存使用量并不高,但这会不会是频繁 GC 之后的假象呢?
为了获取程序运行过程中 GC 日志,我们需要先退出炸弹程序,再在重新启动前赋予一个环境变量,同时为了避免其他日志的干扰,使用 grep 筛选出 GC 日志查看:
GODEBUG=gctrace=1 ./go-pprof-practice | grep gc
日志输出如下: ![[Pasted image 20230802170337.png]]
可以看到,GC 差不多每 3 秒就发生一次,且每次 GC 都会从 16MB 清理到几乎 0MB,说明程序在不断的申请内存再释放,这是高性能 golang 程序所不允许的。
如果你希望进一步了解 golang 的 GC 日志可以查看《如何监控 golang 程序的垃圾回收》,为保证实验节奏,这里不做展开。
所以接下来使用 pprof 排查时,我们在乎的不是什么地方在占用大量内存,而是什么地方在不停地申请内存,这两者是有区别的。
由于内存的申请与释放频度是需要一段时间来统计的,所有我们保证炸弹程序已经运行了几分钟之后,再运行命令:
go tool pprof http://localhost:6060/debug/pprof/allocs
同样使用 top、list、web 大法:
排查协程泄露
由于 golang 自带内存回收,所以一般不会发生内存泄露。但凡事都有例外,在 golang 中,协程本身是可能泄露的,或者叫协程失控,进而导致内存泄露。
我们在浏览器里可以看到,此时程序的协程数已经多达 58条: ![[Pasted image 20230802165916.png]]
虽然 58 条并不算多,但对于这样一个小程序来说,似乎还是不正常的。为求安心,我们再次是用 pprof 来排查一下:
go tool pprof http://localhost:6060/debug/pprof/goroutine
同样是 top、list、web 大法:
排查锁的争用
到目前为止,我们已经解决这个炸弹程序的所有资源占用问题,但是事情还没有完,我们需要进一步排查那些会导致程序运行慢的性能问题,这些问题可能并不会导致资源占用,但会让程序效率低下,这同样是高性能程序所忌讳的。
我们首先想到的就是程序中是否有不合理的锁的争用,我们倒一倒,回头看看上一张图,虽然协程数已经降到 4 条,但还显示有一个 mutex 存在争用问题。
相信到这里,你已经触类旁通了,无需多言,开整。
go tool pprof http://localhost:6060/debug/pprof/mutex
同样是 top、list、web 大法:
排查阻塞操作
好了,我们开始排查最后一个问题。
在程序中,除了锁的争用会导致阻塞之外,很多逻辑都会导致阻塞。
可以看到,这里仍有 2 个阻塞操作,虽然不一定是有问题的,但我们保证程序性能,我们还是要老老实实排查确认一下才对。
go tool pprof http://localhost:6060/debug/pprof/block
top、list、web,你懂得。
性能调优实践和原理
高质量编程与性能调优实战 .pptx - 飞书云文档 (feishu.cn)
p92-p104