go 应用程序性能测试

runtime/pprof

我们要加入对pprof包里的方法调用，程序才能将运行时候程序的堆内存分配状态记录到文件(也可以是写到其他地方，例如网络等)中，以便进一步的分析.

如果你的go程序只是一个应用程序，比如计算fabonacci数列，那么你就不能使用net/http/pprof包了，你就需要使用到runtime/pprof。具体做法就是用到pprof.StartCPUProfile和pprof.StopCPUProfile。(Go语言的pprof是Google C++ profiler的移植.)

比如下面的例子：

import (
    "flag"
    "fmt"
    "os"
    "runtime/pprof"
)

var cpuprofile = flag.String("cpuprofile", "", "write cpu profile to file")

func main() {

    flag.Parse()
    if *cpuprofile != "" {
        f, err := os.Create(*cpuprofile)
        if err != nil {
            fmt.Println(err)
        }
        pprof.StartCPUProfile(f)
        defer pprof.StopCPUProfile()
    }
    // ...
}

 

运行程序的时候加一个--cpuprofile参数，比如fabonacci --cpuprofile=fabonacci.prof

这样程序运行的时候的cpu信息就会记录到XXX.prof中了。

 

以上内容来自：

http://blog.csdn.net/yhcharles/article/details/16820485

http://www.cnblogs.com/yjf512/archive/2012/12/27/2835331.html

http://blog.golang.org/profiling-go-programs 

 

go tool pprof

准备go tool pprof的运行环境，直接运行这个命令需要用到perl，

