13.10 性能调试:分析并优化 Go 程序

    在 Unix 命令行中像这样使用 ,这里的 progexec 是一个 Go 可执行程序,这句命令行输出类似:56.63u 0.26s 56.92r 1642640kB progexec,分别对应用户时间,系统时间,实际时间和最大内存占用。

    如果代码使用了 Go 中 testing 包的基准测试功能,我们可以用 gotest 标准的 -cpuprofile-memprofile 标志向指定文件写入 CPU 或 内存使用情况报告。

    使用方式:go test -x -v -cpuprofile=prof.out -file x_test.go

    编译执行 x_test.go 中的测试,并向 prof.out 文件中写入 cpu 性能分析信息。

    你可以在单机程序 progexec 中引入 runtime/pprof 包;这个包以 pprof 可视化工具需要的格式写入运行时报告数据。对于 CPU 性能分析来说你需要添加一些代码:

    1. var cpuprofile = flag.String("cpuprofile", "", "write cpu profile to file")
    2. func main() {
    3. flag.Parse()
    4. if *cpuprofile != "" {
    5. f, err := os.Create(*cpuprofile)
    6. if err != nil {
    7. }
    8. pprof.StartCPUProfile(f)
    9. defer pprof.StopCPUProfile()
    10. ...

    代码定义了一个名为 cpuprofile 的 flag,调用 Go flag 库来解析命令行 flag,如果命令行设置了 cpuprofile flag,则开始 CPU 性能分析并把结果重定向到那个文件。(os.Create 用拿到的名字创建了用来写入分析数据的文件)。这个分析程序最后需要在程序退出之前调用 StopCPUProfile 来刷新挂起的写操作到文件中;我们用 defer 来保证这一切会在 main 返回时触发。

    现在用这个 flag 运行程序:progexec -cpuprofile=progexec.prof

    然后可以像这样用 gopprof 工具:gopprof progexec progexec.prof

    如果开启了 CPU 性能分析,Go 程序会以大约每秒 100 次的频率阻塞,并记录当前执行的 goroutine 栈上的程序计数器样本。

    此工具一些有趣的命令:

    1)topN

    用来展示分析结果中最开头的 N 份样本,例如:top5 它会展示在程序运行期间调用最频繁的 5 个函数,输出如下:

    第 5 列表示函数的调用频度。

    2)webweb 函数名

    该命令生成一份 SVG 格式的分析数据图表,并在网络浏览器中打开它(还有一个 gv 命令可以生成 PostScript 格式的数据,并在 GhostView 中打开,这个命令需要安装 graphviz)。函数被表示成不同的矩形(被调用越多,矩形越大),箭头指示函数调用链。

    3)list 函数名weblist 函数名

    如果发现函数 runtime.mallocgc(分配内存并执行周期性的垃圾回收)调用频繁,那么是应该进行内存分析的时候了。找出垃圾回收频繁执行的原因,和内存大量分配的根源。

    为了做到这一点必须在合适的地方添加下面的代码:

    1. var memprofile = flag.String("memprofile", "", "write memory profile to this file")
    2. ...
    3. CallToFunctionWhichAllocatesLotsOfMemory()
    4. f, err := os.Create(*memprofile)
    5. log.Fatal(err)
    6. }
    7. pprof.WriteHeapProfile(f)
    8. f.Close()
    9. return
    10. }

    用 -memprofile flag 运行这个程序:progexec -memprofile=progexec.mprof

    然后你可以像这样再次使用 gopprof 工具:gopprof progexec progexec.mprof

    top5list 函数名 等命令同样适用,只不过现在是以 Mb 为单位测量内存分配情况,这是 top 命令输出的例子:

    从第 1 列可以看出,最上面的函数占用了最多的内存。

    同样有一个报告内存分配计数的有趣工具:

    1. gopprof --inuse_objects progexec progexec.mprof

    对于 web 应用来说,有标准的 HTTP 接口可以分析数据。在 HTTP 服务中添加

    1. gopprof http://localhost:6060/debug/pprof/profile # 30-second CPU profile

    在 Go-blog(引用 15)中有一篇很好的文章用具体的例子进行了分析:分析 Go 程序(2011年6月)。