使用 IBM 效能分析工具解決生產環境中的效能問題

luckyfriends發表於2012-12-30

http://www.ibm.com/developerworks/cn/java/j-lo-javacore/index.html

企業級應用系統軟體通常有著對併發數和響應時間的要求,這就要求大量的使用者能在高響應時間內完成業務操作。這兩個效能指標往往決定著一個應用系統軟體能否成功上線,而這也決定了一個專案最終能否驗收成功,能否得到客戶認同,能否繼續在一個行業發展壯大下去。由此可見效能對於一個應用系統的重要性,當然這似乎也成了軟體行業的不可言說的痛 —— 絕大多數的應用系統在上線之前,專案組成員都要經歷一個脫胎換骨的過程。

生產環境的建立包含眾多方面,如儲存規劃、作業系統引數調整、資料庫調優、應用系統調優等等。這幾方面互相影響,只有經過不斷的調整最佳化,才能達到資源的最大利用率,滿足客戶對系統吞吐量和響應時間的要求。在無數次的實踐經驗中,很多軟體專家能夠達成一致的是:應用系統本身的最佳化是至關重要的,否則即使有再大的記憶體,也會被消耗殆盡,尤其是產生 OOM(Out Of Memory)的錯誤的時候,它會貪婪地吃掉你的記憶體空間,直到系統當機。

產生 OOM 的原因有很多種,大體上可以簡單地分為兩種情況,一種就是實體記憶體確實有限,發生這種情況時,我們很容易找到原因,但是它一般不會發生在實際的生產環境中。因為生產環境往往有足以滿足應用系統要求的配置,這在專案最初就是根據系統要求進行購置的。

另外一種引起 OOM 的原因就是應用系統本身對資源的的不恰當使用、配置,引起記憶體使用持續增加,最終導致 JVM Heap Memory 被耗盡,如沒有正確釋放 JDBC 的 Connection Pool 中的物件,使用 Cache 時沒有限制 Cache 的大小等等。本文並不針對各種情況做討論,而是以一個專案案例為背景,探索解決這類問題的方式方法,並總結一些最佳實踐,供廣大開發工程師借鑑參考。

專案背景:

  1. 內網使用者 500 人,需要同時線上進行業務操作(中午休息一小時,晚 6 點下班)。
  2. 生產環境採用傳統的主從式,未做 Cluster ,提供 HA 高可用性。
  3. 伺服器為 AIX P570,8U,16G,但是隻有一半的資源,即 4U,8G 供新系統使用。

專案三月初上線,此前筆者與架構師曾去客戶現場簡單部署過一兩次,主要是軟體的安裝,應用的部署,測一下應用是不是能夠跑起來,算作是上線前的準備工作。應用上線(試執行)當天,專案組全體入住客戶現場,看著使用者登入數不斷攀升,大家心裡都沒有底,高峰時候到了 440,系統開始有點反應變慢,不過還是扛下來了,最後歸結為目前的資源有限,等把另一半資源划過來,就肯定沒問題了。(須知增加資源,調優的工作大部分都要重新做一遍,系統級、資料庫級等等,這也是後面為什麼建議如果資源可用,最好一步到位的原因。)為了臨時解決資源有限的問題,透過和客戶協商,決定中午 12 點半和晚上 11 點透過系統排程重啟一次應用伺服器,這樣,就達到了相隔幾個小時,手動清理記憶體的目的。

專案在試執行階段,仍舊有新的子應用開始投入聯調,同時客戶每天都會提出這樣那樣的需求變更,如果要的很急的話,就要隨時修改,隔天修正使用。修改後沒有充分的時間進行迴歸測試,新部署的程式碼難免會有這樣那樣的問題,遇到過幾次這種情況,最後不得不在業務系統使用的時候,對應用系統進行重新啟動,於是就會出現業務終止引起的資料不一致,還要對這些資料進行修正維護,加大了工作量。期間,應用在執行過程中有幾次異常緩慢的情形,由於業務不能中斷太久,需要迅速恢復系統投入使用,所以往往是重啟一下應用伺服器來釋放記憶體。事後檢查日誌,才發現日誌中赫然記錄有 OOM 的錯誤,這才引起了專案經理的注意,要求架構師對該問題進行進一步研究確認。

但是幾個月過去,問題依舊出現,於是透過客戶和公司的協調,請來幾位專家,包括作業系統專家、資料庫專家,大部分的專家在巡檢之後,給出的結論是:大部分需要調整的引數都已經調整過了,還是要從應用系統本身找原因,看來還是要靠我們自己來解決了。(最終的結果也證明,如此詭異隱蔽的 OOM 問題是很難一眼就能發現的,工具的作用不可忽視。)

我們透過對底層封裝的框架程式碼,主要是 DAO 層與資料庫互動的統一介面,增加了 log 處理以抓取所有執行時間超過 10 秒鐘的 SQL 語句,記錄到應用系統日誌中備查。同時透過資料庫監控輔助工具給出的建議,對所有超標的 SQL 透過建立 index,或者修正資料結構(主要是透過建立冗餘欄位來避免多表關聯查詢)來進行最佳化。這樣過了幾天後,已經基本上不存在執行時間超過 10 秒的 SQL 語句,可以說我們對應用層的最佳化已經達標了。

