【go】pprof 性能分析

前言

go pprof是 Go 语言提供的性能分析工具。它可以帮助开发者分析 Go 程序的性能问题，包括 CPU 使用情况、内存分配情况、阻塞情况等。

主要功能

CPU 性能分析

go pprof可以对程序的 CPU 使用情况进行分析。它通过在一定时间内对程序的执行进行采样，记录每个函数被调用的次数和执行时间。通过分析这些采样数据，可以确定程序中哪些函数占用了较多的 CPU 时间，从而帮助开发者找到性能瓶颈并进行优化。

例如，使用go tool pprof命令加上程序的 CPU 性能分析文件，可以启动一个交互式的分析界面。在这个界面中，可以使用各种命令查看不同函数的 CPU 使用情况，如top命令可以显示占用 CPU 时间最多的函数列表。

内存性能分析

这个工具可以分析程序的内存分配情况。它可以记录程序在运行过程中每个函数分配的内存大小和数量。通过分析这些数据，可以确定程序中哪些函数可能存在内存泄漏或过度分配内存的问题。

例如，使用go tool pprof命令加上程序的内存性能分析文件，可以查看内存分配的情况。可以使用list命令查看特定函数的内存分配情况，或者使用web命令生成一个可视化的内存分配报告。

阻塞分析

go pprof还可以分析程序中的阻塞情况。它可以检测程序在哪些地方出现了阻塞，如等待锁、通道通信或系统调用等。通过分析阻塞情况，可以帮助开发者找到程序中的并发问题并进行优化。

例如，使用go tool pprof命令加上程序的阻塞分析文件，可以查看程序中的阻塞情况。可以使用top命令查看最常见的阻塞点，或者使用list命令查看特定函数的阻塞情况。

优势

易于使用：

go pprof是 Go 语言内置的工具，无需安装额外的软件即可使用。它的使用方法相对简单，只需要在程序中添加几行代码就可以生成性能分析文件，然后使用go tool pprof命令进行分析。

强大的分析功能：

go pprof提供了丰富的分析功能，可以分析程序的 CPU 使用情况、内存分配情况、阻塞情况等。它还可以生成可视化的报告，帮助开发者更直观地了解程序的性能问题。

与 Go 语言紧密集成：

由于go pprof是 Go 语言内置的工具，它与 Go 语言的其他工具和库紧密集成。例如，可以使用go test命令结合-cpuprofile和-memprofile参数来生成性能分析文件，方便在测试过程中进行性能分析。

CPU profiling

pprof 使用非常简单。首先调用pprof.StartCPUProfile()启用 CPU profiling。它接受一个io.Writer类型的参数，pprof会将分析结果写入这个io.Writer中。为了方便事后分析，我们写到一个文件中。

在要分析的代码后调用pprof.StopCPUProfile()。那么StartCPUProfile()和StopCPUProfile()之间的代码执行情况都会被分析。方便起见可以直接在StartCPUProfile()后，用defer调用StopCPUProfile()，即分析这之后的所有代码。

来个普通的demo，后面内存分析也用这段代码

import (
	"math/rand"
	"os"
	"runtime/pprof"
	"strings"
	"time"
)

func generate(n int) []int {
	nums := make([]int, 0)
	for i := 0; i < n; i++ {
		nums = append(nums, rand.Int())
	}
	return nums
}

func bubbleSort(nums []int) {
	for i := 0; i < len(nums); i++ {
		for j := 1; j < len(nums)-i; j++ {
			if nums[j] < nums[j-1] {
				nums[j], nums[j-1] = nums[j-1], nums[j]
			}
		}
	}
}

type A struct {
	b *B
}

type B struct {
	c *C
}

type C struct {
}

func (a *A) func_a() {
	a.b.func_b()
}

func (b *B) func_b() {
	b.c.func_c()
}

func (c *C) func_c() {
	nums := generate(10000)
	bubbleSort(nums)
}

使用 pprof 分析一下运行情况

