記一次隱藏很深的 JVM 線上慘案的分析、排查、解決！

1、本文背景

本文會給大家講解一個比較特殊的JVM最佳化案例，這個最佳化案例本身是因為新手工程師對JVM最佳化可能瞭解了一個半吊子，然後不知道從哪裡找來了一個非常特殊的JVM引數錯誤的設定了一下，就導致線上系統頻繁的出現Full GC的問題。

但是我們後續大量的最佳化案例其實都是各種各樣奇形怪狀的場景，因為正是各種奇怪場景才能讓大家逐步積累出來較為豐富的JVM最佳化實戰經驗

瞭解的場景越多，自己未來在處理JVM效能問題的時候才能更是得心應手。

2、問題的產生

這個場景的發生大致如下過程：某天團隊裡一個新手工程師大概是心血來潮，覺得自己網上看到了某個JVM引數，以為學會了絕世武功秘籍，於是就在當天上線一個系統的時候，自作主張設定了一個JVM引數

這個引數是什麼呢？

不用急，跟著看下面的案例分析即可，現在只要知道他設定了一個奇怪的引數，接著事故就發生了。

因為一般中大型公司都是接入類似Zabbix、OpenFalcon或者公司自研的一些監控系統的，監控系統一般都做的很好，可以讓你的系統直接接入進去，然後在上面可以看到每臺機器的CPU、磁碟、記憶體、網路的一些負載。

而且可以看到你的JVM的記憶體使用波動折線圖，還有你的JVM GC發生的頻率折線圖。包括如果你自己上報某個業務指標，也可以在監控系統裡看到。

而且一般都會針對線上執行的機器和系統設定一些報警，比如說，你可以設定如果10分鐘內發現一個系統的JVM發生了超過3次Full GC，就必須傳送報警給你，可以傳送給你的簡訊、郵箱或者是釘釘之類的IM工具。

類似這樣的監控系統不在我們的專欄範疇內，建議大家自己可以去查閱資料，其實基於我們講解的命令列工具，比如jstat，你可以透過linux上的一些命令，讓jstat自動對jvm進行監控，把監控結果可以輸出到機器的某個檔案裡去。

然後第二天你就可以去查閱那個檔案，也可以看到那臺機器的jvm的一些gc統計。

所以說，沒有視覺化工具，用最簡單的命令列工具，其實同樣可以起到類似的效果。

所以那天那個工程師設定了一個JVM引數之後，直接導致線上頻繁接到JVM的Full GC的報警，大家就很奇怪了，於是就開始排查那個系統了。

3、檢視GC日誌

之前已經給大家講解過如何在啟動系統的時候讓他輸出GC日誌，所以一旦發現報警，直接登入到線上機器，然後就看到對應的GC日誌了。

此時我們看到在GC日誌中有大量的Full GC的記錄。

那麼是為什麼導致的Full GC呢？

在日誌裡，看到了一個“Metadata GC  Threshold”的字樣，類似於如下日誌：

【Full GC（Metadata GC  Threshold）xxxxx, xxxxx】

從這裡就知道，這頻繁的Full GC，實際上是JDK 1.8以後的Metadata後設資料區導致的，也就是類似我們之前說的永久代。

這個Metadata區域一般是放一些載入到JVM裡去的類的。

所以此時就很奇怪了，為什麼會因為Metadata區域頻繁的被塞滿，進而觸發Full GC？而且Full GC大家都知道，會帶動CMS回收老年代，還會回收Metadata區域本身。

我們先看看下圖：

4、檢視Metaspace記憶體佔用情況

接著我們當然是想看一看Metaspace區域的記憶體佔用情況了，簡單點你可以透過jstat來觀察，如果有監控系統，他會給你展示出來一個Metaspace記憶體區域佔用的波動曲線圖，類似下面這種。

看起來Metaspace區域的記憶體呈現一個波動的狀態，他總是會先不斷增加，達到一個頂點之後，就會把Metaspace區域給佔滿，然後自然就會觸發一次Full GC，Full GC會帶著Metaspace區域的垃圾回收，所以接下來Metaspace區域的記憶體佔用又變得很小了。

5、一個綜合性的分析思路

看到這裡，相信大家肯定有一點感覺了，這個很明顯是系統在執行過程中，不停的有新的類產生被載入到Metaspace區域裡去，然後不停的把Metaspace區域佔滿，接著觸發一次Full GC回收掉Metaspace區域中的部分類。

