為什麼要做這個案例分析?
因為在其他同學已經找到問題代碼并修複後,我還沒有徹底弄明白下面這2個問題:
1.為什麼是這段代碼導緻的?
2.為什麼看起來跟問題代碼無關的接口也受影響變得惡化,這段代碼到底是如何造成整個服務雪崩的?
在搞懂上面的一系列問題後,我認為這是一次典型的
慢查詢導緻服務雪崩
案例(因為沒有其他次要因素),沉澱總結下來,或許可以幫助我下次更快更準的找到排查思路,而不至于沒有方向浪費寶貴的排查時間,對于伺服器問題線索的收集是有益的。
最容易獲得的問題資訊
服務品質下降後,一般最快能夠擷取到的資訊,就是服務接口響應監控資訊,例如這一次:訪客服務API平均響應時長變慢,持續惡化,導緻其他上遊服務接口受影響
隻要時間段選擇長一點,就會發現接口響應時間從平均200+ms逐漸惡化到1min+

如何找到出問題的接口
影響平均響應時長的,應該是一些耗時比較長的接口拉高的,但怎麼确認哪些接口是“罪魁禍首”,哪些接口是“受牽連”才惡化的?
在這個典型案例中,下面這兩個步驟可以确定目标:
1)拉長監控時間範圍,觀察服務有惡化端倪的時間點
例如這個案例中,我們發現問題的時間點約11:30,把監控時間段調為11:00~12:00,不難觀察服務有惡化端倪的是11:10開始逐漸惡化
2)監控開始時間調整到開始惡化的時間(11:10),結束時間不變,檢視接口清單,按時間正序排序
這樣做,主要是分析在服務開始惡化時,哪些接口已經出現問題了,而這部分接口往往就是主要問題甚至根本問題所在;順便可以看到,一些接口在服務開始惡化時本來響應良好,随着時間增長不斷才開始惡化的,這些往往都是“受牽連”的接口。
分析接口
本例中,接口線程分析顯示耗時發生在mongo查詢處。
解決的方式比較簡單,也不是讨論的重點,一方面可以直接看看這段sql的語句是否有問題,另一方面可以通過資料庫慢查詢記錄看看具體慢的原因。
為什麼其他接口會受牽連惡化
服務從11:10開始惡化,從mongo監控看主庫的CPU使用率有抖動
而從庫則問題比較明顯,CPU從11:10開始幾乎持續跑滿
再看看一個關鍵監控值:gl_cq_readers,其對應的應該是mongo指令
db.serverStatus()
的"globalLock.currentQueue.readers"字段值,阿裡雲對這個監控名額的解釋如下:
簡單來說,MongoDB中使用的是多粒度鎖,在加鎖時是一個層次性管理方式,從globalLock ===> DBLock ===> CollectionLock …,對于我們使用的WiredTiger引擎,讀寫并發時,使用的是文檔級别鎖。
這裡套用下阿裡雲張友東的部落格内容,
上述代碼⾥,如果holder不為空,Client會先進去kQueuedReader或kQueuedWriter狀态,然後擷取⼀個ticket,擷取到
後轉換為kActiveReader或kActiveWriter狀态。這⾥的ticket是什麼東⻄?
這⾥的ticket是引擎可以設定的⼀個限制。正常情況下,如果沒有鎖競争,所有的讀寫請求都會被pass到引擎層,這樣
就有個問題,你請求到了引擎層⾯,還是得排隊執⾏,⽽且不同引擎處理能⼒肯定也不同,于是引擎層就可以通過設定
這個ticket,來限制⼀下傳到引擎層⾯的最⼤并發數。
wiredtiger設定了讀寫ticket均為128,也就是說wiredtiger引擎層最多⽀持128的讀寫并發(這個值經過測試是⾮常
合理的經驗值,⽆需修改)。
而前面提到的“globalLock.currentQueue.readers”字段值,我的了解,就是目前等待送出到引擎層的請求排隊數量,而當這個數量持續不為0時,說明系統的并發太⾼了,一般可以用下面兩種方式解決:
1)通過優化單個請求的處理時間(⽐如建索引來減少COLLSCAN或SORT)
2)更新後端資源(記憶體、磁盤IO能⼒、CPU)
gl_cq_readers/writers帶來的影響
案例中,主庫在11:32:42監控到gl_cq_writers為18
從庫從11:43開始,gl_cq_readers持續在25~37
而具體是writers或redaers無關緊要,主要是出現了currentQueue的堆積,那麼這些處于等待隊列的資料庫請求耗時一定是比較長的,而這也是大部分“受牽連”的業務接口持續惡化的原因之一,反應出來的問題是并發太高,MongoDB服務品質下降。
遺留問題
本例中,在出現問題的一段時間内,從庫的CPU使用率持續在99%(不少接口在這個時間點出現逾時),是否考慮下提升該資料庫的硬體配置,以提升服務處理能力?
總結
通過這次問題的分析,反推一下這次的關鍵線索:
1)服務接口整體變慢,包括那些平時良好的接口
2)gl_cq_readers/writers名額變化,持續不為0
3)MongoDB CPU持續飙高
而後續接收到服務響應變慢的告警時,基本可以先用下面幾個步驟找到/排除典型慢查詢的問題:
1)找到服務出現問題的時間點
2)找到該時間點的主要問題接口,分析接口逾時原因
3)如果因為資料庫查詢耗時嚴重,到mongo監控中看下CPU使用率
4)觀察gl_cq_readers/writers名額
5)修複慢查詢,釋出驗證