記一次死鎖問題的排查和解決
說起來這個事情還是挺悲催的,記得上周忙的不亦樂乎,目標是修改之前另外一個團隊留下來的一坨代碼中的一些bug,這個項目是做OLAP分析的,分為兩個模塊,邏輯服務器主要負責一些元數據的操作,例如頁面上展示的一些信息,而分析服務器負責執行查詢語句,因為他們之前使用的是mondrian作為OLAP分析引擎,所以輸入的查詢是MDX語句,然後結果是一個二維的數據。這是基本的項目背景,當然使用mondrian的過程中發現他的確夠慢的。
而且mondrian還有一個問題,它的確在內部實現了一些緩存,緩存好像是基於cell的,但是它的緩存全部是保存在進程內部的,這就導致每一個分析服務器是有狀態的,不能擴展成多個,否則就不能利用這些緩存了,另外,因為我們需要支持大量的數據源(每一個產品可能有一個或者多個數據源),每一個數據源可能定義多個報表,每一個報表對應著一個MDX查詢語句,這就導致緩存的數據很大,很容易就造成OOM的現象,因此我們接下來的任務就是把這個緩存移出去,放到第三方的緩存系統中。
回到正題,正當忙完准備周五上線呢,上線之後沒怎麼驗證就匆匆在用戶群裡面吼了一聲,因此大家都打開點啊點,突然老大過來說怎麼現在打開報表什麼的這麼慢啊,我查了一下發現的確挺慢的,為什麼在測試環境中沒有發現呢?多次驗證之後開始懷疑自己可能真的改錯了什麼了,立馬回滾到之前的版本,然後就剩下我一頭汗水中排查到底出現了什麼問題。
好在將線上的環境切到測試環境中很容易就把這個現象給復現了,主要是點開某個報表,然後經過一段時間的加載,接下來點開該報表之後就會快很多,因為接下來的操作都是從緩存中獲取的,但是當我在頁面上點擊“清除緩存”之後(這個操作其實時清除整個報表的緩存和mondrian內部的緩存),發現會等待很長的時間才能返回,然後這個操作是異步的,在頁面上我還能進行其他操作。但是當我再次點擊其它報表的“清除緩存“的操作就會出現卡頓,然後發現打開其他的報表可能要等待一段時間,問題就這麼很容易的復現了。
之前沒有針對java這方面的排查經驗,但是也知道jstack,jmap之類的工具,於是立即用jstack把整個進程的堆棧抓取下來(很是後悔沒有在回滾之前執行jstack),發現的確出現了問題:
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"
這意味著程序裡面出現了死鎖,這裡牽扯到了三個線程,但是其中的兩個線程都持有了一個鎖並且希望鎖住對方持有的鎖,而第三個線程正在等待前兩個線程中某個線程已經持有的鎖,有了這個堆棧就很容易排查問題了,並且在堆棧信息中發現很多線程都在等待這兩個線程中已經持有的鎖,但是因為這兩個線程已經處於死鎖狀態了,其他的線程只能同步的等待,這樣繼續在前端操作這些報表遲早把tomcat中的線程消耗完。
根據堆棧找到對應的代碼,代碼執行的是清理緩存的操作,但是緩存是對於每一個cube下的hierarchy創建的,因此根據具體的堆棧中的調用信息如下:
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)
最先進入的這個flushCache函數是hierarchy級別的緩存清理,它其實是調用它的成員變量reader對象的clearCache方法,這個reader用於讀取這個hierarchy下的members,可以直接從數據源(關系數據庫)中讀取,也維護了members的緩存,因此調用reader的clearCache方法也就是調用它的cache對象的方法,這個cache對象名為rolapCubeCacheHelper,類型為MemberCacheHelper,但是發現在reader中的clearCache方法執行的具體操作如下:
@Override
public void flushCache(){
super.flushCache();
rolapCubeCacheHelper.flushCache();
}
首先調用父類的flushCache方法,父類又是什麼鬼,打開父類的flushCache方法發現更奇怪的事情:
public void flushCache(){
synchronized( cacheHelper){
cacheHelper .flushCache();
}
}
這是父類的flushCache方法,它其實就是對成員變量的cacheHelper對象加鎖,然後使用cacheHelper的flushCache方法,打開cacheHelper對象才發現它又是一個MemberCacheHelper對象,這時候問題來了,為什麼父類和子類都保存了一個MemberCacheHelper對象呢?其實MemberCacheHelper這個對象就是一個緩存的結構體,父類有一些公有的緩存數據,子類有自己的緩存信息,這樣也能說得過去,繼續到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);
}
}
這裡對緩存中的每一個map進行clear,然後又對這個hierarchy執行flushCacheSimple方法,我勒個擦,怎麼又回來了,這個hierarchy對象不就是我們進出進入flushCache的那個hierarchy對象嗎?過了一遍flushCacheSimple方法發現它最終又調用了reader的flushCacheSimple方法,這個函數執行的操作類似於flushCache:
public void flushCacheSimple(){
super.flushCacheSimple();
rolapCubeCacheHelper.flushCacheSimple();
}
好了,繼續到MemberCacheHelper的flushCacheSimple方法:
public void flushCacheSimple(){
synchronized(cacheHelper){
cacheHelper.flushCacheSimple();
}
}
我勒個擦,這裡又加鎖,之前不是已經加過了嗎?當然這個鎖因該是可重入的,這裡自然不會造成死鎖,但是下面的rolapCubeCacheHelper對象也是MemberCacheHelper對象啊!最後進入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);
}
}
這裡面執行的操作和flushCache方法不是一樣的嗎?!這到底是在做什麼,當然理了這麼多也發現了出現死鎖的根源了,就在於reader執行的flushCache方法,這裡面分別調用了父類和當前類的cacheHelper對象的flushCache,但是這個方法還會調用flushCacheSimple方法,這個方法再次調用reader的flushCacheSimple方法,這裡再次調用父類和當前類的cacheHelper對象的flushCacheSimple方法,而且每次調用都需要加鎖,這就導致了如下的死鎖情況:
A線程執行flushCache方法,它已經完成了super.flushCache方法,然後執行當前reader對象的flushCache方法,首先及時需要持有這個helper對象的鎖,然後再執行到flushCacheSimple的時候申請父類的helper對象的鎖。B線程可能在執行super.flushCache進入這個函數意味著需要持有父類的helper,但是當它執行flushCacheSimple的時候有需要申請當前類的helper對象的鎖,於是就造成了死鎖。
開始沒有定位到這個問題之前不曉得死鎖到底是怎麼回事造成的,於是想著讓所有的線程順序執行flushCache方法就可以避免死鎖了(不要並發了),但是嘗試了一下發現不能這樣,因為其他線程還是有可能調用這個flushCache方法,這個不是由我控制的,於是只能具體了解這個函數到底執行了什麼,發現flushCache和flushCacheSimple方法其實是重復的,不曉得當初寫這段代碼的人是怎麼想的,於是就把所有的flushCacheSimple方法的調用去掉,這樣就不會再有持有A鎖再去申請B鎖的情況了。
問題算是解決了,最終hotfix版本也算是上線了,一顆懸著的心也算放下了,著這個過程中我也學到了不少知識:
1、學會並且善於使用java提供的分析工具,例如jstack、jstat、jmap、以及開源的MAT等等。
2、遇到問題不要害怕,不要一味的埋怨這個問題不是我造成的,我也不知道怎麼回事之類的,靜下心來思考整個流程,運用以前的理論知識和經驗一定能夠把問題解決的,沒有什麼問題是偶然的,如果出錯一定是代碼有問題。
3、測試很重要,尤其壓力測試,我們項目目前人手緊缺,QA也沒有專職的,所以基本上是開發在開發環境上測試一下功能,並沒有做過性能測試之類的東西,我覺得測試應該盡可能覆蓋線上可能出現的各種情況。
4、上線之前做好回滾,否則你會很狼狽,幸虧這點我每次操作之前都先備份。
5、在編碼的時候,尤其一個操作會涉及到多個synchronized操作的時候尤其要注意,回憶一下當初避免死鎖的幾個方法,按順序加鎖往往是最好的解決辦法。
6、搞清楚一個方法到底想要做什麼?輸入是什麼,輸出是什麼,會造成什麼影響,在寫完一個方法之後在腦子中模擬一下整個函數的執行流程是否符合預想。
7、如果真的遇到這樣的需求:父類和子類都持有一個類型的對象,讓他們獨立操作,父類對象的操作完成之後在執行子類對象的操作,而不要穿插著調用。
接下來的一段時間要開始搞mondrian了,希望能夠從這個OLAP執行引擎中學到一些東西,不過自己的編譯原理方面的知識幾乎為0,這方面需要補強啊,我對於mondrian中重點要看的東西應該是:1、如何解析MDX(類似於如何解析SQL),2、如何將MDX動態的翻譯成一串SQL(類似於如何生成執行計劃),3、緩存如何實現,4、執行MDX或者SQL時如何使用緩存,5、如果使用聚合表進行優化。
希望順利~