Golang中文学习文档

性能分析

寒江蓑笠翁大约 26 分钟

性能分析

当一个程序编写完毕后，我们对它的要求不仅仅只是能运行，还希望它是一个稳定高效的应用。通过各种各样的测试，我们可以保证程序大部分的稳定性，而程序是否高效，就需要我们对其进行性能分析，在此前的内容中，性能分析的唯一手段就只能通过Benchmark来测试某一个功能单元的平均执行耗时，内存分配情况等，然而现实中对程序性能分析的需求远远不止于此，有时候我们需要分析程序整体的CPU占用，内存占用，堆分配情况，协程状态，热点代码路径等等，这是Benchmark所不能满足的。好在go工具链集成了许多性能分析工具以供开发者使用，下面就来逐一讲解。

逃逸分析

在go中，变量的内存分配是由编译器决定的，一般就分配到栈上和堆上这两个地方。如果一个本该分配到栈上的变量被分配到了堆上，那么这种情况就称之为逃逸，逃逸分析便是要分析程序中的内存分配情况，由于它是在编译期进行，所以是静态分析的一种。

提示

前往内存分配文章了解go具体是如分配内存的。

引用局部指针

package main

func main() {
	GetPerson()
}

type Person struct {
	Name string
	Mom  *Person
}

func GetPerson() Person {
	mom := Person{Name: "lili"}
	son := Person{Name: "jack", Mom: &mom}
	return son
}

GetPerson函数中创建了mom变量，由于它是函数内创建的，本来应该是将其分配到栈上，但是它被son的Mom字段所引用了，并且son被作为了函数返回值返回出去，所以编译器就将其分配到了堆上。这是一个很简单的示例，所以理解起来不需要花费太多力气，但如果是一个大点的项目，代码行数有好几万，人工分析就不是那么的轻松了，为此就需要使用工具来进行逃逸分析。前面提到过内存的分配是由编译器主导的，所以逃逸分析也是由编译器来完成，使用起来十分简单，只需要执行如下命令：

$ go build -gcflags="-m -m -l"

gcflags即编译器gc的参数，

  • -m，打印出代码优化建议，同时出现两个会更加进行细节的输出
  • -l，禁用内联优化

输出如下

$ go build -gcflags="-m -m -l" .
# golearn/example
./main.go:13:2: mom escapes to heap:
./main.go:13:2:   flow: son = &mom:
./main.go:13:2:     from &mom (address-of) at ./main.go:14:35
./main.go:13:2:     from Person{...} (struct literal element) at ./main.go:14:15
./main.go:13:2:     from son := Person{...} (assign) at ./main.go:14:6
./main.go:13:2:   flow: ~r0 = son:
./main.go:13:2:     from return son (return) at ./main.go:15:2
./main.go:13:2: moved to heap: mom

编译器很明确的告诉了我们变量mom发生了逃逸，导致原因是因为返回值包含了函数内的局部指针，除了这种情况外还有其它情况可能会发生逃逸现象

::: tips

如果你对逃逸分析的细节感兴趣，可以在标准库cmd/compile/internal/escape/escape.go里面了解到更多内容。

:::

闭包引用

闭包引用了函数外的变量，那么该变量也会逃逸到堆上，这个很好理解。

package main

func main() {
	a := make([]string, 0)
	do(func() []string {
		return a
	})
}

func do(f func() []string) []string {
	return f()
}

输出

$ go build -gcflags="-m -m -l" .
# golearn/example
./main.go:10:9: f does not escape
./main.go:4:2: main capturing by value: a (addr=false assign=false width=24)
./main.go:4:11: make([]string, 0) escapes to heap:
./main.go:4:11:   flow: a = &{storage for make([]string, 0)}:
./main.go:4:11:     from make([]string, 0) (spill) at ./main.go:4:11
./main.go:4:11:     from a := make([]string, 0) (assign) at ./main.go:4:4
./main.go:4:11:   flow: ~r0 = a:
./main.go:4:11:     from return a (return) at ./main.go:6:3
./main.go:4:11: make([]string, 0) escapes to heap
./main.go:5:5: func literal does not escape

空间不足

栈空间不足时，也会发生逃逸现象，下面创建的切片申请了1<<15的容量

package main

func main() {
	_ = make([]int, 0, 1<<15)
}

输出

