block profile 和 mutex profile 都和锁有关,但记录的位置不同:一个记在等待的人那里,一个记在持锁释放的人那里。这篇用 8 个 goroutine 争同一把锁,把两个 profile 并排看,再看采样设置会让读数偏到多离谱。
TOTAL 0.201
-- block profile(-top,delay):
Type: delay
Showing nodes accounting for 1564.82ms, 100% of 1564.82ms total
flat flat% sum% cum cum%
1363.67ms 87.15% 87.15% 1363.67ms 87.15% sync.(*Mutex).Lock (inline)
201.15ms 12.85% 100% 201.15ms 12.85% sync.(*WaitGroup).Wait
0 0% 100% 1363.67ms 87.15% main.critical
0 0% 100% 201.15ms 12.85% main.main
0 0% 100% 1363.67ms 87.15% main.main.func1
0 0% 100% 201.15ms 12.85% runtime.main
-- mutex profile(-top,delay):
Type: delay
Showing nodes accounting for 1363.74ms, 100% of 1363.74ms total
flat flat% sum% cum cum%
1363.74ms 100% 100% 1363.74ms 100% sync.(*Mutex).Unlock (inline)
0 0% 100% 1363.74ms 100% main.critical
0 0% 100% 1363.74ms 100% main.main.func18 个 goroutine 每个在锁里睡 1 ms,共 160 次。block profile 里等待的时间记在 sync.(*Mutex).Lock(1363.67 ms),mutex profile 里同一段延迟记在 sync.(*Mutex).Unlock(1363.74 ms)。前者告诉你谁在等,后者告诉你谁占着锁耽误了别人。block profile 里还多了 WaitGroup.Wait 的 201.15 ms,是 main 在等。
block profile:1 次事件,累计延迟 302 ms mutex profile:0 次事件,累计延迟 0 ms
main 在 channel 上等了 300 ms,block profile 记了 1 次事件 302 ms,mutex profile 是 0。所以“阻塞 profile 里什么都有”,而 mutex profile 专指 sync.Mutex/RWMutex 的竞争(本文只实验了 Mutex)。
block rate= 1, mutex fraction= 1:block 延迟 1568– 1571 ms(事件 160–160 次);mutex 延迟 1367– 1369 ms(事件 159–159 次) block rate= 1000000, mutex fraction= 10:block 延迟 1569– 1571 ms(事件 160–160 次);mutex 延迟 957– 1595 ms(事件 120–190 次) block rate=100000000, mutex fraction=100:block 延迟 1002– 2001 ms(事件 91–208 次);mutex 延迟 0– 1761 ms(事件 0–200 次)
全采样时读数稳定(160 次、1568–1571 ms)。mutex fraction=10 时事件数 120–190 次、延迟 957–1595 ms;fraction=100 时有的运行读到 0。线上为了省开销用 1/100 之类的比例,要多取几次再下结论。
速率 0(无竞争的 Lock+Unlock):7 ns/次 速率 0(8 个 goroutine 争同一把锁,各 200000 次):平均每次 125 ns 速率 1(无竞争的 Lock+Unlock):7 ns/次 速率 1(8 个 goroutine 争同一把锁,各 200000 次):平均每次 105 ns
这次测量里打开速率 1 没有让无竞争加锁变慢(7 ns 对 7 ns),争锁的情形还略快(125 对 105 ns,差在噪声里)。我只测了一次,不能据此说“零开销”,只能说在这个测法下没看到。
SetBlockProfileRate controls the fraction of goroutine blocking events that are reported in the blocking profile. The profiler aims to sample an average of one blocking event per rate nanoseconds spent blocked. To include every blocking event in the profile, pass rate = 1. To turn off profiling entirely, pass rate <= 0. SetMutexProfileFraction controls the fraction of mutex contention events that are reported in the mutex profile. On average 1/rate events are reported. The previous rate is returned. To turn off profiling entirely, pass rate 0. To just read the current rate, pass rate < 0. (For n>1 the details of sampling may change.)
block 的 rate 是“每多少纳秒的阻塞采一个”,mutex 的 fraction 是“平均每多少个事件采一个”,文档还提示 n>1 时采样细节可能改变。两个数字别混着调。