Redis Cluster Pipeline導致的死鎖問題解決
本文介紹了一次排查Dubbo線程池耗盡問題的過程。通過查看Dubbo線程狀態(tài)、分析Jedis連接池獲取連接的源碼、排查死鎖條件等方面,最終確認是因為使用了cluster pipeline模式且沒有設置超時時間導致死鎖問題。
一、背景介紹
Redis Pipeline是一種高效的命令批量處理機制,可以在Redis中大幅度降低網(wǎng)絡延遲,提高讀寫能力。Redis Cluster Pipeline是基于Redis Cluster的pipeline,通過將多個操作打包成一組操作,一次性發(fā)送到Redis Cluster中的多個節(jié)點,減少了通信延遲,提高了整個系統(tǒng)的讀寫吞吐量和性能,適用于需要高效處理Redis Cluster命令的場景。
本次使用到pipeline的場景是批量從Redis Cluster批量查詢預約游戲信息,項目內(nèi)使用的Redis Cluster Pipeline的流程如下,其中的JedisClusterPipeline是我們內(nèi)部使用的工具類,提供Redis Cluster模式下的pipeline能力:
JedisClusterPipeline使用:
JedisClusterPipline jedisClusterPipline = redisService.clusterPipelined();
List<Object> response;
try {
for (String key : keys) {
jedisClusterPipline.hmget(key, VALUE1, VALUE2);
}
// 獲取結(jié)果
response = jedisClusterPipline.syncAndReturnAll();
} finally {
jedisClusterPipline.close();
}二、故障現(xiàn)場記錄
某天,收到了Dubbo線程池耗盡的告警。查看日志發(fā)現(xiàn)只有一臺機器有問題,并且一直沒恢復,已完成任務數(shù)也一直沒有增加。

查看請求數(shù)監(jiān)控,發(fā)現(xiàn)請求數(shù)歸零,很明顯機器已經(jīng)掛了。

使用arthas查看Dubbo線程,發(fā)現(xiàn)400個線程全部處于waiting狀態(tài)。

三、故障過程分析
Dubbo線程處于waiting狀態(tài)這一點沒有問題,Dubbo線程等待任務的時候也是waiting狀態(tài),但是查看完整調(diào)用棧發(fā)現(xiàn)有問題,下面兩張圖里的第一張是問題機器的棧,第二張是正常機器的棧,顯然問題機器的這個線程在等待Redis連接池里有可用連接。


