記一次死結問題的排查和解決，記一次排查

記一次死結問題的排查和解決，記一次排查
     說起來這個事情還是挺悲催的，記得上周忙的不亦樂乎，目標是修改之前另外一個團隊留下來的一坨代碼中的一些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、如果使用彙總表進行最佳化。希望順利~