golang 性能剖析pprof

pprof

简介

pprof 是用于可视化和分析性能分析数据的工具.

功能

• CPU Profiling：CPU 分析, 按照一定的频率采集所监听的应用程序 CPU（含寄存器）的使用情况, 可确定应用程序在主动消耗 CPU 周期时花费时间的位置.
• Memory Profiling：内存分析, 在应用程序进行堆分配时记录堆栈跟踪, 用于监视当前和历史内存使用情况, 以及检查内存泄漏.
• Block Profiling：阻塞分析, 记录 goroutine 阻塞等待同步（包括定时器通道）的位置.
• Mutex Profiling：互斥锁分析, 报告互斥锁的竞争情况

使用

不同应用下使用方式略有不同, 分为工具型应用、服务型应用、gin框架应用.

模式一: 工具型应用

package main

import (
    "flag"
    "fmt"
    "log"
    "math/rand"
    "os"
    "runtime/pprof"
    "sort"

)

var num = 100000000
var findNum = 10000000

var t = flag.String("t", "map", "use map")

func main() {
    cpuf, err := os.Create("cpu_profile")
    if err != nil {
        log.Fatal(err)
    }
    pprof.StartCPUProfile(cpuf)
    defer pprof.StopCPUProfile()

    flag.Parse()
    if *t == "map" {
        fmt.Println("map")
        findMapMax()
    } else {
        fmt.Println("slice")
        findSliceMax()
    }
}

func findMapMax() {
    m := map[int]int{}
    for i := 0; i < num; i++ {
        m[i] = i
    }

    for i := 0; i < findNum; i++ {
        toFind := rand.Int31n(int32(num))
        _ = m[int(toFind)]
    }
}

func findSliceMax() {
    m := make([]int, num)
    for i := 0; i < num; i++ {
        m[i] = i
    }

    for i := 0; i < findNum; i++ {
        toFind := rand.Int31n(int32(num))
        v := sort.SearchInts(m, int(toFind))
        fmt.Println(v)
    }
}
           

• 内存性能优化使用

pprof.WriteHeapProfile(w io.Writer)
           

分析结果存储在当前目录下的cpu_profile文件中.

模式二: 服务型应用

package main
import (
    _ "net/http/pprof"
    "net/http"
)
func main() {
    http.ListenAndServe("0.0.0.0:8000", nil)
}
           

访问地址: http://localhost:8080/debug/pprof/ , 如图所示:

模式三: Gin框架应用

方法一

package main

import (
	"github.com/gin-contrib/pprof"
	"github.com/gin-gonic/gin"
)

func main() {
  router := gin.Default()
  pprof.Register(router)
  router.Run(":8080")
}
           

方法二

package main

import (
	"github.com/gin-gonic/gin"
	"github.com/DeanThompson/ginpprof"
)

func main() {
	router := gin.Default()
	ginpprof.Wrap(router)
	router.Run(":8080")
}
           

以上两种方法访问地址: http://localhost:8080/debug/pprof/ .

pprof详细介绍

web访问

直接访问 http://127.0.01:8080/debug/pprof/ 便可看到go运行信息:

类型	描述	备注
allocs	内存分配情况的采样信息	可以用浏览器打开, 但可读性不高
blocks	阻塞操作情况的采样信息	可以用浏览器打开, 但可读性不高
cmdline	显示程序启动命令及参数	可以用浏览器打开
goroutine	当前所有协程的堆栈信息	可以用浏览器打开, 但可读性不高
heap	堆上内存使用情况的采样信息	可以用浏览器打开, 但可读性不高
mutex	锁争用情况的采样信息	可以用浏览器打开, 但可读性不高
profile	CPU占用情况的采样信息, 持续 30s	浏览器打开会下载文件
threadcreate	系统线程创建情况的采样信息	可以用浏览器打开, 但可读性不高
trace	程序运行跟踪信息	浏览器打开会下载文件

交互终端

1. go tool pprof http://localhost:8080/debug/pprof/profile?seconds=60

➜  go tool pprof http://localhost:8080/debug/pprof/profile?seconds=60
               
Fetching profile over HTTP from http://127.0.0.1:8080/debug/pprof/profile
Saved profile in /Users/yunzhanghu_bj643/pprof/pprof.samples.cpu.004.pb.gz
Type: cpu
Time: Jun 6, 2020 at 6:10pm (CST)
Duration: 30s, Total samples = 0 
No samples were found with the default sample value type.
Try "sample_index" command to analyze different sample values.
Entering interactive mode (type "help" for commands, "o" for options)
(pprof)  
           

执行 pprof help 可查看命令说明.

(pprof) top10
Showing nodes accounting for 25.92s, 97.63% of 26.55s total
Dropped 85 nodes (cum <= 0.13s)
Showing top 10 nodes out of 21
      flat  flat%   sum%        cum   cum%
    23.28s 87.68% 87.68%     23.29s 87.72%  syscall.Syscall
     0.77s  2.90% 90.58%      0.77s  2.90%  runtime.memmove
     0.58s  2.18% 92.77%      0.58s  2.18%  runtime.freedefer
     0.53s  2.00% 94.76%      1.42s  5.35%  runtime.scanobject
     0.36s  1.36% 96.12%      0.39s  1.47%  runtime.heapBitsForObject
     0.35s  1.32% 97.44%      0.45s  1.69%  runtime.greyobject
     0.02s 0.075% 97.51%     24.96s 94.01%  main.main.func1
     0.01s 0.038% 97.55%     23.91s 90.06%  os.(*File).Write
     0.01s 0.038% 97.59%      0.19s  0.72%  runtime.mallocgc
     0.01s 0.038% 97.63%     23.30s 87.76%  syscall.Write
           

• flat：给定函数上运行耗时
• flat%：同上的 CPU 运行耗时总比例
• sum%：给定函数累积使用 CPU 总比例
• cum：当前函数加上它之上的调用运行总耗时
• cum%：同上的 CPU 运行耗时总比例

2. go tool pprof http://localhost:8080/debug/pprof/heap

➜ go tool pprof http://localhost:8080/debug/pprof/heap
Fetching profile over HTTP from http://localhost:8080/debug/pprof/heap
Saved profile in /Users/eddycjy/pprof/pprof.alloc_objects.alloc_space.inuse_objects.inuse_space.008.pb.gz
Type: inuse_space
Entering interactive mode (type "help" for commands, "o" for options)
(pprof) top
Showing nodes accounting for 837.48MB, 100% of 837.48MB total
      flat  flat%   sum%        cum   cum%
  837.48MB   100%   100%   837.48MB   100%  main.main.func1
           

• inuse_space：分析应用程序的常驻内存占用情况
• alloc_objects：分析应用程序的内存临时分配情况

3. go tool pprof http://localhost:8080/debug/pprof/block

4. go tool pprof http://localhost:8080/debug/pprof/mutex

pprof 可视化界面

➜ go test -bench=. -cpuprofile=cpu.prof
goos: darwin
goarch: amd64
pkg: gpprof
BenchmarkAdd-12          8261594               160 ns/op
PASS
ok      gpprof  2.360s
           

-cpuprofile：cpu profiling 数据要保存的文件地址
-memprofile：memory profiling 数据要报文的文件地址
           

启动 PProf 可视化界面

• 方法一:

$ go tool pprof -http=:8080 cpu.prof
           

• 方法二:

➜ go tool pprof cpu.prof 
(pprof) web
           

web命令需要安装graviz: http://graphviz.org/

火焰图