[golang]7种 Go 程序性能分析方法
<p><span style="font-size: 2em">视频信息 </span></p><p><strong>Seven ways to Profile Go Applications</strong><br>by Dave Cheney<br>at Golang UK Conf. 2016</p>
<div class="owl-media owl-video owl-youtube"><iframe src="https://www.youtube.com/embed/2h_NFBFrciI" frameborder="0" width="320" height="240"></iframe></div>
<ul>
<li>视频：https://www.youtube.com/watch?v=2h_NFBFrciI</li>
<li>幻灯：http://talks.godoc.org/github.com/davecheney/presentations/seven.slide#1</li>
</ul>
<h1 id="fang-fa-yi-time">方法一：<code>time</code> </h1>
<h2 id="shell-nei-zhi-de-time">shell 内置的 <code>time</code> </h2>
<p>最简单的性能测试工具就是 shell 中内置的 <code>time</code> 命令，这是由 POSIX.2 (IEEE Std 1003.2-1992) 标准定义的，因此所有 Unix/Linux 都有这个内置命令。</p>
<table>
<tbody>
<tr>
<td class="code">
<div class="line">$ time go fmt github.com/docker/machine</div>
<div class="line"> </div>
<div class="line">real 0m0.110s</div>
<div class="line">user 0m0.056s</div>
<div class="line">sys 0m0.040s</div>
</td>
</tr>
</tbody>
</table>
<p>这是使用shell<strong>内置的 <code>time</code></strong>来对 <code>go fmt github.com/docker/machine</code> 的命令进行性能分析。</p>
<p>这里一共有3项指标：</p>
<ul>
<li><code>real</code>：从程序开始到结束，实际度过的时间；</li>
<li><code>user</code>：程序在<strong>用户态</strong>度过的时间；</li>
<li><code>sys</code>：程序在<strong>内核态</strong>度过的时间。</li>
</ul>
<p>一般情况下 <code>real</code> <strong>>=</strong> <code>user</code> + <code>sys</code>，因为系统还有其它进程。</p>
<h2 id="gnu-shi-xian-de-time">GNU 实现的 <code>time</code> </h2>
<p>除此以外，对于 Linux 系统，还有一套 GNU 的 <code>time</code>，位于 <code>/usr/bin/time</code>，需要用完整路径去调用，不过这个功能就更强大了。</p>
<table>
<tbody>
<tr>
<td class="code">
<div class="line">vagrant@vagrant:~$ /usr/bin/time -v go fmt github.com/docker/machine</div>
<div class="line"> Command being timed: <span class="string">"go fmt github.com/docker/machine"</span></div>
<div class="line"> User time (seconds): 0.02</div>
<div class="line"> System time (seconds): 0.06</div>
<div class="line"> Percent of CPU this job got: 85%</div>
<div class="line"> Elapsed (wall clock) time (h:mm:ss or m:ss): 0:00.09</div>
<div class="line"> Average shared text size (kbytes): 0</div>
<div class="line"> Average unshared data size (kbytes): 0</div>
<div class="line"> Average stack size (kbytes): 0</div>
<div class="line"> Average total size (kbytes): 0</div>
<div class="line"> Maximum resident <span class="built_in">set size (kbytes): 18556</span></div>
<div class="line"> Average resident <span class="built_in">set size (kbytes): 0</span></div>
<div class="line"> Major (requiring I/O) page faults: 0</div>
<div class="line"> Minor (reclaiming a frame) page faults: 9925</div>
<div class="line"> Voluntary context switches: 430</div>
<div class="line"> Involuntary context switches: 121</div>
<div class="line"> Swaps: 0</div>
<div class="line"> File system inputs: 0</div>
<div class="line"> File system outputs: 32</div>
<div class="line"> Socket messages sent: 0</div>
<div class="line"> Socket messages received: 0</div>
<div class="line"> Signals delivered: 0</div>
<div class="line"> Page size (bytes): 4096</div>
<div class="line"> Exit status: 0</div>
</td>
</tr>
</tbody>
</table>
<p>可以看到这里的功能要强大多了，除了之前的信息外，还包括了：</p>
<ul>
<li>CPU占用率；</li>
<li>内存使用情况；</li>
<li>Page Fault 情况；</li>
<li>进程切换情况；</li>
<li>文件系统IO；</li>
<li>Socket 使用情况；</li>
<li>……</li>
</ul>
<h2 id="bsd-macos-de-time">*BSD、macOS 的 <code>time</code> </h2>
<p>*BSD 也有自己实现的 time，功能稍逊，但也比 Shell 里的 <code>time</code> 强大。比如 macOS 中继承自 FreeBSD 的 <code>time</code>：</p>
<table>
<tbody>
<tr>
<td class="code">
<div class="line">$ /usr/bin/time -l go fmt github.com/docker/machine</div>
<div class="line"> 0.70 real 0.05 user 0.40 sys</div>
<div class="line">11710464maximum resident <span class="built_in">set size</span></div>
<div class="line"> 0average shared memory size</div>
<div class="line"> 0average unshared data size</div>
<div class="line"> 0average unshared stack size</div>
<div class="line"> 8579page reclaims</div>
<div class="line"> 2571page faults</div>
<div class="line"> 0swaps</div>
<div class="line"> 0block input operations</div>
<div class="line"> 0block output operations</div>
<div class="line"> 0messages sent</div>
<div class="line"> 0messages received</div>
<div class="line"> 3signals received</div>
<div class="line"> 1118voluntary context switches</div>
<div class="line"> 1702involuntary context switches</div>
<div class="line">$</div>
</td>
</tr>
</tbody>
</table>
<p>这里有：</p>
<ul>
<li>内存使用情况</li>
<li>Page Fault 情况</li>
<li>IO 情况</li>
<li>进程切换情况</li>
<li>Signal 情况</li>
<li>……</li>
</ul>
<h2 id="go-tool-zhong-de-toolexec-can-shu">go tool 中的 <code>-toolexec</code> 参数 </h2>
<p>当我们构建很慢的时候，如何才能知道为什么慢呢？go 工具链中支持 <code>-x</code> 命令，可以显示具体执行的每一条命令，这样我们就可以看到到底执行到哪里的时候慢了。</p>
<table>
<tbody>
<tr>
<td class="code">
<div class="line">$ go build -x fmt</div>
<div class="line">WORK=/var/folders/wc/9tzsn1hd7c38tvc54kctn4100000gn/T/go-build846067626</div>
<div class="line">mkdir -p <span class="variable">$WORK/runtime/internal/sys/_obj/</span></div>
<div class="line">mkdir -p <span class="variable">$WORK/runtime/internal/</span></div>
<div class="line"><span class="built_in">cd /usr/<span class="built_in">local/Cellar/go/1.9.1/libexec/src/runtime/internal/sys</span></span></div>
<div class="line">/usr/<span class="built_in">local/Cellar/go/1.9.1/libexec/pkg/tool/darwin_amd64/compile -o <span class="variable">$WORK/runtime/internal/sys.a -trimpath <span class="variable">$WORK -goversion go1.9.1 -p runtime/internal/sys -std -+ -complete -buildid 2749cc50ea3a4ebcf</span></span></span></div>
<div class="line">...</div>
</td>
</tr>
</tbody>
</table>
<p>但是如果构建时间很长，或者是计划在 CI 中运行，我们就不可能一直盯着了。当然，我们可以时候从输出中复制粘贴到命令行，前缀上 <code>time</code>，也可以知道每个命令的执行时间。不过这太繁琐了。</p>
<p>go tool 工具链中，还支持一个叫做 <code>-toolexec</code> 的参数，其值将作为工具链每一个命令的前缀来执行。</p>
<table>
<tbody>
<tr>
<td class="code">
<div class="line">go build -toolexec=... github.com/pkg/profile</div>
<div class="line">go <span class="built_in">test -toolexec=... net/http</span></div>
<div class="line">...</div>
</td>
</tr>
</tbody>
</table>
<p>换句话说，如果 <code>-toolexec=time</code>，那么假如有一个 <code>go build xxx.go</code> 的命令，就会变为 <code>time go build xxx.go</code> 来执行。</p>
<table>
<tbody>
<tr>
<td class="code">
<div class="line">$ go build -toolexec=<span class="string">"/usr/bin/time" cmd/compile/internal/gc</span></div>
<div class="line"><span class="comment"># runtime/internal/sys</span></div>
<div class="line"> 0.09 real 0.01 user 0.02 sys</div>
<div class="line"><span class="comment"># runtime/internal/atomic</span></div>
<div class="line"> 0.01 real 0.00 user 0.00 sys</div>
<div class="line"><span class="comment"># runtime/internal/atomic</span></div>
<div class="line"> 0.02 real 0.00 user 0.00 sys</div>
<div class="line"><span class="comment"># runtime</span></div>
<div class="line"> 1.60 real 1.90 user 0.12 sys</div>
<div class="line"><span class="comment"># runtime</span></div>
<div class="line"> 0.00 real 0.00 user 0.00 sys</div>
<div class="line"><span class="comment"># runtime</span></div>
<div class="line"> 0.02 real 0.01 user 0.00 sys</div>
<div class="line"><span class="comment"># runtime</span></div>
<div class="line"> 0.01 real 0.00 user 0.00 sys</div>
<div class="line"><span class="comment"># runtime</span></div>
<div class="line"> 0.00 real 0.00 user 0.00 sys</div>
<div class="line">...</div>
</td>
</tr>
</tbody>
</table>
<p>用好了，这就可以变得很强大，不仅仅是计时。比如，我们 <code>go build</code> 的时候我们可以在 Mac 或者 Linux 上进行交叉编译，但是 <code>go test</code> 的时候，我们希望则在手机设备上直接运行。另外，也可以用来校验输出结果的一致性 （<code>toolstash</code>）</p>
<h1 id="fang-fa-er-godebug">方法二：<code>GODEBUG</code> </h1>
<p><code>/usr/bin/time</code> 是外部工具，除此外，我们还可以使用 Go 内置的功能。Go 的 runtime 可以收集程序运行周期内的很多数据。当然，这些收集默认都是不启用的，你可以手动启用特定信息的收集。</p>
<p>比如，如果你关心垃圾收集，则可以启用 <code>gctrace=1</code> 标志。如：</p>
<table>
<tbody>
<tr>
<td class="code">
<div class="line">$ env GODEBUG=gctrace=1 godoc -http=:8080</div>
<div class="line">gc 1 @18446741350.644s 0%: 0.026+2.0+0.075 ms clock, 0.052+2.6/2.0/0+0.15 ms cpu, 4->4->0 MB, 5 MB goal, 4 P</div>
<div class="line">gc 2 @18446741350.664s 0%: 0.12+1.5+0.049 ms clock, 0.25+0.50/1.2/0+0.098 ms cpu, 4->4->1 MB, 5 MB goal, 4 P</div>
<div class="line">gc 3 @18446741350.695s 0%: 0.024+1.1+0.059 ms clock, 0.072+1.3/0.96/0+0.17 ms cpu, 4->4->1 MB, 5 MB goal, 4P</div>
<div class="line">gc 4 @18446741350.714s 0%: 0.036+1.8+0.092 ms clock, 0.11+1.4/1.7/0+0.27 ms cpu, 4->4->1 MB, 5 MB goal, 4 P</div>
<div class="line">gc 5 @18446741350.746s 0%: 0.021+2.2+0.055 ms clock, 0.087+2.5/2.1/0+0.22 ms cpu, 4->4->1 MB, 5 MB goal, 4 P</div>
<div class="line">gc 6 @18446741350.770s 0%: 0.013+4.5+0.12 ms clock, 0.053+1.3/3.9/0+0.50 ms cpu, 4->4->1 MB, 5 MB goal, 4 P</div>
<div class="line">gc 7 @18446741350.800s 0%: 0.020+2.5+0.056 ms clock, 0.083+2.4/2.5/0+0.22 ms cpu, 4->4->2 MB, 5 MB goal, 4 P</div>
<div class="line">gc 8 @18446741350.817s 0%: 0.030+3.2+0.053 ms clock, 0.12+2.8/3.0/0+0.21 ms cpu, 4->4->2 MB, 5 MB goal, 4 P</div>
<div class="line">gc 9 @18446741350.845s 0%: 0.041+4.7+0.10 ms clock, 0.16+1.6/4.3/0+0.40 ms cpu, 4->4->2 MB, 5 MB goal, 4 P</div>
<div class="line">gc 10 @18446741350.881s 0%: 0.018+3.7+0.070 ms clock, 0.072+2.5/3.6/0+0.28 ms cpu, 4->4->2 MB, 5 MB goal, 4</div>
<div class="line">...</div>
</td>
</tr>
</tbody>
</table>
<p>这样的话，垃圾收集的信息都会被输出出来，可以帮助 GC 排障。如果发现 GC 一直都在很忙碌的工作，那恐怕内存管理上有可以改进的地方。</p>
<h1 id="cha-qu-yi-profiler-shi-ru-he-gong-zuo-de">插曲一：Profiler 是如何工作的？ </h1>
<p>Profiler 会启动你的程序，然后通过配置操作系统，来定期中断程序，然后进行采样。比如发送 <code>SIGPROF</code> 信号给被分析的进程，这样进程就会被暂停，然后切换到 Profiler 中进行分析。Profiler 则取得被分析的程序的每个线程的当前位置等信息进行统计，然后恢复程序继续执行。</p>
<h2 id="xing-neng-fen-xi-zhu-yi-shi-xiang">性能分析注意事项 </h2>
<ul>
<li>性能分析必须在一个<strong>可重复的、稳定的环境</strong>中来进行。
<ul>
<li>机器<strong>必须闲置</strong>。
<ul>
<li>不要在共享硬件上进行性能分析;</li>
<li>不要在性能分析期间，在同一个机器上去浏览网页！！😓；</li>
</ul>
</li>
<li>注意省电模式和过热保护，如果突然进入这些模式，会导致分析数据严重不准确</li>
<li><strong>不要使用虚拟机、共享的云主机</strong>，太多干扰因素，分析数据会很不一致；</li>
<li>不要在 macOS 10.11 及以前的版本运行性能分析，有 bug，之后的版本修复了。</li>
</ul>
</li>
</ul>
<p>如果承受得起，购买专用的性能测试分析的硬件设备，上架。</p>
<ul>
<li>关闭电源管理、过热管理;</li>
<li>绝不要升级，以保证测试的一致性，以及具有可比性。</li>
</ul>
<p>如果没有这样的环境，那就一定要在多个环境中，执行多次，以取得可参考的、具有相对一致性的测试结果。</p>
<h1 id="fang-fa-san-pprof">方法三：<code>pprof</code> </h1>
<p><code>pprof</code> 源自 Google Performance Tools 工具集。Go runtime 中内置了 <code>pprof</code> 的性能分析功能。这包含了两部分：</p>
<ul>
<li>每个 Go 程序中内置 <code>runtime/pprof</code> 包</li>
<li>然后用 <code>go tool pprof</code> 来分析性能数据文件</li>
</ul>
<h2 id="cpu-xing-neng-fen-xi">CPU 性能分析 </h2>
<p>最常用的就是 CPU 性能分析，当 CPU 性能分析启用后，Go runtime 会每 <code>10ms</code> 就暂停一下，记录当前运行的 Go routine 的调用堆栈及相关数据。当性能分析数据保存到硬盘后，我们就可以分析代码中的热点了。</p>
<p>一个函数如果出现在数据中的次数越多，就越说明这个函数调用栈占用了更多的运行时间。</p>
<h2 id="nei-cun-xing-neng-fen-xi">内存性能分析 </h2>
<p>内存性能分析则是在<strong>堆(Heap)分配</strong>的时候，记录一下调用堆栈。默认情况下，是每 <code>1000</code> 次分配，取样一次，这个数值可以改变。</p>
<p><strong>栈(Stack)分配</strong> 由于会随时释放，因此<strong>不会</strong>被内存分析所记录。</p>
<p>由于内存分析是<strong>取样</strong>方式，并且也因为其记录的<strong>是分配内存，而不是使用内存</strong>。因此使用内存性能分析工具来准确判断程序具体的内存使用是比较困难的。</p>
<h2 id="zu-sai-xing-neng-fen-xi">阻塞性能分析 </h2>
<p>阻塞分析是一个很独特的分析。它有点儿类似于 CPU 性能分析，但是它所记录的是 goroutine 等待资源所花的时间。</p>
<p>阻塞分析对分析程序<strong>并发瓶颈</strong>非常有帮助。阻塞性能分析可以显示出什么时候出现了大批的 goroutine 被阻塞了。阻塞包括：</p>
<ul>
<li>发送、接受无缓冲的 channel；</li>
<li>发送给一个满缓冲的 channel，或者从一个空缓冲的 channel 接收；</li>
<li>试图获取已被另一个 go routine 锁定的 <code>sync.Mutex</code> 的锁；</li>
</ul>
<p>阻塞性能分析是特殊的分析工具，在排除 CPU 和内存瓶颈前，不应该用它来分析。</p>
<h2 id="yi-ci-zhi-fen-xi-yi-ge-dong-xi">一次只分析一个东西 </h2>
<p><strong>性能分析不是没有开销的</strong>。虽然性能分析对程序的影响并不严重，但是毕竟有影响，特别是内存分析的时候增加采样率的情况。大多数工具甚至直接就不允许你同时开启多个性能分析工具。如果你同时开启了多个性能分析工具，那很有可能会出现他们互相观察对方的开销从而导致你的分析结果彻底失去意义。</p>
<p>所以，<strong>一次只分析一个东西</strong>。</p>
<h2 id="dui-han-shu-fen-xi">对函数分析 </h2>
<p>最简单的对一个函数进行性能分析的办法就是使用 <code>testing</code> 包。<code>testing</code> 包内置支持生成 CPU、内存、阻塞的性能分析数据。</p>
<ul>
<li><code>-cpuprofile=xxxx</code>： 生成 <strong>CPU</strong> 性能分析数据，并写入文件 <code>xxxx</code>；</li>
<li><code>-memprofile=xxxx</code>： 生成 <strong>内存</strong> 性能分析数据，并写入文件 <code>xxxx</code>；
<ul>
<li><code>-memprofilerate=N</code>：调整采样率为 <code>1/N</code>；</li>
</ul>
</li>
<li><code>-blockprofile=xxxx</code>： 生成 <strong>阻塞</strong> 性能分析数据，并写入文件 <code>xxxx</code>；</li>
</ul>
<p>如：</p>
<table>
<tbody>
<tr>
<td class="code">
<div class="line">$ go <span class="built_in">test -run=XXX -bench=IndexByte -cpuprofile=/tmp/c.p bytes</span></div>
<div class="line">goos: darwin</div>
<div class="line">goarch: amd64</div>
<div class="line">pkg: bytes</div>
<div class="line">BenchmarkIndexByte/10-4 200000000 6.44 ns/op 1553.83 MB/s</div>
<div class="line">BenchmarkIndexByte/32-4 200000000 7.41 ns/op 4318.84 MB/s</div>
<div class="line">BenchmarkIndexByte/4K-4 10000000 210 ns/op 19455.95 MB/s</div>
<div class="line">BenchmarkIndexByte/4M-4 5000 321910 ns/op 13029.39 MB/s</div>
<div class="line">BenchmarkIndexByte/64M-4 300 5406798 ns/op 12411.94 MB/s</div>
<div class="line">BenchmarkIndexBytePortable/10-4 100000000 13.8 ns/op 722.79 MB/s</div>
<div class="line">BenchmarkIndexBytePortable/32-4 30000000 44.9 ns/op 712.86 MB/s</div>
<div class="line">BenchmarkIndexBytePortable/4K-4 500000 2910 ns/op 1407.32 MB/s</div>
<div class="line">BenchmarkIndexBytePortable/4M-4 500 2979323 ns/op 1407.80 MB/s</div>
<div class="line">BenchmarkIndexBytePortable/64M-4 30 47259940 ns/op 1419.99 MB/s</div>
<div class="line">PASS</div>
<div class="line">ok bytes 18.689s</div>
</td>
</tr>
</tbody>
</table>
<blockquote>
<p>注意这里的 <code>-run=XXX</code> 是说只运行 Benchmarks，而不要运行任何 Tests。</p>
</blockquote>
<p>然后我们用 <code>go tool pprof</code> 来分析：</p>
<table>
<tbody>
<tr>
<td class="code">
<div class="line">$ go tool pprof bytes.test /tmp/c.p</div>
</td>
</tr>
</tbody>
</table>
<h2 id="dui-zheng-ge-ying-yong-fen-xi">对整个应用分析 </h2>
<p><code>testing</code> 适用于分析具体某个函数，但是如果想分析整个应用，则可以使用 <code>runtime/pprof</code> 包。当然这比较底层，Dave Cheney 在几年前还写了个包 <code>github.com/pkg/profile</code>，可以简化使用。</p>
<p>只需要在启动的时候加入 <code>defer profile.Start().Stop()</code> 即可。</p>
<table>
<tbody>
<tr>
<td class="code">
<div class="line"><span class="keyword">import <span class="string">"github.com/pkg/profile"</span></span></div>
<div class="line"> </div>
<div class="line"><span class="function"><span class="keyword">func <span class="title">main<span class="params">() {</span></span></span></span></div>
<div class="line"> <span class="keyword">defer profile.Start().Stop()</span></div>
<div class="line"> ...</div>
<div class="line">}</div>
</td>
</tr>
</tbody>
</table>
<h1 id="fang-fa-si-debug-pprof">方法四：<code>/debug/pprof</code> </h1>
<p><code>pprof</code> 适合在开发的时候进行分析，从运行到结束。但是如果应用已经在数据中心运行，我们希望远程启用调试进行在线分析，这种情况，可以通过 <code>http</code> 远程调试。</p>
<table>
<tbody>
<tr>
<td class="code">
<div class="line"><span class="keyword">import _ <span class="string">"net/http/pprof"</span></span></div>
<div class="line"> </div>
<div class="line"><span class="function"><span class="keyword">func <span class="title">main<span class="params">() {</span></span></span></span></div>
<div class="line"> log.Println(http.ListenAndServe(<span class="string">"localhost:3999", <span class="literal">nil))</span></span></div>
<div class="line"> ...</div>
<div class="line">}</div>
</td>
</tr>
</tbody>
</table>
<p>然后使用 <code>pprof</code> 工具来查看一段 <code>30秒</code> 的：</p>
<ul>
<li>CPU 性能分析数据：</li>
</ul>
<table>
<tbody>
<tr>
<td class="code">
<div class="line">go tool pprof http://localhost:3999/debug/pprof/profile</div>
</td>
</tr>
</tbody>
</table>
<ul>
<li>内存性能分析数据：</li>
</ul>
<table>
<tbody>
<tr>
<td class="code">
<div class="line">go tool pprof http://localhost:3999/debug/pprof/heap</div>
</td>
</tr>
</tbody>
</table>
<blockquote>
<p>在 <code>/debug/pprof/heap</code> 页面的最下方，是 <code>runtime.MemStats</code>，这是你的应用真实使用内存的情况（不仅仅是分配）。其中的 <code>HeapSys</code> 是应用从系统申请到的页面数量。</p>
</blockquote>
<ul>
<li>阻塞性能分析数据：</li>
</ul>
<table>
<tbody>
<tr>
<td class="code">
<div class="line">go tool pprof http://localhost:3999/debug/pprof/block</div>
</td>
</tr>
</tbody>
</table>
<h2 id="shi-yong-pprof">使用 <code>pprof</code> </h2>
<p><code>pprof</code> 始终需要两个参数：</p>
<table>
<tbody>
<tr>
<td class="code">
<div class="line">go tool pprof /path/to/your/binary /path/to/your/profile</div>
</td>
</tr>
</tbody>
</table>
<ul>
<li><code>binary</code> 必须指向生成这个性能分析数据的那个二进制可执行文件；</li>
<li><code>profile</code> 必须是该二进制可执行文件所生成的性能分析数据文件。</li>
</ul>
<p>换句话说，<strong><code>binary</code> 和 <code>profile</code> 必须严格匹配</strong>。</p>
<p>由于 <code>pprof</code> 有在线模式，可以获取性能分析数据文件，所以很多人误解了可以只有 profile。所有可能会有人执行：</p>
<table>
<tbody>
<tr>
<td class="code">
<div class="line">go tool pprof /tmp/c.p</div>
</td>
</tr>
</tbody>
</table>
<p><strong>不是这样的</strong>，这样会发现显示 profile 里面是空的。</p>
<p>我们可以在命令行里分析：</p>
<table>
<tbody>
<tr>
<td class="code">
<div class="line">$ go tool pprof bytes.test /tmp/c.p</div>
<div class="line">File: bytes.test</div>
<div class="line">Type: cpu</div>
<div class="line">Time: Oct 22, 2017 at 8:41pm (AEDT)</div>
<div class="line">Duration: 18.60s, Total samples = 16.38s (88.06%)</div>
<div class="line">Entering interactive mode (<span class="built_in">type <span class="string">"help" <span class="keyword">for commands, <span class="string">"o" <span class="keyword">for options)</span></span></span></span></span></div>
<div class="line">(pprof) top</div>
<div class="line">Showing nodes accounting <span class="keyword">for 16300ms, 99.51% of 16380ms total</span></div>
<div class="line">Dropped 30 nodes (cum <= 81.90ms)</div>
<div class="line">Showing top 10 nodes out of 12</div>
<div class="line"> flatflat% sum% cum cum%</div>
<div class="line"> 7560ms 46.15% 46.15% 7560ms 46.15%runtime.indexbytebody /usr/<span class="built_in">local/Cellar/go/1.9.1/libexec/src/runtime/asm_amd64.s</span></div>
<div class="line"> 5950ms 36.32% 82.48% 5950ms 36.32%bytes.indexBytePortable /usr/<span class="built_in">local/Cellar/go/1.9.1/libexec/src/bytes/bytes.go</span></div>
<div class="line"> 2180ms 13.31% 95.79% 15880ms 96.95%bytes_test.bmIndexByte.func1 /usr/<span class="built_in">local/Cellar/go/1.9.1/libexec/src/bytes/bytes_test.go</span></div>
<div class="line"> 420ms2.56% 98.35% 420ms2.56%runtime.usleep /usr/<span class="built_in">local/Cellar/go/1.9.1/libexec/src/runtime/sys_darwin_amd64.s</span></div>
<div class="line"> 190ms1.16% 99.51% 190ms1.16%bytes.IndexByte /usr/<span class="built_in">local/Cellar/go/1.9.1/libexec/src/runtime/asm_amd64.s</span></div>
<div class="line"> 0 0% 99.51% 15880ms 96.95%bytes_test.benchBytes.func1 /usr/<span class="built_in">local/Cellar/go/1.9.1/libexec/src/bytes/bytes_test.go</span></div>
<div class="line"> 0 0% 99.51% 410ms2.50%runtime.mstart /usr/<span class="built_in">local/Cellar/go/1.9.1/libexec/src/runtime/proc.go</span></div>
<div class="line"> 0 0% 99.51% 410ms2.50%runtime.mstart1 /usr/<span class="built_in">local/Cellar/go/1.9.1/libexec/src/runtime/proc.go</span></div>
<div class="line"> 0 0% 99.51% 410ms2.50%runtime.sysmon /usr/<span class="built_in">local/Cellar/go/1.9.1/libexec/src/runtime/proc.go</span></div>
<div class="line"> 0 0% 99.51% 15810ms 96.52%testing.(*B).launch /usr/<span class="built_in">local/Cellar/go/1.9.1/libexec/src/testing/benchmark.go</span></div>
<div class="line">(pprof)</div>
</td>
</tr>
</tbody>
</table>
<p>这显然很不直观，性能分析更好的是使用可视化分析。可以在交互模式下执行 <code>web</code> 命令，这样会生成一个 <code>svg</code> 文件，然后用浏览器或者其它工具打开。</p>
<p><img src="https://blog.lab99.org/pics/golang/profile/pprof.svg" alt="profile svg"></p>
<p>这个图是 CPU 性能分析的图，这里可以直观的看出哪个地方最消耗 CPU，使用时间越多的，方块面积就越大。而且由于其继承关系清晰可见，我们可以很清楚的看到为什么它会消耗很多 CPU。</p>
<p>这里默认是 <code>-svg</code>，还可以设置为 <code>-pdf</code> 等，可以用 <code>go tool pprof -help</code> 来查看详细配置。</p>
<p>推荐阅读：</p>
<ul>
<li>Profiling Go programs</li>
<li>Debugging performance issues in Go programs</li>
</ul>
<p>除了可视化 CPU 性能分析外，同样可以分析内存和阻塞。</p>
<h3 id="nei-cun-xing-neng-fen-xi">内存性能分析： </h3>
<table>
<tbody>
<tr>
<td class="code">
<div class="line">$ go build -gcflags=<span class="string">'-memprofile=/tmp/m.p'</span></div>
<div class="line">$ go tool pprof --alloc_objects -svg $(go tool -n compile) /tmp/m.p > alloc_objects.svg</div>
<div class="line">$ go tool pprof --inuse_objects -svg $(go tool -n compile) /tmp/m.p > inuse_objects.svg</div>
</td>
</tr>
</tbody>
</table>
<ul>
<li>alloc_objects</li>
</ul>
<p><img src="https://blog.lab99.org/pics/golang/profile/alloc_objects.svg" alt="alloc_objects"></p>
<ul>
<li>inuse_objects</li>
</ul>
<p><img src="https://blog.lab99.org/pics/golang/profile/inuse_objects.svg" alt="inuse_objects"></p>
<h3 id="zu-sai-xing-neng-fen-xi">阻塞性能分析 </h3>
<p>这里分析的是 <code>net/http</code> 包：</p>
<table>
<tbody>
<tr>
<td class="code">
<div class="line">$ go <span class="built_in">test -run=XXX -bench=ClientServer -blockprofile=/tmp/b.p net/http</span></div>
<div class="line">$ go tool pprof -svg http.test /tmp/b.p > block.svg</div>
</td>
</tr>
</tbody>
</table>
<p><img src="https://blog.lab99.org/pics/golang/profile/block.svg" alt="inuse_objects"></p>
<h1 id="cha-qu-er-frame-pointer">插曲二：Frame Pointer </h1>
<p>Frame pointer 是整个 Unix/Linux 调试工具链的核心的东西。Frame Pointer 就是一个指向调用栈顶端的寄存器。</p>
<p>Go 从 <code>1.7</code> 开始，编译器默认启用 Frame pointers 了。所以像 gdb、perf 命令也可以理解 Go 的调用栈，从而可以进行调试分析。</p>
<h1 id="fang-fa-wu-perf">方法五：<code>perf</code> </h1>
<p>对于 Linux 用户来说，<code>perf</code> 是一个非常好的工具。由于现在 Go 已经支持了 Frame Pointer，所以可以和 <code>-toolexec=</code> 配合来对 Go 应用进行性能分析。</p>
<table>
<tbody>
<tr>
<td class="code">
<div class="line">$ go build -toolexec=<span class="string">"perf stat" cmd/compile/internal/gc</span></div>
</td>
</tr>
</tbody>
</table>
<p>我们也可以用 <code>perf record</code> 来记录一段性能分析数据。</p>
<table>
<tbody>
<tr>
<td class="code">
<div class="line">$ go build -toolexec=<span class="string">"perf record -g -o /tmp/p" cmd/compile/internal/gc</span></div>
<div class="line">$ perf report -i /tmp/p</div>
</td>
</tr>
</tbody>
</table>
<p><img src="https://github.com/davecheney/presentations/raw/master/seven/perf.png" alt="perf"></p>
<h1 id="fang-fa-liu-huo-yan-tu-flame-graph">方法六：火焰图 (Flame Graph) </h1>
<p>火焰图(Flame Graph) 也是性能分析的利器。最初是由 Netflix 的 Brendan Gregg 发明并推广的。</p>
<p><strong>X 轴</strong>显示的是在该性能指标分析中所<strong>占用的资源量</strong>，也就是横向越宽，则意味着在该指标中占用的资源越多，<strong>Y 轴</strong>则是<strong>调用栈的深度</strong>。</p>
<p>有几点需要注意：</p>
<ul>
<li><strong>左右顺序不重要</strong>，X 轴不是按时间顺序发生的，而是<strong>按字母顺序排序的</strong></li>
<li>虽然很好看，但是<strong>颜色深浅没关系</strong>，这是随机选取的。</li>
</ul>
<p>火焰图可以来自于很多数据源，包括 <code>pprof</code> 和 <code>perf</code>。</p>
<p>感谢 Uber 提供了火焰图的 Go 的工具，go-torch，在你提供了 <code>/debug/pprof</code> 的情况下，可以自动进行分析处理生成火焰图。</p>
<table>
<tbody>
<tr>
<td class="code">
<div class="line">$ go build -gcflags=-cpuprofile=/tmp/c.p .</div>
<div class="line">$ go-torch $(go tool -n compile) /tmp/c.p</div>
</td>
</tr>
</tbody>
</table>
<p><img src="https://github.com/davecheney/presentations/raw/master/seven/torch.svg?sanitize=true" alt="torch"></p>
<h1 id="fang-fa-qi-go-tool-trace">方法七：<code>go tool trace</code> </h1>
<p>在 Go 1.5 的时候，Dmitry Vyukov 在 runtime 里添加了一个新的性能分析工具，execution tracer profile。</p>
<table>
<tbody>
<tr>
<td class="code">
<div class="line">$ go <span class="built_in">test -trace=trace.out path/to/package</span></div>
<div class="line">$ go tool trace pkg.test trace.out</div>
</td>
</tr>
</tbody>
</table>
<p>这个工具可以用来分析程序动态执行的情况，并且分析的精度达到纳秒级别：</p>
<ul>
<li>goroutine 创建、启动、结束</li>
<li>gorouting 阻塞、恢复</li>
<li>网络阻塞</li>
<li>系统调用（syscall）</li>
<li>GC 事件</li>
</ul>
<p>这个工具目前介绍的文档不多，https://golang.org/pkg/runtime/trace/。只有很少量的文档，或许应该有一些文档、博客啥的描述一下。这里有几个文档可以看看：</p>
<ul>
<li>https://docs.google.com/document/u/1/d/1FP5apqzBgr7ahCCgFO-yoVhk4YZrNIDNf9RybngBc14/pub</li>
<li>https://www.dotconferences.com/2016/10/rhys-hiltner-go-execution-tracer</li>
</ul>
<p>通过 <code>-traceprofile=</code> 来标志生成性能分析文件。</p>
<p>比如这里我们构建包 <code>cmd/compile/internal/gc</code>，并生成构建的性能分析数据文件。</p>
<table>
<tbody>
<tr>
<td class="code">
<div class="line">$ go build -gcflags=-traceprofile=/tmp/t.p cmd/compile/internal/gc</div>
<div class="line">$ go tool trace /tmp/t.p</div>
<div class="line">2017/10/23 20:59:09 Parsing trace...</div>
<div class="line">2017/10/23 20:59:10 Serializing trace...</div>
<div class="line">2017/10/23 20:59:10 Splitting trace...</div>
<div class="line">2017/10/23 20:59:11 Opening browser</div>
</td>
</tr>
</tbody>
</table>
<p>这会打开一个浏览器，显示：</p>
<ul>
<li>View trace</li>
<li>Goroutine analysis</li>
<li>Network blocking profile</li>
<li>Synchronization blocking profile</li>
<li>Syscall blocking profile</li>
<li>Scheduler latency profile</li>
</ul>
<p>点进去就可以看到各种分析。</p>
<p><img src="https://blog.lab99.org/pics/golang/profile/trace.jpg" alt="trace"></p>
<p>另外，Dave Cheney 做的 <code>pkg/profile</code> 也支持生成 trace profile 了。</p>
<table>
<tbody>
<tr>
<td class="code">
<div class="line"><span class="keyword">import <span class="string">"github.com/pkg/profile"</span></span></div>
<div class="line"> </div>
<div class="line">...</div>
<div class="line"> </div>
<div class="line"><span class="function"><span class="keyword">func <span class="title">main<span class="params">() {</span></span></span></span></div>
<div class="line"> <span class="keyword">defer profile.Start(profile.TraceProfile).Stop()</span></div>
<div class="line"> ...</div>
<div class="line">}</div>
</td>
</tr>
</tbody>
</table>
<h1 id="zong-jie">总结 </h1>
<p>不同的工具可以从不同的角度对你的应用进行分析。一般你不需要非得把上面提及的每个工具都用一遍，但是建议大家熟悉一下上面的工具，先从小的东西开始，当熟悉之后，在真正需要的时候，才可以快速的选择自己所需的工具来诊断问题。</p>
</div>
<div id="MySignature" role="contentinfo">
<p>本文来自博客园，作者：landv，转载请注明原文链接：https://www.cnblogs.com/landv/p/11274877.html</p><br><br>
来源：https://www.cnblogs.com/landv/p/11274877.html
頁:
[1]