? ? ?說起來這個(gè)事情還是挺悲催的，記得上周忙的不亦樂乎，目標(biāo)是改動(dòng)之前另外一個(gè)團(tuán)隊(duì)留下來的一坨代碼中的一些bug，這個(gè)項(xiàng)目是做OLAP分析的。分為兩個(gè)模塊，邏輯server主要負(fù)責(zé)一些元數(shù)據(jù)的操作，比如頁(yè)面上展示的一些信息，而分析server負(fù)責(zé)運(yùn)行查詢語句。由于他們之前使用的是mondrian作為OLAP分析引擎，所以輸入的查詢是MDX語句，然后結(jié)果是一個(gè)二維的數(shù)據(jù)。這是主要的項(xiàng)目背景，當(dāng)然使用mondrian的過程中發(fā)現(xiàn)他的確夠慢的。

并且mondrian另一個(gè)問題，它的確在內(nèi)部實(shí)現(xiàn)了一些緩存，緩存好像是基于cell的。可是它的緩存所有是保存在進(jìn)程內(nèi)部的，這就導(dǎo)致每個(gè)分析server是有狀態(tài)的，不能擴(kuò)展成多個(gè)。否則就不能利用這些緩存了，另外，由于我們須要支持大量的數(shù)據(jù)源（每個(gè)產(chǎn)品可能有一個(gè)或者多個(gè)數(shù)據(jù)源），每個(gè)數(shù)據(jù)源可能定義多個(gè)報(bào)表，每個(gè)報(bào)表相應(yīng)著一個(gè)MDX查詢語句。這就導(dǎo)致緩存的數(shù)據(jù)非常大，非常easy就造成OOM的現(xiàn)象。因此我們接下來的任務(wù)就是把這個(gè)緩存移出去。放到第三方的緩存系統(tǒng)中。 回到正題，正當(dāng)忙完準(zhǔn)備周五上線呢，上線之后沒怎么驗(yàn)證就匆匆在用戶群里面吼了一聲，因此大家都打開點(diǎn)啊點(diǎn)，突然老大過來說怎么如今打開報(bào)表什么的這么慢啊。我查了一下發(fā)現(xiàn)的確挺慢的，為什么在測(cè)試環(huán)境中沒有發(fā)現(xiàn)呢？多次驗(yàn)證之后開始懷疑自己可能真的改錯(cuò)了什么了，立刻回滾到之前的版本號(hào)，然后就剩下我一頭汗水中排查究竟出現(xiàn)了什么問題。 好在將線上的環(huán)境切到測(cè)試環(huán)境中非常easy就把這個(gè)現(xiàn)象給復(fù)現(xiàn)了。主要是點(diǎn)開某個(gè)報(bào)表，然后經(jīng)過一段時(shí)間的載入，接下來點(diǎn)開該報(bào)表之后就會(huì)快非常多，由于接下來的操作都是從緩存中獲取的。可是當(dāng)我在頁(yè)面上點(diǎn)擊“清除緩存”之后（這個(gè)操作事實(shí)上時(shí)清除整個(gè)報(bào)表的緩存和mondrian內(nèi)部的緩存），發(fā)現(xiàn)會(huì)等待非常長(zhǎng)的時(shí)間才干返回。然后這個(gè)操作是異步的。在頁(yè)面上我還能進(jìn)行其它操作。可是當(dāng)我再次點(diǎn)擊其它報(bào)表的“清除緩存“的操作就會(huì)出現(xiàn)卡頓，然后發(fā)現(xiàn)打開其它的報(bào)表可能要等待一段時(shí)間，問題就這么非常easy的復(fù)現(xiàn)了。