然後這個過程反覆的不斷的迴圈，進而造成Metaspace區域反覆被佔滿，然後反覆導致Full GC的發生，如下圖所示。

6、到底是什麼類不停的被載入？

接著我們就有點奇怪了，到底是什麼類不停的被載入到JVM的Metaspace區域裡去？

這個時候就需要在JVM啟動引數中加入如下兩個引數了：

“-XX:TraceClassLoading -XX:TraceClassUnloading”

這兩個引數，顧名思義，就是追蹤類載入和類解除安裝的情況，他會透過日誌列印出來JVM中載入了哪些類，解除安裝了哪些類。

加入這兩個引數之後，我們就可以看到在Tomcat的catalina.out日誌檔案中，輸出了一堆日誌，裡面顯示類似如下的內容：

【Loaded sun.reflect.GeneratedSerializationConstructorAccessor from __JVM_Defined_Class】

明顯可以看到，JVM在執行期間不停的載入了大量的所謂“GeneratedSerializationConstructorAccessor”類到了Metaspace區域裡去

如下圖所示

相信就是因為JVM執行期間不停的載入這種奇怪的類，然後不停的把Metaspace區域佔滿，才會引發不停的執行Full GC的。

這是一個非常實用的技巧，各位同學一定要掌握，頻繁Full GC不光是老年代觸發的，有時候也會因為Metaspace區域的類太多而觸發。

到此為止，已經慢慢接近真相了。

7、為什麼會頻繁載入奇怪的類？

接著遇到類似這種問題，我們就應該找一下Google或者是百度了，當然推薦是用Google。你完全可以看看那種不停載入的類，到底是什麼類，是你自己寫的類？還是說JDK內建的類？

比如上面的那個類，如果你查閱一些資料，很容易就會搞明白，那個類大概是在你使用Java中的反射時載入的，所謂反射程式碼類似如下所示。

Method method = XXX.class.getDeclaredMethod(xx,xx);

method.invoke(target,params);

友情提示一下，反射是Java中最最基礎的一個概念，不懂的朋友自己查一下資料。

簡單來說，就是透過XXX.class獲取到某個類，然後透過geteDeclaredMethod獲取到那個類的方法。

這個方法就是一個Method物件，接著透過Method.invoke可以去呼叫那個類的某個物件的方法，大概就這個意思。

在執行這種反射程式碼時，JVM會在你反射呼叫一定次數之後就動態生成一些類，就是我們之前看到的那種莫名其妙的類

下次你再執行反射的時候，就是直接呼叫這些類的方法，這是JVM的一個底層最佳化的機制。

看到這裡，有的小夥伴是不是有點蒙？

其實這倒無所謂，這段話看的蒙絲毫不影響你進行JVM最佳化的

你只要記住一個結論：如果你在程式碼裡大量用了類似上面的反射的東西，那麼JVM就是會動態的去生成一些類放入Metaspace區域裡的。

所以上面看到的那些奇怪的類，就是由於不停的執行反射的程式碼才生成的，如下圖所示。

8、JVM建立的奇怪類有什麼玄機？

那麼接下來我們就很奇怪一件事情，就是JVM為什麼要不停的建立那些奇怪的類然後放入Metaspace中去？

其實這就要從一個點入手來分析一下了，因為上面說的那種JVM自己建立的奇怪的類，他們的Class物件都是SoftReference，也就是軟引用的。

大家可千萬別說連類的Class是什麼都沒聽說過？簡單來說，每個類其實本身自己也是一個物件，就是一個Class物件，一個Class物件就代表了一個類。同時這個Class物件代表的類，可以派生出來很多例項物件。

舉例來說，Class Student，這就是一個類，他本身是由一個Class型別的物件表示的。