使用jstack導出線程快照后發(fā)現(xiàn)問題機器所有的Dubbo線程都在等待Redis連接池里有可用連接。
調(diào)查到這里,能發(fā)現(xiàn)兩個問題。
- 線程一直等待連接而沒有被中斷。
- 線程獲取不到連接。
3.1 線程一直等待連接而沒有被中斷原因分析
Jedis獲取連接的邏輯在org.apache.commons.pool2.impl.GenericObjectPool#borrowObject(long)方法下。
public T borrowObject(long borrowMaxWaitMillis) throws Exception {
...
PooledObject<T> p = null;
// 獲取blockWhenExhausted配置項,該配置默認值為true
boolean blockWhenExhausted = getBlockWhenExhausted();
boolean create;
long waitTime = System.currentTimeMillis();
while (p == null) {
create = false;
if (blockWhenExhausted) {
// 從隊列獲取空閑的對象,該方法不會阻塞,沒有空閑對象會返回null
p = idleObjects.pollFirst();
// 沒有空閑對象則創(chuàng)建
if (p == null) {
p = create();
if (p != null) {
create = true;
}
}
if (p == null) {
// borrowMaxWaitMillis默認值為-1
if (borrowMaxWaitMillis < 0) {
// 線程??煺绽锼械膁ubbo線程都卡在這里,這是個阻塞方法,如果隊列里沒有新的連接會一直等待下去
p = idleObjects.takeFirst();
} else {
// 等待borrowMaxWaitMillis配置的時間還沒有拿到連接的話就返回null
p = idleObjects.pollFirst(borrowMaxWaitMillis,
TimeUnit.MILLISECONDS);
}
}
if (p == null) {
throw new NoSuchElementException(
"Timeout waiting for idle object");
}
if (!p.allocate()) {
p = null;
}
}
...
}
updateStatsBorrow(p, System.currentTimeMillis() - waitTime);
return p.getObject();
}由于業(yè)務代碼沒有設置borrowMaxWaitMillis,導致線程一直在等待可用連接 ,該值可以通過配置jedis pool的maxWaitMillis屬性來設置。
到這里已經(jīng)找到線程一直等待的原因,但線程獲取不到連接的原因還需要繼續(xù)分析。
3.2 線程獲取不到連接原因分析
獲取不到連接無非兩種情況:
- 連不上Redis,無法創(chuàng)建連接
- 連接池里的所有連接都被占用了,無法獲取到連接
猜想一:是不是連不上Redis?
詢問運維得知發(fā)生問題的時間點確實有一波網(wǎng)絡抖動,但是很快就恢復了,排查時問題機器是能正常連上Redis的。那有沒有可能是創(chuàng)建Redis連接的流程寫的有問題,無法從網(wǎng)絡抖動中恢復導致線程卡死?這一點要從源碼中尋找答案。
創(chuàng)建連接:
private PooledObject<T> create() throws Exception {
int localMaxTotal = getMaxTotal();
long newCreateCount = createCount.incrementAndGet();
if (localMaxTotal > -1 && newCreateCount > localMaxTotal ||
newCreateCount > Integer.MAX_VALUE) {
createCount.decrementAndGet();
return null;
}
final PooledObject<T> p;
try {
// 創(chuàng)建redis連接,如果發(fā)生超時會拋出異常
// 默認的connectionTimeout和soTimeout都是2秒
p = factory.makeObject();
} catch (Exception e) {
createCount.decrementAndGet();
// 這里會把異常繼續(xù)往上拋出
throw e;
}
AbandonedConfig ac = this.abandonedConfig;
if (ac != null && ac.getLogAbandoned()) {
p.setLogAbandoned(true);
}
createdCount.incrementAndGet();
allObjects.put(new IdentityWrapper<T>(p.getObject()), p);
return p;
}可以看到,連接Redis超時時會拋出異常,調(diào)用create()函數(shù)的borrowObject()也不會捕獲這個異常,這個異常最終會在業(yè)務層被捕獲,所以連不上Redis的話是不會一直等待下去的,網(wǎng)絡恢復后再次調(diào)用create()方法就能重新創(chuàng)建連接。
綜上所訴,第一種情況可以排除,繼續(xù)分析情況2,連接被占用了沒問題,但是一直不釋放就有問題。
猜想二:是不是業(yè)務代碼沒有歸還Redis連接?
連接沒有釋放,最先想到的是業(yè)務代碼里可能有地方漏寫了歸還Redis連接的代碼,pipeline模式下需要在finally塊中手動調(diào)用JedisClusterPipeline#close()方法將連接歸還給連接池,而普通模式下不需要手動釋放(參考redis.clients.jedis.JedisClusterCommand#runWithRetries,每次執(zhí)行完命令后都會自動釋放),在業(yè)務代碼里全局搜索所有使用到了cluster pipeline的代碼,均手動調(diào)用了JedisClusterPipeline#close()方法,所以不是業(yè)務代碼的問題。
猜想三:是不是Jedis存在連接泄露的問題?
既然業(yè)務代碼沒問題,那有沒有可能是歸還連接的代碼有問題,存在連接泄露?2.10.0版本的Jedis確實可能發(fā)生連接泄露,具體可以看這個issue:https://github.com/redis/jedis/issues/1920,不過我們項目內(nèi)使用的是2.9.0版本,所以排除連接泄露的情況。
猜想四:是不是發(fā)生了死鎖?
排除以上可能性后,能想到原因的只剩死鎖,思考后發(fā)現(xiàn)在沒有設置超時時間的情況下,使用pipeline確實有概率發(fā)生死鎖,這個死鎖發(fā)生在從連接池(LinkedBlockingDeque)獲取連接的時候。
先看下cluster pipeline模式下的Redis和普通的Redis有什么區(qū)別。Jedis為每個Redis實例都維護了一個連接池,cluster pipeline模式下,先使用查詢用的key計算出其所在的Redis實例列表,再從這些實例對應的連接池里獲取到連接,使用完后統(tǒng)一釋放。而普通模式下一次只會獲取一個連接池的連接,用完后立刻釋放。這意味著cluster pipeline模式在獲取連接時是符合死鎖的“占有并等待”條件的,而普通模式不符合這個條件。
JedisClusterPipeline使用:
JedisClusterPipline jedisClusterPipline = redisService.clusterPipelined();
List<Object> response;
try {
for (String key : keys) {
// 申請連接,內(nèi)部會先調(diào)用JedisClusterPipeline.getClient(String key)方法獲取連接
jedisClusterPipline.hmget(key, VALUE1, VALUE2);
// 獲取到了連接,緩存到poolToJedisMap
}
// 獲取結(jié)果
response = jedisClusterPipline.syncAndReturnAll();
} finally {
// 歸還所有連接
jedisClusterPipline.close();
}JedisClusterPipeline部分源碼:
public class JedisClusterPipline extends PipelineBase implements Closeable {
private static final Logger log = LoggerFactory.getLogger(JedisClusterPipline.class);
// 用于記錄redis命令的執(zhí)行順序
private final Queue<Client> orderedClients = new LinkedList<>();
// redis連接緩存
private final Map<JedisPool, Jedis> poolToJedisMap = new HashMap<>();
private final JedisSlotBasedConnectionHandler connectionHandler;
private final JedisClusterInfoCache clusterInfoCache;
public JedisClusterPipline(JedisSlotBasedConnectionHandler connectionHandler, JedisClusterInfoCache clusterInfoCache) {
this.connectionHandler = connectionHandler;
this.clusterInfoCache = clusterInfoCache;
}
@Override
protected Client getClient(String key) {
return getClient(SafeEncoder.encode(key));
}
@Override
protected Client getClient(byte[] key) {
Client client;
// 計算key所在的slot
int slot = JedisClusterCRC16.getSlot(key);
// 獲取solt對應的連接池
JedisPool pool = clusterInfoCache.getSlotPool(slot);
// 從緩存獲取連接
Jedis borrowedJedis = poolToJedisMap.get(pool);
// 緩存中沒有連接則從連接池獲取并緩存
if (null == borrowedJedis) {
borrowedJedis = pool.getResource();
poolToJedisMap.put(pool, borrowedJedis);
}
client = borrowedJedis.getClient();
orderedClients.add(client);
return client;
}
@Override
public void close() {
for (Jedis jedis : poolToJedisMap.values()) {
// 清除連接內(nèi)的殘留數(shù)據(jù),防止連接歸還時有數(shù)據(jù)漏讀的現(xiàn)象
try {
jedis.getClient().getAll();
} catch (Throwable throwable) {
log.warn("關(guān)閉jedis時遍歷異常,遍歷的目的是:清除連接內(nèi)的殘留數(shù)據(jù),防止連接歸還時有數(shù)據(jù)漏讀的現(xiàn)象");
}
try {
jedis.close();
} catch (Throwable throwable) {
log.warn("關(guān)閉jedis異常");
}
}
// 歸還連接
clean();
orderedClients.clear();
poolToJedisMap.clear();
}
/**
* go through all the responses and generate the right response type (warning :
* usually it is a waste of time).
*
* @return A list of all the responses in the order
*/
public List<Object> syncAndReturnAll() {
List<Object> formatted = new ArrayList<>();
List<Throwable> throwableList = new ArrayList<>();
for (Client client : orderedClients) {
try {
Response response = generateResponse(client.getOne());
if(response == null){
continue;
}
formatted.add(response.get());
} catch (Throwable e) {
throwableList.add(e);
}
}
slotCacheRefreshed(throwableList);
return formatted;
}
}
舉個例子:
假設有一個集群有兩臺Redis主節(jié)點(集群模式下最小的主節(jié)點數(shù)量是3,這里只是為了舉例),記為節(jié)點1/2,有個java程序有4個Dubbo線程,記為線程1/2/3/4,每個Redis實例都有一個大小為2的連接池。
線程1和線程2,先獲取Redis1的連接再獲取Redis2的連接。線程3和線程4,先獲取Redis2的連接再獲取Redis1的連接,假設這四個線程在獲取到連接第一個連接后都等待了一會,在獲取第二個連接的時候就會發(fā)生死鎖(等待時間越長,觸發(fā)的概率越大)。