但是,當機的問題並沒有徹底解決,陸續發生了幾次,透過短暫的控制檯監控,發現都有執行緒等待的現象發生,還有兩三次產生了幾個 G 大小的 heapdump 檔案,同時伴隨有 javacore 檔案產生。因為每次當機的時候都需要緊急處理,不允許長時間監控,只能保留應用伺服器日誌和產生的 heapdump 檔案,做進一步的研究。透過日誌檢查,我們發現幾次當機時都發生在相同的某兩個業務點上,但是多次對處理該業務功能的程式碼進行檢查分析,仍舊沒有找到原因。看來只能寄希望於當機產生的 heapdump 和 javacore 了,於是開始重點對 OOM 產生的這些檔案進行分析。

這裡,我們簡單介紹一下 heapdump 檔案和 javacore 檔案。heapdump 檔案是一種映象檔案,是指定時刻的 Java 堆疊的快照。應用程式在發生記憶體洩露的錯誤時,往往會生成 heapdump 檔案,同時伴隨有 javacore 檔案生成,javacore 包含 JVM 和應用程式相關的在特定時刻的一些診斷資訊,如作業系統,記憶體,應用程式環境,執行緒等的資訊。如本文案例中分析的下圖中的 heapdump.20090602.134015.430370.phd 和 javacore.20090602.134015.430370.txt。

由於筆者之前並沒有這方面的分析經驗,覺得 heapdump 檔案很大,就想當然拿它開刀了。首先是尋找工具,類似的工具有多種,筆者最後選擇了 IBM 的 HeapAnalyzer()。透過對 heapdump 檔案的解析,HeapAnalyzer 可以分析出哪些物件佔用了太多的堆疊空間,從而發現導致記憶體洩露或者可能引起記憶體洩露的物件。它的使用很簡單,可以從它的 readme 文件中找到,這裡我們簡單舉個例子如下:

#/usr/java50/bin/java – Xmx2000m – jar ha36.jar heapdump.20090602.134015.430370.phd
			

通常我們需要使用較大的 heapsize 來啟動 HeapAnalyzer,因為透過 HeapAnalyzer 開啟過大的 heapdump 檔案時,也可能會因為 heapsize 不夠而產生 OOM 的錯誤。開始的時候,筆者從伺服器上將 heapdump 檔案透過 ftp 下載下來,然後試圖透過本機 window 環境進行分析。筆者使用的電腦是 2G 記憶體,啟動 HeapAnalyzer 時指定的是 1536 M,但是幾次都是到 90% 多的時候進度條就停止前進了。迫不得已同時也是為了能達到環境一致的效果,筆者將 HeapAnalyzer 上傳到生產環境,直接在生產環境下開啟 heapdump 檔案。


分析 phd 後的結果 

個人感覺 HeapAnalyzer 給出的分析結果可讀性不強,而且不能準確定位問題,從分析結果看大致是因為載入的物件過多,但是是哪個模組導致的問題就跟蹤不到了。筆者開始尋找 HeapAnalyzer 分析結果相關的資料,試圖從這個可讀性不強的結果中找到蛛絲馬跡,可是許久沒有進展,再一次陷入了困境。

在多次研究 heapdump 檔案無果的情況下,筆者開始逐漸將注意力轉移到 javacore 檔案上,雖然它比較小,說不定內藏玄機呢。透過多方搜尋,找到了 IBM Thread and Monitor Dump Analyzer for Java(以下簡稱 jca)—— A tool that allows identification of hangs, deadlocks, resource contention, and bottlenecks in Java threads。透過它自身的這段描述來看,這正是筆者所需要的好工具。

這個工具的使用和 HeapAnalyzer 一樣,非常容易,同樣提供了詳細的 readme 文件,這裡也簡單舉例如下:

#/usr/java50/bin/java -Xmx1000m -jar jca37.jar


啟動 jca 

筆者直接在生產環境下直接透過它對產生的 javacore 檔案進行分析,令人驚喜的是,其分析結果非常明瞭,筆者心頭的疑雲在對結果進行進一步分析核實後也漸漸散去。



jca 的分析結果 - 第一部分 

從圖中,我們可以清楚地看到引發錯誤的原因 —— The failure was caused because the class loader limit was exceeded。同時我們還能看出當前生產環境使用的 JRE 版本是:J2RE 5.0 IBM J9 2.3 AIX ppc-32 build j9vmap3223-20070201 ,這個 SR4 的版本有個問題,我們可以從分析結果圖的第二部分的 NOTE 小節清楚地看到:



jca 的分析結果 - 第二部分 

NOTE: Only for Java 5.0 Service Refresh 4 (build date:February 1st, 2007) and older. When you use delegated class loaders, the JVM can create a large number of ClassLoader objects. On IBM Java 5.0 Service Refresh 4 and older, the number of class loaders that are permitted is limited to 8192 by default and an OutOfMemoryError exception is thrown when this limit is exceeded. Use the -Xmxcl parameter to increase the number of class loaders allowed to avoid this problem, for example to 25000, by setting -Xmxcl25000, until the problem is resolved.

