search

zshuangyan / blog

我的个人博客
2 stars 0 forks source link

使用pprof定位golang程序 #34

Open zshuangyan opened 5 years ago

zshuangyan commented 5 years ago

工作中我们常常会遇到程序占用cpu过高，内存过高等问题，光从代码层面很难快速排查到导致问题的原因，这个时候就需要知道程序在执行时，cpu和内存主要被哪些函数消耗了。不同的语言有不同的定位手段，这里主要介绍golang的进程定位工具pprof.

pprof集成在golang的内置包中，如果要使用pprof，得先在程序里边导入这个包

import _ "net/http/pprof"

然后确保程序监听到某个端口号上，接收http请求

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

  1. 查看系统的内存，cpu, 阻塞，锁的统计情况，通过/debug/pprof/路径 image

  2. 查看完整的goroutine堆栈，通过/debug/pprof/goroutine?debug=2路径 image

  3. 查看cpu的统计信息

    [zhangshuangyan@gs-server-5693 ~]$ go tool pprof http://localhost:6031/debug/pprof/profile?seconds=30
Fetching profile over HTTP from http://localhost:6031/debug/pprof/profile?seconds=30
Saved profile in /home/zhangshuangyan@gridsum.com/pprof/pprof.falcon-hbs.samples.cpu.004.pb.gz
File: falcon-hbs
Type: cpu
Time: Apr 9, 2019 at 4:36pm (CST)
Duration: 30s, Total samples = 180ms (  0.6%)
Entering interactive mode (type "help" for commands, "o" for options)
(pprof) top10 
Showing nodes accounting for 180ms, 100% of 180ms total
Showing top 10 nodes out of 85
  flat  flat%   sum%        cum   cum%
  90ms 50.00% 50.00%       90ms 50.00%  syscall.Syscall /usr/local/go/src/syscall/asm_linux_amd64.s
  30ms 16.67% 66.67%       30ms 16.67%  runtime.futex /usr/local/go/src/runtime/sys_linux_amd64.s
  10ms  5.56% 72.22%       10ms  5.56%  internal/poll.(*FD).writeUnlock /usr/local/go/src/internal/poll/fd_mutex.go
  10ms  5.56% 77.78%      100ms 55.56%  net.(*conn).Write /usr/local/go/src/net/net.go
  10ms  5.56% 83.33%       10ms  5.56%  runtime.duffzero /usr/local/go/src/runtime/duff_amd64.s
  10ms  5.56% 88.89%       10ms  5.56%  runtime.mallocgc /usr/local/go/src/runtime/malloc.go
  10ms  5.56% 94.44%       10ms  5.56%  runtime.mallocgc /usr/local/go/src/runtime/mheap.go
  10ms  5.56%   100%       10ms  5.56%  runtime.readvarint /usr/local/go/src/runtime/symtab.go
     0     0%   100%       10ms  5.56%  database/sql.(*DB).Exec /usr/local/go/src/database/sql/sql.go
     0     0%   100%       10ms  5.56%  database/sql.(*DB).ExecContext /usr/local/go/src/database/sql/sql.go

    我们可以看到，执行go tool pprof http://:/debug/pprof/profile后，会把结果保存在当前用户home目录下的pprof目录中，并且进入交互模式，可以输入top10查看最耗cpu的十个函数。

我们也可以使用go tool pprof -top [main_binary] profile.pb.gz 来查看

