FGC發(fā)生頻率優(yōu)化了400倍，如何做到？
不點藍字，我們哪來故事？
作者 | cmlbeliever
通過這一個多月的努力，將FullGC從40次/天優(yōu)化到近10天才觸發(fā)一次，而且YoungGC的時間也減少了一半以上，這么大的優(yōu)化，有必要記錄一下中間的調(diào)優(yōu)過程。
對于JVM垃圾回收，之前一直都是處于理論階段，就知道新生代，老年代的晉升關系，這些知識僅夠應付面試使用的。前一段時間，線上服務器的FullGC非常頻繁，平均一天40多次，而且隔幾天就有服務器自動重啟了，這表明的服務器的狀態(tài)已經(jīng)非常不正常了，得到這么好的機會，當然要主動請求進行調(diào)優(yōu)了。未調(diào)優(yōu)前的服務器GC數(shù)據(jù)，F(xiàn)ullGC非常頻繁。
重磅！Spring Boot 2.5.0火熱發(fā)布，還學得動嗎？
首先服務器的配置非常一般（2核4G），總共4臺服務器集群。每臺服務器的FullGC次數(shù)和時間基本差不多。其中JVM幾個核心的啟動參數(shù)為：
-Xms1000M -Xmx1800M -Xmn350M -Xss300K -XX:+DisableExplicitGC -XX:SurvivorRatio=4 -XX:+UseParNewGC -XX:+UseConcMarkSweepGC -XX:CMSInitiatingOccupancyFraction=70 -XX:+CMSParallelRemarkEnabled -XX:LargePageSizeInBytes=128M -XX:+UseFastAccessorMethods -XX:+UseCMSInitiatingOccupancyOnly -XX:+PrintGCDetails -XX:+PrintGCTimeStamps -XX:+PrintHeapAtGC
-Xmx1800M：設置JVM最大可用內(nèi)存為1800M。 -Xms1000m：設置JVM初始化內(nèi)存為1000m。此值可以設置與-Xmx相同，以避免每次垃圾回收完成后JVM重新分配內(nèi)存。 -Xmn350M：設置年輕代大小為350M。整個JVM內(nèi)存大小=年輕代大小 + 年老代大小 + 持久代大小。持久代一般固定大小為64m，所以增大年輕代后，將會減小年老代大小。此值對系統(tǒng)性能影響較大，Sun官方推薦配置為整個堆的3/8。 -Xss300K：設置每個線程的堆棧大小。JDK5.0以后每個線程堆棧大小為1M，以前每個線程堆棧大小為256K。更具應用的線程所需內(nèi)存大小進行調(diào)整。在相同物理內(nèi)存下，減小這個值能生成更多的線程。但是操作系統(tǒng)對一個進程內(nèi)的線程數(shù)還是有限制的，不能無限生成，經(jīng)驗值在3000~5000左右。
第一次優(yōu)化
一看參數(shù)，馬上覺得新生代為什么這么小，這么小的話怎么提高吞吐量，而且會導致YoungGC的頻繁觸發(fā)，如上如的新生代收集就耗時830s。初始化堆內(nèi)存沒有和最大堆內(nèi)存一致，查閱了各種資料都是推薦這兩個值設置一樣的，可以防止在每次GC后進行內(nèi)存重新分配。基于前面的知識，于是進行了第一次的線上調(diào)優(yōu)：提升新生代大小，將初始化堆內(nèi)存設置為最大內(nèi)存
-Xmn350M -> -Xmn800M
-XX:SurvivorRatio=4 -> -XX:SurvivorRatio=8
-Xms1000m ->-Xms1800m
將SurvivorRatio修改為8的本意是想讓垃圾在新生代時盡可能的多被回收掉。就這樣將配置部署到線上兩臺服務器（prod，prod2另外兩臺不變方便對比）上后，運行了5天后，觀察GC結果，YoungGC減少了一半以上的次數(shù)，時間減少了400s，但是FullGC的平均次數(shù)增加了41次。YoungGC基本符合預期設想，但是這個FullGC就完全不行了。
干貨篇：深入剖析 MySQL 索引和 SQL 調(diào)優(yōu)實戰(zhàn)
就這樣第一次優(yōu)化宣告失敗。
第二次優(yōu)化
在優(yōu)化的過程中，我們的主管發(fā)現(xiàn)了有個對象T在內(nèi)存中有一萬多個實例，而且這些實例占據(jù)了將近20M的內(nèi)存。于是根據(jù)這個bean對象的使用，在項目中找到了原因：匿名內(nèi)部類引用導致的，偽代碼如下：
public void doSmthing(T t){
redis.addListener(new Listener(){
public void onTimeout(){
if(t.success()){
//執(zhí)行操作
}
}
});
}
由于listener在回調(diào)后不會進行釋放，而且回調(diào)是個超時的操作，當某個事件超過了設定的時間（1分鐘）后才會進行回調(diào)，這樣就導致了T這個對象始終無法回收，所以內(nèi)存中會存在這么多對象實例。
通過上述的例子發(fā)現(xiàn)了存在內(nèi)存泄漏后，首先對程序中的error log文件進行排查，首先先解決掉所有的error事件。然后再次發(fā)布后，GC操作還是基本不變，雖然解決了一點內(nèi)存泄漏問題，但是可以說明沒有解決根本原因，服務器還是繼續(xù)莫名的重啟。
內(nèi)存泄漏調(diào)查
經(jīng)過了第一次的調(diào)優(yōu)后發(fā)現(xiàn)內(nèi)存泄漏的問題，于是大家都開始將進行內(nèi)存泄漏的調(diào)查，首先排查代碼，不過這種效率是蠻低的，基本沒發(fā)現(xiàn)問題。于是在線上不是很繁忙的時候繼續(xù)進行dump內(nèi)存，終于抓到了一個大對象
什么是數(shù)據(jù)湖？為什么要數(shù)據(jù)湖？如何建湖？如何ETL？
這個對象竟然有4W多個，而且都是清一色的ByteArrowRow對象，可以確認這些數(shù)據(jù)是數(shù)據(jù)庫查詢或者插入時產(chǎn)生的了。于是又進行一輪代碼分析，在代碼分析的過程中，通過運維的同事發(fā)現(xiàn)了在一天的某個時候入口流量翻了好幾倍，竟然高達83MB/s，經(jīng)過一番確認，目前完全沒有這么大的業(yè)務量，而且也不存在文件上傳的功能。咨詢了阿里云客服也說明完全是正常的流量，可以排除攻擊的可能。
就在我還在調(diào)查入口流量的問題時，另外一個同事找到了根本的原因，原來是在某個條件下，會查詢表中所有未處理的指定數(shù)據(jù)，但是由于查詢的時候where條件中少加了模塊這個條件，導致查詢出的數(shù)量達40多萬條，而且通過log查看當時的請求和數(shù)據(jù)，可以判斷這個邏輯確實是已經(jīng)執(zhí)行了的，dump出的內(nèi)存中只有4W多個對象，這個是因為dump時候剛好查詢出了這么多個，剩下的還在傳輸中導致的。而且這也能非常好的解釋了為什么服務器會自動重啟的原因。
解決了這個問題后，線上服務器運行完全正常了，使用未調(diào)優(yōu)前的參數(shù)，運行了3天左右FullGC只有5次
收藏吧！產(chǎn)品再要求實現(xiàn)這個功能，就把這篇轉(zhuǎn)給他！
第二次調(diào)優(yōu)
內(nèi)存泄漏的問題已經(jīng)解決了，剩下的就可以繼續(xù)調(diào)優(yōu)了，經(jīng)過查看GC log，發(fā)現(xiàn)前三次GullGC時，老年代占據(jù)的內(nèi)存還不足30%，卻發(fā)生了FullGC。于是進行各種資料的調(diào)查，在https://blog.csdn.net/zjwstz/article/details/77478054 博客中非常清晰明了的說明metaspace導致FullGC的情況，服務器默認的metaspace是21M，在GC log中看到了最大的時候metaspace占據(jù)了200M左右，于是進行如下調(diào)優(yōu)，以下分別為prod1和prod2的修改參數(shù)，prod3，prod4保持不變
-Xmn350M -> -Xmn800M
-Xms1000M ->1800M
-XX:MetaspaceSize=200M
-XX:CMSInitiatingOccupancyFraction=75
和
-Xmn350M -> -Xmn600M
-Xms1000M ->1800M
-XX:MetaspaceSize=200M
-XX:CMSInitiatingOccupancyFraction=75
prod1和2只是新生代大小不一樣而已，其他的都一致。到線上運行了10天左右，進行對比：prod1：
Spring Security 5.5發(fā)布，正式實裝OAuth2.0的第五種授權模式
prod2：
prod3：
拼多多面試真題：如何用 Redis 統(tǒng)計獨立用戶訪問量！
prod4：
Spring越來越強，而我們越來越快餐！離開了Spring，居然API都寫不出來了！
對比來說，1，2兩臺服務器FullGC遠遠低于3，4兩臺，而且1，2兩臺服務器的YounGC對比3，4也減少了一半左右，而且第一臺服務器效率更為明顯，除了YoungGC次數(shù)減少，而且吞吐量比多運行了一天的3，4兩臺的都要多（通過線程啟動數(shù)量），說明prod1的吞吐量提升尤為明顯。通過GC的次數(shù)和GC的時間，本次優(yōu)化宣告成功，且prod1的配置更優(yōu)，極大提升了服務器的吞吐量和降低了GC一半以上的時間。
prod1中的唯一一次FullGC：
通過GC log上也沒看出原因，老年代在cms remark的時候只占據(jù)了660M左右，這個應該還不到觸發(fā)FullGC的條件，而且通過前幾次的YoungGC調(diào)查，也排除了晉升了大內(nèi)存對象的可能，通過metaspace的大小，也沒有達到GC的條件。這個還需要繼續(xù)調(diào)查，有知道的歡迎指出下，這里先行謝過了。
總結
通過這一個多月的調(diào)優(yōu)總結出以下幾點：
FullGC一天超過一次肯定就不正常了 發(fā)現(xiàn)FullGC頻繁的時候優(yōu)先調(diào)查內(nèi)存泄漏問題 內(nèi)存泄漏解決后，jvm可以調(diào)優(yōu)的空間就比較少了，作為學習還可以，否則不要投入太多的時間 如果發(fā)現(xiàn)CPU持續(xù)偏高，排除代碼問題后可以找運維咨詢下阿里云客服，這次調(diào)查過程中就發(fā)現(xiàn)CPU 100%是由于服務器問題導致的，進行服務器遷移后就正常了。 數(shù)據(jù)查詢的時候也是算作服務器的入口流量的，如果訪問業(yè)務沒有這么大量，而且沒有攻擊的問題的話可以往數(shù)據(jù)庫方面調(diào)查 有必要時常關注服務器的GC，可以及早發(fā)現(xiàn)問題
往期推薦
下方二維碼關注我
技術草根，堅持分享 編程，算法，架構