在給某個項(xiàng)目做長時間極限壓測的時候，經(jīng)常會出現(xiàn)壓幾小時不出問題，突然就崩了(延遲大幅上升)的情況。

查看監(jiān)控發(fā)現(xiàn)崩的時候 goroutine 突然漲起來了，那么可以用我之前開發(fā)的問題診斷工具了，配置下面的策略：若 goroutine 突然開始暴漲，則將 goroutine 文本 dump 下來。對這個診斷工具不了解的，可以看看我之前寫的?無人值守的自動 dump-2[1]?和?無人值守的自動 dump[2]。

代碼集成好之后再壓，發(fā)現(xiàn)崩潰時，總是有很多卡在鎖上的 goroutine：

10760?@?0x42f81f?0x4401d9?0x4401af?0x43ff4d?0x474df9?0x95709a?0x952d0d?0x17466fc?0x17462c4?0x174c8a8?0x174c88a?0x174e308?0x1755b78?0x1749432?0x17588e8?0xf90a54?0xc9670d?0x45d061 #?0x43ff4c?sync.runtime_SemacquireMutex+0x3c????/Users/xargin/sdk/go1.12.17/src/runtime/sema.go:71 #?0x474df8?sync.(*Mutex).Lock+0x108?????/Users/xargin/sdk/go1.12.17/src/sync/mutex.go:134 #?0x957099?github.com/rcrowley/go-metrics.(*UniformSample).Update+0x39?/Users/xargin/mosn/vendor/github.com/rcrowley/go-metrics/sample.go:508 #?0x952d0c?github.com/rcrowley/go-metrics.(*StandardHistogram).Update+0x3c?/Users/xargin/mosn/vendor/github.com/rcrowley/go-metrics/histogram.go:199 .....這下面就是一堆業(yè)務(wù)代碼了......1?@?0x42f81f?0x4401d9?0x4401af?0x43ff4d?0x474df9?0x504a3d?0x5040ba?0x5040ac?0x957187?0x957172?0x952d0d?0x17465d0?0x17462c4?0x174c8a8?0x174c88a?0x174e308?0x1755b78?0x1749432?0x17588e8?0xf90a54?0xc9670d?0x45d061 #?0x43ff4c?sync.runtime_SemacquireMutex+0x3c????/Users/xargin/sdk/go1.12.17/src/runtime/sema.go:71 #?0x474df8?sync.(*Mutex).Lock+0x108?????/Users/xargin/sdk/go1.12.17/src/sync/mutex.go:134 #?0x504a3c?math/rand.(*lockedSource).Int63+0x2c????/Users/xargin/sdk/go1.12.17/src/math/rand/rand.go:380 #?0x5040b9?math/rand.(*Rand).Int63+0x69?????/Users/xargin/sdk/go1.12.17/src/math/rand/rand.go:85 #?0x5040ab?math/rand.(*Rand).Int63n+0x5b?????/Users/xargin/sdk/go1.12.17/src/math/rand/rand.go:117 #?0x957186?math/rand.Int63n+0x126??????/Users/xargin/sdk/go1.12.17/src/math/rand/rand.go:319 #?0x957171?github.com/rcrowley/go-metrics.(*UniformSample).Update+0x111?/Users/xargin/mosn/vendor/github.com/rcrowley/go-metrics/sample.go:514 #?0x952d0c?github.com/rcrowley/go-metrics.(*StandardHistogram).Update+0x3c?/Users/xargin/mosn/vendor/github.com/rcrowley/go-metrics/histogram.go:199 ....這下面是一堆業(yè)務(wù)代碼了.....

如果分析原因的話，其實(shí)不難理解，極限壓測時 CPU 利用率都比較高 90%+，這時鎖沖突就是會導(dǎo)致整個服務(wù)因?yàn)殒i沖突而直接崩掉(goroutine 暴漲 OOM 之類的，或者延遲大幅上升，不可用)。

但問題是為什么是壓了一段時間后才崩，而不是一開始就崩呢，壓測平臺給服務(wù)的壓力在這個期間并沒有什么變化，看監(jiān)控也沒有 tcp retrans 之類的事件發(fā)生。

正好最近在一個朋友群，有前同事拉出了我之前寫的一篇文章：一個和 rlock 有關(guān)的小故事[3]來鞭尸，當(dāng)時寫的比較粗糙，后來被網(wǎng)友打臉：又一個和 rlock 有關(guān)的小故事[4]，并且有網(wǎng)友在評論區(qū)指出了一些問題，我把改進(jìn)后的 demo 貼在這里：

?????1?package?main2?3?import?(4??"fmt"5??"os"6??"runtime/trace"7??"sync"8??"sync/atomic"9??"time"10?)11?12?var?mlock?sync.RWMutex13?var?wg?sync.WaitGroup14?15?func?main()?{16??trace.Start(os.Stderr)17??defer?trace.Stop()18??wg.Add(100)19?20??for?i?:=?0;?i?<?100;?i++?{21???go?gets()22??}23?24??wg.Wait()25??if?a?>?0?{26???fmt.Println("here",?a)27??}28?}29?30?func?gets()?{31??for?i?:=?0;?i?<?100000;?i++?{32???get(i)33??}34??wg.Done()35?}36?37?var?a?int6438?39?func?get(i?int)?{40??beginTime?:=?time.Now()41??mlock.RLock()42??tmp1?:=?time.Since(beginTime).Nanoseconds()?/?100000043??if?tmp1?>?100?{?//?超過100ms44???atomic.AddInt64(&a,?1)45??}46??mlock.RUnlock()47?}

當(dāng)控制臺有輸出時，把 trace 記錄下來，可以發(fā)現(xiàn) RLock 取鎖成功之后，time.Since 函數(shù)調(diào)用時被協(xié)作式搶占調(diào)度出去了。這里搶占的原因是函數(shù)擴(kuò)棧，不是因?yàn)?syscall。

schedule out

這個結(jié)論能給我們一些參考意義，在 CPU 使用率較高時，獲取 RLock 的 goroutine 還是有一定概率被搶占的，這種搶占對于我們的服務(wù)是有較大的破壞性的：

Authors of parallel programs have known for decades that performance can suffer badly if a thread is preempted while holding a lock; this is sometimes referred to as inopportune preemption.

也就是說，如果在持鎖期間被搶占，那么其它 goroutine 就必須等這個 goroutine 從全局隊(duì)列里重新被調(diào)度回來，并執(zhí)行完它的臨界區(qū)，才能搶鎖成功。

假如這時候來一個 write lock，那就有意思了。而因?yàn)檫@種調(diào)度本身就具有一定的隨機(jī)性，所以如果真的是碰上了，也確實(shí)很難定位。

具體的現(xiàn)象是，平穩(wěn)了很長時間，突然它就崩了！

[1]

無人值守的自動 dump-2:?https://xargin.com/autodumper-for-go-ii/

[2]

無人值守的自動 dump:?https://xargin.com/autodumper-for-go/

[3]

一個和 rlock 有關(guān)的小故事:?https://xargin.com/a-rlock-story/

[4]

又一個和 rlock 有關(guān)的小故事:?https://cloud.tencent.com/developer/article/1560331

總結(jié)

以上是生活随笔為你收集整理的读锁调度导致高延迟的 case 一例的全部內(nèi)容，希望文章能夠幫你解決所遇到的問題。

如果覺得生活随笔網(wǎng)站內(nèi)容還不錯，歡迎將生活随笔推薦給好友。