高併發場景建立 JedisPool 有哪些注意事項?

語言: CN / TW / HK

一、背景

一個平靜的下午,報警、Moji 群裡接連傳來並行 MOA 預設叢集 /service/parallel 出現異常的提示資訊,服務維護人員檢視日誌發現是發生了並行任務執行緒池被打滿的問題。執行緒池滿會導致新請求直接被拒絕,大量業務請求報錯,極速版附近的人、基因、聊天室等多個業務進入降級狀態... 而導致這一系列嚴重影響的問題原因,是大家最熟悉不過的 new JedisPool() 這一行程式碼。

Jedis 是 Java 訪問 Redis 最常用的客戶端元件

二、問題分析

從慢請求日誌我們發現,單一請求阻塞執行緒的時間最長可達到 10 分鐘以上。簡單的 new JedisPool()為何會長時間阻塞執行緒?通過搭建測試服務、復現問題、抓取 jstack 分析後,我們發現 JedisPool 中向 JMX 註冊物件的邏輯,在特定的場景會出現嚴重的鎖競爭與阻塞問題。

包依賴說明

並行 MOA 工程 ->MOA(MOARedisClient) ->MCF(RedisDao) ->Jedis(JedisPool) ->commons-pool(BaseGenericObjectPool) ->JDK(JMX)

問題出現在並行 MOA 通過 MOARedisClient 訪問下游服務新啟動例項的過程中,此時需要通過 new JedisPool()建立與下游例項的連線池。

new JedisPool()中與 JMX 的互動

JedisPool 使用 commons-pool 來管理連線物件,commons-pool 建立物件池時會向 JMX 註冊,以便於在執行時通過 JMX 介面獲取物件池相關的監控資料。但向 JMX 註冊的過程,包含以下邏輯

  1. commons-pool 向 JMX 註冊 BaseGenericObjectPool 物件,JMX 要求每個物件有不同的名字

  2. commons-pool 生成不同名字的方式是:基於一個預設相同的名字,末尾新增一個自增 ID

  3. 每次 new JedisPool()時 ID 從 1 開始嘗試,發現名字重複後 ID 自增+1 後再次重試,直至發現一個未被佔用的 ID、重試成功為止

  4. 嘗試某個名字是否被佔用,會共用一把全域性的鎖,同一時刻只能有一個 JedisPool 物件對某一個名字 ID 驗證是否重複

commons-pool 中遍歷 ID 嘗試註冊 objName 的程式碼

JMX 中註冊物件的程式碼,會獲取一把全域性的鎖

問題產生的條件

  1. 當前程序中已建立了大量的 JedisPool,有大量的自增 ID 已被佔用(如 1~1w 已被佔用)

  2. 此時建立下一個 JedisPool,需要遍歷 1w 次已有 ID 才能以 1w + 1 這個 ID 註冊物件,這 1w 次嘗試每次都需要加鎖

  3. 當有多個執行緒同時建立 JedisPool 時,每個執行緒都需要遍歷所有 ID,並且遍歷過程中每次加鎖都會導致其他執行緒無法重試、只能等待

  4. 假設 1 個執行緒遍歷 1w 次需要 1 秒,100 個執行緒各遍歷 1w 次、共計 100w 次嘗試需要序列執行,並且 100 個執行緒是交替獲得鎖、交替重試,最終導致 100 個執行緒都需要 100 秒才能重試完

三、問題排查過程

問題產生

16:14 /service/phpmoa/v1_microvideo_index 執行常規的釋出操作 16:16 /service/parallel 並行任務執行緒池被打滿、開始通過擴容和隔離例項解決 16:26 服務逐步恢復

並行 MOA 使用了 MSC 執行緒池元件,從活躍執行緒數監控可以看到每個並行 MOA 例項執行緒池被打滿到恢復的時間

被阻塞的執行緒是能夠自動恢復的,並且恢復的時間並不統一。從日誌中我們首先找到了阻塞執行緒的慢請求

execution finished after parallel timeout: /service/phpmoa/v1_microvideo_index,isRiskFeeds, startTime = 2020-11-30 16:26:02,428, server = 10.116.88.15:20000, routeTime = 2020-11-30 16:26:02,428, blacklistTime = 2020-11-30 16:26:02,428, executeTime = 2020-11-30 16:37:21,657, timeCost = 679229

複製程式碼

剛好是呼叫 /service/phpmoa/v1_microvideo_index 服務,但記錄的執行時間最長可達到 10 分鐘以上。慢日誌中包含各個階段的耗時,因此耗時的邏輯可以鎖定在 blacklistTime 和 executeTime 之間,這裡只對應一行通過 MOA 框架 MOARedisClient 呼叫下游服務的程式碼

