我写的一个服务,有段时间CPU占用一直是100%。因为一直在开发环境,还没上线,今天终于有时间了就排查了一下。100%这种占用,一看就感觉是某个for循环导致的。
首先,选择分析工具,Golang的性能分析工具pprof。
在Gin这个框架中,需要通过注册才可以使用。
方式
if ok, _ := strconv.ParseBool(utils.GetEnv("DEVELOP_MODE")); ok {
pprof.Register(router)
}
我们用了一个环境变量DEVELOP_MODE来控制,这样子方便控制是否打开调试,因为这个东西一旦开启会对性能有影响。
如果不是用的gin框架,那么直接导入包import _ "net/http/pprof"
就会打开调试,为啥呢?因为pprof/pprof.go文件是这么写的,只要程序启动,导入后,该包就会被扫描到,然后就会默认加载以下几项debug工具。
func init() {
http.HandleFunc("/debug/pprof/", Index)
http.HandleFunc("/debug/pprof/cmdline", Cmdline)
http.HandleFunc("/debug/pprof/profile", Profile)
http.HandleFunc("/debug/pprof/symbol", Symbol)
http.HandleFunc("/debug/pprof/trace", Trace)
}
还有其他几个没有列出来,比如以下的几项,这些是在Index函数里加载进来的。
profiles.m = map[string]*Profile{
"goroutine": goroutineProfile,
"threadcreate": threadcreateProfile,
"heap": heapProfile,
"allocs": allocsProfile,
"block": blockProfile,
"mutex": mutexProfile,
}
好了,废话不多说。启动性能调试,我们是CPU占用,所以要使用profile模式来定位cpu占用的问题,它会收集30s左右的运行数据。
命令行输入以下命令:go tool pprof http://xxxx:port/debug/pprof/profile
等待30s后会进入交互模式,支持的命令可以通过输入help来查看。
这里我们输入top
如下
top命令输出5个字段,如下
- flat 本函数的执行耗时
- flat% flat占 CPU 总时间的比例。程序总耗时 16.22s, Eat 的 16.19s 占了 99.82%
- sum% 前面每一行的 flat 占比总和
- cum 累计量。指该函数加上该函数调用的函数总耗时
- cum% cum 占 CPU 总时间的比例
如果命令看起来不够装逼,go还提供了可视化的工具。我们只要输入web这个命令,就能得到一张svg图,可通过浏览器打开,如下图所示。
如果说top命令不够直观,那么这张图,就能看出来了吧,我们的程序20.19秒内一直在调用selectgo
。看这张图,是不是对于golang里select channel
的有了那么一些了解了。看起来select耗时里最多的还是加解锁selunlock
、sellock
,然后就是hchan的排序sortkey。
扯远了,有时间要好好研究一下golang的select实现。回到问题本身,调用selectgo的是我们的程序里一个叫handleXXEvent的for select语句。这个语句我咋写的呢,类似如下的代码
for {
select {
case x1 <- sss:
// go do something
case x2 <- ss:
// go do something
default:
}
我们知道select具有轮询多个channel的功能,如果有事件进来,就走,否则就block住。但是有default的话,没有事件就会走default。外面有一个for循环,所以就造成了cpu满载空转的问题。删除default就好了,select就会block在那里,等待io。