高并發(fā)場(chǎng)景創(chuàng)建JedisPool有哪些注意事項(xiàng)

本篇內(nèi)容介紹了“高并發(fā)場(chǎng)景創(chuàng)建JedisPool有哪些注意事項(xiàng)”的有關(guān)知識(shí)，在實(shí)際案例的操作過程中，不少人都會(huì)遇到這樣的困境，接下來就讓小編帶領(lǐng)大家學(xué)習(xí)一下如何處理這些情況吧！希望大家仔細(xì)閱讀，能夠?qū)W有所成！

一、背景

一個(gè)平靜的下午，報(bào)警、Moji群里接連傳來并行MOA默認(rèn)集群 /service/parallel 出現(xiàn)異常的提示信息，服務(wù)維護(hù)人員查看日志發(fā)現(xiàn)是發(fā)生了并行任務(wù)線程池被打滿的問題。線程池滿會(huì)導(dǎo)致新請(qǐng)求直接被拒絕，大量業(yè)務(wù)請(qǐng)求報(bào)錯(cuò)，極速版附近的人、基因、聊天室等多個(gè)業(yè)務(wù)進(jìn)入降級(jí)狀態(tài)... 而導(dǎo)致這一系列嚴(yán)重影響的問題原因，是大家最熟悉不過的 new JedisPool() 這一行代碼。

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

二、問題分析

從慢請(qǐng)求日志我們發(fā)現(xiàn)，單一請(qǐng)求阻塞線程的時(shí)間最長可達(dá)到10分鐘以上。簡單的new JedisPool()為何會(huì)長時(shí)間阻塞線程？通過搭建測(cè)試服務(wù)、復(fù)現(xiàn)問題、抓取jstack分析后，我們發(fā)現(xiàn)JedisPool中向JMX注冊(cè)對(duì)象的邏輯，在特定的場(chǎng)景會(huì)出現(xiàn)嚴(yán)重的鎖競(jìng)爭(zhēng)與阻塞問題。

包依賴說明

并行MOA工程 ->
MOA（MOARedisClient） ->
MCF（RedisDao） ->
Jedis（JedisPool） ->
commons-pool（BaseGenericObjectPool） ->
JDK（JMX）

問題出現(xiàn)在并行MOA通過MOARedisClient訪問下游服務(wù)新啟動(dòng)實(shí)例的過程中，此時(shí)需要通過new JedisPool()創(chuàng)建與下游實(shí)例的連接池。

new JedisPool()中與JMX的交互

JedisPool使用commons-pool來管理連接對(duì)象，commons-pool創(chuàng)建對(duì)象池時(shí)會(huì)向JMX注冊(cè)，以便于在運(yùn)行時(shí)通過JMX接口獲取對(duì)象池相關(guān)的監(jiān)控?cái)?shù)據(jù)。但向JMX注冊(cè)的過程，包含以下邏輯

1. commons-pool向JMX注冊(cè)BaseGenericObjectPool對(duì)象，JMX要求每個(gè)對(duì)象有不同的名字

2. commons-pool生成不同名字的方式是：基于一個(gè)默認(rèn)相同的名字，末尾添加一個(gè)自增ID

3. 每次new JedisPool()時(shí)ID從1開始嘗試，發(fā)現(xiàn)名字重復(fù)后ID自增+1后再次重試，直至發(fā)現(xiàn)一個(gè)未被占用的ID、重試成功為止

4. 嘗試某個(gè)名字是否被占用，會(huì)共用一把全局的鎖，同一時(shí)刻只能有一個(gè)JedisPool對(duì)象對(duì)某一個(gè)名字ID驗(yàn)證是否重復(fù)

commons-pool中遍歷ID嘗試注冊(cè)objName的代碼

JMX中注冊(cè)對(duì)象的代碼，會(huì)獲取一把全局的鎖

問題產(chǎn)生的條件

1. 當(dāng)前進(jìn)程中已創(chuàng)建了大量的JedisPool，有大量的自增ID已被占用（如1~1w已被占用）

2. 此時(shí)創(chuàng)建下一個(gè)JedisPool，需要遍歷1w次已有ID才能以1w + 1這個(gè)ID注冊(cè)對(duì)象，這1w次嘗試每次都需要加鎖

