Golang性能分析调优工具pprof和trace

简介：在开发Golang程序的过程中，go pprof可以对我们编写的算法甚至整个应用程序进行性能分析，帮助我们快速将效率低或资源低的问题解决掉。定位消费 很多地方。 Go提供了pprof和trace工具。本文分别介绍这两个工具的简要使用方法。希望你能够快速理解并快速开始Go性能调优。

作者 |谢久阳（昕希）

来源 |凌云时刻（微信ID：linuxpk）

我们先来演练一下

在介绍枯燥的基础知识之前，我们先来看看。一个简单的例子，这个例子很简单，通过pprof可以快速定位协程阻塞问题。？

go tool pprof xxx/goroutine-test http://localhost:8080/debug/pprof/goroutine

两条结果默认保存在$home/pprof目录下（如果PPROF_TMPDIRPPROFPPROF$home/pprof 变量设置输入变量并且环境设置好了）在）-base参数中找到profile文件来比较两个profile文件是否增长，使用如下命令：

go tool pprof -base xxx/goroutine-test xxxx001.pb.gz xxxx002.pb.gz

并使用top命令来简单查看

Entering interactive mode (type "help" for commands, "o" for options)
(pprof) top
Showing nodes accounting for 640,  of 643 total
Dropped 8 nodes (cum <= 3)flat  flat%   sum%        cum   cum%640          640   runtime.gopark0     0%         641 99.69%  0     0%         641 99.69%  runtime.chansend0     0%         641 99.69%  runtime.chansend10     0%         641 99.69%  runtime.goparkunlock
(pprof)

从上面的内容可以看到，第二次记录在profile文件中的goroutines数量相比第一次增加了640（持平），持平%的占用率意味着这里基本有协程被阻塞

使用跟踪查看所有配置文件统计信息，包括堆栈的一些内容

(pprof) traces
Type: goroutine
Time: May 6, 2020 at 9:53am (CST)
-----------+-------------------------------------------------------641   runtime.goparkruntime.goparkunlockruntime.chansendruntime.chansend1
-----------+-------------------------------------------------------1   net/http.(*connReader).backgroundRead
-----------+--------------------------------------------------------1   runtime.goparkruntime.netpollblockinternal/poll.runtime_pollWaitinternal/poll.(*pollDesc).waitinternal/poll.(*pollDesc).waitReadinternal/poll.(*FD).Readnet.(*netFD).Readnet.(*conn).Readnet/http.(*connReader).backgroundRead
-----------+-------------------------------------------------------

在第一行中，查看 641 runtime.gopark ，然后调用 您查看该调用堆栈 是

使用list命令看

(pprof) list 
Total: 643
ROUTINE ========================  in /Users/xinxi/Desktop/test/main-goroutine.go0        641 (flat, cum) 99.69% of Total.          .     32:}.          .     33:.          .     34:func ch1(ch chan<- int) {.          .     35:   go func() {.          .     36:       defer fmt.Println("ch1 stop").        641     37:       ch <- 0.          .     38:   }().          .     39:}

在上面的代码片段中，你可以很快找到将数字0写入ch的过程中的37行代码，这导致了很多阻塞。目前，已经增加到641个goroutine。被屏蔽了

那你可以调查一下为什么ch这个频道被屏蔽了？这是因为bool变量flag没有赋值，一直为false，所以通道ch没有被读取，所以37行代码一直阻塞。这个程序比较简单，但是实际的产品代码要复杂得多，所以如果你在找问题的话，你不会一眼就能找到问题所在。你还需要多练习，多收集。接下来我会介绍一些枯燥的基础知识，所以注意啦~

pprof 提供了三种使用


Benchmark 编写的包的方法，你可以使用 benchmark 测试和 pprof 来检查是否算法是否高效以及内存使用是否合理。

调用基准测试时，将-cpuprofile和-memprofile

❝分别与CPU参数进行匹配。您也可以同时使用两者。在这两个参数中，必须添加profiling文件的保存路径，如：

