天天看點

性能調優篇:困擾我半年之久的RocketMQ timeout exception 終于破解了

在内網環境中,逾時問題,網絡表示這個鍋我不背。

筆者對于逾時的了解,随着在工作中不斷實踐,其了解也越來越深刻,RocketMQ在生産環境遇到的逾時問題,已經困擾了我将近半年,現在終于取得了比較好的成果,和大家來做一個分享。

本次技術分享,由于涉及到網絡等諸多筆者不太熟悉的領域,如果存在錯誤,請大家及時糾正,實作共同成長與進步。

1、網絡逾時現象

時不時總是接到項目組回報說生産環境MQ發送逾時,用戶端相關的日志截圖如下:

性能調優篇:困擾我半年之久的RocketMQ timeout exception 終于破解了

今天的故事将從張圖開始。

2、問題排查

2.1 初步分析

上圖中有兩條非常關鍵日志:

  • invokeSync:wait response timeout exception

    網絡調用逾時

  • recive response,but not matched any request

    這條日志非常之關鍵,表示盡管用戶端在擷取服務端傳回結果時逾時了,但用戶端最終還是能收到服務端的響應結果,隻是此時用戶端已經等待足夠時間後放棄處理了。

關于第二條日志,我再詳細闡述一下其運作機制,其實也是用一條連結發送多個請求的程式設計套路。一條長連接配接,向服務端先後發送2個請求,用戶端在收到服務端響應結果時,怎麼判斷這個響應結果對應的是哪個請求呢?如下圖所示:

性能調優篇:困擾我半年之久的RocketMQ timeout exception 終于破解了

用戶端多個線程,通過一條連接配接發送了req1,req2兩個請求,但在服務端通常都是多線程處理,傳回結果時可能會先收到req2的響應,那用戶端如何識别服務端傳回的資料是對應哪個請求的呢?

解決辦法是用戶端在發送請求之前,會為該請求生成一個本機器唯一的請求id(requestId),并且會采用Future模式,将requestId與Future對象放入一個Map中,然後将reqestId放入請求體中,服務端在傳回響應結果時将請求ID原封不動的放入到響應結果中,當用戶端收到響應時,先界面出requestId,然後從緩存中找到對應的Future對象,喚醒業務線程,将傳回結構通知給調用方,完成整個通信。

故從這裡能看到,用戶端在指定時間内沒有收到服務端的請求,但最終還是能收到,矛頭直接指向Broker端,是不是Broker有瓶頸,處理很慢導緻的。

2.2 Broker端處理瓶頸分析

在我的“經驗”中,RocketMQ消息發送如果出現瓶頸,通常會傳回各種各樣的Broker Busy,而且可以通過跟蹤Broker端寫入PageCache的資料名額來判斷Broker是否遇到了瓶頸。

grep "PAGECACHERT" store.log
           

得到的結果類似如下截圖:

性能調優篇:困擾我半年之久的RocketMQ timeout exception 終于破解了
溫馨提示:上圖是我本機中的截圖,當時分析問題的時候,MQ叢集中各個Broker中這些資料,寫入PageCache的時間沒有超過100ms的。

正是由于良好的pagecache寫入資料,根據如下粗糙的網絡互動特性,我提出将沖突點轉移到網絡方面:

性能調優篇:困擾我半年之久的RocketMQ timeout exception 終于破解了

并且我還和業務方确定,雖然消息發送傳回逾時,但消息是被持久化到MQ中的,消費端也能正常消費,網絡組同僚雖然從理論上來說區域網路不會有什麼問題,但鑒于上述現象,網絡組還是開啟了網絡方面的排查。

溫馨提示:最後證明是被我帶偏了。

2.3 網絡分析

通常網絡分析有兩種手段,netstat 與網絡抓包。

2.3.1 netstat檢視Recv-Q與Send-Q

我們可以通過netstat重點觀察兩個名額Recv-Q、Send-Q。

性能調優篇:困擾我半年之久的RocketMQ timeout exception 終于破解了
  • Recv-Q

    tcp通道的接受緩存區

  • Send-Q

    tcp通道的發送緩存區

在TCP中,Recv-Q與Send-Q的作用如下圖所示:

性能調優篇:困擾我半年之久的RocketMQ timeout exception 終于破解了
  • 用戶端調用網絡通道,例如NIO的Channel寫入資料,資料首先是寫入到TCP的發送緩存區,如果發送發送區已滿,用戶端無法繼續向該通道發送請求,從NIO層面調用Channel底層的write方法,會傳回0,表示發送緩沖區已滿,需要注冊寫事件,待發送緩存區有空閑時再通知上層應用程式可以發消息。
  • 資料進入到發送緩存區後,接下來資料會随網絡到達目标端,首先進入的是目标端的接收緩存區,如果與NIO挂鈎的化,通道的讀事件會繼續,應用從接收緩存區中成功讀取到位元組後,會發送ACK給發送方。
  • 發送方在收到ACK後,會删除發送緩沖區中的資料,如果接收方一直不讀取資料,那發送方也無法發送資料。

網絡同僚分布在用戶端、MQ伺服器上通過每500ms采集一次netstat ,經過對采集結果進行彙總,出現如下圖所示:

性能調優篇:困擾我半年之久的RocketMQ timeout exception 終于破解了

從用戶端來看,用戶端的Recv-Q中會出現大量積壓,對應的是MQ的Send-Q中出現大量積壓。

從上面的通訊模型來看,再次推斷是否是因為用戶端從網絡中讀取位元組太慢導緻的,因為用戶端為虛拟機,從netstat 結果來看,疑似是用戶端的問題(備注,其實最後并不是用戶端的問題,請别走神)。

