• 性能分析,有哪些工具可以用?
  • 概要文件的采样、收集和输出是怎样的,包括怎样启动和停止采样、怎样设定采样频率以及怎样控制输出内容的格式和详细程度?
  • 每一种概要信息代表了什么,包含什么样的内容?
  • runtime/pprof.Lookup 函数的正确调用方式是什么?
  • 通过这些怎么检查程序瓶颈?
  • 怎么为基于 HTTP 协议的网络服务添加性能分析接口?
  • runtime/trace 代码包的功用是什么?

Go 程序性能分析基础

接口和工具

API

Go 语言为程序开发者们提供了丰富的性能分析 API 以及非常好用的标准工具。这些 API 主要存在于一下三个代码包中:

  • runtime/pprof
  • net/http/pprof (常用)
  • runtime/trace (还没接触)

另外,runtime 代码包中还包含了一些更底层的 API。它们可以被用来收集或输出 Go 程序运行过程中的一些关键指标,并帮助我们生成相应的概要文件以供后续分析使用。

Tools

标准工具主要有:

  • go tool pprof(常用)
  • go tool trace(还没接触)

它们可以解析概要文件中的信息,并以人类易读的方式把这些信息展示出来。

此外,go test 命令也可以在程序测试完成后生成概要文件。

概要文件

在 Go 语言中,用于分析程序性能的概要文件有三种:CPU 概要文件(CPU Profile)内存概要文件(Mem Profile)阻塞概要文件(Block Profile)

这些概要文件中包含的是:在某一段时间内,对 Go 程序的相关指标进行多次采样后得到的概要信息。

  • CPU 概要文件来说,其中的每一段独立的概要信息都记录着,在进行某一次采样的那个时刻,CPU 上正在执行的 Go 代码。

  • 内存概要文件来说,其中的每一段概要信息都记载着,在某个采样时刻,正在执行的 Go 代码以及堆内存的使用情况,这里包含已分配和已释放的字节数量和对象数量

  • 阻塞概要文件来说,其中的每一段概要信息,都代表着 Go 程序中的一个 goroutine 阻塞事件。

Note: 在默认情况下,这些概要文件中的信息并不是普通的文件,它们都是以二进制的形式展现的。如果你使用一个常规的文件编辑器查看它们的话,那么肯定会看到一堆 乱码

查看这些概要文件包含的信息,就需要使用 go tool pprof 这个工具了。我们可以通过它进入一个基于命令行的交互式界面,并对指定的概要文件进行查询。就像下面这样:

1
2
3
4
5
6
$ go tool pprof cpuprofile.out
Type: cpu
Time: Nov 9, 2018 at 4:31pm (CST)
Duration: 7.96s, Total samples = 6.88s (86.38%)
Entering interactive mode (type "help" for commands, "o" for options)
(pprof) 

关于这个工具的具体用法:在交互式界面输入 help + Enter

性能分析数据的采样工作

前面提到了,要分析程序的相关性能指标,如 CPU、Mem、Block 等,就要从与其对应得概要文件入手进行分析,那么这些概要文件数据是怎么得来的呢? 概要文件不是普通的文件,它又是如何生成的呢? 来,让我们继续往下看

Go 程序的概要文件时通过 protocol buffers 生成的二进制数据流,或者说字节流。

概括来讲,protocol buffers 是一种数据序列化协议,同时也是一个序列化工具。它可以把一个值,比如一个结构体或者一个字典,转换成一段字节流。 换句话说,protocol buffers 定义和实现了一种“可以让数据在结构形态和扁平形态之间互相转换”的方式。

首先来看看第一个问题吧!

怎样让程序对 CPU 概要信息进行采样?

对这个问题的典型回答:

这需要用到 runtime/pprof 包中的 API。更具体地说,在我们想让程序开始对 CPU 概要信息进行采样的时候,需要调用这个代码包中的 StartCPUProfile 函数,而在停止采样的时候则需要调用该包中的 StopCPUProfile 函数。