在Windows下可以安装ActivePerl(http://www.activestate.com/activeperl),我这里下载的是：ActivePerl 5.16.3 for Windows (64-bit, x64) 。

没有安装perl，会报下面错误：

D:gocodessrclogDemo>go tool pprof
go tool: perl not found

D:gocodessrclogDemo>go tool pprof logDemo.exe a.prof
go tool: perl not found

安装好后，如下输入命令，就可以看到一些统计信息：

这里的例子是使用go tool pprof your-executable-name profile-filename即可进入pprof命令模式分析数据

D:gocodessrclogDemo>go tool pprof logDemo.exe a.prof
Welcome to pprof!  For help, type 'help'.
(pprof) top
Total: 236 samples
      19   8.1%   8.1%       32  13.6% runtime.mallocgc
      12   5.1%  13.1%       26  11.0% fmt.(*pp).printArg
      12   5.1%  18.2%      236 100.0% text
       9   3.8%  22.0%        9   3.8% runtime.memmove
       8   3.4%  25.4%       55  23.3% os.(*File).writeConsole
       8   3.4%  28.8%        8   3.4% runtime.indexbytebody
       7   3.0%  31.8%      144  61.0% fmt.Fprintln
       7   3.0%  34.7%       11   4.7% runtime.makeslice
       6   2.5%  37.3%       25  10.6% bufio.(*Reader).ReadSlice
       5   2.1%  39.4%        6   2.5% fmt.(*fmt).padString
(pprof)

top命令可以看最耗时的function。它的输出格式各字段的含义依次是：

1. 采样点落在该函数中的次数
2. 采样点落在该函数中的百分比
3. 上一项的累积百分比
4. 采样点落在该函数，以及被它调用的函数中的总次数
5. 采样点落在该函数，以及被它调用的函数中的总次数百分比
6. 函数名

http://blog.csdn.net/yhcharles/article/details/16820485

当然我们也可以用下面方式来查看各个函数/方法的内存消耗排名。

D:gocodessrclogDemo>go tool pprof logDemo.exe --text a.prof
Total: 236 samples
      19   8.1%   8.1%       32  13.6% runtime.mallocgc
      12   5.1%  13.1%       26  11.0% fmt.(*pp).printArg
      12   5.1%  18.2%      236 100.0% text
       9   3.8%  22.0%        9   3.8% runtime.memmove
       8   3.4%  25.4%       55  23.3% os.(*File).writeConsole
       8   3.4%  28.8%        8   3.4% runtime.indexbytebody
       7   3.0%  31.8%      144  61.0% fmt.Fprintln
       7   3.0%  34.7%       11   4.7% runtime.makeslice
       6   2.5%  37.3%       25  10.6% bufio.(*Reader).ReadSlice
       5   2.1%  39.4%        6   2.5% fmt.(*fmt).padString
       5   2.1%  41.5%        6   2.5% runtime.entersyscall
       5   2.1%  43.6%        5   2.1% runtime.memclr
       5   2.1%  45.8%        6   2.5% unicode/utf8.DecodeRune
       4   1.7%  47.5%        9   3.8% assertE2Tret
       4   1.7%  49.2%        7   3.0% copyout
       4   1.7%  50.8%       30  12.7% fmt.(*pp).doPrint
       4   1.7%  52.5%       30  12.7% gostringsize
       4   1.7%  54.2%       81  34.3% os.(*File).Write
       4   1.7%  55.9%       16   6.8% runtime.cgocall
       4   1.7%  57.6%        9   3.8% runtime.deferreturn
       4   1.7%  59.3%       40  16.9% runtime.slicebytetostring
       4   1.7%  61.0%        4   1.7% sync/atomic.AddUint32
       4   1.7%  62.7%       20   8.5% syscall.Syscall6
       4   1.7%  64.4%       15   6.4% unicode/utf16.Encode
       3   1.3%  65.7%       28  11.9% bufio.(*Reader).ReadLine
       3   1.3%  66.9%        9   3.8% copyin
       3   1.3%  68.2%        5   2.1% endcgo
       3   1.3%  69.5%        6   2.5% fmt.(*cache).put
       3   1.3%  70.8%        5   2.1% fmt.(*fmt).init
       3   1.3%  72.0%       11   4.7% fmt.(*pp).fmtString
       3   1.3%  73.3%        9   3.8% fmt.(*pp).free
       3   1.3%  74.6%        6   2.5% runtime.deferproc
       3   1.3%  75.8%        6   2.5% runtime.mal
       3   1.3%  77.1%        3   1.3% runtime.markallocated
       3   1.3%  78.4%        6   2.5% sync.(*Mutex).Lock
       3   1.3%  79.7%        7   3.0% sync.(*Mutex).Unlock
       3   1.3%  80.9%        3   1.3% sync/atomic.CompareAndSwapUint32
       3   1.3%  82.2%        4   1.7% syscall.(*LazyProc).Addr
       2   0.8%  83.1%        3   1.3% cnew
       2   0.8%  83.9%        2   0.8% fmt.(*fmt).clearflags
       2   0.8%  84.7%      146  61.9% fmt.Println
       2   0.8%  85.6%        3   1.3% freedefer
       2   0.8%  86.4%        2   0.8% popdefer
       2   0.8%  87.3%        2   0.8% runtime.MSpanList_IsEmpty
       2   0.8%  88.1%        2   0.8% runtime.memcopy64
       2   0.8%  89.0%       21   8.9% syscall.WriteConsole
       2   0.8%  89.8%        2   0.8% unicode/utf8.decodeRuneInternal
       1   0.4%  90.3%       10   4.2% bufio.(*Reader).fill
       1   0.4%  90.7%        9   3.8% bytes.IndexByte
       1   0.4%  91.1%        2   0.8% fmt.(*cache).get
       1   0.4%  91.5%        8   3.4% fmt.(*fmt).fmt_s
       1   0.4%  91.9%        1   0.4% fmt.(*fmt).truncate
       1   0.4%  92.4%        1   0.4% newdefer
       1   0.4%  92.8%       77  32.6% os.(*File).write
       1   0.4%  93.2%       10   4.2% runtime.MCentral_AllocList
       1   0.4%  93.6%        1   0.4% runtime.MSpanList_Insert
       1   0.4%  94.1%       10   4.2% runtime.assertE2T
       1   0.4%  94.5%        1   0.4% runtime.casp
       1   0.4%  94.9%        4   1.7% runtime.cnewarray
       1   0.4%  95.3%       10   4.2% runtime.convT2E
       1   0.4%  95.8%        1   0.4% runtime.efacethash
       1   0.4%  96.2%        1   0.4% runtime.exitsyscall
       1   0.4%  96.6%        3   1.3% runtime.new
       1   0.4%  97.0%        1   0.4% runtime.stdcall
       1   0.4%  97.5%        1   0.4% runtime.strcopy
       1   0.4%  97.9%        2   0.8% runtime.unlockOSThread
       1   0.4%  98.3%        1   0.4% save
       1   0.4%  98.7%        1   0.4% syscall.(*LazyProc).Find
       1   0.4%  99.2%        6   2.5% syscall.Read
       1   0.4%  99.6%        2   0.8% unicode/utf8.FullRune
       1   0.4% 100.0%        1   0.4% unlockOSThread
       0   0.0% 100.0%        7   3.0% MCentral_Grow
       0   0.0% 100.0%        3   1.3% MHeap_AllocLocked
       0   0.0% 100.0%        1   0.4% MHeap_FreeLocked
       0   0.0% 100.0%       17   7.2% fmt.newPrinter
       0   0.0% 100.0%        4   1.7% makeslice1
       0   0.0% 100.0%        9   3.8% os.(*File).Read
       0   0.0% 100.0%        9   3.8% os.(*File).read
       0   0.0% 100.0%       10   4.2% runtime.MCache_Refill
       0   0.0% 100.0%        7   3.0% runtime.MHeap_Alloc
       0   0.0% 100.0%        2   0.8% runtime.assertE2T2
       0   0.0% 100.0%      236 100.0% runtime.gosched0
       0   0.0% 100.0%        1   0.4% runtime.lock
       0   0.0% 100.0%      236 100.0% runtime.main
       0   0.0% 100.0%        1   0.4% runtime.nanotime
       0   0.0% 100.0%        1   0.4% syscall.(*LazyProc).mustFind
       0   0.0% 100.0%        5   2.1% syscall.ReadFile

D:gocodessrclogDemo>

使用图表展示

如果想不仅看到各个方法/函数的内存消耗排名，还想看到它们之间的调用关系，那就需要安装graphviz或者ghostview才行，相对来说graphviz使用者更多，这里就以它为例。

http://blog.raphaelzhang.com/2014/01/memory-leak-detection-in-go/ 

下载地址：http://www.graphviz.org/Download..php 我下载的是 graphviz-2.36.msi

安装好后，不要忘了设置环境变量。比如我安装的是下面目录： C:Program Files (x86)Graphviz2.36in 需要把它设置到 path环境变量中。

生成图表展示的方法：

1. 使用go tool pprof your-executable-name --dot profile-filename > heap.gv命令生成可以在graphviz里面看的gv文件，在查看各个方法/函数的内存消耗的同时查看它们之间的调用关系
2. 生成了gv文件之后通过dot -Tpng heap.gv > heap.png生成调用关系网与内存消耗图的png图形文件

注意，直接在 pprof 命令行输入 web， 如果不是 web程序，生成时会报下面错误：

D:gocodessrclogDemo>go tool pprof logDemo.exe a.prof
Welcome to pprof!  For help, type 'help'.
(pprof) web
Total: 236 samples
Dropping nodes with <= 1 samples; edges with <= 0 abs(samples)
Loading web page file:///C:UsersGUOHON~1AppDataLocalTempm9inAYN4pq.0.svg
'uname' 不是内部或外部命令，也不是可运行的程序
或批处理文件。
系统找不到指定的路径。
系统找不到指定的路径。
'google-chrome' 不是内部或外部命令，也不是可运行的程序
或批处理文件。
'firefox' 不是内部或外部命令，也不是可运行的程序
或批处理文件。
Could not load web browser.
(pprof)