程序各种指标
是指程序中己动态分配的堆内存由于某种原因程序未释放或无法释放,造成系统内存的浪费,导致程序运行速度减慢甚至系统崩溃等严重后果。在程序中一个不小心的操作可能会导致内存泄漏,但是写程序的人可能根本没有意识到,所以我们要对我们的项目做测试,检查程序那些地方的内存没有被回收导致了内存的泄漏。
好在golang为我们提供了pprof包,通过它的HTTP服务端提供pprof可视化工具期望格式的运行时剖面文件数据服务。关于pprof的更多信息,参见http://code.google.com/p/google-perftools/。
- 如果你的程序是web程序
- 在没有使用任何框架的前提下,在程序中导入import _ "net/http/pprof",然后同样监听本地的一个端口http.ListenAndServe("localhost:6060", nil),即可,启动程序,你可以访问localhost:6060/debug/pprof监控页面,大致样子是:
/debug/pprof/
profiles:
0block
7goroutine
86heap
0mutex
13threadcreate
full goroutine stack dump
- 如果你使用了其他的go-web框架,那么也可以自己添加路由"/debug/pprof/profile,handler方法即使用net/http/pprof下的方法即可。
gin-web框架的/debug/pprof可以参考:github.com/DeanThompson/ginpprof
net/http/pprof下的方法有很多个,都是为我们提供程序运行的一些参数的,你可以在$GOROOT/src/net/http/pprof下查看。/net/http/pprof其实也只是对/runtime/pprof的一层封装而已
- 如果你的程序不是web程序
- 同时也不想开一个端口来获得程序运行时的cpu,内存和其他的一些参数。那么可以直接使用/runtime/下的一些包
import (
"runtime/pprof"
"log"
)
func main() {
f, err := os.OpenFile("cpu.prof", os.O_RDWR|os.O_CREATE, 0644)
if err != nil {
log.Fatal(err)
}
defer f.Close()
/**
省略操作
*/
pprof.StartCPUProfile(f)
defer pprof.StopCPUProfile()
}
os.O_CREATE表示该文件不存在则创建,运行这个程序后就会在该目录下生成一个cpu.prof文件
现在使用go tool pprof来分析这个prof文件。
pprof分析.prof文件命令为:go tool pprof <程序名称> <.prof文件路径>
然后进入pprof的控制台,输入help会得到一些常用命令,如top 10。
更多命令以及其中的含义可以参见:go tool pprof
进一步分析(svg)
安装FlameGraph
git clone https://github.com/brendangregg/FlameGraph.git
cp FlameGraph/flamegraph.pl /usr/local/bin
然后执行命令flamegraph.pl -h查看是否有help信息表明是否安装成功
web浏览
假设现在已经启动了一个web程序,然后我们开一个终端用命令go tool pprof --seconds 25 http://localhost:8080/debug/pprof/profile设置采样时间和路径,再开一个终端用wrk压测工具:压测30s,其他参数自定义。等到时间结束后,在第一个终端那里会出现(pprof),这和之前分析.prof文件效果是一样的,不同的是这里没有生成文件。然后我们输入命令web——表示用web浏览器打开。如果出现如下提示
Failed to execute dot. Is Graphviz installed? Error: exec: "dot": executable file not found in$PATH
此时可用如下命令安装Graphviz
sudo apt install graphviz
然后再次输入web,那么会在web页面看到
这是一个很简单程序生成的svg图都这么多内容,难以想象一个复杂的程序读这样的图时该从哪个地方下手,找出部分函数的cpu使用超标,内存使用超标来进行性能的优化。
更加直观的火焰图go-torch
go-torch是Uber开发的一个工具,它的github地址
go get github.com/uber/go-torch
go install github.com/uber/go-torch
即可完成go-torch的安装
- 现在打开一个终端,运行go-torch
- 另开一个终端,再次使用wrk压测工具压测30s等到时间结束之后,大致可以在go-torch的目录下看到这样的信息
INFO[21:37:37] Run pprof command: go tool pprof -raw -seconds 30 http://localhost:8080/debug/pprof/profile
INFO[21:38:08] Writing svg to torch.svg
对于这个torch.svg,使用浏览器打开,效果如下:
- 每一个小方块都是可以点击查看详细信息
- y轴表示cpu调用方法的先后
- x轴表示在每个采样调用时间内,方法所占的时间百分比,越宽代表占据cpu时间越多。
trace
前面讲的pprof适合于跟踪运行缓慢的函数,或者找到大部分CPU时间花费在哪里,并且显示在每个函数中花费的CPU时间的百分比;而trace则更适合于找出程序在一段时间内正在做什么,而不是总体上的开销。
func main() {
f, err := os.Create("trace.out")
if err != nil {
panic(err)
}
defer f.Close()
err = trace.Start(f)
if err != nil {
panic(err)
}
defer trace.Stop()
//每10s执行一次GC
t1 := time.NewTicker(time.Second * 10)
go func() {
for {
select {
case <-t1.C:
log.Println("runtime.gc()")
runtime.GC()
}
}
}()
// Your logic code here
}
- 这是代码的一部分,当程序运行起来之后,每隔10s就会向trace.out中写入gc的信息。
- 如果你想在控制台看到gc的信息,可以运行如下命令
go build yourProgram
GODEBUG=gctrace=1 ./yourProgram
控制台打印信息类似于
gc 1 @10.003s 0%: 0.086+1.2+0.026 ms clock, 0.25+0/1.2/0+0.078 ms cpu, 1->1->0 MB, 4 MB goal, 4 P (forced)
gc 2 @20.003s 0%: 0.061+0.44+0.016 ms clock, 0.18+0/0.42/0.41+0.050 ms cpu, 0->0->0 MB, 4 MB goal, 4 P (forced)
scvg0: inuse: 1, idle: 1, sys: 2, released: 0, consumed: 2 (MB)
控制台打印信息的说明
- gc后面的数字表示第几次执行gc
- 0%表示表示垃圾回收时间占用的百分比
- 0.086+1.2+0.026ms clock表示垃圾回收的时间。分别为STW(stop-the-world)清扫的时间, 并发标记和扫描的时间,STW标记的时间
- 0.25+0/1.2/0+0.078 ms cpu表示垃圾回收占用cpu时间
- 1->1->0 MB表示堆的大小,gc后堆的大小,存活堆的大小
- 4 MB goal表示整体堆的大小
- 4 P表示处理器的数量
- 系统内存回收信息
scvg0: inuse: 1, idle: 1, sys: 2, released: 0, consumed: 2 (MB)
inuse:使用多少M内存
idle:剩下要清除的内存
sys:系统映射的内存
released:释放的系统内存
consumed:申请的系统内存
- 或者使用go tool trace分析trace.out文件,看看gc更加详细的情况
go tool trace -http="localhost:8888" <yourProgramName> trace.out
该命令在go1.6以下的版本中需要<yourProgramName>参数,即可运行的二进制文件,在go1.6之后的版本则不再需要这个参数。
现在你可以访问localhost:8888看看trace文件中都记录了什么内容,访问localhost:8888/trace即可看到更详细的信息。
- 上述代码是直接在程序中生成trace.out二进制文件,如果你为trace开通了http服务,那么直接运行如下命令可进行10s的采样数据
curl 127.0.0.1:port/debug/pprof/trace?seconds=10 trace.data
如果提示curl(6)错误,那么你可以直接在浏览器访问localhost:port/debug/pprof/trace?seconds=10也会得到相应的采样数据,获得采样数据之后可以利用上述步骤分析trace文件