func main() {
    f, _ := os.OpenFile("cpu.pprof", os.O_CREATE|os.O_RDWR, 0644)
    defer f.Close()
    pprof.StartCPUProfile(f)
    defer pprof.StopCPUProfile()

    a := &A{
            b: &B{
                    c: &C{},
            },
    }
    a.func_a()

    time.Sleep(time.Second)
}

执行go run main.go，会生成一个cpu.pprof文件。这个文件记录了程序的运行状态。使用go tool pprof命令分析这个文件：

>> go tool pprof cpu.pprof            
File: pprof2
Type: cpu
Time: Sep 11, 2024 at 5:40pm (CST)
Duration: 202.37ms, Total samples = 70ms (34.59%)
Entering interactive mode (type "help" for commands, "o" for options)
(pprof) top
Showing nodes accounting for 70ms, 100% of 70ms total
      flat  flat%   sum%        cum   cum%
      70ms   100%   100%       70ms   100%  main.bubbleSort (inline)
         0     0%   100%       70ms   100%  main.(*A).func_a (inline)
         0     0%   100%       70ms   100%  main.(*B).func_b (inline)
         0     0%   100%       70ms   100%  main.(*C).func_c
         0     0%   100%       70ms   100%  main.main
         0     0%   100%       70ms   100%  runtime.main
(pprof) 

list 分析

上面用top命令查看耗时最高的 10 个函数。可以看到bubbleSort函数耗时最高，累计耗时 70ms，占了总耗时的 100%。我们也可以使用top 5和top 20分别查看耗时最高的 5 个 和 20 个函数。

当找到耗时较多的函数，我们还可以使用list命令查看该函数是怎么被调用的，各个调用路径上的耗时是怎样的。list命令后跟一个表示方法名的模式：