3. 當(dāng)有多個(gè)線程同時(shí)創(chuàng)建JedisPool時(shí)，每個(gè)線程都需要遍歷所有ID，并且遍歷過程中每次加鎖都會(huì)導(dǎo)致其他線程無法重試、只能等待

4. 假設(shè)1個(gè)線程遍歷1w次需要1秒，100個(gè)線程各遍歷1w次、共計(jì)100w次嘗試需要串行執(zhí)行，并且100個(gè)線程是交替獲得鎖、交替重試，最終導(dǎo)致100個(gè)線程都需要100秒才能重試完

三、問題排查過程

問題產(chǎn)生

16:14 /service/phpmoa/v1_microvideo_index 執(zhí)行常規(guī)的發(fā)布操作
16:16 /service/parallel 并行任務(wù)線程池被打滿、開始通過擴(kuò)容和隔離實(shí)例解決
16:26 服務(wù)逐步恢復(fù)

并行MOA使用了MSC線程池組件，從活躍線程數(shù)監(jiān)控可以看到每個(gè)并行MOA實(shí)例線程池被打滿到恢復(fù)的時(shí)間

被阻塞的線程是能夠自動(dòng)恢復(fù)的，并且恢復(fù)的時(shí)間并不統(tǒng)一。從日志中我們首先找到了阻塞線程的慢請(qǐng)求

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

剛好是調(diào)用 /service/phpmoa/v1_microvideo_index 服務(wù)，但記錄的執(zhí)行時(shí)間最長可達(dá)到10分鐘以上。慢日志中包含各個(gè)階段的耗時(shí)，因此耗時(shí)的邏輯可以鎖定在 blacklistTime 和 executeTime 之間，這里只對(duì)應(yīng)一行通過MOA框架MOARedisClient調(diào)用下游服務(wù)的代碼

初步分析

在MOARedisClient.exeuteByServer()內(nèi)部，僅有2個(gè)邏輯可能出現(xiàn)較長的耗時(shí)，一個(gè)是RedisFactory.getRedisDao()，這里會(huì)與下游實(shí)例創(chuàng)建連接。另一個(gè)是doInvoke()真正發(fā)起請(qǐng)求，由于后者的耗時(shí)會(huì)提交到Hubble，并且未發(fā)現(xiàn)達(dá)到分鐘級(jí)的耗時(shí)，因此問題的原因更可能出現(xiàn)在創(chuàng)建RedisDao的邏輯中。

排查瓶頸

由于RedisFactory.getRedisDao()各個(gè)階段的耗時(shí)缺少監(jiān)控，并且服務(wù)出現(xiàn)異常期間沒有及時(shí)通過jstack打印堆棧信息，問題排查到這一步僅靠分析很難繼續(xù)進(jìn)行。

問題復(fù)現(xiàn)

我們查找了 /service/phpmoa/v1_microvideo_index 的發(fā)布記錄，發(fā)現(xiàn)這個(gè)服務(wù)每次發(fā)布的時(shí)候，/service/parallel 都會(huì)有短暫的errorCount波動(dòng)，因此推斷該問題是能夠通過重啟 /service/phpmoa/v1_microvideo_index 來復(fù)現(xiàn)的。

搭建測(cè)試服務(wù)

重啟線上服務(wù)有可能再次導(dǎo)致服務(wù)異常、影響線上業(yè)務(wù)，所以我們先嘗試在線上環(huán)境復(fù)制上下游項(xiàng)目、發(fā)布成不同的ServiceUri，并增加一個(gè)測(cè)試接口，通過壓測(cè)平臺(tái)制造流量，搭建起和線上調(diào)用鏈路基本一致的測(cè)試環(huán)境。

增加監(jiān)控

除了在MOA和MCF的代碼中增加各階段耗時(shí)的日志外，對(duì)于并行MOA出現(xiàn)線程池滿拒絕請(qǐng)求、以及出現(xiàn)10秒以上慢請(qǐng)求的場(chǎng)景，均增加了自動(dòng)打印jstack的機(jī)制。

獲得排查依據(jù)

在適當(dāng)調(diào)整模擬流量的壓力后，重啟測(cè)試的 /service/phpmoa/v1_microvideo_index 服務(wù)后，問題提復(fù)現(xiàn)了。這一次我們拿到了詳細(xì)的耗時(shí)信息，以及線程池滿后的jstack堆棧信息，才進(jìn)一步分析到問題的根本原因。

