排查因调用同步原语（synchronization primitives）导致阻塞操作
使用前需要先调用 runtime.SetMutexProfileFraction。
在程序中，除了锁的争用会导致阻塞之外，很多逻辑都会导致阻塞。
Demo
package main
import (
"net/http"
_ "net/http/pprof"
"runtime"
"sync"
"time"
)
func main() {
runtime.GOMAXPROCS(1)
runtime.SetMutexProfileFraction(1)
runtime.SetBlockProfileRate(1)
go func() {
http.ListenAndServe(":6060", nil)
}()
for {
stupidBlockUse()
time.Sleep(time.Second)
}
}
func stupidBlockUse() {
m := &sync.Mutex{}
m.Lock()
go func() {
println("do something1")
<-time.After(time.Second)
println("do something2")
}()
}
分析：
$ go tool pprof http://localhost:6060/debug/pprof/block
Fetching profile over HTTP from http://localhost:6060/debug/pprof/block
Saved profile in /Users/weishi/pprof/pprof.contentions.delay.013.pb.gz
Type: delay
Time: Aug 22, 2020 at 1:22pm (+08)
Entering interactive mode (type "help" for commands, "o" for options)
(pprof) top
Showing nodes accounting for 8.02s, 100% of 8.02s total
Dropped 4 nodes (cum <= 0.04s)
flat flat% sum% cum cum%
8.02s 100% 100% 8.02s 100% runtime.chanrecv1
0 0% 100% 8.02s 100% main.stupidBlockUse.func1
(pprof) list stupid
Total: 8.02s
ROUTINE ======================== main.stupidBlockUse.func1 in /Users/weishi/Working/GoPlayground/sw_pprof/sw_pprof.go
0 8.02s (flat, cum) 100% of Total
. . 27:func stupidBlockUse() {
. . 28: m := &sync.Mutex{}
. . 29: m.Lock()
. . 30: go func() {
. . 31: println("do something1")
. 8.02s 32: <-time.After(time.Second)
. . 33: println("do something2")
. . 34: }()
. . 35:}
你应该可以看懂，不同于睡眠一秒，这里是从一个 channel 里读数据时，发生了阻塞，直到这个 channel 在一秒后才有数据读出，这就导致程序阻塞了一秒而非睡眠了一秒。
Reference
- https://github.com/google/pprof/blob/master/doc/README.md
- https://golang.org/doc/diagnostics.html
- https://golang.org/pkg/net/http/pprof/
- https://blog.golang.org/pprof
- https://golang.org/pkg/runtime/pprof/
- https://blog.wolfogre.com/posts/go-ppof-practice/