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/