$ go build -gcflags="-m -m -l" .
# golearn/example
./main.go:4:10: make([]int, 0, 32768) escapes to heap:
./main.go:4:10:   flow: {heap} = &{storage for make([]int, 0, 32768)}:
./main.go:4:10:     from make([]int, 0, 32768) (too large for stack) at ./main.go:4:10
./main.go:4:10: make([]int, 0, 32768) escapes to heap

长度未知

当切片的长度是一个变量的时候，由于其长度未知，便会发生逃逸现象（map并不会）

package main

func main() {
	n := 100
	_ = make([]int, n)
}

输出

$ go build -gcflags="-m -m -l" .
# golearn/example
./main.go:5:10: make([]int, n) escapes to heap:
./main.go:5:10:   flow: {heap} = &{storage for make([]int, n)}:
./main.go:5:10:     from make([]int, n) (non-constant size) at ./main.go:5:10
./main.go:5:10: make([]int, n) escapes to heap

还有一种特殊情况便是函数参数为...any类型时也可能会发生逃逸

package main

import "fmt"

func main() {
	n := 100
	fmt.Println(n)
}

输出

$ go build -gcflags="-m -m -l" .
# golearn/example
./main.go:7:14: n escapes to heap:
./main.go:7:14:   flow: {storage for ... argument} = &{storage for n}:
./main.go:7:14:     from n (spill) at ./main.go:7:14
./main.go:7:14:     from ... argument (slice-literal-element) at ./main.go:7:13
./main.go:7:14:   flow: {heap} = {storage for ... argument}:
./main.go:7:14:     from ... argument (spill) at ./main.go:7:13
./main.go:7:14:     from fmt.Println(... argument...) (call parameter) at ./main.go:7:13
./main.go:7:13: ... argument does not escape
./main.go:7:14: n escapes to heap

我们之所以要进行逃逸分析，把内存分配控制的这么细，主要是为了减轻GC压力，不过go并不是c语言，内存分配的最终决定权依旧掌握在编译器手里，除了极端的性能要求情况下，大多数时候我们也无需太过于专注内存分配的细节，毕竟GC诞生的目的就是为了解放开发者。

小细节

对于一些引用类型，当确认以后不会再用到它时，我们可以将其置为nil，来告诉GC可以将其回收。

type Writer struct {
	buf []byte
}

func (w Writer) Close() error {
	w.buff = nil
	return nil
}

pprof

pprof（program profiling），是一个程序性能分析的利器，它会对程序运行时的数据进行部分采样，涵盖了cpu，内存，协程，锁，堆栈信息等许多方面，然后再使用工具对采样的数据进行分析并展示结果。

所以pprof的使用步骤就只有两步：

  1. 采集数据
  2. 分析结果

采集

数据采集的方式有两种，自动和手动，各有优劣。在此之前，编写一个简单的函数来模拟内存和cpu的消耗

func Do() {
	for i := 0; i < 10; i++ {
		slice := makeSlice()
		sortSlice(slice)
	}
}

func makeSlice() []int {
	var s []int
	for range 1 << 24 {
		s = append(s, rand.Int())
	}
	return s
}

func sortSlice(s []int) {
	slices.Sort(s)
}

手动

手动采集就是通过代码来控制，其优点是可控，灵活，可以自定义，直接在代码中使用pprof需要引入runtime/pprof包

package main

import (
	"log"
	"os"
	"runtime/pprof"
)

func main() {
    Do()
	w, _ := os.Create("heap.pb")
	heapProfile := pprof.Lookup("heap")
	err := heapProfile.WriteTo(w, 0)
	if err != nil {
		log.Fatal(err)
	}
}

pprof.Lookup支持的参数如下面代码所示

profiles.m = map[string]*Profile{
    "goroutine":    goroutineProfile,
    "threadcreate": threadcreateProfile,
    "heap":         heapProfile,
    "allocs":       allocsProfile,
    "block":        blockProfile,
    "mutex":        mutexProfile,
}

该函数会将采集到的数据写入到指定文件中，在写入时传入的数字有以下几个含义

  • 0，写入压缩后的Protobuf数据，没有可读性
  • 1，写入文本格式的数据，能够阅读，http接口返回的就是这一种数据
  • 2，仅goroutine可用，表示打印panic风格的堆栈信息

采集cpu数据需要单独使用 pprof.StartCPUProfile函数，它需要一定的时间进行采样，且其原始数据不可读，如下所示

package main

import (
	"log"
	"os"
	"runtime/pprof"
	"time"
)

