Go 自带的 pprof

Web程序

只要添加如下代码即可:

package main

import (
	_ "net/http/pprof"
)


func main() {

}

这样子添加后,就可以在 http://127.0.0.1:8080/debug/pprof (假设是监听在8080端口)查看性能数据了.

生成数据

这个是启动30秒内收集数据的:输入命令后,要停留在收集状态,(这时,可以启动你的压测工具压它),30秒后,就会自动进入交互状态.

go tool pprof 你的二进制文件名 http://127.0.0.1:8080/debug/pprof/profile

注意,那个参数 你的二进制文件名 是用来查看相应的源码的。否则的话,它会以下这些类似的错误。

No source information for ....

查看各方法耗时

进入交互状态后,TOP的输出格式:(查看耗时)

flat  flat%   sum%        cum   cum%
2720ms 18.01% 18.01%     2880ms 19.07%  syscall.Syscall

查看具体某方法耗时

list 方法名的输出格式:

(pprof) list GetAdinfoRedis
Total: 15.10s
ROUTINE ======================== service.GetAdinfoRedis in /home/sky/go-dsp/src/service/AdInfoCache.go
      30ms      1.14s (flat, cum)  7.55% of Total
         .          .     29:	if con.Err() != nil {
         .          .     30:		logrus.Errorf("get redis con error :%v", con.Err())
         .          .     31:		return
         .          .     32:	}
         .          .     33:	key := constant.AdInfo + crtid
      10ms      320ms     34:	v, err := con.Do("GET", key)
         .          .     35:
      10ms       20ms     36:	value, err := redis.String(v, err)
         .          .     37:
         .          .     38:	if err != nil {
         .          .     39:		logrus.Warnf("GetAdinfoRedis invald data : %v, error=%v", v, err.Error())
         .          .     40:		return
         .          .     41:	}
         .          .     42:
         .          .     43:	if len(value) == 0 {
         .          .     44:		return
         .          .     45:	}
         .       30ms     46:	adinfo = new(bean.AdInfo)
         .      690ms     47:	err = json.Unmarshal([]byte(value), adinfo)
         .          .     48:	if err != nil {
         .          .     49:		logrus.Errorf("unmarshal data [%v] to type adinfo error ", err.Error())
         .          .     50:	}
      10ms       80ms     51:	return
         .          .     52:}
         .          .     53:
         .          .     54:// SetAdInfoLocal :
         .          .     55:func SetAdInfoLocal(adInfo *bean.AdInfo) {
         .          .     56:	MemoryCache.Set(constant.AdInfo+adInfo.CreativeID, *adInfo, goCache.NoExpiration)
(pprof) 

flat: 表示该方法自身(不包括调用其他方法)在取样总时间内的总耗时 cum:表示该方法(包括调用其他方法)的总耗时)在取样总时间内的总耗时

查看调用关系耗时

(pprof) peek GetAdinfoRedis
12s of 15.10s total (79.47%)
Dropped 392 nodes (cum <= 0.08s)
----------------------------------------------------------|-------------
      flat  flat%   sum%        cum   cum%   calls calls% + context 	 	 
----------------------------------------------------------|-------------
                                             1.14s   100% |   service.isAdInfoMatch
     0.03s   0.2%   0.2%      1.14s  7.55%                | service.GetAdinfoRedis
                                             0.68s 62.96% |   encoding/json.Unmarshal
                                             0.31s 28.70% |   github.com/garyburd/redigo/redis.(*pooledConnection).Do
                                             0.06s  5.56% |   github.com/garyburd/redigo/redis.(*pooledConnection).Close
                                             0.03s  2.78% |   runtime.newobject
----------------------------------------------------------|-------------
(pprof) 

在浏览器中查看list

输入weblist确定即可

普通应用程序

import (
    "runtime/pprof"
)

func main(){
    pprof.StartCPUProfile(要写到CPU分析的文件)
    pprof.WriteHeapProfile(要写到的内存分析的文件)
    defer pprof.StopCPUProfile()


}

查看:goo tool pprof AppName /path/to/pro文件。 更多命令: go tool pprof -h

图形化查看

sudo apt-get install kcachegrind

进入以上的交互式命令,可以看到有一个callgrind命令。使用方式:

在go tool pprof的交互式命令行里输入:
callgrind > /tmp/prof.grind


然后在另一个普通bash(zsh)里输入:

kcachegrind /tmp/prof.grind

即可看到图形了

可以pprof的url

trace

30秒收集 trace 的数据:
curl http://127.0.0.1:9090/debug/pprof/trace\?seconds\=30 > /tmp/trace.data

然后查看:
go tool trace -http=":9999" main /tmp/trace.data

heap

go tool pprof http://127.0.0.1:9090/debug/pprof/heap

profile

go tool pprof http://127.0.0.1:8080/debug/pprof/profile

其他

http://127.0.0.1:9090/debug/pprof/threadcreate

http://127.0.0.1:9090/debug/pprof/block
````

## GC 日志 

### 收集日志

```bash
 GODEBUG="gctrace=1" ./main 2>/tmp/go-gc.log

日志格式

更多信息,参考官方文档 golang runtime

gc 99 @5065.785s 0%: 0.006+1.1+0.23 ms clock, 0.026+0/1.0/3.2+0.93 ms cpu, 6->6->6 MB, 13 MB goal, 4 P

gc 99:表示第99次GC

@5065.785s : 从程序开始启动到现在的时间,单位为秒

0% : 从程序启动以来,GC时间占用的百分比

0.006+1.1+0.23 ms clock : GC阶段的时钟数

0.026+0/1.0/3.2+0.93 ms cpu : GC阶段CPU时间

6->6->6 MB : GC开始时堆的大小/GC结束时堆的大小/存活的堆大小

13 MB goal : 目标堆大小(总大小,包括垃圾对象)

4 P:该次GC使用的CPU核心数

GODEBUG

查看调度器

GOMAXPROCS=设置你的核数 GODEBUG=schedtrace=N(单位是毫秒,即每N毫秒输出一次) ./main 

查看更详细

GOMAXPROCS=设置你的核数 GODEBUG=schedtrace=1000,scheddetail=1 ./main

参考来源