benchmark + pprof 分析 Go 程序性能

618 阅读3分钟

这是我参与8月更文挑战的第6天,活动详情查看:8月更文挑战

benchmark 对程序进行基准测试: Benchmark

代码

package aes

import (
   "bytes"
   "crypto/aes"
   "crypto/cipher"
   "encoding/base64"
   "fmt"
   "log"
   "os"
   "testing"
)

func AesEncryptA(aesKey, IV, origin []byte) []byte {
   block, err := aes.NewCipher(aesKey)
   if err != nil {
      return nil
   }
   blocksize := block.BlockSize()
   blockMode := cipher.NewCBCEncrypter(block, IV)
   originData := PKCS5Padding(origin, blocksize)
   crypted := make([]byte, len(originData))
   blockMode.CryptBlocks(crypted, originData)
   return crypted
}

func AesEncryptB(aesKey, IV, origin []byte) []byte {
   block, err := aes.NewCipher(aesKey)
   if err != nil {
      return nil
   }
   blocksize := block.BlockSize()
   blockMode := cipher.NewCBCEncrypter(block, IV)
   originData := PKCS5Padding(origin, blocksize)
   crypted := make([]byte, len(originData))
   blockMode.CryptBlocks(crypted, originData)

   // 把加密结果打印到日志看看
   f, _ := os.Create("temp.log")
   defer f.Close()
   log.SetOutput(f)
   log.Println(fmt.Sprintf("encrypt res is %s", base64.StdEncoding.EncodeToString(crypted)))

   return crypted
}

/**
PKCS5包装
*/
func PKCS5Padding(cipherText []byte, blockSize int) []byte {
   padding := blockSize - len(cipherText)%blockSize
   padText := bytes.Repeat([]byte{byte(padding)}, padding)
   return append(cipherText, padText...)
}

/*
解包装
*/
func PKCS5Trimming(encrypt []byte) []byte {
   padding := encrypt[len(encrypt)-1]
   return encrypt[:len(encrypt)-int(padding)]
}

func BenchmarkAesEncryptB(b *testing.B) {
   aesKey := []byte("1234567890abcdef")
   IV := []byte("7878676756564545")

   originData := bytes.Repeat([]byte{28}, 1<<29)
   b.ResetTimer()
   for i := 0; i < b.N; i++ {
      AesEncryptB(aesKey, IV, originData)
   }
}

命令执行:

go test -bench BenchmarkAesEncryptB  -run none  -benchmem -cpuprofile cpuprofile.out -memprofile memprofile.out

命令解释:

  • bench 表示执行某些基准测试函数,后面加需要执行的基础测试函数名称, 也可以加. 表示执行所有基准测试函数,(-bench 可以跟正则表达式)
  • run 表示执行某些单元测试和示例测试函数, 一般加 none ,表示都不执行
  • benchmem 表示打印机执行过程中的内存分配
  • cpuprofile 表示全过程的CPU 写到文件 cpuprofile.out 中
  • memprofile 表示全过程的内存数据行动一些该要数据写到文件。memprofile.out 中

执行结果:

goos: darwin
goarch: amd64
pkg: code.xxxx.org/xxxx.hit/GoProject/main/gobase/aes
cpu: Intel(R) Core(TM) i7-9750H CPU @ 2.60GHz
BenchmarkAesEncryptB-12                1        3597342551 ns/op        6218809432 B/op       51 allocs/op
PASS
ok      code.xxxx.org/xxxx.hit/GoProject/main/gobase/aes       4.214s

上述执行结果可以看到:

image.png

从执行结果中能看到,for 循环每执行一次,耗时 3597342551 纳秒,同时会有55次内存分配操作,每次操作 6218809432 字节。

pprof 分析 CPU

pprof 是 go 中自带的分析 CPU 分析器,常用来分析性能瓶颈

pprof 既可以通过命令行交互的方式查看CPU(内存)的概要数据,也可以通过web的方式查看直观的图形化展示。这里我们主要通过web的方式来展示。

当然,使用pprof工具前,你需要先安装 graphviz,如果是mac,执行 brew install graphviz

使用 pprof 分析 CPU

执行如下命令:

go tool pprof -http=":8081" cpuprofile.out

然后通过访问地址 http://localhost:8081/ui/ 能看到

image.png

可以看到加密部分用了 2.64s 其中加密用了0.67s, 日志打印和字符串转化用了0.41+0.86s 。

用 pprof 分析内存

go tool pprof -http=":8081" memprofile.out

通过地址 http://localhost:8081/ui/ 能看到

image.png

可以看到总共用了 5930.71MB,实际上加密用值用了 640MB 上,可以看到其他内存耗费在fmt 和 log 打印上了

AesEncryptA 对于 AesEncryptB 的优化

func BenchmarkAesEncryptA(b *testing.B) {
   aesKey := []byte("1234567890abcdef")
   IV := []byte("7878676756564545")

   originData := bytes.Repeat([]byte{28}, 1<<29)
   b.ResetTimer()
   for i := 0; i < b.N; i++ {
      AesEncryptA(aesKey, IV, originData)
   }
}


func BenchmarkAesEncryptB(b *testing.B) {
   aesKey := []byte("1234567890abcdef")
   IV := []byte("7878676756564545")

   originData := bytes.Repeat([]byte{28}, 1<<29)
   b.ResetTimer()
   for i := 0; i < b.N; i++ {
      AesEncryptB(aesKey, IV, originData)
   }
}

执行命令:

go test -bench . -run none -benchmem -cpuprofile cpuprofile.out -memprofile memprofile.out

执行结果:

goos: darwin
goarch: amd64
pkg: code.xxxx.org/xxxx.hit/GoProject/main/gobase/aes
cpu: Intel(R) Core(TM) i7-9750H CPU @ 2.60GHz
BenchmarkAesEncryptA-12                1        1011892174 ns/op        1207970544 B/op       16 allocs/op
BenchmarkAesEncryptB-12                1        3382908467 ns/op        6218813680 B/op       54 allocs/op
PASS
ok      code.xxxx.org/xxxx.hit/GoProject/main/gobase/aes       5.014s

可以看到BenchmarkAesEncryptA 每次循环消耗 1011892174 ns 每次操作 1207970544 B 内存,比 BenchmarkAesEncryptB 每次循环消耗 3382908467 ns, 每次操作 6218813680 B 内存,可以看到得到了很大的改善,区别主要是 去掉了一些日志打印的结果。

总结

可以借助 benchmark 进行基准测试,跑出 cpuprofile.out 和memprofile.out ,然后利用 pprof 进行 cpu 和内存分析