JVM完全解讀之GC日志記錄分析
相信大家在系統(tǒng)學習jvm的時候都會有遇到過這樣的問題，散落的jvm知識點知道很多，但是真正在線上環(huán)境遇到一些莫名其妙的gc異常時候卻無從下手去分析。
關于這塊的苦我也表示能夠理解，之前光是JVM相關的八股文就整理了許多，但是經常是不知道如何在實戰(zhàn)中使用。最近也嘗試在模擬一些案例來訓練自己的JVM相關知識，本文特意記錄下這段調優(yōu)經歷。
Java應用的GC評估
可能大多數程序員在開發(fā)完某個需求之后，往線上環(huán)境一丟，然后就基本不怎么關注后續(xù)的變化了。但是是否有考慮過，這些新引入的代碼會對原有系統(tǒng)造成的影響呢？下邊我們通過一段實戰(zhàn)來帶各位讀者較好地去深入理解這個過程。
模擬場景
有一個應用程序（暫且稱呼為moment服務）準備在小程序上開展社交動態(tài)推送功能，大概就是每次用戶刷新頁面時候便會按照一定規(guī)則推送出20條用戶動態(tài)數據。由于該產品的c端用戶數量比較多，于是便在上線該產品之前進行了相應的壓測，判斷該功能的承載能力。
在壓測開始的初期，接口響應速度都還可以，但是漸漸地開始加壓的時候，發(fā)現程序出現了OOM。經過排查后，排除數據庫層的問題。于是開始懷疑是否是Java應用內部出現了異常。
應用的啟動參數：
java -Xmx1512m -Xms1512m -Xmn1024m -XX:+UseConcMarkSweepGC -XX:+UseParNewGC -XX:+HeapDumpOnOutOfMemoryError -XX:+PrintGCDetails -XX:+PrintGCTimeStamps -Xloggc:log/gc.log -jar qiyu-framework-demo-jvm.jar
單節(jié)點壓測，壓力測試10w次請求，1000并發(fā)。使用ab工具進行壓力測試：
ab -n100000 -c1000 http://localhost:8080/user/batch-query
jstat 查看GC，每隔5秒打印一次，持續(xù)20次
jstat -gc 5673 5000 20
經過一段時間的施壓，在施壓的持續(xù)了1分鐘之后，YGC的頻率讓人感覺著實有些高。通常一個健康的系統(tǒng)ygc應該是20-30min左右一次，full gc可能是好幾周才一次。
通過jstat可以看出，年輕代的gc會比較頻繁，并且停頓時間嚴重影響了正常的業(yè)務使用。為了得到更加精準的數據，我嘗試將gc日志放到GCeasy工具上進行可視化分析：
這是一款非常不錯的gc日志分析工具
https://www.gceasy.io/
GC日志的可視化分析
首先是JVM內存中的占用分析，很清晰地可以看出，年輕代的內存和老年代的內存幾乎占滿，元空間基本沒有變動過。
然后是整個系統(tǒng)的GC耗時分析：
從整體來看，大部分的GC耗時都是在0-100ms內，極端情況下的GC耗時可能會達到700ms。
接下來是看看GC回收對堆內存整體的一個影響。觀測發(fā)現，基本每次GC都能夠回收達改200mb左右的內存。
再繼續(xù)分析，可以發(fā)現CMS回收器在回收的各個階段中所消耗的時間：初始標記，并發(fā)標記，修正標記，并發(fā)清除
除了單純分析GC回收的耗時之外，這款工具還有個非常贊的功能，可以幫助我們分析這段時間內，該Java程序產生對象的速率：
可以發(fā)現，一秒大概要產生445mb的對象，大概一秒就會有2.5mb對象晉升到老年代。
內存逃逸分析沒有發(fā)現異常記錄。
通過對這份報告分析完畢之后，我的第一直覺告訴我，年輕代不足，需要對年輕代內存進行增加。但是仔細觀察下，產生對象的速率竟然高達445mb/s，這感覺非常不正常啊，極度懷疑是程序內部存在大對象的情況。
于是嘗試使用jvisualVM這款工具進行深入分析，通過對CPU樣例的監(jiān)控，發(fā)現了一些異常信息：
似乎這個方法對CPU的消耗比較高，接著是內存的一個監(jiān)控：
此時大概可以定位出異常方法所在的位置了，接下來便是對系統(tǒng)內部的業(yè)務代碼進行分析了。
最后排查結果發(fā)現，其實是系統(tǒng)內部的一個方法調用，加載了5k個User對象到內存中做計算，而每個User對象里存放了一個大小為1kb的byte數組。大概的代碼邏輯為：
于是便需要從業(yè)務層面對該方法進行優(yōu)化，例如調小5k這個數值，同時對User對象內的byte數組進行過濾（因為實際使用不到這個字段）。
調整后發(fā)現GC的頻率降低了許多，比較正常。
頻繁GC的排查思路總結
通過本次實驗，大概能夠梳理出Java應用在出現頻繁GC的時候該如何去排查問題點，大致為：
通過結合工具分析GC日志，排查是否有大量對象頻繁創(chuàng)建所導致。
通過對GC日志的分析能夠排查出年輕代和老年代的GC頻率。
通過對CPU占用比較高的線程，或者內存占用比較高的對象進行分析，定位異常點。
最后結合業(yè)務系統(tǒng)代碼進行分析，精確定位異常點。
以上就是JVM完全解讀之GC日志記錄分析的詳細內容，更多關于JVM解讀GC日志記錄分析的資料請關注腳本之家其它相關文章！
相關文章
這篇文章主要介紹了使用JPA自定義id策略避免主鍵自增問題,具有很好的參考價值,希望對大家有所幫助,如有錯誤或未考慮完全的地方,望不吝賜教2024-08-08
Java并發(fā)編程中的ReentrantLock類詳解
這篇文章主要介紹了Java并發(fā)編程中的ReentrantLock類詳解,ReentrantLock是juc.locks包中的一個獨占式可重入鎖,相比synchronized,它可以創(chuàng)建多個條件等待隊列,還支持公平/非公平鎖、可中斷、超時、輪詢等特性,需要的朋友可以參考下2023-12-12
這篇文章主要介紹了java中的快速排序，本文給大家介紹的非常詳細，對大家的學習或工作具有一定的參考借鑒價值，需要的朋友可以參考下2021-08-08
這篇文章主要介紹了詳解Java阻塞隊列(BlockingQueue)的實現原理，阻塞隊列是Java util.concurrent包下重要的數據結構，是一種特殊的隊列，需要的朋友可以參考下2021-10-10
這篇文章主要介紹了Spring Boot 項目啟動失敗的解決方案，幫助大家更好的理解和學習使用Spring Boot，感興趣的朋友可以了解下2021-03-03
springboot用controller跳轉html頁面的實現
這篇文章主要介紹了springboot用controller跳轉html頁面的實現，文中通過示例代碼介紹的非常詳細，對大家的學習或者工作具有一定的參考學習價值，需要的朋友們下面隨著小編來一起學習學習吧2020-09-09
下面小編就為大家?guī)硪黄猨ava求兩個數中的大數(實例講解)。小編覺得挺不錯的，現在就分享給大家，也給大家做個參考。一起跟隨小編過來看看吧2017-10-10
這篇文章主要介紹了Java中反射reflect的基礎知識講解,Java中的反射,它算是Java當中非常底層的一個技術,平時我們我們用得不多,實際上它也的確非常復雜同時也難以理解,但是涉及到底層的東西Java都給我們封裝好了,我們直接拿來調用即可,需要的朋友可以參考下2023-10-10
本文講解了Spring中最常用的注解之一@Autowired, 平時我們可能都是使用屬性注入的，但是后續(xù)建議大家慢慢改變習慣，使用構造器注入。同時也講解了這個注解背后的實現原理,需要的朋友可以參考下2023-01-01
本篇文章主要介紹了Spring整合Quartz分布式調度的示例代碼，小編覺得挺不錯的，現在分享給大家，也給大家做個參考。一起跟隨小編過來看看吧2018-04-04