golang pprof記錄

這是一個建立於 的文章，其中的資訊可能已經有所發展或是發生改變。

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:\gocodes\src\logDemo>go tool pprof 
go tool: perl not found

D:\gocodes\src\logDemo>go tool pprof logDemo.exe a.prof 
go tool: perl not found

安裝好後，如下輸入命令，就可以看到一些統計資訊：

這裡的例子是使用go tool pprof your-executable-name profile-filename即可進入pprof命令模式分析資料

   1: D:\gocodes\src\logDemo>go tool pprof logDemo.exe a.prof

   2: Welcome to pprof!  For help, type 'help'.

   3: (pprof) top

   4: Total: 236 samples

   5:       19   8.1%   8.1%       32  13.6% runtime.mallocgc

   6:       12   5.1%  13.1%       26  11.0% fmt.(*pp).printArg

   7:       12   5.1%  18.2%      236 100.0% text

   8:        9   3.8%  22.0%        9   3.8% runtime.memmove

   9:        8   3.4%  25.4%       55  23.3% os.(*File).writeConsole

  10:        8   3.4%  28.8%        8   3.4% runtime.indexbytebody

  11:        7   3.0%  31.8%      144  61.0% fmt.Fprintln

  12:        7   3.0%  34.7%       11   4.7% runtime.makeslice

  13:        6   2.5%  37.3%       25  10.6% bufio.(*Reader).ReadSlice

  14:        5   2.1%  39.4%        6   2.5% fmt.(*fmt).padString

  15: (pprof)

top命令可以看最耗時的function。它的輸出格式各欄位的含義依次是：

1. 採樣點落在該函數中的次數
2. 採樣點落在該函數中的百分比
3. 上一項的累積百分比
4. 採樣點落在該函數，以及被它調用的函數中的總次數
5. 採樣點落在該函數，以及被它調用的函數中的總次數百分比
6. 函數名

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

當然我們也可以用下面方式來查看各個函數/方法的記憶體消耗排名。

D:\gocodes\src\logDemo>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:\gocodes\src\logDemo>

使用圖表展示

如果想不僅看到各個方法/函數的記憶體消耗排名，還想看到它們之間的調用關係，那就需要安裝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.36\bin 需要把它設定到 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:\gocodes\src\logDemo>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:\Users\GUOHON~1\AppData\Local\Temp\m9inAYN4pq.0.svg 
'uname' 不是內部或外部命令，也不是可啟動並執行程式 
或批次檔。 
系統找不到指定的路徑。 
系統找不到指定的路徑。 
'google-chrome' 不是內部或外部命令，也不是可啟動並執行程式 
或批次檔。 
'firefox' 不是內部或外部命令，也不是可啟動並執行程式 
或批次檔。 
Could not load web browser. 
(pprof)

原文連結地址 http://blog.csdn.net/susubuhui/article/details/39117763

 

忽略傳回值時需要注意，尤其當傳回值為指標類型時，若傳回值會分配記憶體，迴圈調用時，會導致重複分配記憶體卻不能釋放