问题解析

runtime/pprof.StartCPUProfile 函数(以下简称 StartCPUProfile 函数)在被调用的时候,先会去设定 CPU 概要信息的 采样频率,并会在单独的 goroutine 中进行 CPU 概要信息的收集和输出。

Note: StartCPUProfile 函数设定的采样频率总是固定的,即 100 赫兹。也就是说,每 s 采样 100 次,或者说每 10ms 采样一次。

扩展知识:

赫兹,也称 Hz,是从英文单词“Hertz”(一个英文姓氏)音译过来的一个中文词。它是 CPU 主频的基本单位。

CPU 主频指的是,CPU 内核工作的时钟频率,也常被称为 CPU clock speed。这个时钟频率的倒数即为时钟周期(clock cycle),也就是一个 CPU 内核执行一条运算指令所需的时间,单位是秒。

StartCPUProfile 函数设定的 CPU 概要信息采样频率,相对于现代的 CPU 主频来说是非常低的。这主要有两个方面的原因:

  • 其一:

    过高的采样频率会对 Go 程序的运行效率造成很明显的负面影响。因此,runtime 包中 SetCPUProfileRate 函数在被调用的时候,会保证采样频率不超过 1MHz(兆赫),也就是说它只允许美 1 微秒最多采样一次。StartCPUProfile 函数正是通过调用这个函数来设定 CPU 概要信息的采样频率的。

  • 其二

    经过大量的实验,Go 语言团队发现 100 Hz 是一个比较合适的设定。因为这样做既可以得到足够多、足够有用的概要信息,又不至于让程序的运行出现停滞。另外,操作系统对高频采样的处理能力也是有限的,一般情况下,超过 500 Hz 就很可能得不到及时的响应了。

    在 StartCPUProfile 函数执行后,一个新启用的 goroutine 将会负责执行 CPU 概要信息的收集和输出,直到 runtime/pprof 包中的 StopCPUProfile 函数被成功调用。

    StopCPUProfile 函数也会调用 runtime.SetCPUProfileRate 函数,并把参数值(也就是采样频率) 设为0。这会让针对 CPU 概要信息的采样工作停止。同时,它也会给负责收集 CPU 概要信息的代码一个 信号,以告知收集工作也需要停止了。

    在接收到这样的信号之后,那部分程序将会把这段时间内收集到的所有 CPU 概要信息,全部写入到我们在调用 StartCPUProfile 函数的时候指定的写入器中。只有在上述操作全部完成之后,StopCPUProfile 函数才会返回。

怎样设定内存概要信息的采样频率?

针对内存概要信息的采样会按照一定比例收集 Go 程序在运行期间的堆内存使用情况。设定内存概要信息采样频率的方法很简单,只要为 runtime.MemProfileRate 变量赋值即可。

这个变量的含义是:平均每分配多少个字节,就对堆内存的使用情况进行一次采样。如果把该变量的值设为 0, Go 语言运行时系统就会完全停止对内存概要信息的采样。该变量的缺省值是 512 KB

Note: 注意,如果你要设定这个采样频率,那么越早设定越好,并且只应该设定一次,否则就可能会对 Go 语言运行时系统的采样工作,造成不良影响。比如,只在 main 函数的开始出设定一次。

在这之后,当我们想获取内存概要信息的时候,还需要调用 runtime/pprof 包中的 WriteHeapProfile 函数。该函数会把收集好的内存概要信息,写入到我们指定的写入器中。

Note: 我们通过 WriteHeapProfile 函数得到的内存概要信息并不是实时的,它是一个快照,是在最近一次的内存垃圾收集工作完成时产生的。如果你想要实时的信息,那么可以调用 runtime.ReadMemStats 函数。不过要特别注意,该函数会引起 Go 语言的短暂停顿。

怎样获取到阻塞概要信息?

我们调用 runtime 包中的 SetBlockProfileRate 函数,即可对阻塞概要信息的采样频率进行设定。该函数有一个名叫 rate 的参数,它是 int 类型的。