(pprof) list bubbleSort
Total: 50ms
ROUTINE ======================== main.bubbleSort in /Users/jasper/work/gitee/test-go/src/pprof/pprof2.go
      50ms       50ms (flat, cum)   100% of Total
         .          .     58:   return nums
         .          .     59:}
      10ms       10ms     60:func bubbleSort(nums []int) {
      40ms       40ms     61:   for i := 0; i < len(nums); i++ {
         .          .     62:           for j := 1; j < len(nums)-i; j++ {
         .          .     63:                   if nums[j] < nums[j-1] {
         .          .     64:                           nums[j], nums[j-1] = nums[j-1], nums[j]
         .          .     65:                   }
         .          .     66:           }
(pprof) %                                                

help 查看所有的命令

(pprof) help
  Commands:
    callgrind        Outputs a graph in callgrind format
    comments         Output all profile comments
    disasm           Output assembly listings annotated with samples
    dot              Outputs a graph in DOT format
    eog              Visualize graph through eog
    evince           Visualize graph through evince
    gif              Outputs a graph image in GIF format
    gv               Visualize graph through gv
    kcachegrind      Visualize report in KCachegrind
    list             Output annotated source for functions matching regexp
    pdf              Outputs a graph in PDF format
    peek             Output callers/callees of functions matching regexp
    png              Outputs a graph image in PNG format
    proto            Outputs the profile in compressed protobuf format
    ps               Outputs a graph in PS format
    raw              Outputs a text representation of the raw profile
    svg              Outputs a graph in SVG format
    tags             Outputs all tags in the profile
    text             Outputs top entries in text form
    top              Outputs top entries in text form
    topproto         Outputs top entries in compressed protobuf format
    traces           Outputs all profile samples in text form
    tree             Outputs a text rendering of call graph
    web              Visualize graph through web browser
    weblist          Display annotated source in a web browser
    o/options        List options and their current values
    q/quit/exit/^D   Exit pprof

  Options:
    call_tree        Create a context-sensitive call tree
    compact_labels   Show minimal headers
    divide_by        Ratio to divide all samples before visualization
    drop_negative    Ignore negative differences
    edgefraction     Hide edges below <f>*total
    focus            Restricts to samples going through a node matching regexp
    hide             Skips nodes matching regexp
    ignore           Skips paths going through any nodes matching regexp
    intel_syntax     Show assembly in Intel syntax
    mean             Average sample value over first value (count)
    nodecount        Max number of nodes to show
    nodefraction     Hide nodes below <f>*total
    noinlines        Ignore inlines.
    normalize        Scales profile based on the base profile.
    output           Output filename for file-based outputs
    prune_from       Drops any functions below the matched frame.
    relative_percentages Show percentages relative to focused subgraph
    sample_index     Sample value to report (0-based index or name)
    show             Only show nodes matching regexp
    show_from        Drops functions above the highest matched frame.
    source_path      Search path for source files
    tagfocus         Restricts to samples with tags in range or matched by regexp
    taghide          Skip tags matching this regexp
    tagignore        Discard samples with tags in range or matched by regexp
    tagleaf          Adds pseudo stack frames for labels key/value pairs at the callstack leaf.
    tagroot          Adds pseudo stack frames for labels key/value pairs at the callstack root.
    tagshow          Only consider tags matching this regexp
    trim             Honor nodefraction/edgefraction/nodecount defaults
    trim_path        Path to trim from source paths before search
    unit             Measurement units to display

  Option groups (only set one per group):
    granularity      
      functions        Aggregate at the function level.
      filefunctions    Aggregate at the function level.
      files            Aggregate at the file level.
      lines            Aggregate at the source code line level.
      addresses        Aggregate at the address level.
    sort             
      cum              Sort entries based on cumulative weight
      flat             Sort entries based on own weight
  :   Clear focus/ignore/hide/tagfocus/tagignore

  type "help <cmd|option>" for more information
(pprof) 

web 模式查看

在浏览器中分析CPU性能数据

go tool pprof -http=:8081 cpu.pprof

火焰图

Memory profiling

上面的CPU分析，内容换成字符串拼接

func (c *C) func_c() {
	concat(30000)
}

const letterBytes = "abcdefghijklmnopqrstuvwxyz"

func randomString(n int) string {
	b := make([]byte, n)
	for i := range b {
		b[i] = letterBytes[rand.Intn(len(letterBytes))]
	}
	return string(b)
}

func concat(n int) string {
    var s = ""
	for i := 0; i < n; i++ {
		s += randomString(100)
	}
	return s
}

func main() {
	f, _ := os.OpenFile("mem.pprof", os.O_CREATE|os.O_RDWR, 0644)
	defer f.Close()

	a := &A{
		b: &B{
			c: &C{},
		},
	}
	a.func_a()

	pprof.WriteHeapProfile(f)

	time.Sleep(time.Second)
}

分析

分析的过程，与上面的CPU部分类似

>> go tool pprof mem.pprof
File: pprof2
Type: inuse_space
Time: Sep 11, 2024 at 5:55pm (CST)
Entering interactive mode (type "help" for commands, "o" for options)
(pprof) top 
Showing nodes accounting for 674.18kB, 100% of 674.18kB total
      flat  flat%   sum%        cum   cum%
  674.18kB   100%   100%   674.18kB   100%  main.concat
         0     0%   100%   674.18kB   100%  main.(*A).func_a (inline)
         0     0%   100%   674.18kB   100%  main.(*B).func_b (inline)
         0     0%   100%   674.18kB   100%  main.(*C).func_c (inline)
         0     0%   100%   674.18kB   100%  main.main
         0     0%   100%   674.18kB   100%  runtime.main
(pprof) list concat
Total: 674.18kB
ROUTINE ======================== main.concat in /Users/jasper/work/gitee/test-go/src/pprof/pprof2.go
  674.18kB   674.18kB (flat, cum)   100% of Total
         .          .     46:func concat(n int) string {
         .          .     47:   var s = ""
         .          .     48:   for i := 0; i < n; i++ {
  674.18kB   674.18kB     49:           s += randomString(100)
         .          .     50:   }
         .          .     51:   return s
         .          .     52:}
         .          .     53:
         .          .     54:func generate(n int) []int {
(pprof) 

用+做字符串拼接是很耗内存的，各位可以试着用strings.Builder，然后观察内存占用的变化。

web 模式查看

在浏览器中分析CPU性能数据

go tool pprof -http=:8081 mem.pprof