引言

某日,需要给云主机添加端口映射时,发现一个核上的CPU使用率100%,后经过初步排除,确定是自己的IM开源项目(im_gate)进程引起,怪不得MAC上电脑很卡。
通过度娘后,学习到go 自带pprof可以进行cpu和内存泄漏方面等的分析,经过一顿调查后成功找到了问题,总共耗费不到1个小时,为Golang的生态点赞👍👍👍。

我的开源项目在这里:

CoffeeChat。参考了TeamTalk、瓜子IM等知名项目,包含服务端(go)和客户端(flutter),单聊和机器人(小微、图灵、思知)聊天功能已完成,目前正在研发群聊功能,欢迎对golang和跨平台开发flutter技术感兴趣的小伙伴Star加关注

CPU

生成profile文件

go中有pprof包来做代码的性能监控:

  • net/http/pprof
  • runtime/pprof

其实net/http/pprof中只是使用runtime/pprof包来进行封装了一下,并在http端口上暴露出来。对于非Web类应用,使用runtime/pprof包。

关键代码:

f, err := os.OpenFile("cpu.prof", os.O_RDWR|os.O_CREATE, 0644)
if err != nil {
    fmt.Fatal(err)
    return
}
pprof.StartCPUProfile(f)

// 退出时调用
f.Close()
pprof.StopCPUProfile()

完整代码如下:

import "runtime/pprof"

var f *os.File

// 优雅退出
func waitExit(c chan os.Signal) {
    for i := range c {
        switch i {
        case syscall.SIGHUP, syscall.SIGINT, syscall.SIGTERM, syscall.SIGQUIT:
            logger.Sugar.Info("receive exit signal ", i.String(), ",exit...")

            // CPU 性能分析
            f.Close()
            pprof.StopCPUProfile()

            os.Exit(0)
        }
    }
}

func main(){
    //CPU 性能分析
    f, err := os.OpenFile("cpu.prof", os.O_RDWR|os.O_CREATE, 0644)
    if err != nil {
        logger.Sugar.Fatal(err)
        return
    }
    pprof.StartCPUProfile(f)

    // to do
    // your code

    // before exit, cleanup something ...
    c := make(chan os.Signal)
    signal.Notify(c, syscall.SIGHUP, syscall.SIGINT, syscall.SIGTERM,   syscall.SIGQUIT)
    waitExit(c)
}

按住Ctrl+C(linux/mac)后,在同目录下应该生成了cpu.prof的文件。

meki-mac-pro:im_gate xuyc$ ls
cpu.prof          gate.go           log
gate-example.toml im_gate           server.pid

使用pprof工具分析

go自带了pprof工具,使用如下命令查看:

go tool pprof im_gate cpu.prof # im_gate 是程序名字

然后输入top命令(help命令查看更多功能),查看前CPU占用率TOP10,如下:

meki-mac-pro:im_gate xuyc$ go tool pprof im_gate cpu.prof
File: im_gate
Type: cpu
Time: Jan 11, 2020 at 6:58pm (CST)
Duration: 4.66s, Total samples = 4.26s (91.38%)
Entering interactive mode (type "help" for commands, "o" for options)

(pprof) top # 这里是输入的top命令
Showing nodes accounting for 4250ms, 99.77% of 4260ms total
Dropped 5 nodes (cum <= 21.30ms)
      flat  flat%   sum%        cum   cum%
    1520ms 35.68% 35.68%     1520ms 35.68%  runtime.chanrecv
    1470ms 34.51% 70.19%     4030ms 94.60%  github.com/CoffeeChat/server/src/internal/gate/tcpserver.init.0.func1
    1040ms 24.41% 94.60%     2560ms 60.09%  runtime.selectnbrecv
     220ms  5.16% 99.77%      220ms  5.16%  runtime.nanotime
         0     0% 99.77%      220ms  5.16%  runtime.mstart
         0     0% 99.77%      220ms  5.16%  runtime.mstart1
         0     0% 99.77%      220ms  5.16%  runtime.sysmon
(pprof)

当然也可以使用png命令生成图片,使用前需安装graphviz:

brew install graphviz # mac 安装 graphviz

输出:

(pprof)
(pprof) png  # 这里 在pprof命令行中输入的web命令
(pprof) exit
meki-mac-pro:im_gate xuyc$ ls
cpu.prof          gate.go           log               server.pid
gate-example.toml im_gate           profile001.png


一目了然找到了CPU空转的地方:
github.com/CoffeeChat/server/src/internal/gate/tcpserver.init.0.func1

参考

https://www.cnblogs.com/yjf512/archive/2012/12/27/2835331.html
golang cpu性能图形分析工具:https://blog.csdn.net/Vivid_110/article/details/100561459
使用pprof分析cpu占用过高问题:https://studygolang.com/articles/21841?fr=sidebar
使用go tool pprof分析内存泄漏、CPU消耗:https://www.cnblogs.com/ghj1976/p/5473693.html