初步分析

在 MOARedisClient.exeuteByServer()內部,僅有 2 個邏輯可能出現較長的耗時,一個是 RedisFactory.getRedisDao(),這裡會與下游例項建立連線。另一個是 doInvoke()真正發起請求,由於後者的耗時會提交到 Hubble,並且未發現達到分鐘級的耗時,因此問題的原因更可能出現在建立 RedisDao 的邏輯中。

排查瓶頸

由於 RedisFactory.getRedisDao()各個階段的耗時缺少監控,並且服務出現異常期間沒有及時通過 jstack 列印堆疊資訊,問題排查到這一步僅靠分析很難繼續進行。

問題復現

我們查找了 /service/phpmoa/v1_microvideo_index 的釋出記錄,發現這個服務每次釋出的時候,/service/parallel 都會有短暫的 errorCount 波動,因此推斷該問題是能夠通過重啟 /service/phpmoa/v1_microvideo_index 來複現的。

搭建測試服務

重啟線上服務有可能再次導致服務異常、影響線上業務,所以我們先嚐試在線上環境複製上下游專案、釋出成不同的 ServiceUri,並增加一個測試介面,通過壓測平臺製造流量,搭建起和線上呼叫鏈路基本一致的測試環境。

增加監控

除了在 MOA 和 MCF 的程式碼中增加各階段耗時的日誌外,對於並行 MOA 出現執行緒池滿拒絕請求、以及出現 10 秒以上慢請求的場景,均增加了自動列印 jstack 的機制。

獲得排查依據

在適當調整模擬流量的壓力後,重啟測試的 /service/phpmoa/v1_microvideo_index 服務後,問題提復現了。這一次我們拿到了詳細的耗時資訊,以及執行緒池滿後的 jstack 堆疊資訊,才進一步分析到問題的根本原因。

四、問題驗證

測試服務驗證

  1. 問題復現後的 jstack 堆疊,611 個執行緒停留在等待鎖的步驟

  2. 將 JMX 關閉後,對比其他未關閉的例項沒有再復現該問題

與問題現象匹配

並行 MOA 的特徵

  1. 呼叫的下游服務極多、下游例項數極多,需要建立大量的 JedisPool

  2. 下游重啟過程中並行 MOA 需要建立大量新的 JedisPool,並且並行建立的執行緒數很多(最多 800 個)

問題發生過程

  1. 下游服務釋出後出問題(microvideo_index)、下游例項數多的服務釋出問題嚴重(230 個)、釋出速度快的服務問題嚴重(2 分鐘)、多個服務同時釋出的時候問題嚴重(microvideo_index 和 user_location 在同一時間段做釋出)

  2. 各個並行 MOA 例項能夠自動恢復,但恢復的時間點差異較大(具體耗時取決於已有 ID 數量、並行建立 JedisPool 的執行緒資料量,各例項的情況可能不一致)

  3. 異常期間並行 MOA 服務的 CPU 使用率大幅升高(在頻繁獲取鎖)

  4. 相同時刻其他並行 MOA 的叢集未出問題(因為請求量低、並行建立 JedisPool 的執行緒少)

五、解決方案

問題影響範圍

業務上使用 JedisPool 的場景,多通過 MCF 的 RedisDao 封裝。RedisDao 主要用於兩個場景

MomoStore

通過 MomoStore 訪問 Redis 資料來源、訪問 OneStore 底層使用 RedisDao。由於 MomoStore 對於新例項的連線建立是在接收事件通知後單執行緒執行的,受併發建立 JedisPool 的影響較少。

MOARedisClient

由於與下游新例項建立連線的動作是在業務請求中完成的,所以使用 MOARedisClient 的場景受併發建立 JedisPool 影響的可能性較大。當服務與並行 MOA 具備類似的特徵:下游服務多、例項多,並行執行的請求多,在下游服務釋出時也容易出現相同的問題。使用 MOARedisClient 在某些場景下的執行時間超出設定的 timeout 時間,也與該問題有關。

修復方案

最簡單有效的解決方案是關閉 JedisPool 的 JMX 配置,可以在 MCF 的程式碼中統一修改、通過升級 MCF 版本修復。對於已接入 Mesh 的服務,由於 MOARedisClient 實際與下游通訊的地址是 127.0.0.1,所需建立的連線池很少,所以不會受該問題影響。後續我們會掃描所有使用 MOARedisClient、但尚未接入 Mesh 的服務,推動升級 MCF 版本消除這一隱患。

其他改進項

在 MSC 執行緒池中加入執行緒池滿自動列印 jstack 的機制。