|
sp; 1.20GB 100% runtime.main
?
查看到占用1G多的内存
内存回收
go tool pprof http://localhost:6060/debug/pprof/allocs
top
(pprof) top
Showing nodes accounting for 592MB, 99.75% of 593.50MB total
Dropped 16 nodes (cum <= 2.97MB)
flat flat% sum% cum cum%
592MB 99.75% 99.75% 592MB 99.75% github.com/wolfogre/go-pprof-practice/animal/canidae/dog.(*Dog).Run (inline)
0 0% 99.75% 592MB 99.75% github.com/wolfogre/go-pprof-practice/animal/canidae/dog.(*Dog).Live
0 0% 99.75% 592MB 99.75% main.main
0 0% 99.75% 592.50MB 99.83% runtime.main
?
可以看到 github.com/wolfogre/go-pprof-practice/animal/canidae/dog.(*Dog).Run 会进行无意义的内存申请，而这个函数又会被频繁调用，这才导致程序不停地进行 GC:
func (d *Dog) Run() {
log.Println(d.Name(), "run")
_ = make([]byte, 16 * constant.Mi)
}
排查协程泄露
go tool pprof http://localhost:6060/debug/pprof/goroutine
(pprof) top
Showing nodes accounting for 103, 99.04% of 104 total
Showing top 10 nodes out of 33
flat flat% sum% cum cum%
102 98.08% 98.08% 102 98.08% runtime.gopark
1 0.96% 99.04% 1 0.96% runtime.goroutineProfileWithLabels
0 0% 99.04% 100 96.15% github.com/wolfogre/go-pprof-practice/animal/canidae/wolf.(*Wolf).Drink.func1
0 0% 99.04% 1 0.96% github.com/wolfogre/go-pprof-practice/animal/felidae/cat.(*Cat).Live
0 0% 99.04% 1 0.96% github.com/wolfogre/go-pprof-practice/animal/felidae/cat.(*Cat).Pee
0 0% 99.04% 1 0.96% internal/poll.(*FD).Accept
0 0% 99.04% 1 0.96% internal/poll.(*FD).acceptOne
0 0% 99.04% 1 0.96% internal/poll.(*pollDesc).wait
0 0% 99.04% 1 0.96% internal/poll.execIO
排查锁的争用
go tool pprof http://localhost:6060/debug/pprof/mutex
(pprof) top
Showing nodes accounting for 126.40s, 100% of 126.40s total
flat flat% sum% cum cum%
126.40s 100% 100% 126.40s 100% sync.(*Mutex).Unlock (inline)
0 0% 100% 126.40s 100% github.com/wolfogre/go-pprof-practice/animal/canidae/wolf.(*Wolf).Howl.func1
func (w *Wolf) Howl() {
log.Println(w.Name(), "howl")
m := &sync.Mutex{}
m.Lock()
go func() {
time.Sleep(time.Second)
m.Unlock()
}()
m.Lock()
}
可以看到，这个锁由主协程 Lock，并启动子协程去 Unlock，主协程会阻塞在第二次 Lock 这儿等待子协程完成任务，但由于子协程足足睡眠了一秒，导致主协程等待这个锁释放足足等了一秒钟。
|