四、問題驗(yàn)證

測(cè)試服務(wù)驗(yàn)證

1. 問題復(fù)現(xiàn)后的jstack堆棧，611個(gè)線程停留在等待鎖的步驟

2. 將JMX關(guān)閉后，對(duì)比其他未關(guān)閉的實(shí)例沒有再復(fù)現(xiàn)該問題

與問題現(xiàn)象匹配

并行MOA的特征

1. 調(diào)用的下游服務(wù)極多、下游實(shí)例數(shù)極多，需要?jiǎng)?chuàng)建大量的JedisPool

2. 下游重啟過程中并行MOA需要?jiǎng)?chuàng)建大量新的JedisPool，并且并行創(chuàng)建的線程數(shù)很多（最多800個(gè)）

問題發(fā)生過程

1. 下游服務(wù)發(fā)布后出問題（microvideo_index）、下游實(shí)例數(shù)多的服務(wù)發(fā)布問題嚴(yán)重（230個(gè)）、發(fā)布速度快的服務(wù)問題嚴(yán)重（2分鐘）、多個(gè)服務(wù)同時(shí)發(fā)布的時(shí)候問題嚴(yán)重（microvideo_index和user_location在同一時(shí)間段做發(fā)布）

2. 各個(gè)并行MOA實(shí)例能夠自動(dòng)恢復(fù)，但恢復(fù)的時(shí)間點(diǎn)差異較大（具體耗時(shí)取決于已有ID數(shù)量、并行創(chuàng)建JedisPool的線程數(shù)據(jù)量，各實(shí)例的情況可能不一致）

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

4. 相同時(shí)刻其他并行MOA的集群未出問題（因?yàn)檎?qǐng)求量低、并行創(chuàng)建JedisPool的線程少）

五、解決方案

問題影響范圍

業(yè)務(wù)上使用JedisPool的場(chǎng)景，多通過MCF的RedisDao封裝。RedisDao主要用于兩個(gè)場(chǎng)景

MomoStore

通過MomoStore訪問Redis數(shù)據(jù)源、訪問OneStore底層使用RedisDao。由于MomoStore對(duì)于新實(shí)例的連接建立是在接收事件通知后單線程執(zhí)行的，受并發(fā)創(chuàng)建JedisPool的影響較少。

MOARedisClient

由于與下游新實(shí)例創(chuàng)建連接的動(dòng)作是在業(yè)務(wù)請(qǐng)求中完成的，所以使用MOARedisClient的場(chǎng)景受并發(fā)創(chuàng)建JedisPool影響的可能性較大。當(dāng)服務(wù)與并行MOA具備類似的特征：下游服務(wù)多、實(shí)例多，并行執(zhí)行的請(qǐng)求多，在下游服務(wù)發(fā)布時(shí)也容易出現(xiàn)相同的問題。使用MOARedisClient在某些場(chǎng)景下的執(zhí)行時(shí)間超出設(shè)定的timeout時(shí)間，也與該問題有關(guān)。

修復(fù)方案

最簡單有效的解決方案是關(guān)閉JedisPool的JMX配置，可以在MCF的代碼中統(tǒng)一修改、通過升級(jí)MCF版本修復(fù)。對(duì)于已接入Mesh的服務(wù)，由于MOARedisClient實(shí)際與下游通信的地址是127.0.0.1，所需建立的連接池很少，所以不會(huì)受該問題影響。后續(xù)我們會(huì)掃描所有使用MOARedisClient、但尚未接入Mesh的服務(wù)，推動(dòng)升級(jí)MCF版本消除這一隱患。

其他改進(jìn)項(xiàng)

在MSC線程池中加入線程池滿自動(dòng)打印jstack的機(jī)制。

“高并發(fā)場(chǎng)景創(chuàng)建JedisPool有哪些注意事項(xiàng)”的內(nèi)容就介紹到這里了，感謝大家的閱讀。如果想了解更多行業(yè)相關(guān)的知識(shí)可以關(guān)注億速云網(wǎng)站，小編將為大家輸出更多高質(zhì)量的實(shí)用文章！