1.2 基准测试
基准测试(benchmarking)是一种测量和评估软件性能指标的活动。在某个时候通过基准测试建立一个已知的性能水平(称为基准线),当系统的软硬件环境发生变化之后再进行一次基准测试,以确定那些变化对性能的影响,这是基准测试最常见的用途。其他用途包括测定某种负载水平下的性能极限,管理系统或环境的变化、发现可能导致性能问题的条件等。
在_test.go结尾的测试文件中,如下形式的函数(基准测试的函数必须以 Benchmark (基准)开头,必须是可导出的:
func BenchmarkXxxx(*testing.B)
被认为是基准测试,通过go test命令,加上-bench选项来执行。多个基准测试按照顺序运行。
基准测试函数样例如下:
./02_testing/test04/test04_test.go
package test04 import ( "fmt" "testing" ) func BenchmarkHello(b *testing.B) { // 基准函数会运行目标代码b.N次。 for i := 0; i < b.N; i++ { fmt.Sprintf("hello") } }
执行测试命令(在基准执行期间,会调整 b.N 直到基准测试函数持续足够长的时间,输出):
go test -v -run="none" -bench="." ./02_testing/test04 # go test -v -run="none" -bench="BenchmarkHello" BenchmarkHello BenchmarkHello-8 21805216 55.71 ns/op PASS ok go.standard.library.study/02_testing/test04 1.308s
意味着循环执行了21805216次,每次循环花费了55.71ns。
运行基准测试也要使用go test命令,不过要加上-bench标记,他接受一个表达式作为参数,匹配基准测试的函数,这里使用的-bench="."代表运行所有基准测试,如果改成-bench="BenchmarkHello",就代表只执行这一个基准测试。
因为默认情况go test会运行单元测试,为了防止单元测试的输出影响查看基准测试的结果,可以使用-run="none"匹配一个不存在的 单元测试,过滤掉单元测试的输出,这里使用的none,因为基本不会创建这个名字的单元测试。
下面着重解释一下输出的结果:
BenchmarkHello-8后面的-8表示运行对应的GOMAXPROCS的值;
21805216代表着运行for循环的次数,也就是调用被测试代码的次数;
55.71 ns/op代表每次循环需要花费55.71ns;
以上测试时间默认是1s,也就是说1s的时间调用了21805216次,每次花费55.71ns。如果想让测试时间更长,可以通过-benchtime指定,比如3s:
$ go test -bench="." -benchtime="3s" -run="none"
当然,在一般情况下,加长测试时间,只会导致测试的次数变 ,但是最终的性能结果并没有太大变化 建议测试时间不要超过 3s ,当然,具体情况具体分析。
如果在运行前基准测试需要进行一些耗时的配置,则可以先重置定时器,再进入for循环(例如避免for循环之前的初始化代码的干扰):
func BenchmarkBigLen(b *testing.B){ ... // 初始化代码 b.ResetTimer() // 重置时间 ... // 通常是一个for循环 }
b.ResetTimer():将运行的基准时间和内存分配计数器归零,并删除用户报告的指标。
如果基准测试需要在 并行设置中测试性能,则可以使用RunParallel 辅助函数,这样的基准测试一般与go test -cpu标志一起使用:
func BenchmarkTemplateParallel(b *testing.B) { templ:=template.Must(template.New("test").Parse("hello,{{.}}!")) b.RunParallel(func(pb *testing.PB) { // 每一个goroutine都有属于自己的bytes.Buffer var buf bytes.Buffer for pb.Next() { // 所有 goroutine一起,循环一共执行b.N次( N指默认的 CPU 核心数) buf.Reset() templ.Execute(&buf,"world") } }) }
基准测试是一种测试代码性能的方法。想要测试解决同一问题的不同方案的性能,以及查看 哪种解决方案的性能更好时,基准测试就会很有用。基准测试也可以用来识别某段代码的 CPU 或者内存效率问题,而这段代码的效率可能会严重影响整个应用程序的性能。许多开发人员会用 基准测试来测试不同的并发模式,或者用基准测试来辅助配置工作池的数量,以保证能最大化系统的吞吐量。
1. 性能对比
最上面那个基准测试的例子,其实是一个int 类型转为string类型的例子,标准库里还有几种方法,我们来看看哪一种性能更加高效:
./02_testing/test06/test06_test.go
package test06 import ( "fmt" "strconv" "testing" ) func BenchmarkSprintf(b *testing.B) { num := 10 b.ResetTimer() for i := 0; i < b.N; i++ { fmt.Sprintf("%d", num) } } func BenchmarkFormat(b *testing.B) { num := int64(10) b.ResetTimer() for i := 0; i < b.N; i++ { strconv.FormatInt(num, 10) } } func BenchmarkItoa(b *testing.B) { num := 10 b.ResetTimer() for i := 0; i < b.N; i++ { strconv.Itoa(num) } }
执行测试命令:
$ go test -run="none" -bench="." ./02_testing/test06 goos: windows goarch: amd64 pkg: go.standard.library.study/02_testing/test06 cpu: Intel(R) Core(TM) i5-10210U CPU @ 1.60GHz BenchmarkSprintf BenchmarkSprintf-8 15552018 76.09 ns/op BenchmarkFormat BenchmarkFormat-8 443492250 2.719 ns/op BenchmarkItoa BenchmarkItoa-8 446563802 2.709 ns/op PASS ok go.standard.library.study/02_testing/test06 4.265s
从结果来看,strconv.FormatInt函数最快,其次是strconv.Itoa,而fmt.Sprintf最慢。
为了进一步分析三个函数的快慢的根源,可以通过-benchmem分析内存的使用情况。-benchmem可以提供每次操作分配内存的次数,以及每次操作分配的字节数(B)。
$ go test -run="none" -bench="." -benchmem ./02_testing/test06 goos: windows goarch: amd64 pkg: go.standard.library.study/02_testing/test06 cpu: Intel(R) Core(TM) i5-10210U CPU @ 1.60GHz BenchmarkSprintf-8 14670589 76.02 ns/op 2 B/op 1 allocs/op BenchmarkFormat-8 449164497 2.679 ns/op 0 B/op 0 allocs/op BenchmarkItoa-8 442082088 2.694 ns/op 0 B/op 0 allocs/op PASS ok go.standard.library.study/02_testing/test06 4.180s
这次输出的结果会多出两组新的数值,一组数值的单位是B/op,另一组的单位是allocs/op,
allocs/op的值表示每次操作从堆上分配内存的次数。可以看到Sprinf函数每次操作都会从堆上分配1个值,而另外两个函数都是0个值。
B/op的值表示每次操作分配的B字节数,你可以看到Sprintf1次分配内存消耗了2B的内存,而另外两个都是0B。
从这个数据就可以知道为什么它这么慢了,内存分配和占用都太高。
在运行单元测试和基准测试的时候,还有很多选项可以使用,建议都查看一遍,以便在编写自己的包和工程时,充分利用测试框架。
在代码开发中,对与要求性能的地方,编写基准测试非常重要,这有助于开发出性能更好的代码。不过性能、可用性、复用性等也要有一个相对的取舍,不能为了追求性能而过度优化。
2. pprof
在之前的例子中,只能查看函数的执行时间,如果想进一步分析函数的具体执行状况可以配合其他选项使用。上面曾经使用到一些基准测试的选项,其中常用的测试选项如下:
1.-bench="regexp":regexp可以为任何正则表达式,表示需要运行的基准测试函数,一般可以用-bench="."来执行当前目录下的所有的基准测试;
2.-benchmem:在输出内容中包含基准测试的内存分配统计信息;
3.-benchtime="ts" t表示执行单个参数函数的累计耗时上线,默认是1s;
4.cpuprofile="out path":输出cpu profile到指定路径,可以使用pprof查看;
5.memprofile="out path":输出内存profile到指定路径,可以使用pprof查看
执行一个基准测试的时候,可以指定相关的选项,例如下面这样:
$ go test -bench="." -benchmem -cpuprofile="./02_testing/test06/cpu.prof" -memprofile="./02_testing/test06/memory.prof" ./02_testing/test06
生成两个文件是无法直接查看的,需要使用工具去解析。
这就需要本节的主角 pprof 登场了,这是 Go 语言提供的性能分析工具,可以分 cpu profile 、memory profile、 heap profile 、block profile 等信息。
在上面的基准测试中,己经知道怎样生成 cpu.prof 文件了,然后可以利用 go tool pprof 工具来查看:
$ go tool pprof bench_test.test ,./02_testing/test06/cpu.prof bench_test.test: open bench_test.test: The system cannot find the file specified. Fetched 1 source profiles out of 2 Type: cpu Time: Jul 17, 2022 at 4:38pm (CST) Duration: 4.46s, Total samples = 3.41s (76.52%) Entering interactive mode (type "help" for commands, "o" for options) (pprof)
这时会进入一个可交互环境,输入 help 可以查看所有的交互命令,现在可以使用 top 10 来查看测试过程中最耗 CPU 资源的函数:
(pprof) top10 Showing nodes accounting for 2390ms, 70.09% of 3410ms total 显示节点占2390ms,占3410ms总数的70.09% Dropped 61 nodes (cum <= 17.05ms) 缺失61个节点(cum <= 17.05ms) Showing top 10 nodes out of 78 显示78个节点中的前10个节点 flat flat% sum% cum cum% 1030ms 30.21% 30.21% 1330ms 39.00% strconv.FormatInt 300ms 8.80% 39.00% 300ms 8.80% strconv.small (inline) 280ms 8.21% 47.21% 1000ms 29.33% go.standard.library.study/02_testing/test06.BenchmarkFormat 250ms 7.33% 54.55% 940ms 27.57% go.standard.library.study/02_testing/test06.BenchmarkItoa 130ms 3.81% 58.36% 130ms 3.81% runtime.stdcall3 100ms 2.93% 61.29% 150ms 4.40% runtime.mallocgc 90ms 2.64% 63.93% 170ms 4.99% fmt.(*fmt).fmtInteger 80ms 2.35% 66.28% 80ms 2.35% runtime.stdcall1 80ms 2.35% 68.62% 690ms 20.23% strconv.Itoa (inline) 50ms 1.47% 70.09% 310ms 9.09% fmt.(*pp).doPrintf
现在解释每一列的含义,在默认情况下,Go语言的运行时系统会以100Hz的频率对CPU使用情况进行取样。也就是说,每1s取样100次,即每10ms取样一次(100Hz 即足够产生有用的数据,又不至于让系统产生停顿)。
实际上,这里所说的对CPU使用情况的取样就是对当前的goroutine 的堆栈上的 程序计数器的取样,由此就可以从样本记录中分析哪些代码是计算时间最长,或者最耗CPU资源的部分了。
第一列``flat` :
表示取样点落在该函数里的总数(不包括调用其他函数),比如strconv.FormatInt这个函数,总执行时间为1030ms,那么总抽样点数为103次;
第二列flat%:
表示落在该函数里取样点占总取样点的百分比,strconv.FormatInt这个函数占用总共的30.21%;
第三列sum%:
列表示的是前几行加起来的执行时间占总共执行时间的多少,top10 命令的默 认排序是按第一列(执行时间〉排序。例如第三行的第三列表示的是前三行函数的执行时间加起来占总共执行时间的 47.21%;
第四列cum:
表示取样点落在该函数里和它直接调用、间接调用的函数里的总数。比如strconv.FormatInt这个函数,总时间为 1330ms ,表示该函数的执行时间加上函数调用的其它函数的执行时间,共1330ms;
第五列cum%:
表示第四列的时间占总时间的百分比。
从top10的输出里,至少可以知道每个函数的执行时间占比,以及每个函数的调用栈的执行时间的占比。如果某个函数自身执行时间过长,那说明这个函数的是否有逻辑错误,是否需要拆分。如果某个函数的调用栈的执行时间过长,是否是因为调用了过多的不需要的函数。