工作日志-OOM事件
某項目,年前開始報OOM,頻率保持在一月一次,發生OOM的時候,heap free size還有7~800M,比較奇怪,年后系統上集群,系統發生OOM的頻率開始變得頻繁,基本在4-5天,由于用的是sun jdk 1.4.2_08,無法獲取到heap dump,建議用戶升級到1.4.2_14(該版本以后sun添加了HeapDumpOnOutOfMemoryError參數,便于獲取dump幫助診斷該類問題),4天之后,我們獲取到了heapdump文件,通過對dump的分析,基本上排除了對象泄漏。
根據環境(64bit Solaris + 32bit JDK),客戶把Heap最大設置為2G,開始懷疑32bit JDK無法分配這么大的Heap,經過驗證,不存在這樣的問題(sun網站也有相關說明,在solaris 64bit系統上,32bit jdk最大可以設置到4G)
但是從dump看到application classes loader大小已經到了60M以上,有點懷疑Perm區設置太小導致,查了一下sun的文檔,Perm區缺省大小為64M,估計是應用加載太多classes導致Perm區溢出,
我們也簡單模擬了一下Perm溢出,強制設置max perm大小為32M,并對GC進行了監控,結果和我們預想的一致,看下面的gc log:
151.836: [Full GC 151.836: [Tenured: 25735K->25736K(1048576K), 0.8380858 secs] 25911K->25736K(1557568K), [Perm : 32767K->32767K(32768K)], 0.8382804 secs]
152.676: [Full GC 152.676: [Tenured: 25736K->25722K(1048576K), 0.8464782 secs] 25752K->25722K(1557568K), [Perm : 32767K->32766K(32768K)], 0.8466638 secs]
153.525: [Full GC 153.525: [Tenured: 25722K->25724K(1048576K), 0.8419056 secs] 25738K->25724K(1557568K), [Perm : 32767K->32767K(32768K)], 0.8420986 secs]
154.368: [Full GC 154.368: [Tenured: 25724K->25724K(1048576K), 0.8398816 secs] 25724K->25724K(1557568K), [Perm : 32767K->32767K(32768K)], 0.8400498 secs]
155.212: [Full GC 155.212: [Tenured: 25724K->25725K(1048576K), 0.8365448 secs] 25788K->25725K(1557568K), [Perm : 32767K->32767K(32768K)], 0.8367370 secs]
156.050: [Full GC 156.050: [Tenured: 25725K->25722K(1048576K), 0.8422488 secs] 25725K->25722K(1557568K), [Perm : 32767K->32766K(32768K)], 0.8424328 secs]
156.895: [Full GC 156.895: [Tenured: 25722K->25724K(1048576K), 0.8443532 secs] 25738K->25724K(1557568K), [Perm : 32767K->32767K(32768K)], 0.8445450 secs]
157.740: [Full GC 157.741: [Tenured: 25724K->25724K(1048576K), 0.8427754 secs] 25740K->25724K(1557568K), [Perm : 32767K->32767K(32768K)], 0.8429634 secs]
158.587: [Full GC 158.588: [Tenured: 25724K->25726K(1048576K), 0.8352290 secs] 25820K->25726K(1557568K), [Perm : 32767K->32767K(32768K)], 0.8354212 secs]
159.424: [Full GC 159.424: [Tenured: 25726K->25723K(1048576K), 0.8435336 secs] 25726K->25723K(1557568K), [Perm : 32767K->32766K(32768K)], 0.8437092 secs]
160.270: [Full GC 160.270: [Tenured: 25723K->25725K(1048576K), 0.8477722 secs] 25739K->25725K(1557568K), [Perm : 32767K->32767K(32768K)], 0.8479596 secs]
161.119: [Full GC 161.119: [Tenured: 25725K->25725K(1048576K), 0.8543338 secs] 25725K->25725K(1557568K), [Perm : 32767K->32767K(32768K)], 0.8545040 secs
從日志看,和我們現場的狀況非常相似,heap空間充足,但是perm已經到了32M,無法再進一步分配空間,直接導致jvm頻繁做Full GC,控制臺也開始拋出OOM(Perm引起的回收都是full gc),這樣看基本我們判斷是Perm太小,導致無法加載classes導致的
和客戶溝通之后,我們本來打算進一步驗證(在生產環節打開PrintGCDetail,獲取詳細的GC log),后面仔細檢查nohup.out,發現里面已經拋出了 OutOfMemoryError:PermGen Space,至此我們確定是Perm設置不合理導致了本次事故,和客戶確認之后,我們在啟動參數中加上了MaxPermSize
后面想到中間上了集群之后,eos加載了大量的jboss cache class,這也直接解釋了為什么這段時間OOM出現的頻率比之前更頻繁的原因
這里總結一下,希望對碰到類似問題的tx有借鑒意義,強烈建議用sun jdk 1.4.2的同學升級到>=1.4.2_12,便于對OOM問題的診斷,并加上GC log協助驗證。
這里再介紹一下JVM發生OOM的幾種情況:
1、java.lang.OutOfMemoryError: Java heap space
這是我們平常理解的OOM,是由于heap space確實沒有空間分配,這種一般是由于內存泄漏導致,也有可能是heap space設置太小。需要具體分析
2、java.lang.OutOfMemoryError: PermGen space
jvm規范里面有定義一個method space,這里主要放classes和method list和一個string pool,string有一個intern方法,通過這個方法定義的string都放在這里(好像不常用),這里設置不太小會導致OOM,缺省64M,主要由于現在應用依賴的第三方類越來越多,導致這類問題頻繁發生,需要引起重視
3、Requested array size exceeds VM limit
這種是由于申請的array size超出了heap space大小,比如在一個256M的heap space中申請一個512M的array,這種基本都是應用bug導致
4、request <size> bytes for <reason>. Out of swap space?
這種是由于heap size設置相對于系統物理內存太大,導致系統swap space不足,這種的解決辦法就是減小heap size大小
5、<reason> <stack trace> (Native method)
這種估計是最麻煩的了,也是最少碰到的,是由于jni或native method導致,如果自己沒有寫這類的東西,基本可以說是jdk問題
posted on 2008-03-16 22:38 tacy lee 閱讀(2734) 評論(2) 編輯 收藏 所屬分類: 性能相關