之前沒有針對(duì)java這方面的排查經(jīng)驗(yàn)。可是也知道jstack，jmap之類的工具，于是馬上用jstack把整個(gè)進(jìn)程的堆棧抓取下來（非常是懊悔沒有在回滾之前運(yùn)行jstack），發(fā)現(xiàn)的確出現(xiàn)了問題： Found one Java-level deadlock: ============================= "mondrian.rolap.RolapResultShepherd$executor_160":waiting to lock monitor 0x0000000043b2bf70 (object 0x0000000702080db0, a mondrian.rolap.MemberCacheHelper),which is held by "mondrian.rolap.RolapResultShepherd$executor_152" "mondrian.rolap.RolapResultShepherd$executor_152":waiting to lock monitor 0x00007f4e6c0751c8 (object 0x0000000702081270, a mondrian.rolap.MemberCacheHelper),which is held by "http-8182-11" "http-8182-11":waiting to lock monitor 0x0000000043b2bf70 (object 0x0000000702080db0, a mondrian.rolap.MemberCacheHelper),which is held by "mondrian.rolap.RolapResultShepherd$executor_152"
這意味著程序里面出現(xiàn)了死鎖。這里牽扯到了三個(gè)線程，可是當(dāng)中的兩個(gè)線程都持有了一個(gè)鎖而且希望鎖住對(duì)方持有的鎖，而第三個(gè)線程正在等待前兩個(gè)線程中某個(gè)線程已經(jīng)持有的鎖，有了這個(gè)堆棧就非常easy排查問題了，而且在堆棧信息中發(fā)現(xiàn)非常多線程都在等待這兩個(gè)線程中已經(jīng)持有的鎖。可是由于這兩個(gè)線程已經(jīng)處于死鎖狀態(tài)了，其它的線程僅僅能同步的等待。這樣繼續(xù)在前端操作這些報(bào)表遲早把tomcat中的線程消耗完。

依據(jù)堆棧找到相應(yīng)的代碼，代碼運(yùn)行的是清理緩存的操作，可是緩存是對(duì)于每個(gè)cube下的hierarchy創(chuàng)建的，因此依據(jù)詳細(xì)的堆棧中的調(diào)用信息例如以下： at mondrian.rolap.SmartMemberReader.flushCacheSimple(SmartMemberReader.java:577)- waiting to lock <0x00000007020a8990> (a mondrian.rolap.MemberCacheHelper)at mondrian.rolap.RolapCubeHierarchy$CacheRolapCubeHierarchyMemberReader.flushCacheSimple(RolapCubeHierarchy.java:883)at mondrian.rolap.RolapCubeHierarchy.flushCacheSimple(RolapCubeHierarchy.java:458)at mondrian.rolap.MemberCacheHelper.flushCache(MemberCacheHelper.java:166)- locked <0x00000007020a8e50> (a mondrian.rolap.MemberCacheHelper)at mondrian.rolap.RolapCubeHierarchy$CacheRolapCubeHierarchyMemberReader.flushCache(RolapCubeHierarchy.java:878)at mondrian.rolap.RolapCubeHierarchy.flushCache(RolapCubeHierarchy.java:451)
? ? ?最先進(jìn)入的這個(gè)flushCache函數(shù)是hierarchy級(jí)別的緩存清理，它事實(shí)上是調(diào)用它的成員變量reader對(duì)象的clearCache方法。這個(gè)reader用于讀取這個(gè)hierarchy下的members，能夠直接從數(shù)據(jù)源（關(guān)系數(shù)據(jù)庫(kù)）中讀取，也維護(hù)了members的緩存，因此調(diào)用reader的clearCache方法也就是調(diào)用它的cache對(duì)象的方法，這個(gè)cache對(duì)象名為rolapCubeCacheHelper，類型為MemberCacheHelper，可是發(fā)如今reader中的clearCache方法運(yùn)行的詳細(xì)操作例如以下： @Overridepublic void flushCache(){super.flushCache();rolapCubeCacheHelper.flushCache();}
? ? ?首先調(diào)用父類的flushCache方法。父類又是什么鬼，打開父類的flushCache方法發(fā)現(xiàn)更奇怪的事情： public void flushCache(){synchronized( cacheHelper){cacheHelper .flushCache();}}
? ? ?這是父類的flushCache方法，它事實(shí)上就是對(duì)成員變量的cacheHelper對(duì)象加鎖，然后使用cacheHelper的flushCache方法，打開cacheHelper對(duì)象才發(fā)現(xiàn)它又是一個(gè)MemberCacheHelper對(duì)象，這時(shí)候問題來了。為什么父類和子類都保存了一個(gè)MemberCacheHelper對(duì)象呢？事實(shí)上MemberCacheHelper這個(gè)對(duì)象就是一個(gè)緩存的結(jié)構(gòu)體，父類有一些公有的緩存數(shù)據(jù)，子類有自己的緩存信息，這樣也能說得過去。繼續(xù)到MemberCacheHelper類的flushCache方法： // Must sync here because we want the three maps to be modified together.public synchronized void flushCache() {mapMemberToChildren.clear();mapKeyToMember.clear();mapLevelToMembers.clear();if (rolapHierarchy instanceof RolapCubeHierarchy){((RolapCubeHierarchy)rolapHierarchy ).flushCacheSimple();}// We also need to clear the approxRowCount of each level.for (Level level : rolapHierarchy.getLevels()) {((RolapLevel)level ).setApproxRowCount(Integer. MIN_VALUE);}}
這里對(duì)緩存中的每個(gè)map進(jìn)行clear。然后又對(duì)這個(gè)hierarchy運(yùn)行flushCacheSimple方法，我勒個(gè)擦。怎么又回來了，這個(gè)hierarchy對(duì)象不就是我們進(jìn)出進(jìn)入flushCache的那個(gè)hierarchy對(duì)象嗎？過了一遍flushCacheSimple方法發(fā)現(xiàn)它終于又調(diào)用了reader的flushCacheSimple方法，這個(gè)函數(shù)運(yùn)行的操作類似于flushCache： public void flushCacheSimple(){super.flushCacheSimple();rolapCubeCacheHelper.flushCacheSimple();}
好了。繼續(xù)到MemberCacheHelper的flushCacheSimple方法： public void flushCacheSimple(){synchronized(cacheHelper){cacheHelper.flushCacheSimple();}}
我勒個(gè)擦。這里又加鎖，之前不是已經(jīng)加過了嗎？當(dāng)然這個(gè)鎖因該是可重入的，這里自然不會(huì)造成死鎖，可是以下的rolapCubeCacheHelper對(duì)象也是MemberCacheHelper對(duì)象啊！