这个参数的含义是,只要发现一个阻塞时间的持续时间达到了多少个纳秒,就可以对其进行采样。如果这个参数的值小于或等于0,那么久意味着 Go 语言运行时系统将会完全停止对阻塞概要信息的采样。

runtime 包中,还有一个名叫 blockprofilerate 的包级私有变量,它是 uint64 类型的。这个变量的含义是,只要发现一个阻塞事件的持续时间跨越了多少个 CPU 时钟周期,就可以对其进行采样。 (与 rate 参数很相似,其区别仅仅在于单位不同)

另一方面,当我们需要获取阻塞概要信息的时候,需要先调用 runtime/pprof 包中的 Lookup 函数并传入参数值 block,从而得到一个 *runtime/pprof.Profile 类型的值(以下简称 Profile 值)。在这之后,我们还需要调用这个 Profile 值得 WriteTo 方法,以驱使它把概要信息写进我们指定的写入器中。

这个 WriteTo 方法有两个参数,一个参数就是我们刚刚提到的写入器,它是 io.Writer 类型的。而另一个参数则代表了概要信息详细程度的 int 类型参数 debug.

debug 参数主要的可选值有两个,即 01

  • 当 debug 为 0 时,通过 WriteTo 方法写进写入器的概要信息仅会包含 go tool pprof 工具所需的内存地址,这些内存地址会以十六进制的形式展现出来。

  • 当 debug 为 1 时,相应的包名、函数名、源码文件路径、代码行号等信息就都会作为注释被加入进去。另外,debug 为 0 时的概要信息,会经由 protocol buffers 转换为字节流。而在 debug 为 1 的时候,WriteTo 方法输出的这些概要信息就是我们可以读懂的普通文本了。

  • 除此之外,debug的值也可以是2。这时,被输出的概要信息也会是普通的文本,并且通常会包含更多的细节。至于这些细节都包含哪些内容,那就要看我们调用 runtime/pprof.Lookup 函数的时候传入的是什么样的参数值了。

runtime/pprof.Lookup 函数的正确调用方式是什么?

runtime/pprof.Lookup 函数的功能是:提供与给定名称相对应的概要信息。这个概要信息会由一个 Profile 值代表。如果该函数返回了一个 nil,那么久说明不存在与给定名称相对应的概要信息。

runtime/pprof 包已经为我们预定义了 6 个概要名称。它们对应的概要信息收集方法和输出方法也都已经准备好了。我们可以直接拿来使用:goroutine、heap、allocs、treadcreate、block 和 mutex

  • 当我们把 goroutine 传入 Lookup 函数的时候,该函数会利用相应的方法,收集到当前正在使用的所有 goroutine 的堆栈跟踪信息。注意,这样的收集会引起 Go 语言调度器的短暂停顿。

    • 当调用该函数返回的 Profile 值得 WriteTo 方法时,如果参数 debug 的值大于或等于 2,那么该方法就会输出所有 goroutine 的堆栈跟踪信息。这些信息可能会非常多。如果它们占用的空间超过了 64 MB (也就是64兆字节),那么相应的方法就会将超出的部分截掉。
  • 如果 Lookup 函数接到的参数值是 heap,那么它就会收集与堆内存的分配和释放有关的采样信息。这实际上就是我们在前面讨论过的内存概要信息。在我们传入 “allocs” 的时候,后续的操作会与之非常的相似。

    • 在这两种情况下,Lookup 函数返回的 Profile 函数值也会及其相像。只不过,在这两种 Profile 值得 WriteTo 方法被调用时,他们输出的概要信息会有细微的差别,而且这仅仅体现在参数 debug 等于 0 的时候

    • heap 会使得被输出的内存概要信息默认以 在用空间(inuse_space) 的视角呈现,而 allocs 对应的默认视角则是 已分配空间(alloc_space)

      • 在用空间(inuse_space):指已经分配但还未被释放的内存空间。go tool pprof 工具并不会去理会与已释放空间有关的那部分信息。而在“已分配空间”的视角下,所有的内存分配信息都会被展现出来,无论这些内存空间在采样时是否已被释放。
  • 参数值 threadcreate 会使Lookup函数去收集一些堆栈跟踪信息。这些堆栈跟踪信息中的每一个都会描绘出一个代码调用链,这些调用链上的代码都导致新的操作系统线程产生。这样的Profile值的输出规格也只有两种,取决于我们传给其WriteTo方法的参数值是否大于0。

    • 再说 blockmutexblock 代表的是,因争用同步原语而被阻塞的那些代码的堆栈跟踪信息。mutex 代表的是,曾经作为同步原语持有者的那些代码,它们的堆栈跟踪信息。它们的输出规格也都只有两种,取决于debug是否大于0。