所以pipeline是可能導致死鎖的,這個死鎖的條件很容易破壞,等待連接的時候設置超時時間即可。還可以增大下連接池的大小,資源夠的話也不會發(fā)生死鎖。
四、死鎖證明
以上只是猜想,為了證明確實發(fā)生了死鎖,需要以下條件:
- 線程當前獲取到了哪些連接池的連接
- 線程當前在等待哪些連接池的連接
- 每個連接池還剩多少連接
已知問題機器的Dubbo線程池大小為400,Redis集群主節(jié)點數(shù)量為12,Jedis配置的連接池大小為20。
4.1 步驟一:獲取線程在等待哪個連接池有空閑連接
第一步:先通過jstack和jmap分別導出棧和堆
第二步:通過分析??梢灾谰€程在等待的鎖的地址,可以看到Dubbo線程383在等待0x6a3305858這個鎖對象,這個鎖屬于某個連接池,需要找到具體是哪個連接池。

第三步:使用mat(Eclipse Memory Analyzer Tool)工具分析堆,通過鎖的地址找到對應的連接池。

使用mat的with incoming references功能順著引用一層層的往上找。

引用關(guān)系:ConditionObject->LinkedBlockingDeque

引用關(guān)系:LinkedBlockingDeque->GenericObjectPool

