Random walk to my blog

my blog for sharing my knowledge,experience and viewpoint

0%

Golang的性能测试

本文介绍Golang的性能测试(Benchmark)。

使用testing包

看下面的bench_test.go:

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
import "testing"

func Fib(n int) int {
switch n {
case 0:
return 0
case 1:
return 1
default:
return Fib(n-1) + Fib(n-2)
}
}

func BenchmarkFib20(b *testing.B) {
for n := 0; n < b.N; n++ {
Fib(20) // run the Fib function b.N times
}
}

运行程序

1
2
3
4
5
6
7
> $ go test -bench=. -run=^BenchmarkFib20$
goos: darwin
goarch: amd64
pkg: github.com/liangyaopei/GolangTester/bench
BenchmarkFib20-8 25608 46494 ns/op
PASS
ok github.com/liangyaopei/GolangTester/bench 1.678s

从输出可以看到, BenchmarkFib20-8中的-8后缀,指的是GOMAXPROCS,它与CPU的数量有关。可以通过-cpu标志来指定

1
> $ go test -bench=. -cpu=1,2,4 -run=^BenchmarkFib20$

25608表示进行了25608次循环,每次循环耗时46494ns (46494 ns/op)。

其他标志

作用 例子
-benchtime 指定运行时间 go test -bench=. -benchtime=10s -run=^BenchmarkFib20$
-count 指定运行次数 go test -bench=. -count=10 -run=^BenchmarkFib20$
-benchmem 监控内存分配 go test -bench=. -benchmem -run=^BenchmarkFib20$

将test保存为二进制文件

go test -c将测试的代码保存为二进制文件,方便下次调用。

CPU/内存/Block的Profile

  • -cpuprofile=$FILE 将 CPU profile 输出 $FILE.
  • -memprofile=$FILE, 将 内存 profile 输出 $FILE, -memprofilerate=N adjusts the profile rate to 1/N.
  • -blockprofile=$FILE, 将 block profile 输出to $FILE.

例子:

1
2
> $ go test -bench=.  -run=^BenchmarkFib20$ -cpuprofile=profile
> $ go tool pprof profile

使用PProf

profile用来跟踪整个程序的运行,用来定位程序性能的问题。

pprof来自Google Perf Tools, 它被整合进Golang的runtime。pprof包含2个部分,

  • runtime/pprof 每个Golang程序都有用到
  • go tool pprof 用来读取profile输出文件

pprof的类型

  • CPU Profile

    程序运行时(runtime), CPU Profile每隔10ms会打断(interrupt)程序执行, 记录当前运行的Goroutine的堆栈踪迹(stack trace)。

  • Memory profiling

    当堆内存分配时,Memory profiling记录stack trace.

    与CPU Profile类似,默认情况下,每1000次堆内存分配,Memory profiling会进行1次取样。

    Memory profiling是取样的,并且它跟踪的时没有使用的内存分配,因此它不能确定整个程序运行使用的内存。

  • Block (or blocking) profiling

    Block profiling记录一个Goroutine等待共享资源的时间,这可以用来确定程序中的并发瓶颈。

  • Mutex contention profiling

    Mutex contention profiling记录因为互斥导致延迟的操作。

每次一个Profile

使用profile是有性能消耗的,使用时每次只用1种类型的Profile。如果同时使用多个Profile,Profile之间会相互影响。

使用PProf

看下面的例子words.go

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
import (
"fmt"
"io"
"log"
"os"
"unicode"

"github.com/pkg/profile"
)

func readbyte(r io.Reader) (rune, error) {
var buf [1]byte
_, err := r.Read(buf[:])
return rune(buf[0]), err
}

func main() {
defer profile.Start().Stop()

f, err := os.Open(os.Args[1])
if err != nil {
log.Fatalf("could not open file %q: %v", os.Args[1], err)
}

words := 0
inword := false
for {
r, err := readbyte(f)
if err == io.EOF {
break
}

if err != nil {
log.Fatalf("could not read file %q: %v", os.Args[1], err)
}

if unicode.IsSpace(r) && inword {
words++
inword = false
}
inword = unicode.IsLetter(r)
}
fmt.Printf("%q: %d words\n", os.Args[1], words)
}

进行性能测试:

1
2
3
4
5
> $ go run words.go whales.txt
2021/02/06 14:38:20 profile: cpu profiling enabled, /var/folders/q9/5v5tz4_92gd343hvb3mb1_s40000gn/T/profile247619673/cpu.pprof
"whales.txt": 181276 words
2021/02/06 14:38:21 profile: cpu profiling disabled, /var/folders/q9/5v5tz4_92gd343hvb3mb1_s40000gn/T/profile247619673/cpu.pprof

使用命令go tool pprof读取文件

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
> $ go tool pprof /var/folders/q9/5v5tz4_92gd343hvb3mb1_s40000gn/T/profile247619673/cpu.pprof
Type: cpu
Time: Feb 6, 2021 at 2:38pm (CST)
Duration: 1.63s, Total samples = 1.29s (79.06%)
Entering interactive mode (type "help" for commands, "o" for options)
(pprof) top
Showing nodes accounting for 1.29s, 100% of 1.29s total
flat flat% sum% cum cum%
1.29s 100% 100% 1.29s 100% syscall.syscall
0 0% 100% 1.29s 100% internal/poll.(*FD).Read
0 0% 100% 1.29s 100% internal/poll.ignoringEINTR
0 0% 100% 1.29s 100% main.main
0 0% 100% 1.29s 100% main.readbyte (inline)
0 0% 100% 1.29s 100% os.(*File).Read
0 0% 100% 1.29s 100% os.(*File).read (inline)
0 0% 100% 1.29s 100% runtime.main
0 0% 100% 1.29s 100% syscall.Read
0 0% 100% 1.29s 100% syscall.read

可以看到syscall.syscall耗费最多的CPU资源, 因为每次readbyte(f)都会发生系统调用,读取字符。

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
(pprof) list main.main
Total: 1.29s
ROUTINE ======================== main.main in /Users/liangyaopei/workspace/GolangTester/profile/words.go
0 1.29s (flat, cum) 100% of Total
. . 25: }
. . 26:
. . 27: words := 0
. . 28: inword := false
. . 29: for {
. 1.29s 30: r, err := readbyte(f)
. . 31: if err == io.EOF {
. . 32: break
. . 33: }
. . 34:
. . 35: if err != nil {

go tool pprof常用命令

说明
top Top 命令会按指标大小列出前 10 个函数,比如 CPU 是按执行时间长短,内存是按内存占用多少。
traces 打印所有调用栈和调用栈的指标信息。
list list 命令则是用来帮我们确认函数在代码中的位置。
web 打开浏览器图形界面
go tool pprof -http=:8080 使用浏览器形式读取Profile输出

编译器优化

编译器优化主要包括3个方面

  • 逃逸分析
  • 函数内联(inline)
  • 死代码(dead code)清除

go build 命令

作用 例子
-m 打印编译器的逃逸分析决定 go build -gcflags=-m example.go
-l 是否内联 -gcflags=-l禁止内联; -gcflags='-l -l' 两层内联

参考文献

  1. High Performance Go Workshop

我的公众号:lyp分享的地方

我的知乎专栏: https://zhuanlan.zhihu.com/c_1275466546035740672

我的博客:www.liangyaopei.com

Github Page: https://liangyaopei.github.io/