# 获取cpu的profiling文件
go test -bench=. -benchmem -cpuprofile profile.out
# 获取heap的profiling文件
go test -bench=. -benchmem -memprofile memprofile.out
# 获取cpu以及heap的profiling文件
go test -bench=. -benchmem -memprofile memprofile.out -cpuprofile profile.out

生成的profiling文件可以通过go工具 pprof直接访问结果数据。稍后我们将通过Web和控制台详细介绍如何使用该工具。

单独程序调用

必须输入的包：

import _ "runtime/pprof"

cpu 日期记录：

// file 是  结构，用来创建 pprof 要写入的文件
// 开始写入 cpu 的分析信息
(file)// 必须要添加这个，将所有信息在结束前都写入到文件中
defer pprof.StopCPUProfile()

堆日期记录： 和 是依赖于定义文件的），直接查看结果通过 go 工具 pprof 命令获取数据。稍后我们将通过Web和控制台详细介绍如何读取和使用数据。

webserver

如果我们想要分析一个服务，例如http或grpc服务器，那么使用webserver更合适。对外开放一个Web服务器，通过指定端口访问pprof数据

需要导入的包：

_ "net/http/pprof"

需要在main函数中添加以下内容：

func main() {go func() {if err := ("", nil); err != nil {("%v", err)}}()...
}

该方法可以请求以下信息：

• Profile：显示激活的 goroutine 所花费的 CPU 时间
• Heap：注册内存分配信息
• threadcreate：注册程序创建系统线程当前堆栈的一部分
• block：显示 grooutins 被阻塞和等待时的信息（敲板！此块默认关闭，必须使用打开）
• 互斥体：显示块内容。如果由于互斥锁争用，无法充分使用CPU的时候可以尝试使用它（敲板！这个互斥锁默认也是禁用的，需要使用来禁用它）
• Trace：跟踪一段时间的程序运行情况，根据生成的结果找到程序问题（trace在最后给大家介绍）

pprof 环境变量和共享参数


环境变量

PPROF_TMPDIR：pprof文件存放的位置，默认位置为$HOME/pprof

PPROF_TOOLS，通过默认工具搜索； pprof 工具使用 GNU Binutils 来验证和反编译二进制文件；有兴趣的同学可以查看：https://www.gnu.org/software/binutils/

PPROF_BINARY_PATH：搜索$HOME/pprof/binaries中存储的二进制路径。如果找到，它将看起来像 $name, $path

, ❀$build,id$build $path\$buildid 按顺序继续。

常用参数

• -基本：输入两个剖面文件，以第一个剖面为基准，用第二个剖面减去第一个统计结果（此参数比较常用） - diff_base：返回两个配置文件的比较。显示的百分比基于第一个配置文件的统计数量。
• -http：在 Web UI 中打开 pprof 文件。
• -秒：将指定秒数设置为 pprof 的间隔。信息，这只适用于获取时间统计的方式，如CPU profile
• -cum：按累计总数排序
• -flat：按当前统计数量排序
• -inuse_space：显示已使用空间
• -inuse_objects：显示正在使用的对象
• -alloc_space：显示已分配的总空间
• -alloc_objects：显示已分配的总对象 ❀❀♿ ❀♿❙ 常规常用字段 含义
  • flat：当前函数占用的轮廓样本数量
  • flat%：当前函数占用的轮廓样本百分比
  • sum%：当前行上所有 flat% 的总和
  • cum：累积的profile样本量（cum全文：累积）
  • cum%：累积的profile样本量，代表总数的百分比

  对于上述字段，不同的profile含义基本相似，例如， heap profile，flat是当前函数内存使用情况，if goroutine profile是当前函数中的goroutines数量等。

  如下例所示，显示内存使用情况：

  Showing nodes accounting for 1056.67kB, 100% of 1056.67kB total
  Showing top 10 nodes out of 30flat  flat%   sum%        cum   cum%544.67kB 34.72% 34.72%   544.67kB 34.72%  google.golang.org/grpc/internal/transport.newBufWriter512.01kB 32.64%   100%   512.01kB 32.64%  github.com/golang/protobuf/proto.makeMessageMarshaler0     0%   100%   512.01kB 32.64%  github.com/golang/protobuf/proto.(*InternalMessageInfo).Size0     0%   100%   512.01kB 32.64%  github.com/golang/protobuf/proto.(*marshalFieldInfo).computeMarshalFieldInfo0     0%   100%   512.01kB 32.64%  github.com/golang/protobuf/proto.(*marshalFieldInfo).setMarshaler
  

  控制台

  常用命令

  • 默认为最高计数的 1 个样本。如果后面跟有数字，则显示指定的数字。条目，如：top3
  • Traces：返回所有profile的统计信息
  • List：返回与给定正则表达式匹配的方法源代码，列表后面可以跟正则表达式
  • Bam：退出全部来电。关系
  • Web：生成轮廓 svg 矢量图像并使用 web 打开。如果没有指定参数，则显示所有参数。如果指定了指定的方法，则显示指定的方法。
  • pdf：生成 pdf profile 文件，显示头像内容
  • cum：按累积的 profile 样本大小排序
  • flat：按当前函数占用的 profile 排序