原來,OOM 竟然是因為這個原因產生的。那麼到底是哪裡載入的物件超過了這個 8192 的限制呢?接下來筆者結合分析結果和應用系統 log 進行了進一步的分析,更加驗證了 JCA 分析結果的正確性。

在分析結果中可以看到 Current Thread ,就是對應引起 OOM 的應用伺服器的執行緒,使用該執行緒的名稱作為關鍵字在我們的 log 裡進行搜尋,迅速定位到了業務點——這是一個定時的排程,其功能是按固定時間間隔以 DBLink 的方式從外部應用的資料庫系統中抽取資料,透過應用層邏輯轉換後儲存到內網資料庫系統中。應用層的邏輯是對所有的業務資料進行迴圈,對每條業務資料進行到 POJO 的一一對照轉換,這意味這一條業務資料需要 10 幾個 POJO 進行組合對照,也就是說,如果外網在指定的時間間隔內資料量稍大,就會載入大量的物件,使 JVM 的 class loaders 瞬間超過 8192 的限制,而產生 OOM 的錯誤,從而使記憶體不斷被消耗,直至當機。

jca 還提供了對垃圾回收和執行緒狀態的詳細分析資料,可以參考如下兩圖:



jca 的分析結果 - 第三部分 


jca 的分析結果 - 第四部分 

問題核實後,如何進行解決呢?分析結果中也給出了相應的建議,從圖 4 的 Recommended 小節我們可以看到:

Recommended -Xmxcl setting (only for IBM Java 5.0, up to and including Service Refresh 4 (build date:February 1st ,2007)) : 10,649 or greater。

為了考慮到對既有舊系統不產生影響,我們沒有對 JRE 進行升級,而是採用了分析結果給出的建議,在應用伺服器啟動後設定 -Xmxcl 引數為 25000,為驗證我們的修改是不是成功解決掉了 OOM 當機的問題,筆者取消了對應用伺服器的自動重啟排程,透過一段時間的監控發現,系統執行良好,一直沒有再出現 OOM 而當機的問題,問題得以最終解決。

  1. 整體規劃

    系統上線前要做好充分的準備工作,這一點很重要,上線計劃可不是拍拍腦門就能想出來的,需要很多專案成員的參與。

    1. 專案實施計劃書:要包括預計實施目標,雙方的實施負責人(包括 backup),協調哪些資源應該找哪些人,詳細的階段性計劃等等。
    2. 實施小組:指定具有實施經驗的架構師,系統工程師,開發組長組成實施小組,負責生產環境的搭建及調整。成員構成上一定要包含專案組內的穩定核心人員,以保證能在特殊情況需要時做 backup。核心人員的流動會引起專案風險,尤其是在上線初期的不穩定階段。
    3. 對可規劃使用的資源一定要充分利用,這一點應包含在專案實施計劃書內,儘量做到資源一步到位。因為本專案案例中,舊有系統和新系統並行執行,可用的資源在不斷髮生變化,期間為解決效能問題,曾嘗試將資源分配向新系統傾斜,以嘗試是否能解決問題,這在一定程度上也會影響實施的進度。
    4. 需要對核心的配置進行確認,如 JRE 版本,資料庫版本等。如果我們在生產環境建立的初期,就把 JRE 升級到最新的版本,可能就避免了這次 6 個月當機的煎熬。
  2. 壓力測試

    大部分具有併發需求的應用系統上線前,都要經過開發團隊的壓力測試,這樣在試執行階段才能心裡有底。本專案案例中,由於工期過於緊張,加之其他因素,導致壓力測試不夠充分,雖然 OOM 的問題並不是因為併發數過多產生,但是這一環節是不可忽視的。

  3. 攻堅團隊

    一個擁有高度的執行力的團隊一定是一個責任分明的團隊。在應對突發、嚴重、緊急情況時,要有專門的攻堅團隊來解決這類問題,這個團隊應該包括專案組的核心開發人員,有較強的動手能力和研究能力,能夠變通解決問題,思路開闊。他們的作用是至關重要的,往往可能決定專案的成敗。

  4. 信心很重要

    每一次攻堅記憶體洩露的問題都是一次探險之旅,需要有清醒的意識和頭腦,更要凝結你的意志和信心,因為這是一個艱苦的過程。本文案例由發生至解決有半年之久,當筆者轉向分析 javacore 檔案後,迅速定位了問題,終於柳暗花明,這種喜悅是難以言表的。

  5. 紙上得來終覺淺, 絕知此事要躬行。

    這一條不多說了,有所行,才有所得。


學習

獲得產品和技術

  • 下載 IBM 軟體試用版,體驗強大的 DB2®,Lotus®,Rational®,Tivoli®和 WebSphere®軟體。

討論

來自 “ ITPUB部落格 ” ,連結:http://blog.itpub.net/14710393/viewspace-751870/,如需轉載,請註明出處,否則將追究法律責任。

相關文章