分享一下兩個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腳本:
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();
}
}
執行後很快就找到了代碼什麼地方調用了Inflater,於是加上了顯式的調用Inflater.end,搞定收工。
偶爾頻繁FGC的排查Case
這個Case就沒上面的那個那麼順利了,查了有接近一個月才查出最終的原因。
當這個應用出現頻繁FGC時,dump了內存,用MAT分析後,看到內存被消耗完的原因是由於幾個線程內的ThreadLocalMap中有大量的數據,ThreadLocal中消耗最多內存的主要是一個HashMap,這裡面有大量的數據。
於是當時想到的第一個方法就是查查應用裡面什麼地方往ThreadLocal裡放了HashMap,杯具的是,當查找代碼後發現應用本身的代碼並沒有往ThreadLocal裡放HashMap,那就只能是應用依賴的其他jar包做了這樣的事了,但不可能去抓出這個應用依賴的所有的jar的源碼來掃描,於是繼續借助BTrace,寫了個腳本來跟蹤這類型的線程中誰調用了ThreadLocal.set,並且放的是HashMap,btrace腳本如下:
import static com.sun.btrace.BTraceUtils.*;
import com.sun.btrace.annotations.*;
@BTrace public class Trace{
@OnMethod(
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("-------------------------");
jstack();
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通常能幫上很大的忙。