天天看點

兩個OOM Cases排查過程的分享

分享一下兩個oom cases的查找過程,一個應用是native oom;另外一個應用其實沒有oom,隻是每隔一段時間就會出現頻繁fgc的現象,oom的查找已經具備了不錯的工具,但有些時候還是會出現很難查的現象,希望這兩個排查過程的分享能給需要的同學帶來一些幫助。

native oom的排查case

之前的幾個ppt裡我都說到了,目前查找native oom最好的方法就是用google perftools了,于是挂上google perftools,等待應用再次native oom,很幸運,兩天後,應用就再次native oom了,于是分析crash之前那段時間誰在不斷的配置設定堆外的記憶體,pprof看到的結果主要是java.util.inflater造成的,由于之前已經碰到過類似的case,知道如果使用了inflater,但不顯式的調用inflater.end的話,确實會造成這個現象。

于是剩下的問題就是找出代碼裡什麼地方調用了inflater,這種時候btrace這個神器就可以發揮作用了,一個簡單的btrace腳本:

[java]

import static com.sun.btrace.btraceutils.;

import com.sun.btrace.annotations.;

@btrace public class trace{

@onmethod(

clazz="java.util.zip.inflater",

method="/.*/"

)

public static void traceexecute(@probemethodname string methodname){

println(concat("who call inflater.",methodname));

jstack();

}

[/java]

執行後很快就找到了代碼什麼地方調用了inflater,于是加上了顯式的調用inflater.end,搞定收工。

偶爾頻繁fgc的排查case

這個case就沒上面的那個那麼順利了,查了有接近一個月才查出最終的原因。

當這個應用出現頻繁fgc時,dump了記憶體,用mat分析後,看到記憶體被消耗完的原因是由于幾個線程内的threadlocalmap中有大量的資料,threadlocal中消耗最多記憶體的主要是一個hashmap,這裡面有大量的資料。

于是當時想到的第一個方法就是查查應用裡面什麼地方往threadlocal裡放了hashmap,杯具的是,當查找代碼後發現應用本身的代碼并沒有往 threadlocal裡放hashmap,那就隻能是應用依賴的其他jar包做了這樣的事了,但不可能去抓出這個應用依賴的所有的jar的源碼來掃描,于是繼續借助btrace,寫了個腳本來跟蹤這類型的線程中誰調用了threadlocal.set,并且放的是hashmap,btrace腳本如下:

clazz="java.lang.threadlocal",

method="set"

public static void traceexecute(object value){

if(startswith(name(currentthread()),"xxx") && startswith("java.util.hashmap",name(classof(value))) ){

println("————————-");

println();

ok,開始運作上面的腳本,發現竟然一直都沒列印出什麼内容,隻能一直等了,杯具的是一直到了一周後再次出現頻繁fgc時,這個腳本都沒輸出任何的東西,于是隻好轉換思路。

既然是hashmap裡put了大量的某種類型的資料,那幹脆用btrace來看看是誰在往hashmap裡put這些資料,于是又寫了一個 btrace腳本,執行後,很快就看到了是代碼中什麼地方在put這些資料,但是從抓到的調用者來看,不僅僅是目前有大量資料的這類型的線程會調,其他類型的線程也會調用,如果這個地方有問題的話,應該就全部有問題了,于是跳過這裡。

回到mat看到的現象,會不會是因為代碼什麼地方用threadlocal的方式不對,又或是什麼地方往threadlocal裡放了東西,又忘了清除呢,是以要做的就是找出這個應用中所有屬性為threadlocal的地方,來人肉分析了,于是寫了一個jsp,掃描所有的classloader中的所有class,找出屬性類型為threadlocal的,掃描後找到了一些,還真發現有一個和現在hashmap中放的資料一樣的private threadlocal,這種用法線上程複用的情況下,如果是每次new threadlocal的話,會導緻threadlocal放的東西一直不釋放,興奮的以為已經發現原因了,可惜和業務方一确認,這個類借助spring 保證了singleton的,是以不會有問題。

好吧,到這一步,隻能猜想是由于某種參數請求的時候造成業務上會獲得大量的資料了,于是想着要找業務方來分析代碼了,這個非常麻煩,于是到此就幾乎停滞不前了。

今天靜下心來,重新仔細的看了下mat分析的結果,決定仍然用btrace跟蹤下之前往hashmap中put資料的那個業務代碼,突然發現,在 web類型的處理線程中它借助的是filter去clear資料的,而杯具的是出問題的這種類型線程的處理機制是沒有filter機制的,是以猜測問題估計出在這裡了,繼續btrace,看看這種類型的線程中是不是隻有人調put,沒人調clear,btrace腳本運作,很快就驗證了這個猜測,于是相應的解決掉了這個case,搞定收工。

在這第二個case中,可見在頻繁fgc或者oom時,很有可能mat隻能告訴你初步的原因,但要對應到代碼上到底是什麼地方造成的,還得花很大精力分析了,這個時候btrace通常能幫上很大的忙。

本文來源于"阿裡中間件團隊播客",原文發表時間" 2011-01-13"