func main() {
    Do()
	w, _ := os.Create("cpu.out")
	err := pprof.StartCPUProfile(w)
	if err != nil {
		log.Fatal(err)
	}
	time.Sleep(time.Second * 10)
	pprof.StopCPUProfile()
}

采集trace的数据也是同样如此

package main

import (
	"log"
	"os"
	"runtime/trace"
	"time"
)

func main() {
    Do()
	w, _ := os.Create("trace.out")
	err := trace.Start(w)
	if err != nil {
		log.Fatal(err)
	}
	time.Sleep(time.Second * 10)
	trace.Stop()
}

自动

net/http/pprof包将上面的分析函数包装成了http接口，并注册到了默认路由中，如下所示

package pprof

import ...

func init() {
    http.HandleFunc("/debug/pprof/", Index)
    http.HandleFunc("/debug/pprof/cmdline", Cmdline)
    http.HandleFunc("/debug/pprof/profile", Profile)
    http.HandleFunc("/debug/pprof/symbol", Symbol)
    http.HandleFunc("/debug/pprof/trace", Trace)
}

这使得我们可以直接一键运行pprof数据采集

package main

import (
	"net/http"
    // 记得要导入这个包
	_ "net/http/pprof"
)

func main() {
    go func(){
        http.ListenAndServe(":8080", nil)
    }
    for {
        Do()
    }
}

此时打开浏览器访问http://127.0.0.1:8080/debug/pprof，就会出现这样的页面

页面中有几个可供选择的选项，它们分别代表了

  • allocs：内存分配抽样
  • block：同步原语的阻塞跟踪
  • cmdline：当前程序的命令行调用
  • goroutine：跟踪所有的协程
  • heap：对于存活对象的内存分配抽样
  • mutex：互斥锁相关信息的跟踪
  • profile：cpu分析，会分析一段时间并下载一个文件
  • threadcreate：分析导致创建新OS线程原因
  • trace：当前程序执行情况的跟踪，同样会下载一个文件

这里的数据大多数可读性并不高，主要是拿来给工具分析用的，如下所图

具体的分析工作要留到后面再进行，除了profile和trace两个选项之外，如果你想要在网页中下载数据文件，可以将query参数debug=1去掉。也可以将这些接口集成到自己的路由中而不是使用默认路由，如下所示

package main

import (
	"net/http"
	"net/http/pprof"
)

func main() {
	mux := http.NewServeMux()
	mux.HandleFunc("/trace", pprof.Trace)
	servre := &http.Server{
		Addr:    ":8080",
		Handler: mux,
	}
	servre.ListenAndServe()
}

如此一来，也能其集成到其它的web框架中，比如gin，iris等等。

分析

在得到了采集的数据文件后，有两种方式进行分析，命令行或网页，两者都需要借助pprof命令行工具，go默认集成该工具，所以不需要额外下载。

pprof开源地址：google/pprof: pprof is a tool for visualization and analysis of profiling data (github.com)open in new window

命令行

将此前收集到的数据文件作为参数

$ go tool pprof heap.pb

如果数据是由web采集的话，用web url替换掉文件名即可。

$ go tool pprof -http :8080 http://127.0.0.1/debug/pprof/heap

然后就会出现一个交互式的命令行

15:27:38.3266862 +0800 CST
Type: inuse_space
Time: Apr 15, 2024 at 3:27pm (CST)
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)

输入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
	...

在命令行中查看数据一般使用top命令，也可以用traces命令不过它的输出很冗长，top命令只是简单的看个大概。

(pprof) top 5
Showing nodes accounting for 117.49MB, 100% of 117.49MB total
      flat  flat%   sum%        cum   cum%
  117.49MB   100%   100%   117.49MB   100%  main.makeSlice (inline)
         0     0%   100%   117.49MB   100%  main.Do
         0     0%   100%   117.49MB   100%  main.main
         0     0%   100%   117.49MB   100%  runtime.main

简单介绍一些其中的一些指标（cpu同理）

  • flat，代表着当前函数所消耗的资源
  • cum，当前函数及其后续调用链所消耗的资源总和
  • flat%，flat/total
  • cum%，cum/total

我们可以很明显的看到整个调用栈的内存占用是117.49MB，由于Do函数本身什么都没做，只是调用了其它函数，所以其flat的指标是0，创建切片的事情是由makeSlice函数在负责，所以其flat指标是100%。

我们可以将转换可视化的格式，pprof支持相当多的格式，比如pdf，svg，png，gif等等（需要安装Graphvizopen in new window）。

