Redis Cluster Pipeline導(dǎo)致的死鎖問題解決
本文介紹了一次排查Dubbo線程池耗盡問題的過程。通過查看Dubbo線程狀態(tài)、分析Jedis連接池獲取連接的源碼、排查死鎖條件等方面,最終確認(rèn)是因?yàn)槭褂昧薱luster pipeline模式且沒有設(shè)置超時(shí)時(shí)間導(dǎo)致死鎖問題。
一、背景介紹
Redis Pipeline是一種高效的命令批量處理機(jī)制,可以在Redis中大幅度降低網(wǎng)絡(luò)延遲,提高讀寫能力。Redis Cluster Pipeline是基于Redis Cluster的pipeline,通過將多個(gè)操作打包成一組操作,一次性發(fā)送到Redis Cluster中的多個(gè)節(jié)點(diǎn),減少了通信延遲,提高了整個(gè)系統(tǒng)的讀寫吞吐量和性能,適用于需要高效處理Redis Cluster命令的場(chǎng)景。
本次使用到pipeline的場(chǎng)景是批量從Redis Cluster批量查詢預(yù)約游戲信息,項(xiàng)目?jī)?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)場(chǎng)記錄
某天,收到了Dubbo線程池耗盡的告警。查看日志發(fā)現(xiàn)只有一臺(tái)機(jī)器有問題,并且一直沒恢復(fù),已完成任務(wù)數(shù)也一直沒有增加。
查看請(qǐng)求數(shù)監(jiān)控,發(fā)現(xiàn)請(qǐng)求數(shù)歸零,很明顯機(jī)器已經(jīng)掛了。
使用arthas查看Dubbo線程,發(fā)現(xiàn)400個(gè)線程全部處于waiting狀態(tài)。
三、故障過程分析
Dubbo線程處于waiting狀態(tài)這一點(diǎn)沒有問題,Dubbo線程等待任務(wù)的時(shí)候也是waiting狀態(tài),但是查看完整調(diào)用棧發(fā)現(xiàn)有問題,下面兩張圖里的第一張是問題機(jī)器的棧,第二張是正常機(jī)器的棧,顯然問題機(jī)器的這個(gè)線程在等待Redis連接池里有可用連接。
使用jstack導(dǎo)出線程快照后發(fā)現(xiàn)問題機(jī)器所有的Dubbo線程都在等待Redis連接池里有可用連接。
調(diào)查到這里,能發(fā)現(xiàn)兩個(gè)問題。
- 線程一直等待連接而沒有被中斷。
- 線程獲取不到連接。
3.1 線程一直等待連接而沒有被中斷原因分析
Jedis獲取連接的邏輯在org.apache.commons.pool2.impl.GenericObjectPool#borrowObject(long)方法下。
public T borrowObject(long borrowMaxWaitMillis) throws Exception { ... PooledObject<T> p = null; // 獲取blockWhenExhausted配置項(xiàng),該配置默認(rèn)值為true boolean blockWhenExhausted = getBlockWhenExhausted(); boolean create; long waitTime = System.currentTimeMillis(); while (p == null) { create = false; if (blockWhenExhausted) { // 從隊(duì)列獲取空閑的對(duì)象,該方法不會(huì)阻塞,沒有空閑對(duì)象會(huì)返回null p = idleObjects.pollFirst(); // 沒有空閑對(duì)象則創(chuàng)建 if (p == null) { p = create(); if (p != null) { create = true; } } if (p == null) { // borrowMaxWaitMillis默認(rèn)值為-1 if (borrowMaxWaitMillis < 0) { // 線程棧快照里所有的dubbo線程都卡在這里,這是個(gè)阻塞方法,如果隊(duì)列里沒有新的連接會(huì)一直等待下去 p = idleObjects.takeFirst(); } else { // 等待borrowMaxWaitMillis配置的時(shí)間還沒有拿到連接的話就返回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è)務(wù)代碼沒有設(shè)置borrowMaxWaitMillis,導(dǎo)致線程一直在等待可用連接 ,該值可以通過配置jedis pool的maxWaitMillis屬性來設(shè)置。
到這里已經(jīng)找到線程一直等待的原因,但線程獲取不到連接的原因還需要繼續(xù)分析。
3.2 線程獲取不到連接原因分析
獲取不到連接無非兩種情況:
- 連不上Redis,無法創(chuàng)建連接
- 連接池里的所有連接都被占用了,無法獲取到連接
猜想一:是不是連不上Redis?
詢問運(yùn)維得知發(fā)生問題的時(shí)間點(diǎn)確實(shí)有一波網(wǎng)絡(luò)抖動(dòng),但是很快就恢復(fù)了,排查時(shí)問題機(jī)器是能正常連上Redis的。那有沒有可能是創(chuàng)建Redis連接的流程寫的有問題,無法從網(wǎng)絡(luò)抖動(dòng)中恢復(fù)導(dǎo)致線程卡死?這一點(diǎn)要從源碼中尋找答案。
創(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ā)生超時(shí)會(huì)拋出異常 // 默認(rèn)的connectionTimeout和soTimeout都是2秒 p = factory.makeObject(); } catch (Exception e) { createCount.decrementAndGet(); // 這里會(huì)把異常繼續(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超時(shí)時(shí)會(huì)拋出異常,調(diào)用create()函數(shù)的borrowObject()也不會(huì)捕獲這個(gè)異常,這個(gè)異常最終會(huì)在業(yè)務(wù)層被捕獲,所以連不上Redis的話是不會(huì)一直等待下去的,網(wǎng)絡(luò)恢復(fù)后再次調(diào)用create()方法就能重新創(chuàng)建連接。
綜上所訴,第一種情況可以排除,繼續(xù)分析情況2,連接被占用了沒問題,但是一直不釋放就有問題。
猜想二:是不是業(yè)務(wù)代碼沒有歸還Redis連接?
連接沒有釋放,最先想到的是業(yè)務(wù)代碼里可能有地方漏寫了歸還Redis連接的代碼,pipeline模式下需要在finally塊中手動(dòng)調(diào)用JedisClusterPipeline#close()方法將連接歸還給連接池,而普通模式下不需要手動(dòng)釋放(參考redis.clients.jedis.JedisClusterCommand#runWithRetries,每次執(zhí)行完命令后都會(huì)自動(dòng)釋放),在業(yè)務(wù)代碼里全局搜索所有使用到了cluster pipeline的代碼,均手動(dòng)調(diào)用了JedisClusterPipeline#close()方法,所以不是業(yè)務(wù)代碼的問題。
猜想三:是不是Jedis存在連接泄露的問題?
既然業(yè)務(wù)代碼沒問題,那有沒有可能是歸還連接的代碼有問題,存在連接泄露?2.10.0版本的Jedis確實(shí)可能發(fā)生連接泄露,具體可以看這個(gè)issue:https://github.com/redis/jedis/issues/1920,不過我們項(xiàng)目?jī)?nèi)使用的是2.9.0版本,所以排除連接泄露的情況。
猜想四:是不是發(fā)生了死鎖?
排除以上可能性后,能想到原因的只剩死鎖,思考后發(fā)現(xiàn)在沒有設(shè)置超時(shí)時(shí)間的情況下,使用pipeline確實(shí)有概率發(fā)生死鎖,這個(gè)死鎖發(fā)生在從連接池(LinkedBlockingDeque)獲取連接的時(shí)候。
先看下cluster pipeline模式下的Redis和普通的Redis有什么區(qū)別。Jedis為每個(gè)Redis實(shí)例都維護(hù)了一個(gè)連接池,cluster pipeline模式下,先使用查詢用的key計(jì)算出其所在的Redis實(shí)例列表,再從這些實(shí)例對(duì)應(yīng)的連接池里獲取到連接,使用完后統(tǒng)一釋放。而普通模式下一次只會(huì)獲取一個(gè)連接池的連接,用完后立刻釋放。這意味著cluster pipeline模式在獲取連接時(shí)是符合死鎖的“占有并等待”條件的,而普通模式不符合這個(gè)條件。
JedisClusterPipeline使用:
JedisClusterPipline jedisClusterPipline = redisService.clusterPipelined(); List<Object> response; try { for (String key : keys) { // 申請(qǐng)連接,內(nèi)部會(huì)先調(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; // 計(jì)算key所在的slot int slot = JedisClusterCRC16.getSlot(key); // 獲取solt對(duì)應(yīng)的連接池 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í)有數(shù)據(jù)漏讀的現(xiàn)象 try { jedis.getClient().getAll(); } catch (Throwable throwable) { log.warn("關(guān)閉jedis時(shí)遍歷異常,遍歷的目的是:清除連接內(nèi)的殘留數(shù)據(jù),防止連接歸還時(shí)有數(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; } }
舉個(gè)例子:
假設(shè)有一個(gè)集群有兩臺(tái)Redis主節(jié)點(diǎn)(集群模式下最小的主節(jié)點(diǎn)數(shù)量是3,這里只是為了舉例),記為節(jié)點(diǎn)1/2,有個(gè)java程序有4個(gè)Dubbo線程,記為線程1/2/3/4,每個(gè)Redis實(shí)例都有一個(gè)大小為2的連接池。
線程1和線程2,先獲取Redis1的連接再獲取Redis2的連接。線程3和線程4,先獲取Redis2的連接再獲取Redis1的連接,假設(shè)這四個(gè)線程在獲取到連接第一個(gè)連接后都等待了一會(huì),在獲取第二個(gè)連接的時(shí)候就會(huì)發(fā)生死鎖(等待時(shí)間越長(zhǎng),觸發(fā)的概率越大)。
所以pipeline是可能導(dǎo)致死鎖的,這個(gè)死鎖的條件很容易破壞,等待連接的時(shí)候設(shè)置超時(shí)時(shí)間即可。還可以增大下連接池的大小,資源夠的話也不會(huì)發(fā)生死鎖。
四、死鎖證明
以上只是猜想,為了證明確實(shí)發(fā)生了死鎖,需要以下條件:
- 線程當(dāng)前獲取到了哪些連接池的連接
- 線程當(dāng)前在等待哪些連接池的連接
- 每個(gè)連接池還剩多少連接
已知問題機(jī)器的Dubbo線程池大小為400,Redis集群主節(jié)點(diǎn)數(shù)量為12,Jedis配置的連接池大小為20。
4.1 步驟一:獲取線程在等待哪個(gè)連接池有空閑連接
第一步:先通過jstack和jmap分別導(dǎo)出棧和堆
第二步:通過分析棧可以知道線程在等待的鎖的地址,可以看到Dubbo線程383在等待0x6a3305858這個(gè)鎖對(duì)象,這個(gè)鎖屬于某個(gè)連接池,需要找到具體是哪個(gè)連接池。
第三步:使用mat(Eclipse Memory Analyzer Tool)工具分析堆,通過鎖的地址找到對(duì)應(yīng)的連接池。
使用mat的with incoming references功能順著引用一層層的往上找。
引用關(guān)系:ConditionObject->LinkedBlockingDeque
引用關(guān)系:LinkedBlockingDeque->GenericObjectPool
引用關(guān)系:GenericObjectPool->JedisPool。這里的ox6a578ddc8就是這個(gè)鎖所屬的連接池地址。
這樣我們就能知道Dubbo線程383當(dāng)前在等待0x6a578ddc8這個(gè)連接池的連接。
通過這一套流程,我們可以知道每個(gè)Dubbo線程分別在等待哪些連接池有可用連接。
4.2 步驟二:獲取線程當(dāng)前持有了哪些連接池的連接
第一步:使用mat在堆中查找所有JedisClusterPipeline類(正好400個(gè),每個(gè)Dubbo線程都各有一個(gè)),然后查看里面的poolToJedisMap,其中保存了當(dāng)前JedisClusterPipeline已經(jīng)持有的連接和其所屬的連接池。
下圖中,我們可以看到JedisClusterPipeline(0x6ac40c088)對(duì)象當(dāng)前的poolToJedisMap里有三個(gè)Node對(duì)象(0x6ac40dd40, 0x6ac40dd60, 0x6ac40dd80),代表其持有三個(gè)連接池的連接,可以從Node對(duì)象中找到JedisPool的地址。
第二步:第一步拿到JedisClusterPipeline持有哪個(gè)連接池的連接后,再查找持有此JedisClusterPipeline的Dubbo線程,這樣就能得到Dubbo線程當(dāng)前持有哪些連接池的連接。
4.3 死鎖分析
通過流程一可以發(fā)現(xiàn)雖然Redis主節(jié)點(diǎn)有12個(gè),但是所有的Dubbo線程都只在等待以下5個(gè)節(jié)點(diǎn)對(duì)應(yīng)的連接池之一:
- 0x6a578e0c8
- 0x6a578e048
- 0x6a578ddc8
- 0x6a578e538
- 0x6a578e838
通過流程二我們可以得知這5個(gè)連接池的連接當(dāng)前被哪些線程占用:
已知每個(gè)連接池的大小都配置為了20,這5個(gè)連接池的所有連接已經(jīng)被100個(gè)Dubbo線程占用完了,而所有的400個(gè)Dubbo線程又都在等待這5個(gè)連接池的連接,并且其等待的連接當(dāng)前沒被自己占用,通過這些條件,我們可以確定發(fā)生了死鎖。
五、總結(jié)
這篇文章主要展現(xiàn)了一次系統(tǒng)故障的分析過程。在排查過程中,作者使用jmap和jstack保存故障現(xiàn)場(chǎng),使用arthas分析故障現(xiàn)場(chǎng),再通過閱讀和分析源碼,從多個(gè)可能的角度一步步的推演故障原因,推測(cè)是死鎖引起的故障。在驗(yàn)證死鎖問題時(shí),作者使用mat按照一定的步驟來尋找線程在等待哪個(gè)連接池的連接和持有哪些連接池的連接,再結(jié)合死鎖檢測(cè)算法最終確認(rèn)故障機(jī)器發(fā)生了死鎖。
排查線上問題并非易事,不僅要對(duì)業(yè)務(wù)代碼有足夠的了解,還要對(duì)相關(guān)技術(shù)知識(shí)有系統(tǒng)性的了解,推測(cè)出可能導(dǎo)致問題的原因后,再熟練運(yùn)用好排查工具,最終確認(rèn)問題原因。
到此這篇關(guān)于Redis Cluster Pipeline導(dǎo)致的死鎖問題解決的文章就介紹到這了,更多相關(guān)Redis Cluster Pipeline死鎖內(nèi)容請(qǐng)搜索腳本之家以前的文章或繼續(xù)瀏覽下面的相關(guān)文章希望大家以后多多支持腳本之家!
相關(guān)文章
Redis鎖的過期時(shí)間小于業(yè)務(wù)的執(zhí)行時(shí)間如何續(xù)期
本文主要介紹了Redis鎖的過期時(shí)間小于業(yè)務(wù)的執(zhí)行時(shí)間如何續(xù)期,Redisson它能給Redis分布式鎖實(shí)現(xiàn)過期時(shí)間自動(dòng)續(xù)期,具有一定的參考價(jià)值,感興趣的可以了解一下2024-05-05Redis實(shí)戰(zhàn)之Redis實(shí)現(xiàn)異步秒殺優(yōu)化詳解
這篇文章主要給大家介紹了Redis實(shí)戰(zhàn)之Redis實(shí)現(xiàn)異步秒殺優(yōu)化方法,文章通過圖片和代碼介紹的非常詳細(xì),對(duì)大家的學(xué)習(xí)或工作有一定的幫助,感興趣的同學(xué)可以自己動(dòng)手試一下2023-09-09Redis和Nginx實(shí)現(xiàn)限制接口請(qǐng)求頻率的示例
限流就是限制API訪問頻率,當(dāng)訪問頻率超過某個(gè)閾值時(shí)進(jìn)行拒絕訪問等操作,本文主要介紹了Redis和Nginx實(shí)現(xiàn)限制接口請(qǐng)求頻率的示例,具有一定的參考價(jià)值,感興趣的可以了解一下2024-02-02springboot中redis并發(fā)鎖的等待時(shí)間設(shè)置長(zhǎng)短的方法
在SpringBoot應(yīng)用中,Redis鎖的等待時(shí)間設(shè)置不當(dāng)可能導(dǎo)致資源浪費(fèi)、響應(yīng)時(shí)間增加、死鎖風(fēng)險(xiǎn)升高、系統(tǒng)負(fù)載增加、業(yè)務(wù)邏輯延遲以及故障恢復(fù)慢等問題,建議合理設(shè)置等待時(shí)間,并考慮使用其他分布式鎖實(shí)現(xiàn)方式提高性能2024-10-10關(guān)于分布式鎖的三種實(shí)現(xiàn)方式
這篇文章主要介紹了關(guān)于分布式鎖的三種實(shí)現(xiàn)方式,具有很好的參考價(jià)值,希望對(duì)大家有所幫助。如有錯(cuò)誤或未考慮完全的地方,望不吝賜教2022-08-08Redis為什么快如何實(shí)現(xiàn)高可用及持久化
這篇文章主要介紹了Redis為什么快如何實(shí)現(xiàn)高可用及持久化,本文給大家介紹的非常詳細(xì),對(duì)大家的學(xué)習(xí)或工作具有一定的參考借鑒價(jià)值,需要的朋友可以參考下2020-12-12