记一次golang服务cpu占用过高排查过程

一开始直接top查看，发现pid=1334434的cpu占用过高

PID USER      PR  NI    VIRT    RES    SHR S  %CPU %MEM     TIME+ COMMAND
1334434 root      20   0  493548  72236  28496 S 199.7  0.9   0:10.76 meetingBuyServi
1096315 root      20   0    2276   1236    948 S   1.0  0.0 120:01.83 bash
2373218 root      20   0 3849676   1.1g   3624 S   0.7 14.9 276:26.00 java

然后直接在main里接入pprof

import(
    "net/http"
    _ "net/http/pprof"
)

func main(){
....
     go func() {
       log.Println(http.ListenAndServe(":6060", nil))
    }()
}

编译发布到测试环境

本机执行go tool pprof http://x.x.x.x:6060/debug/pprof/profile

这个时候等待采集数据，这里需要注意到是，如果采集期间你的cpu没占满，采集结果是无法分析cpu的问题的。刚好我的这个服务一启动就是将cpu占满的

等待30秒左右后
自动进入pprof

(pprof) top10
Showing nodes accounting for 59.84s, 99.93% of 59.88s total
Dropped 19 nodes (cum <= 0.30s)
      flat  flat%   sum%        cum   cum%
    26.64s 44.49% 44.49%     26.64s 44.49%  sync.(*Mutex).Lock
    22.01s 36.76% 81.25%     22.01s 36.76%  sync.(*Mutex).Unlock
     6.37s 10.64% 91.88%      6.37s 10.64%  net.(*UDPConn).ReadFrom
     4.82s  8.05% 99.93%     59.84s 99.93%  github.com/micro/go-micro/v2/util/mdns.(*Server).recv

(pprof) traces
Type: cpu
Time: Jul 21, 2020 at 11:00am (CST)
Duration: 30.14s, Total samples = 59.88s (198.64%)
-----------+-------------------------------------------------------
    20.98s   sync.(*Mutex).Unlock
             github.com/micro/go-micro/v2/util/mdns.(*Server).recv
-----------+-------------------------------------------------------
       23s   sync.(*Mutex).Lock
             github.com/micro/go-micro/v2/util/mdns.(*Server).recv
-----------+-------------------------------------------------------
     1.17s   net.(*UDPConn).ReadFrom
             github.com/micro/go-micro/v2/util/mdns.(*Server).recv
-----------+-------------------------------------------------------
     1.03s   sync.(*Mutex).Unlock
             github.com/micro/go-micro/v2/util/mdns.(*Server).recv
-----------+-------------------------------------------------------
     950ms   github.com/micro/go-micro/v2/util/mdns.(*Server).recv
-----------+-------------------------------------------------------
     1.04s   sync.(*Mutex).Lock
             github.com/micro/go-micro/v2/util/mdns.(*Server).recv
-----------+-------------------------------------------------------
     1.43s   net.(*UDPConn).ReadFrom
             github.com/micro/go-micro/v2/util/mdns.(*Server).recv
-----------+-------------------------------------------------------
      10ms   runtime.sysmon
-----------+-------------------------------------------------------
     1.07s   github.com/micro/go-micro/v2/util/mdns.(*Server).recv
-----------+-------------------------------------------------------
     1.55s   net.(*UDPConn).ReadFrom
             github.com/micro/go-micro/v2/util/mdns.(*Server).recv
-----------+-------------------------------------------------------
     1.50s   sync.(*Mutex).Lock
             github.com/micro/go-micro/v2/util/mdns.(*Server).recv
-----------+-------------------------------------------------------
     1.03s   net.(*UDPConn).ReadFrom
             github.com/micro/go-micro/v2/util/mdns.(*Server).recv
-----------+-------------------------------------------------------
     1.44s   github.com/micro/go-micro/v2/util/mdns.(*Server).recv
-----------+-------------------------------------------------------
     1.10s   sync.(*Mutex).Lock
             github.com/micro/go-micro/v2/util/mdns.(*Server).recv
-----------+-------------------------------------------------------
     1.19s   net.(*UDPConn).ReadFrom
             github.com/micro/go-micro/v2/util/mdns.(*Server).recv
-----------+-------------------------------------------------------
     1.35s   github.com/micro/go-micro/v2/util/mdns.(*Server).recv
-----------+-------------------------------------------------------
      10ms   github.com/micro/go-micro/v2/util/mdns.(*Server).recv

发现cpu都在处理lock,找到问题，然后解决问题即可