高质量编程与性能调优实战:通过实战和测试,分析和优化任意项目中存在的性能问题|青训营

65 阅读4分钟

基准测试函数

// 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

打开/debug/pprof/

页面上展示了可用的程序运行采样数据

类型描述备注
allocs内存分配情况的采样信息可以用浏览器打开,但可读性不高
blocks阻塞操作情况的采样信息可以用浏览器打开,但可读性不高
cmdline显示程序启动命令及参数可以用浏览器打开,这里会显示 ./go-pprof-practice
goroutine当前所有协程的堆栈信息可以用浏览器打开,但可读性不高
heap堆上内存使用情况的采样信息可以用浏览器打开,但可读性不高
mutex锁争用情况的采样信息可以用浏览器打开,但可读性不高
profileCPU 占用情况的采样信息浏览器打开会下载文件
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

进入交互式终端,而后,再一次使用 toplist 来定问问题代码 ![[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