引用關(guān)系:GenericObjectPool->JedisPool。這里的ox6a578ddc8就是這個鎖所屬的連接池地址。

這樣我們就能知道Dubbo線程383當前在等待0x6a578ddc8這個連接池的連接。
通過這一套流程,我們可以知道每個Dubbo線程分別在等待哪些連接池有可用連接。
4.2 步驟二:獲取線程當前持有了哪些連接池的連接
第一步:使用mat在堆中查找所有JedisClusterPipeline類(正好400個,每個Dubbo線程都各有一個),然后查看里面的poolToJedisMap,其中保存了當前JedisClusterPipeline已經(jīng)持有的連接和其所屬的連接池。
下圖中,我們可以看到JedisClusterPipeline(0x6ac40c088)對象當前的poolToJedisMap里有三個Node對象(0x6ac40dd40, 0x6ac40dd60, 0x6ac40dd80),代表其持有三個連接池的連接,可以從Node對象中找到JedisPool的地址。

第二步:第一步拿到JedisClusterPipeline持有哪個連接池的連接后,再查找持有此JedisClusterPipeline的Dubbo線程,這樣就能得到Dubbo線程當前持有哪些連接池的連接。

4.3 死鎖分析
通過流程一可以發(fā)現(xiàn)雖然Redis主節(jié)點有12個,但是所有的Dubbo線程都只在等待以下5個節(jié)點對應的連接池之一:
- 0x6a578e0c8
- 0x6a578e048
- 0x6a578ddc8
- 0x6a578e538
- 0x6a578e838
通過流程二我們可以得知這5個連接池的連接當前被哪些線程占用:

已知每個連接池的大小都配置為了20,這5個連接池的所有連接已經(jīng)被100個Dubbo線程占用完了,而所有的400個Dubbo線程又都在等待這5個連接池的連接,并且其等待的連接當前沒被自己占用,通過這些條件,我們可以確定發(fā)生了死鎖。
五、總結(jié)
這篇文章主要展現(xiàn)了一次系統(tǒng)故障的分析過程。在排查過程中,作者使用jmap和jstack保存故障現(xiàn)場,使用arthas分析故障現(xiàn)場,再通過閱讀和分析源碼,從多個可能的角度一步步的推演故障原因,推測是死鎖引起的故障。在驗證死鎖問題時,作者使用mat按照一定的步驟來尋找線程在等待哪個連接池的連接和持有哪些連接池的連接,再結(jié)合死鎖檢測算法最終確認故障機器發(fā)生了死鎖。
排查線上問題并非易事,不僅要對業(yè)務代碼有足夠的了解,還要對相關(guān)技術(shù)知識有系統(tǒng)性的了解,推測出可能導致問題的原因后,再熟練運用好排查工具,最終確認問題原因。
到此這篇關(guān)于Redis Cluster Pipeline導致的死鎖問題解決的文章就介紹到這了,更多相關(guān)Redis Cluster Pipeline死鎖內(nèi)容請搜索腳本之家以前的文章或繼續(xù)瀏覽下面的相關(guān)文章希望大家以后多多支持腳本之家!
相關(guān)文章
Redis鎖的過期時間小于業(yè)務的執(zhí)行時間如何續(xù)期
本文主要介紹了Redis鎖的過期時間小于業(yè)務的執(zhí)行時間如何續(xù)期,Redisson它能給Redis分布式鎖實現(xiàn)過期時間自動續(xù)期,具有一定的參考價值,感興趣的可以了解一下2024-05-05
Redis實戰(zhàn)之Redis實現(xiàn)異步秒殺優(yōu)化詳解
這篇文章主要給大家介紹了Redis實戰(zhàn)之Redis實現(xiàn)異步秒殺優(yōu)化方法,文章通過圖片和代碼介紹的非常詳細,對大家的學習或工作有一定的幫助,感興趣的同學可以自己動手試一下2023-09-09
Redis和Nginx實現(xiàn)限制接口請求頻率的示例
限流就是限制API訪問頻率,當訪問頻率超過某個閾值時進行拒絕訪問等操作,本文主要介紹了Redis和Nginx實現(xiàn)限制接口請求頻率的示例,具有一定的參考價值,感興趣的可以了解一下2024-02-02
springboot中redis并發(fā)鎖的等待時間設置長短的方法
在SpringBoot應用中,Redis鎖的等待時間設置不當可能導致資源浪費、響應時間增加、死鎖風險升高、系統(tǒng)負載增加、業(yè)務邏輯延遲以及故障恢復慢等問題,建議合理設置等待時間,并考慮使用其他分布式鎖實現(xiàn)方式提高性能2024-10-10