我们的第一个例子，top、trace和list是三个最常用的命令。通过 Top 来快速查看占用率最高的位置在哪里，然后使用迹线快速定位，最后使用列表查看代码问题在哪里

Web

使用时只需给出 -http 参数即可pprof 命令，如：

go tool pprof -http=:8080 [profiling file path]

图形部分的含义

• Flat value：当前函数配置文件的值，以字体大小显示在图形中。字体越大代表平坦值越大；字体越小代表平坦值越小
• 累积值：累积的轮廓值（包括子节点）由图中节点的颜色表示。红色代表当前值比较大，灰色代表值比较小，绿色代表负值
• 实体线：当前节点调用另一个节点，箭头指向谁，就代表当前节点调用谁
• 红色粗实线：该路径上使用的资源较多
• 细实线：该路径上使用的资源相对较少
• 虚线：表示该过程被省略。 pprof 会根据情况去掉一些内部调用关系，这样更容易展示整套图

在Web Ui中也可以看到Top的信息内容，也可以http使用://host:port/ui/flamegraph显示火焰图等信息

看了这么多基本的环境变量、参数和命令，回过头来回顾一下第一个例子，结合命令进行操作时再看一遍线条和网页图形，你会更容易理解它们。而且，您必须根据自己的需要来使用它们。遇到不同的情况，使用不同的命令和参数

Trace

Trace 也是 Go 工具链中的一个重要工具。它和上面的 pprof 本质区别在于：