[zhangshuangyan@gs-server-5693 ~]$ go tool pprof -top /opt/falcon/hbs/bin/falcon-hbs /home/zhangshuangyan@gridsum.com/pprof/pprof.falcon-hbs.samples.cpu.004.pb.gz
File: falcon-hbs
Type: cpu
Time: Apr 9, 2019 at 4:36pm (CST)
Duration: 30s, Total samples = 180ms (  0.6%)
Showing nodes accounting for 180ms, 100% of 180ms total
      flat  flat%   sum%        cum   cum%
      90ms 50.00% 50.00%       90ms 50.00%  syscall.Syscall /usr/local/go/src/syscall/asm_linux_amd64.s
      30ms 16.67% 66.67%       30ms 16.67%  runtime.futex /usr/local/go/src/runtime/sys_linux_amd64.s
      10ms  5.56% 72.22%       10ms  5.56%  internal/poll.(*FD).writeUnlock /usr/local/go/src/internal/poll/fd_mutex.go
      10ms  5.56% 77.78%      100ms 55.56%  net.(*conn).Write /usr/local/go/src/net/net.go
      10ms  5.56% 83.33%       10ms  5.56%  runtime.duffzero /usr/local/go/src/runtime/duff_amd64.s
      10ms  5.56% 88.89%       10ms  5.56%  runtime.mallocgc /usr/local/go/src/runtime/malloc.go
      10ms  5.56% 94.44%       10ms  5.56%  runtime.mallocgc /usr/local/go/src/runtime/mheap.go
      10ms  5.56%   100%       10ms  5.56%  runtime.readvarint /usr/local/go/src/runtime/symtab.go
...

除了top以外，还支持其他查看选项，可以参照go tool pprof -h

  1. 查看内存的统计信息

    [zhangshuangyan@gs-server-5693 ~]$ go tool pprof http://localhost:6031/debug/pprof/heap
Fetching profile over HTTP from http://localhost:6031/debug/pprof/heap
Saved profile in /home/zhangshuangyan@gridsum.com/pprof/pprof.falcon-hbs.alloc_objects.alloc_space.inuse_objects.inuse_space.003.pb.gz
File: falcon-hbs
Type: inuse_space
Time: Apr 9, 2019 at 4:52pm (CST)
Entering interactive mode (type "help" for commands, "o" for options)
(pprof) top10
Showing nodes accounting for 5153.48kB, 100% of 5153.48kB total
Showing top 10 nodes out of 19
  flat  flat%   sum%        cum   cum%
3076.50kB 59.70% 59.70%  3076.50kB 59.70%  encoding/json.(*Decoder).refill /usr/local/go/src/encoding/json/stream.go
1024.44kB 19.88% 79.58%  1024.44kB 19.88%  net/rpc/jsonrpc.NewServerCodec /usr/local/go/src/net/rpc/jsonrpc/client.go
540.51kB 10.49% 90.06%   540.51kB 10.49%  github.com/open-falcon/falcon-plus/modules/hbs/db.QueryHosts /home/zhangshuangyan@gridsum.com/go/src/github.com/open-falcon/falcon-plus/modules/hbs/db/host.go
512.03kB  9.94%   100%   512.03kB  9.94%  syscall.anyToSockaddr /usr/local/go/src/syscall/syscall_linux.go
     0     0%   100%  3076.50kB 59.70%  encoding/json.(*Decoder).Decode /usr/local/go/src/encoding/json/stream.go
     0     0%   100%  3076.50kB 59.70%  encoding/json.(*Decoder).readValue /usr/local/go/src/encoding/json/stream.go
     0     0%   100%   540.51kB 10.49%  github.com/open-falcon/falcon-plus/modules/hbs/cache.(*SafeHostMap).Init /home/zhangshuangyan@gridsum.com/go/src/github.com/open-falcon/falcon-plus/modules/hbs/cache/hosts.go
     0     0%   100%   540.51kB 10.49%  github.com/open-falcon/falcon-plus/modules/hbs/cache.LoopInit /home/zhangshuangyan@gridsum.com/go/src/github.com/open-falcon/falcon-plus/modules/hbs/cache/cache.go
     0     0%   100%  1536.47kB 29.81%  github.com/open-falcon/falcon-plus/modules/hbs/rpc.Start /home/zhangshuangyan@gridsum.com/go/src/github.com/open-falcon/falcon-plus/modules/hbs/rpc/rpc.go
     0     0%   100%   512.03kB  9.94%  internal/poll.(*FD).Accept /usr/local/go/src/internal/poll/fd_unix.go

  2. 查看阻塞的统计信息 go tool pprof http://:/debug/pprof/block

  3. 查看锁的统计信息 go tool pprof http://:/debug/pprof/mutex