最后進(jìn)入flushCacheSimple方法，這徹底凌亂了：

public synchronized void flushCacheSimple() {mapMemberToChildren.clear();mapKeyToMember.clear();mapLevelToMembers.clear();// We also need to clear the approxRowCount of each level.for (Level level : rolapHierarchy.getLevels()) {((RolapLevel)level).setApproxRowCount(Integer.MIN_VALUE);}}
這里面運(yùn)行的操作和flushCache方法不是一樣的嗎？。這究竟是在做什么。當(dāng)然理了這么多也發(fā)現(xiàn)了出現(xiàn)死鎖的根源了。就在于reader運(yùn)行的flushCache方法，這里面分別調(diào)用了父類和當(dāng)前類的cacheHelper對(duì)象的flushCache，可是這種方法還會(huì)調(diào)用flushCacheSimple方法。這種方法再次調(diào)用reader的flushCacheSimple方法，這里再次調(diào)用父類和當(dāng)前類的cacheHelper對(duì)象的flushCacheSimple方法。并且每次調(diào)用都須要加鎖。這就導(dǎo)致了例如以下的死鎖情況： A線程運(yùn)行flushCache方法，它已經(jīng)完畢了super.flushCache方法，然后運(yùn)行當(dāng)前reader對(duì)象的flushCache方法。首先及時(shí)須要持有這個(gè)helper對(duì)象的鎖。然后再運(yùn)行到flushCacheSimple的時(shí)候申請(qǐng)父類的helper對(duì)象的鎖。

B線程可能在運(yùn)行super.flushCache進(jìn)入這個(gè)函數(shù)意味著須要持有父類的helper，可是當(dāng)它運(yùn)行flushCacheSimple的時(shí)候有須要申請(qǐng)當(dāng)前類的helper對(duì)象的鎖。于是就造成了死鎖。

開始沒有定位到這個(gè)問題之前不曉得死鎖究竟是怎么回事造成的，于是想著讓全部的線程順序運(yùn)行flushCache方法就能夠避免死鎖了（不要并發(fā)了），可是嘗試了一下發(fā)現(xiàn)不能這樣，由于其它線程還是有可能調(diào)用這個(gè)flushCache方法，這個(gè)不是由我控制的。于是僅僅能詳細(xì)了解這個(gè)函數(shù)究竟運(yùn)行了什么，發(fā)現(xiàn)flushCache和flushCacheSimple方法事實(shí)上是反復(fù)的，不曉得當(dāng)初寫這段代碼的人是怎么想的，于是就把全部的flushCacheSimple方法的調(diào)用去掉。這樣就不會(huì)再有持有A鎖再去申請(qǐng)B鎖的情況了。
問題算是攻克了，終于hotfix版本號(hào)也算是上線了，一顆懸著的心也算放下了，著這個(gè)過程中我也學(xué)到了不少知識(shí)： 1、學(xué)會(huì)而且善于使用java提供的分析工具。比如jstack、jstat、jmap、以及開源的MAT等等。 2、遇到問題不要害怕，不要一味的埋怨這個(gè)問題不是我造成的，我也不知道怎么回事之類的。靜下心來思考整個(gè)流程，運(yùn)用曾經(jīng)的理論知識(shí)和經(jīng)驗(yàn)一定可以把問題解決的。沒有什么問題是偶然的。假設(shè)出錯(cuò)一定是代碼有問題。 3、測(cè)試非常重要。尤其壓力測(cè)試，我們項(xiàng)目眼下人手緊缺。QA也沒有專職的，所以基本上是開發(fā)在開發(fā)環(huán)境上測(cè)試一下功能。并沒有做過性能測(cè)試之類的東西，我認(rèn)為測(cè)試應(yīng)該盡可能覆蓋線上可能出現(xiàn)的各種情況。

4、上線之前做好回滾，否則你會(huì)非常狼狽，幸虧這點(diǎn)我每次操作之前都先備份。 5、在編碼的時(shí)候，尤其一個(gè)操作會(huì)涉及到多個(gè)synchronized操作的時(shí)候尤其要注意，回顧一下當(dāng)初避免死鎖的幾個(gè)方法。按順序加鎖往往是最好的解決的方法。 6、搞清楚一個(gè)方法究竟想要做什么？輸入是什么，輸出是什么。會(huì)造成什么影響。在寫完一個(gè)方法之后在腦子中模擬一下整個(gè)函數(shù)的運(yùn)行流程是否符合預(yù)想。

7、假設(shè)真的遇到這種需求：父類和子類都持有一個(gè)類型的對(duì)象，讓他們獨(dú)立操作。父類對(duì)象的操作完畢之后在運(yùn)行子類對(duì)象的操作，而不要穿插著調(diào)用。

接下來的一段時(shí)間要開始搞mondrian了，希望可以從這個(gè)OLAP運(yùn)行引擎中學(xué)到一些東西。只是自己的編譯原理方面的知識(shí)差點(diǎn)兒為0，這方面須要補(bǔ)強(qiáng)啊，我對(duì)于mondrian中重點(diǎn)要看的東西應(yīng)該是：1、怎樣解析MDX（類似于怎樣解析SQL）。2、怎樣將MDX動(dòng)態(tài)的翻譯成一串SQL（類似于怎樣生成運(yùn)行計(jì)劃），3、緩存怎樣實(shí)現(xiàn)，4、運(yùn)行MDX或者SQL時(shí)怎樣使用緩存。5、假設(shè)使用聚合表進(jìn)行優(yōu)化。 希望順利~

轉(zhuǎn)載于:https://www.cnblogs.com/liguangsunls/p/7136843.html

總結(jié)

以上是生活随笔為你收集整理的记一次死锁问题的排查和解决的全部?jī)?nèi)容，希望文章能夠幫你解決所遇到的問題。

如果覺得生活随笔網(wǎng)站內(nèi)容還不錯(cuò)，歡迎將生活随笔推薦給好友。