• pprof 更适合看程序效率，比如你想看谁占用内存时间长，谁的协程被阻塞等等。
• 跟踪是程序运行过程中信息的跟踪。你可以用直观的方式来看看程序在这段时间做了什么。并了解GC对程序的影响等。和网络调用方法是一样的。单元测试是添加-trace参数。对于应用程序，需要添加以下代码：

  // 需要引入的包
  import _ "runtime/pprof"// file 是  结构，用来创建 pprof 要写入的文件
  // 开始 trace
  trace.Start(file)
  // 结束 trace，并将trace信息完全写入到文件中
  defer trace.Stop()
  

  执行完成后，会生成trace文件。

  对于Web，使用以下命令下载指定时间段的trace文件：

  curl "http://localhost:8080/debug/pprof/trace?seconds=50" > 
  

  其中，?Seconds=50指获取50秒的trace信息。这个时间可以根据具体情况来确定。默认页面

  • 踪迹查看：图形化界面 踪迹内容以形式显示
  • 协程分析：协程分析，列出协程数量以及每个协程的调用时间
  • 网络阻塞概况：使用关系关系图展示网络阻塞情况
  • 同步阻塞概况：同步阻塞耗时情况，使用调用关系图展示
  • Syscall 阻塞概况：系统调用阻塞耗时情况，使用
  • 的调用关系图 显示调度程序延迟概况： 调度程序延迟 耗时情况，使用调用关系图 要显示
  • 用户定义的任务：来自用户定义跟踪的任务
  • 用户定义的区域：来自用户自定义的trace
  • 最小mutator用法：不太好翻译成中文（保留原名词，大家自己体会），这里会用一个曲线图来展示GC对我们程序的影响。可以用来分析判断 GC

  User Defined Tasks 和 User Defined Regions 是否优化 你可能不知道这两个点击起来是做什么的；其实这是go 1.11版本中引入的一个特性。 Trace可以添加我们自定义的内容来快速追踪我们想要查看的代码块的耗时点，因此Trace提供了三个概念，分别是：message、task、region ，包括 区域 可以 任务sss , 任务和名店Region单我会单独给你写一篇文章来介绍如何使用。对于上面这么多的跟踪内容，我们的文章主要支付给查看跟踪和最小变异器使用。 ？所有执行协程。

  在该界面中，可以通过快捷键进行操作：

  • w 按钮：放大图形，主要根据鼠标位置 使用鼠标位置进行缩小
  • a 按钮：将图形向右移动
  • d 按钮：将图形向左移动 ♹❀ 中间的图形是矢量，我们可以放大查看详细信息 的执行状态协程，还有GC的Mark Assist和STW（Stop the World）状态

    上图太复杂了。我们找一张协程数量很少的图给大家看一下

    

    这张图中我们有6个协程，每个协程都有它的编号。它们的含义如下：

    • G1：主函数
    • G18：跟踪协程
    • G19、G20、G21、G22 是 主函数中打开的四个协程♹和❙第一个 G1 和❙最后一个 G1 分别是'程序的运行时间；从图中你很快就能注意到 G19 到 G22 协程中间有一个空白区域。这个空缺就是协程。暂停（可能是在等待什么，造成阻塞），四个协程都暂停了一小段时间才继续执行，导致效率低下，或许达不到我们的预期。

      对于这次中断，我添加了一个互斥锁。这个锁不会在短时间内释放，因此每个协程在给定任务时都必须等到锁释放后才能继续执行，从而导致性能不佳。不像预期的那样。所以对于这个块我们可以根据自己的需求采用不同的方式进行优化，以达到最好的效果。

      最小 Mutator 利用率

      此工具于 1.12 引入。它的主要作用是帮助查看GC对我们程序的影响。标准图表如下：

      

      从图中可以看到，我们的程序在大约80微秒后获取CPU使用率。在这 80 微秒之前，GC 执行 STW（停止世界）。随着横坐标上时间的增加，曲线逐渐开始接近100%，这意味着我们程序的CPU可用性越来越高。从这条曲线来看，GC 没问题，不需要优化。如果随着时间的推移曲线仍然不高，则说明GC负载比较高。重，占用系统资源较多。这时候我们就需要对GC进行优化。

      图右侧有几个选项，其含义分别是：

      • System：整个系统的使用
      • Per-Goroutine：每个协程的使用 ❀❀❀所有协程可以同时暂停。做GC时，STW
      • 后台工作者：GC协程消耗了25%的利用率。在GC期间，它们以后台模式执行
      • 标记辅助：当GC想要减慢内存分配时，分配goroutine来标记它
      • 扫描：回收GC之间未使用的内存
      • 显示除了大多数基本数据之外，还显示了mutator使用的百分比

      每选择一个选项，曲线就会相应变化。大家可以根据自己的需求来看看。

      总结
      

      

      对于开发者来说，单元测试、代码审查甚至集成测试都非常重要，但这些方法无法发现和定位隐藏的问题，比如：goroutine阻塞、内存占用过多、CPU占用率过高、这些问题前期很难发现，但是如果上线前没有发现并解决的话，很容易会遇到一些意想不到的错误，会很被动，所以要花一些时间进行一轮的性能分析和调优该计划可能会产生意想不到的效果。