2.3.2 網絡轉包

網絡組同僚為了更加嚴謹,還發現了如下的包:

性能調優篇:困擾我半年之久的RocketMQ timeout exception 終于破解了

這裡有一個問題非常值得懷疑,就是用戶端與服務端的滑動視窗隻有190個位元組,一個MQ消息發送傳回包大概有250個位元組左右,這樣會已響應包需要傳輸兩次才能被接收,一開始以為這裡是主要原因,但通過其他對比,發現不是滑動視窗大于250的用戶端也存在逾時,進而判斷這個不是主要原因,後面網絡同僚利用各種工具得出結論,網絡不存在問題,是應用方面的問題。

想想也是,畢竟是區域網路,那接下來我們根據netstat的結果,将目光放到了用戶端的讀性能上。

2.4 用戶端網絡讀性能瓶頸分析

為此,我為了證明讀寫方面的性能,我修改了RocketMQ CLient相關的包,加入了Netty性能采集方面的代碼,其代碼截圖如下:

性能調優篇:困擾我半年之久的RocketMQ timeout exception 終于破解了

我的主要思路是判斷用戶端對于一個通道,每一次讀事件觸發,一個通道會進行多少次讀取操作,如果一次讀事件觸發,需要觸發很多次的讀取,說明一個通道中确實積壓了很多資料,網絡讀存在瓶頸。

但令人失望的是用戶端的網絡讀并不存在瓶頸,部分采集資料如下所示:

性能調優篇:困擾我半年之久的RocketMQ timeout exception 終于破解了

通過awk指令對其進行分析,發現一次讀事件觸發,大部分通道讀兩次即可将讀緩存區中的資料抽取成功,讀方面并不存在瓶頸,對awk執行的統計分析如下圖所示:

性能調優篇:困擾我半年之久的RocketMQ timeout exception 終于破解了

那矛頭又将指向Broker,是不是寫到緩存區中比較慢呢?

2.5 Broker端網絡層面瓶頸

經過上面的分析,Broker服務端寫入pagecache很快,次元将響應結果寫入網絡這個環節并未監控,是不是寫入響應結果并不及時,大量積壓在Netty的寫緩存區,進而導緻并未及時寫入到TCP的發送緩沖區,進而造成逾時。

筆者本來想也對其代碼進行改造,從Netty層面去監控服務端的寫性能,但考慮到風險較大,暫時沒有去修改代碼,而是再次認真讀取了RocketMQ封裝Netty的代碼,在此次讀取源碼之前,我一直以為RocketMQ的網絡層基本不需要進行參數優化,因為公司的伺服器都是64核心的,而Netty的IO線程預設都是CPU的核數,但在閱讀源碼發現,在RocketMQ中與IO相關的線程參數有如下兩個:

  • serverSelectorThreads

    預設值為3。

  • serverWorkerThreads

    預設值為8。

serverSelectorThreads,在Netty中,就是WorkGroup,即所謂的IO線程池,每一個線程池會持有一個NIO中的Selector對象用來進行事件選擇,所有的通道會輪流注冊在這3個線程中,綁定在一個線程中的所有Channel,會串行進行讀寫操作,即所有通道從TCP讀緩存區,将資料寫到發送緩存區都在這個線程中執行。

我們的MQ伺服器的配置,CPU的核屬都在64C及以上,用3個線程來做這個事情,顯然有點太“小家子氣”,該參數可以調優。

serverWorkerThreads,在Netty的線程模型中,預設情況下事件的傳播(編碼、解碼)都在IO線程中,即在上文中提到的Selector對象所在的線程,為了降低IO線程的壓力,RocketMQ單獨定義一個線程池,用于事件的傳播,即IO線程隻負責網絡讀、寫,讀取的資料進行解碼、寫入的資料進行編碼等操作,單獨放在一個獨立的線程池,線程池線程數量由serverWorkerThreads指定。

看到這裡,終于讓我心潮澎湃,感覺離真相越來越近了。參考Netty将IO線程設定為CPU核數的兩倍,我第一波參數優化設定為serverSelectorThreads=16,serverWorkerThreads=32,在生産環境進行一波驗證。

經過1個多月的驗證,在叢集機器數量減少(雙十一之後縮容),隻出現過極少數的消息發送逾時,基本可以忽略不計。

溫馨提示:關于Netty線程模型的詳解,可以參考 圖解Netty線程模型
性能調優篇:困擾我半年之久的RocketMQ timeout exception 終于破解了

3、總結

本文詳細介紹了筆者排查MQ發送逾時的精力,最終定位到的是RocketMQ服務端關于網絡通信線程模型參數設定不合理。

之是以耗費這麼長時間,其實有值得反思的地方,我被我的“經驗”誤導了,其實以前我對逾時的原因直接歸根于網絡,理由是RocketMQ的寫入PageCache資料非常好,基本都沒有超過100ms的寫入請求,以為RocketMQ服務端沒有性能瓶頸,并沒有從整個網絡通信層考慮。

好了,本文就介紹到這裡了,一鍵三連(關注、點贊、留言)是對我最大的鼓勵。

掌握一到兩門java主流中間件,是敲開BAT等大廠必備的技能,送給大家一個Java中間件學習路線,助力大家實作職場的蛻變。

Java進階之梯,成長路線與學習資料,助力突破中間件領域

最後分享筆者一個硬核的RocketMQ電子書,您将獲得千億級消息流轉的運維經驗。

性能調優篇:困擾我半年之久的RocketMQ timeout exception 終于破解了

擷取方式:RocketMQ電子書。

繼續閱讀