(pprof) png
Generating report in profile001.png

通过图片我们可以更加清晰的看到整个调用栈的内存情况。

通过list命令以源代码的形式查看

(pprof) list Do
Total: 117.49MB
ROUTINE ======================== main.Do in D:\WorkSpace\Code\GoLeran\golearn\example\main.go
         0   117.49MB (flat, cum)   100% of Total
         .          .     21:func Do() {
         .          .     22:   for i := 0; i < 10; i++ {
         .   117.49MB     23:           slice := makeSlice()
         .          .     24:           sortSlice(slice)
         .          .     25:   }
         .          .     26:}
         .          .     27:
         .          .     28:func makeSlice() []int {

对于图片和源代码而言，还可以用web和weblist命令在浏览器中查看图片和源代码。

网页

在此之前为了数据更加多样化，修改一下模拟的函数

func Do1() {
	for i := 0; i < 10; i++ {
		slice := makeSlice()
		sortSlice(slice)
	}
}

func Do2() {
	for i := 0; i < 10; i++ {
		slice := makeSlice()
		sortSlice(slice)
	}
}

func makeSlice() []int {
	var s []int
	for range 1 << 12 {
		s = append(s, rand.Int())
	}
	return s
}

func sortSlice(s []int) {
	slices.Sort(s)
}

网页分析可以可视化结果，免去了我们手动操作命令行，在使用网页分析时，只需执行如下命令

$ go tool pprof -http :8080 heap.pb

如果数据是由web采集的话，将web url替换掉文件名即可

$ go tool pprof -http :8080 http://127.0.0.1:9090/debug/pprof/heap
$ go tool pprof -http :8080 http://127.0.0.1:9090/debug/pprof/profile
$ go tool pprof -http :8080 http://127.0.0.1:9090/debug/pprof/goroutine

提示

关于如何分析数据，前往pprof: How to read the graphopen in new window了解更多

网页中总共有6个可查看的项

  • Top，同命令top
  • Graph，直线图
  • Flame Graph，火焰图
  • Peek，
  • Source，查看源代码
  • Disassemble，反汇编查看

对于内存而言四个维度可以分析

  • alloc_objects：目前已分配的所有对象数量，包括已释放
  • alloc_spcae：目前为止已分配的所有内存空间，包括已释放
  • inuse_objects：正在使用的对象数量
  • inuse_space：正在使用的内存空间
内存分析图
内存分析图

上图最下方的白色叶子节点代表着不同大小的对象占用。

cpu分析图
cpu分析图

关于折线图，有几个点要注意

  • 块的颜色越深，占用越高，线越粗，占用越高
  • 实线代表着直接调用，虚线代表着略过了一些调用链。
内存火焰图
内存火焰图
cpu火焰图
cpu火焰图

对于火焰图而言，从上往下看是调用链，从左往右看是cum的占用百分比。

trace

pprof主要负责分析程序的资源占用，而trace更适合跟踪程序的运行细节，它与前者的数据文件互不兼容，由go tool trace命令来完成相关的分析工作。

如果是手动采集的数据，可以将文件名作为参数

$ go tool trace trace.out

如果是自动采集，也是同样的道理

$ curl http://127.0.0.1:8080/debug/pprof/trace > trace.out && go tool trace trace.out

执行后会开启一个web server

2024/04/15 17:15:40 Preparing trace for viewer...
2024/04/15 17:15:40 Splitting trace for viewer...
2024/04/15 17:15:40 Opening browser. Trace viewer is listening on http://127.0.0.1:51805

打开后页面大概如下所示

这里面主要包含了以下几个部分，这些数据要看懂还挺不容易的。

  • Event timelines for running goroutines

    • trace by proc：显示每一时刻在该处理器上运行的协程时间线

    • trace by thread：显示每一时刻在OS线程上运行的协程时间线

    • Goroutine analysis：展示每组主函数的协程相关统计信息

  • Profiles

    • Network blocking profile： 因网络IO而阻塞的协程信息
    • Synchronization blocking profile：因同步原语而阻塞的协程信息
    • Syscall profile：因系统调用而阻塞的协程信息

  • User-defined tasks and regions

    • User-defined tasks：用户定义任务的相关协程信息
    • User-defined regions：用户定义代码区域的相关协程信息

  • Garbage collection metrics

    • Minimum mutator utilization：展示最近GC的最大耗时