go pprof
susubuhui · · 7138 次点击 · · 开始浏览runtime/pprof
我们要加入对pprof包里的方法调用,程序才能将运行时候程序的堆内存分配状态记录到文件(也可以是写到其他地方,例如网络等)中,以便进一步的分析.
如果你的go程序只是一个应用程序,比如计算fabonacci数列,那么你就不能使用net/http/pprof包了,你就需要使用到runtime/pprof。具体做法就是用到pprof.StartCPUProfile和pprof.StopCPUProfile。(Go语言的pprof是Google C++ profiler的移植.)
比如下面的例子:
1:
2: import (
3: "flag"
4: "fmt"
5: "os"
6: "runtime/pprof"
7: )
8:
9: var cpuprofile = flag.String("cpuprofile", "", "write cpu profile to file")
10:
11: func main() {
12:
13: flag.Parse()
14: if *cpuprofile != "" {
15: f, err := os.Create(*cpuprofile)
16: if err != nil {
17: fmt.Println(err)
18: }
19: pprof.StartCPUProfile(f)
20: defer pprof.StopCPUProfile()
21: }
22: // ...
23: }
运行程序的时候加一个--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。它的输出格式各字段的含义依次是:
- 采样点落在该函数中的次数
- 采样点落在该函数中的百分比
- 上一项的累积百分比
- 采样点落在该函数,以及被它调用的函数中的总次数
- 采样点落在该函数,以及被它调用的函数中的总次数百分比
- 函数名
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环境变量中。
生成图表展示的方法:
- 使用
go tool pprof your-executable-name --dot profile-filename> heap.gv命令生成可以在graphviz里面看的gv文件,在查看各个方法/函数的内存消耗的同时查看它们之间的调用关系 - 生成了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)
有疑问加站长微信联系(非本文作者)
入群交流(和以上内容无关):加入Go大咖交流群,或添加微信:liuxiaoyan-s 备注:入群;或加QQ群:692541889
关注微信- 请尽量让自己的回复能够对别人有帮助
- 支持 Markdown 格式, **粗体**、~~删除线~~、
`单行代码` - 支持 @ 本站用户;支持表情(输入 : 提示),见 Emoji cheat sheet
- 图片支持拖拽、截图粘贴等方式上传
收入到我管理的专栏 新建专栏
runtime/pprof
我们要加入对pprof包里的方法调用,程序才能将运行时候程序的堆内存分配状态记录到文件(也可以是写到其他地方,例如网络等)中,以便进一步的分析.
如果你的go程序只是一个应用程序,比如计算fabonacci数列,那么你就不能使用net/http/pprof包了,你就需要使用到runtime/pprof。具体做法就是用到pprof.StartCPUProfile和pprof.StopCPUProfile。(Go语言的pprof是Google C++ profiler的移植.)
比如下面的例子:
1:
2: import (
3: "flag"
4: "fmt"
5: "os"
6: "runtime/pprof"
7: )
8:
9: var cpuprofile = flag.String("cpuprofile", "", "write cpu profile to file")
10:
11: func main() {
12:
13: flag.Parse()
14: if *cpuprofile != "" {
15: f, err := os.Create(*cpuprofile)
16: if err != nil {
17: fmt.Println(err)
18: }
19: pprof.StartCPUProfile(f)
20: defer pprof.StopCPUProfile()
21: }
22: // ...
23: }
运行程序的时候加一个--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。它的输出格式各字段的含义依次是:
- 采样点落在该函数中的次数
- 采样点落在该函数中的百分比
- 上一项的累积百分比
- 采样点落在该函数,以及被它调用的函数中的总次数
- 采样点落在该函数,以及被它调用的函数中的总次数百分比
- 函数名
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环境变量中。
生成图表展示的方法:
- 使用
go tool pprof your-executable-name --dot profile-filename> heap.gv命令生成可以在graphviz里面看的gv文件,在查看各个方法/函数的内存消耗的同时查看它们之间的调用关系 - 生成了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)