某核心JAVA長鏈接服務使用mongodb做爲主要存儲,客戶端數百臺機器鏈接同一mongodb集羣,短時間內出現屢次性能抖動問題,此外,還出現一次「雪崩」故障,同時流量瞬間跌零,沒法自動恢復。本文分析這兩次故障的根本緣由,包括客戶端配置使用不合理、mongodb內核連接認證不合理、代理配置不全等一系列問題,最終通過多方努力肯定問題根源。java
該集羣有十來個業務接口訪問,每一個接口部署在數十臺業務服務器上面,訪問該mongodb機器的客戶端總數超過數百臺,部分請求一次拉取數十行甚至百餘行數據。linux
該集羣爲2機房同城多活集羣(選舉節不消耗太多資源,異地的第三機房來部署選舉節點),架構圖以下:git
從上圖能夠看出,爲了實現多活,在每一個機房都部署有對應代理,對應機房客戶端連接對應機房的mongos代理,每一個機房多個代理。代理層部署IP:PORT地址列表(注意:不是真實IP地址)以下:github
A機房三個代理部署在三臺不一樣物理機,B機房2個代理部署在同一臺物理機。此外,A機房和B機房爲同城機房,跨機房訪問時延能夠忽略。算法
集羣存儲層和config server都採用一樣的架構:A機房(1主節點+1從節點) + B機房(2從節點)+C機房(1個選舉節點arbiter),即2(數據節點)+2(數據節點)+1(選舉節點)模式。mongodb
該機房多活架構能夠保證任一機房掛了,對另外一機房的業務無影響,具體機房多活原理以下:後端
本文重點分析以下6個疑問點:服務器
該集羣一段時間內有屢次短暫的抖動,當A機房客戶端抖動後,發現A機房對應代理負載很高,因而切換A機房訪問B機房代理,可是切換後B機房代理一樣抖動,也就是多活切換沒有做用,具體過程分析以下。網絡
首先,分析該集羣全部mongod存儲節點系統CPU、MEM、IO、load等監控信息,發現一切正常,因而分析每一個mongod節點慢日誌(因爲該集羣對時延敏感,所以慢日誌調整爲30ms),分析結果以下:多線程
從上圖能夠看出,存儲節點在業務抖動的時候沒有任何慢日誌,所以能夠判斷存儲節點一切正常,業務抖動和mongod存儲節點無關。
存儲節點沒有任何問題,所以開始排查mongos代理節點。因爲歷史緣由,該集羣部署在其餘平臺,該平臺對QPS、時延等監控不是很全,形成早期抖動的時候監控沒有及時發現。抖動後,遷移該平臺集羣到oppo自研的新管控平臺,新平臺有詳細的監控信息,遷移後QPS監控曲線以下:
每一個流量徒增時間點,對應業務監控都有一波超時或者抖動,以下:
分析對應代理mongos日誌,發現以下現象:抖動時間點mongos.log日誌有大量的建連接和斷連接的過程,以下圖所示:
從上圖能夠看出,一秒鐘內有幾千個連接創建,同時有幾千個連接斷開,此外抓包發現不少連接短時間內即斷開連接,現象以下(斷鏈時間-建鏈時間=51ms, 部分100多ms斷開):
對應抓包以下:
此外,該機器代理上客戶端連接低峯期都很高,甚至超過正常的QPS值,QPS大約7000-8000,可是conn連接缺高達13000,
mongostat獲取到監控信息以下:
每次突發流量的時候,代理負載很高,經過部署腳本按期採樣,抖動時間點對應監控圖以下圖所示:
從上圖能夠看出,每次流量高峯的時候CPU負載都很是的高,並且是sy%負載,us%負載很低,同時Load甚至高達好幾百,偶爾甚至過千。
從上面的分析能夠看出,某些時間點業務有突發流量引發系統負載很高。根因真的是由於突發流量嗎?其實否則,請看後續分析,這實際上是一個錯誤結論。沒過幾天,同一個集羣雪崩了。
因而業務梳理突發流量對應接口,梳理出來後下掉了該接口,QPS監控曲線以下:
爲了減小業務抖動,所以下掉了突發流量接口,此後幾個小時業務再也不抖動。當下掉突發流量接口後,咱們還作了以下幾件事情:
可是,內心始終有不少疑惑和懸念,主要在如下幾個點:
好景不長,業務下掉突發流量的接口沒過幾天,更嚴重的故障出現了,機房B的業務流量在某一時刻直接跌0了,不是簡單的抖動問題,而是業務直接流量跌0,系統sy%負載100%,業務幾乎100%超時重連。
機器CPU和系統負載監控以下:
從上圖能夠看出,幾乎和前面的突發流量引發的系統負載太高現象一致,業務CPU sy%負載100%,load很高。登錄機器獲取top信息,現象和監控一致。
同一時刻對應網絡監控以下:
磁盤IO監控以下:
從上面的系統監控分析能夠看出,出問題的時間段,系統CPU sy%、load負載都很高,網絡讀寫流量幾乎跌0,磁盤IO一切正常,能夠看出整個過程幾乎和以前突發流量引發的抖動問題徹底一致。
第一次突發流量引發的抖動問題後,咱們擴容全部的代理到8個,同時通知業務把全部業務接口配置上全部代理。因爲業務接口衆多,最終B機房的業務沒有配置所有代理,只配置了原先的兩個處於同一臺物理機的代理(4.4.4.4:1111,4.4.4.4:2222),最終觸發mongodb的一個性能瓶頸(詳見後面分析),引發了整個mongodb集羣」雪崩」
最終,業務經過重啓服務,同時把B機房的8個代理同時配置上,問題得以解決。
分析該時間段代理日誌,能夠看出和2.1一樣得現象,大量的新鍵鏈接,同時新鏈接在幾十ms、一百多ms後又關閉鏈接。整個現象和以前分析一致,這裏不在統計分析對應日誌。
此外,分析當時的代理QPS監控,正常query讀請求的QPS訪問曲線以下,故障時間段QPS幾乎跌零雪崩了:
從上面的統計能夠看出,當該代理節點的流量故障時間點有一波尖刺,同時該時間點的command統計瞬間飆漲到22000(實際可能更高,由於咱們監控採樣週期30s,這裏只是平均值),也就是瞬間有2.2萬個鏈接瞬間進來了。Command統計其實是db.ismaster()統計,客戶端connect服務端成功後的第一個報文就是ismaster報文,服務端執行db.ismaster()後應答客戶端,客戶端收到後開始正式的sasl認證流程。
正常客戶端訪問流程以下:
客戶端SDK連接創建成功後發送db.isMaster()給服務端的目的是爲了負載均衡策略和判斷節點是什麼類型,保證客戶端快速感知到訪問時延高的代理,從而快速剔除往返時延高的節點,同時肯定訪問的節點類型。
此外,經過提早部署的腳本,該腳本在系統負載高的時候自動抓包,從抓包分析結果以下圖所示:
上圖時序分析以下:
第3和第1個報文之間相差大約150ms,最後和業務肯定該客戶端IP對應的超時時間配置,肯定就是150ms。此外,其餘抓包中有相似40ms、100ms等超時配置,經過對應客戶端和業務確認,肯定對應客戶端業務接口超時時間配置的就是40ms、100ms等。所以,結合抓包和客戶端配置,能夠肯定當代理超過指定超時時間尚未給客戶端db.isMaster()返回值,則客戶端立馬超時,超時後立馬發起重連請求。
總結:經過抓包和mongos日誌分析,能夠肯定連接創建後快速斷開的緣由是:客戶端訪問代理的第一個請求db.isMaster()超時了,所以引發客戶端重連。重連後又開始獲取db.isMaster()請求,因爲負載CPU 100%, 很高,每次重連後的請求都會超時。其中配置超時時間爲500ms的客戶端,因爲db.isMaster()不會超時,所以後續會走sasl認證流程。
所以能夠看出,系統負載高和反覆的建鏈斷鏈有關,某一時刻客戶端大量創建連接(2.2W)引發負載高,又由於客戶端超時時間配置不一,超時時間配置得比較大得客戶端最終會進入sasl流程,從內核態獲取隨機數,引發sy%負載高,sy%負載高又引發客戶端超時,這樣整個訪問過程就成爲一個「死循環」,最終引發mongos代理雪崩。
2.3 線下模擬故障
到這裏,咱們已經大概肯定了問題緣由,可是爲何故障突發時間點那一瞬間2萬個請求就會引發sy%負載100%呢,理論上一秒鐘幾萬個連接不會引發如此嚴重的問題,畢竟咱們機器有40個CPU。所以,分析反覆建鏈斷鏈爲什麼引發系統sy%負載100%就成爲了本故障的關鍵點。
模擬頻繁建鏈斷鏈故障步驟以下:
經過上面的操做,能夠保證全部請求超時,超時後客戶端又會立馬開始從新建鏈,再次建鏈後訪問mongodb還會超時,這樣就模擬了反覆建鏈斷鏈的過程。此外,爲了保證和雪崩故障環境一致,把2個mongos代理部署在同一臺物理機。
爲了保證和故障的mongos代理硬件環境一致,所以選擇故障一樣類型的服務器,而且操做系統版本同樣(2.6.32-642.el6.x86_64),程序都跑起來後,問題立馬浮現:
因爲出故障的服務器操做系統版本linux-2.6太低,所以懷疑可能和操做系統版本有問題,所以升級同一類型的一臺物理機到linux-3.10版本,測試結果以下:
從上圖能夠看出,客戶端6000併發反覆重連,服務端壓力正常,全部CPU消耗在us%,sy%消耗很低。用戶態CPU消耗3個CPU,內核態CPU消耗幾乎爲0,這是咱們期待的正常結果,所以以爲該問題可能和操做系統版本有問題。
爲了驗證更高並反覆建鏈斷鏈在Linux-3.10內核版本是否有2.6版本一樣的sy%內核態CPU消耗高的問題,所以把併發從6000提高到30000,驗證結果以下:
測試結果:經過修改mongodb內核版本故意讓客戶端超時反覆建鏈斷鏈,在linux-2.6版本中,1500以上的併發反覆建鏈斷鏈系統CPU sy% 100%的問題便可浮現。可是,在Linux-3.10版本中,併發到10000後,sy%負載逐步增長,併發越高sy%負載越高。
總結:linux-2.6系統中,mongodb只要每秒有幾千的反覆建鏈斷鏈,系統sy%負載就會接近100%。Linux-3.10,併發20000反覆建鏈斷鏈的時候,sy%負載能夠達到30%,隨着客戶端併發增長,sy%負載也相應的增長。Linux-3.10版本相比2.6版本針對反覆建鏈斷鏈的場景有很大的性能改善,可是不能解決根本問題。
爲了分析%sy系統負載高的緣由,安裝perf獲取系統top信息,發現全部CPU消耗在以下接口:
從perf分析能夠看出,cpu 消耗在_spin_lock_irqsave函數,繼續分析內核態調用棧,獲得以下堆棧信息:
- 89.81% 89.81% [kernel] [k] _spin_lock_irqsave ▒
- _spin_lock_irqsave ▒
- mix_pool_bytes_extract ▒
- extract_buf ▒
extract_entropy_user ▒
urandom_read ▒
vfs_read ▒
sys_read ▒
system_call_fastpath ▒
0xe82d
上面的堆棧信息說明,mongodb在讀取 /dev/urandom ,而且因爲多個線程同時讀取該文件,致使消耗在一把spinlock上。
到這裏問題進一步明朗了,故障root case 不是每秒幾萬的鏈接數致使sys 太高引發。根本緣由是每一個mongo客戶端的新連接會致使mongodb後端新建一個線程,該線程在某種狀況下會調用urandom_read 去讀取隨機數/dev/urandom ,而且因爲多個線程同時讀取,致使內核態消耗在一把spinlock鎖上,出現cpu 高的現象。
上面的分析已經肯定,問題根源是mongodb內核多個線程讀取/dev/urandom隨機數引發,走讀mongodb內核代碼,發現讀取該文件的地方以下:
上面是生成隨機數的核心代碼,每次獲取隨機數都會讀取」/dev/urandom」系統文件,因此只要找到使用該接口的地方便可便可分析出問題。
繼續走讀代碼,發現主要在以下地方:
//服務端收到客戶端sasl認證的第一個報文後的處理,這裏會生成隨機數
//若是是mongos,這裏就是接收客戶端sasl認證的第一個報文的處理流程
Sasl_scramsha1_server_conversation::_firstStep(...) {
... ...
unique_ptr<SecureRandom> sr(SecureRandom::create());
binaryNonce[0] = sr->nextInt64();
binaryNonce[1] = sr->nextInt64();
binaryNonce[2] = sr->nextInt64();
... ...
}
//mongos相比mongod存儲節點就是客戶端,mongos做爲客戶端也須要生成隨機數
SaslSCRAMSHA1ClientConversation::_firstStep(...) {
... ...
unique_ptr<SecureRandom> sr(SecureRandom::create());
binaryNonce[0] = sr->nextInt64();
binaryNonce[1] = sr->nextInt64();
binaryNonce[2] = sr->nextInt64();
... ...
}
從2.5.1分析能夠看出,mongos處理客戶端新鏈接sasl認證過程都會經過"/dev/urandom"生成隨機數,從而引發系統sy% CPU太高,咱們如何優化隨機數算法就是解決本問題的關鍵。
繼續分析mongodb內核源碼,發現使用隨機數的地方不少,其中有部分隨機數經過用戶態算法生成,所以咱們能夠採用一樣方法,在用戶態生成隨機數,用戶態隨機數生成核心算法以下:
class PseudoRandom {
... ...
uint32_t _x;
uint32_t _y;
uint32_t _z;
uint32_t _w;
}
該算法能夠保證產生的數據隨機分佈,該算法原理詳見:
http://en.wikipedia.org/wiki/Xorshift
也能夠查看以下git地址獲取算法實現:
總結:經過優化sasl認證的隨機數生成算法爲用戶態算法後,CPU sy% 100%的問題得以解決,同時代理性能在短連接場景下有了數倍/數十倍的性能提高。
從上面的分析能夠看出,該故障由多種因素連環觸發引發,包括客戶端配置使用不當、mongodb服務端內核極端狀況異常缺陷、監控不全等。總結以下:
分析到這裏,咱們能夠回答第1章節的6個疑問點了,以下:
爲何突發流量業務會抖動?
答:因爲業務是java業務,採用連接池方式連接mongos代理,當有突發流量的時候,連接池會增長連接數來提高訪問mongodb的性能,這時候客戶端就會新增連接,因爲客戶端衆多,形成可能瞬間會有大量新鏈接和mongos建鏈。連接創建成功後開始作sasl認證,因爲認證的第一步須要生成隨機數,就須要訪問操做系統"/dev/urandom"文件。又由於mongos代理模型是默認一個連接一個線程,因此會形成瞬間多個線程訪問該文件,進而引發內核態sy%負載太高。
爲什麼mongos代理引發「雪崩」,流量爲什麼跌零不可用?
答:緣由客戶端某一時刻可能由於流量忽然有增長,連接池中連接數不夠用,因而增長和mongos代理的連接,因爲是老集羣,代理仍是默認的一個連接一個線程模型,這樣瞬間就會有大量連接,每一個連接創建成功後,就開始sasl認證,認證的第一步服務端須要產生隨機數,mongos服務端經過讀取"/dev/urandom"獲取隨機數,因爲多個線程同時讀取該文件觸發內核態spinlock鎖CPU sy% 100%問題。因爲sy%系統負載太高,因爲客戶端超時時間設置太小,進一步引發客戶端訪問超時,超時後重連,重連後又進入sasl認證,又加重了讀取"/dev/urandom"文件,如此反覆循環持續。
此外,第一次業務抖動後,服務端擴容了8個mongos代理,可是客戶端沒有修改,形成B機房業務配置的2個代理在同一臺服務器,沒法利用mongo java sdk的自動剔除負載高節點這一策略,因此最終形成」雪崩」
爲何數據節點沒有任何慢日誌,可是代理負載卻CPU sy% 100%?
答:因爲客戶端java程序直接訪問的是mongos代理,因此大量連接只發生在客戶端和mongos之間,同時因爲客戶端超時時間設置過短(有接口設置位幾十ms,有的接口設置位一百多ms,有的接口設置位500ms),就形成在流量峯值的時候引發連鎖反應(突發流量系統負載高引發客戶端快速超時,超時後快速重連,進一步引發超時,無限死循環)。Mongos和mongod之間也是連接池模型,可是mongos做爲客戶端訪問mongod存儲節點的超時很長,默認都是秒級別,因此不會引發反覆超時建鏈斷鏈。
爲什麼A機房代理抖動的時候,A機房業務切到B機房後,仍是抖動?
答:當A機房業務抖動,業務切換到B機房的時候,客戶端須要從新和服務端創建連接認證,又會觸發大量反覆建鏈斷鏈和讀取隨機數"/dev/urandom"的流程,因此最終形成機房多活失敗。
爲什麼異常時候抓包分析,客戶端頻繁建鏈斷鏈,而且同一個連接建鏈到斷鏈間隔很短?
答:頻繁建鏈斷鏈的根本緣由是系統sy%負載高,客戶端極短期內創建連接後又端口的緣由是客戶端配置超時時間過短。
理論上代理就是七層轉發,消耗資源更少,相比mongod存儲應該更快,爲什麼mongod存儲節點無任何抖動,mongos代理卻有嚴重抖動?
答:因爲採用分片架構,全部mongod存儲節點前面都有一層mongos代理,mongos代理做爲mongod存儲節點的客戶端,超時時間默認秒級,不會出現超時現象,也就不會出現頻繁的建鏈斷鏈過程。
若是mongodb集羣採用普通複製集模式,客戶端頻繁建鏈斷鏈是否可能引發mongod存儲節點一樣的」雪崩」?
答:會。若是客戶端過多,操做系統內核版本太低,同時超時時間配置過段,直接訪問複製集的mongod存儲節點,因爲客戶端和存儲節點的認證過程和與mongos代理的認證過程同樣,因此仍是會觸發引發頻繁讀取"/dev/urandom"文件,引發CPU sy%負載太高,極端狀況下引發雪崩。
從上面的一系列分析,問題在於客戶端配置不合理,加上mongodb內核認證過程讀取隨機數在極端狀況下存在缺陷,最終形成雪崩。若是沒有mongodb內核研發能力,能夠經過規範化客戶端配置來避免該問題。固然,若是客戶端配置規範化,同時mongodb內核層面解決極端狀況下的隨機數讀取問題,這樣問題能夠獲得完全解決。
在業務接口不少,客戶端機器不少的業務場景,客戶端配置必定要作到以下幾點:
若是沒有mongodb內核源碼研發能力,能夠參考該客戶端配置方法,同時淘汰linux-2.6版本內核,採用linux-3.10或者更高版本內核,基本上能夠規避踩一樣類型的坑。
詳見2.5.2 章節。
因爲PHP業務屬於短連接業務,若是流量很高,不可避免的要頻繁建鏈斷鏈,也就會走sasl認證流程,最終多線程頻繁讀取"/dev/urandom"文件,很容易引發前面的問題。這種狀況,能夠採用4.1 java客戶端相似的規範,同時不要使用低版本的Linux內核,採用3.x以上內核版本,就能夠規避該問題的存在。
本文相關的Mongodb線程模型及隨機數算法實現相關源碼分析以下:
若是你以爲這篇內容對你還蠻有幫助,我想邀請你幫我三個小忙:
點贊,轉發,有大家的 『點贊和評論』,纔是我創造的動力。
關注公衆號 『 java爛豬皮 』,不按期分享原創知識。
同時能夠期待後續文章ing🚀