但是如果你走一個Student student = new Student(），這就是例項化了這個Student類的一個物件，這是一個Student型別的例項物件。

所以我們這裡所說的Class物件，就是JVM在發射過程中動態生成的類的Class物件，他們都是SoftReference軟引用的。

所謂的軟引用，最早我們再一篇文章裡說過，正常情況下不會回收，但是如果記憶體比較緊張的時候就會回收這些物件。

那麼SoftReference物件到底在GC的時候要不要回收是透過什麼公式來判斷的呢？

是如下的一個公式：

clock - timestamp <= freespace * SoftRefLRUPolicyMSPerMB。

這個公式的意思就是說，“clock - timestamp”代表了一個軟引用物件他有多久沒被訪問過了，freespace代表JVM中的空閒記憶體空間，SoftRefLRUPolicyMSPerMB代表每一MB空閒記憶體空間可以允許SoftReference物件存活多久。

舉個例子，假如說現在JVM建立了一大堆的奇怪的類出來，這些類本身的Class物件都是被SoftReference軟引用的。

然後現在JVM裡的空間記憶體空間有3000MB，SoftRefLRUPolicyMSPerMB的預設值是1000毫秒，那麼就意味著，此時那些奇怪的SoftReference軟引用的Class物件，可以存活3000 * 1000 = 3000秒，就是50分鐘左右。

當然上面都是舉例而已，大家都知道，一般來說發生GC時，其實JVM內部或多或少總有一些空間記憶體的，所以基本上如果不是快要發生OOM記憶體溢位了，一般軟引用也不會被回收。

所以大家就知道了，按理說JVM應該會隨著反射程式碼的執行，動態的建立一些奇怪的類，他們的Class物件都是軟引用的，正常情況下不會被回收，但是也不應該快速增長才對。

9、為什麼JVM建立的奇怪的類會不停的變多？

那麼究竟為什麼JVM建立的那些奇怪的類會不停的變多呢？

原因很簡單，因為文章開頭那個新手工程師不知道從哪裡扒出來了SoftRefLRUPolicyMSPerMB這個JVM啟動引數，他直接把這個引數設定為0了。

他想的是，一旦這個引數設定為0，任何軟引用物件就可以儘快釋放掉，不用留存，儘量給記憶體釋放空間出來，這樣不就可以提高記憶體利用效率了麼？

真是想的很傻很天真。

實際上一旦這個引數設定為0之後，直接導致clock - timestamp <= freespace * SoftRefLRUPolicyMSPerMB這個公式的右半邊是0，就導致所有的軟引用物件，比如JVM生成的那些奇怪的Class物件，剛建立出來就可能被一次Young GC給帶著立馬回收掉一些。

如下圖所示。

比如JVM好不容易給你弄出來100個奇怪的類，結果因為你瞎設定軟引用的引數，導致突然一次GC就給你回收掉幾十個類

接著JVM在反射程式碼執行的過程中，就會繼續建立這種奇怪的類，在JVM的機制之下，會導致這種奇怪類越來越多。

也許下一次gc又會回收掉一些奇怪的類，但是馬上JVM還會繼續生成這種類，最終就會導致Metaspace區域被放滿了，一旦Metaspace區域被佔滿了，就會觸發Full GC，然後回收掉很多類，接著再次重複上述迴圈，如下圖所示。

其實很多人會有一個疑問，到底為什麼軟引用的類因為錯誤的引數設定被快速回收之後，就會導致JVM不停建立更多的新的類呢？

其實大家不用去扣這裡的細節，這裡有大量的底層JDK原始碼的實現，異常複雜，要真的說清楚，得好幾篇文章才能講清楚JDK底層原始碼的這些細節。

大家只要記住這個結論，明白這個道理就好。

10、如何解決這個問題？

雖然底層JDK的一些實現細節我們沒分析，但是大致梳理出來了一個思路，大家也很清楚問題所在和原因了

解決方案很簡單。在有大量反射程式碼的場景下，大家只要把

-XX:SoftRefLRUPolicyMSPerMB=0

這個引數設定大一些即可，千萬別讓一些新手同學設定為0，可以設定個1000，2000，3000，或者5000毫秒，都可以。

提高這個數值，就是讓反射過程中JVM自動建立的軟引用的一些類的Class物件不要被隨便回收，當時我們最佳化這個引數之後，就可以看到系統穩定執行了。

基本上Metaspace區域的記憶體佔用是穩定的，不會來回大幅度波動了。

11、今日思考題

結合昨天的內容，大家思考一下這個線上事故的本質是什麼？

其實說白了不是JVM的問題，是人的問題。

大家可以考慮一下，如果你是公司的架構師，是否應該嚴格稽核各個系統的生產環境JVM引數？

比如完全可以推行一套JVM引數模板，如果有人要做定製的JVM最佳化，是不是應該先在測試環嘗試一下，然後還得交給你們高階別的架構師來稽核？

如果有人稽核，那麼就不會發生類似之類的血案了。

來源：公眾號狸貓技術窩的專欄：

《從零開始帶你成為JVM實戰高手》

本篇是作者救火隊隊長開放的試讀