这里所说的同步原语,指的是存在于 Go 语言运行时系统内部的的一种底层的同步工具,或者说一种同步机制。

它是直接面向内存地址的,并以异步信号量和原子操作作为实现手段。我们已经熟知的通道、互斥锁、条件变量、”WaitGroup“,以及 Go 语言运行时系统本身,都会利用它来实现自己的功能。

如何为基于 HTTP 协议的网络服务添加性能分析接口?

添加方式如下:

先在程序中导入 net/http/pprof 代码包,就像这样:

1
import _ "net/http/pprof"

然后,启动网络服务并开始监听,比如:

1
log.Println(http.ListenAndServer("localhost:8082", nil))

在运行这个程序之后,我们就可以通过在网络浏览器中访问 http://localhost:8082/debug/pprof 这个地址看到一个简约的网页。

Note:

  • /debug/pprof/heap 路径下,可以接收一个名叫 gc 的查询参数,它用于控制是否在获取概要信息之前强制执行一次垃圾回收,只要它的值大于 0,程序就会这样做。

  • /debug/pprof/profile 路径下,可以接收一个名为 seconds 的查询参数。该参数的含义是,采样工作需要持续多少秒。默认(缺省) 30s。 例如:go tool pprof http://localhost:6060/debug/pprof/profile?seconds=60

  • /debug/pprof/trace 被访问时,程序主要会利用 runtime/trace 代码包中的 API 来处理我们的请求

    • 更具体地说,程序会先调用 trace.Start 函数,然后再查询参数 seconds 指定的持续时间之后再调用 trace.Stop 函数。这里的 seconds 的缺省值是 1s

定制路由:

 1
 2
 3
 4
 5
 6
 7
 8
 9
10
11
12
13
14
15
16
17
18
19
20
mux := http.NewServeMux()
pathPrefix := "/d/pprof/"
mux.HandleFunc(pathPrefix,
	func(w http.ResponseWriter, r *http.Request) {
		name := strings.TrimPrefix(r.URL.Path, pathPrefix)
		if name != "" {
			pprof.Handler(name).ServeHTTP(w, r)
			return
		}
		pprof.Index(w, r)
	})
mux.HandleFunc(pathPrefix+"cmdline", pprof.Cmdline)
mux.HandleFunc(pathPrefix+"profile", pprof.Profile)
mux.HandleFunc(pathPrefix+"symbol", pprof.Symbol)
mux.HandleFunc(pathPrefix+"trace", pprof.Trace)

server := http.Server{
	Addr:    "localhost:8083",
	Handler: mux,
}

扩展问题

问题:runtime/trace 代码包的功用是什么?

Package trace contains facilities(实施) for programs to generate traces for the Go execution tracer(执行追踪器).

总结

Go 语言的运行时系统会根据要求对程序的相关指标进行多次采样,并对采样的结果进行组织和整理,最后形成一份完整的性能分析报告。 而我们需要理解以 采样收集输出 为代表的一系列操作步骤,以及每一种概要信息都代表了什么,它们分别都包含了什么样的内容。

Click Here for Demo Code

See Also

Thanks to the authors 🙂