千鋒扣丁學(xué)堂Java培訓(xùn)之深入學(xué)習(xí)GC日志解讀
2019-06-10 13:49:50
1083瀏覽
今天千鋒扣丁學(xué)堂Java培訓(xùn)老師給大家分享一篇關(guān)于深入學(xué)習(xí)JAVAGC日志的相關(guān)知識(shí),首先JVM在Java應(yīng)用程序優(yōu)化中是不可缺少的一大重項(xiàng),如何合理配置Java參數(shù),如何驗(yàn)證配置參數(shù)的有效性,從GC日志中可以獲得很重要的提示。
GC環(huán)境模擬
首先我們給出如下代碼用來觸發(fā)GC
public static void main(String[] args) {
// 每100毫秒創(chuàng)建100線程,每個(gè)線程創(chuàng)建一個(gè)1M的對(duì)象,即每100ms申請(qǐng)100M堆空間
Executors.newScheduledThreadPool(1).scheduleAtFixedRate(() -> {
for (int i = 0; i < 100; i++) {
new Thread(() -> {
try {
// 申請(qǐng)1M
byte[] temp = new byte[1024 * 1024];
Thread.sleep(new Random().nextInt(1000)); // 隨機(jī)睡眠1秒以內(nèi)
} catch (InterruptedException e) {
e.printStackTrace();
}
}).start();
}
}, 1000, 100, TimeUnit.MILLISECONDS);
}
我們要模擬的場(chǎng)景是年輕代不斷地YoungGC,并有一部分對(duì)象晉升到老年代,當(dāng)老年代空間不足時(shí)觸發(fā)FullGC。
程序邏輯:每100毫秒鐘創(chuàng)建100個(gè)線程,每個(gè)線程創(chuàng)建一個(gè)1M的對(duì)象,即每100ms申請(qǐng)100M堆空間。之所以每個(gè)線程隨機(jī)睡眠1s,是為了避免對(duì)象朝生夕滅,保證可以有一部分對(duì)象能晉升到老年代,更好的觸發(fā)YoungGC和FullGC,注意這個(gè)睡眠時(shí)間如果大了,會(huì)導(dǎo)致OOM,如果小了,很難觸發(fā)FULLGC。
虛擬機(jī)參數(shù)解釋
啟動(dòng)Java進(jìn)程:java-Xms200m-Xmx200m-Xmn100m-verbose:gc-XX:+PrintGCDetails-Xloggc:./gc.log-XX:+PrintGCDateStamps-jardemo-0.0.1-SNAPSHOT.jar
-Xms200m-Xmx200m最小/最大堆內(nèi)存200M
-Xmn100m年輕代內(nèi)存100M
-verbose:gc開啟GC日志
-XX:+PrintGCDetails-Xloggc:./gc.log-XX:+PrintGCDateStamps將GC日志詳情輸入到gc.log中
jmap分析
jcmd獲取我們Java進(jìn)程的Id:6264
jmap-heap6264查看堆信息
第一次查看,我們發(fā)現(xiàn)Eden區(qū)是98M,S0、S1是1M
第二次查看,Eden區(qū)是99M,S0、S1是0.5M
Eden區(qū)與Survivor區(qū)的比例在動(dòng)態(tài)的變化,并不是默認(rèn)的8:1:1。
原來我們使用默認(rèn)的垃圾收集器ParallelScavenge+ParallelOld組合,而該收集器下-XX:+UseAdaptiveSizePolicy是默認(rèn)開啟的,即Eden區(qū)與Survivor區(qū)比例根據(jù)GC情況會(huì)自適應(yīng)變化。
我們加上參數(shù),關(guān)閉年輕代自適應(yīng),年輕代比例設(shè)置為8:1:1
-XX:-UseAdaptiveSizePolicy-XX:SurvivorRatio=8
另外為了盡早的觸發(fā)FULLGC,我們新增虛擬機(jī)參數(shù)
-XX:MaxTenuringThreshold=10
晉升年齡由默認(rèn)的15修改為10,使得年輕代的對(duì)象更容易晉升到老年代
重啟虛擬機(jī)查看jmap
年輕代
Eden區(qū)80M已使用51M,當(dāng)前使用率63.8%
S0區(qū)10M已使用0.43M,使用率4.37%
S1區(qū)10M使用率為空
老年代
100M已使用18.39M,使用率18.9%
GC日志內(nèi)容分析
查看我們輸出的GC日志gc.log,選取其中兩段
2019-06-09T02:55:30.993+0800: 330.811: [GC (Allocation Failure) [PSYoungGen: 82004K->384K(92160K)] 184303K->102715K(194560K), 0.0035647 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]
2019-06-09T02:55:30.997+0800: 330.815: [Full GC (Ergonomics) [PSYoungGen: 384K->0K(92160K)] [ParOldGen: 102331K->5368K(102400K)] 102715K->5368K(194560K), [Metaspace: 16941K->16914K(1064960K)], 0.0213953 secs] [Times: user=0.02 sys=0.00, real=0.02 secs]
YoungGC
2019-06-09T02:55:30.993+0800: 330.811: [GC (Allocation Failure) [PSYoungGen: 82004K->384K(92160K)] 184303K->102715K(194560K), 0.0035647 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]
2019-06-09T02:55:30.997+0800: 330.815: [Full GC (Ergonomics) [PSYoungGen: 384K->0K(92160K)] [ParOldGen: 102331K->5368K(102400K)] 102715K->5368K(194560K), [Metaspace: 16941K->16914K(1064960K)], 0.0213953 secs] [Times: user=0.02 sys=0.00, real=0.02 secs]
解釋:
年輕代GC:[GC前年輕代80.08M->GC后0.37M(年輕代總大小90M)]GC前堆179.98M->GC后堆100.3M(堆總大小190M),用時(shí)]
其中年輕代總大小是90M而不是100M,這里我理解是年輕代當(dāng)前最大申請(qǐng)到90M
100M*80%=80M是Eden區(qū)大小
80M*80%=64MEden區(qū)默認(rèn)占用超過8成即64M就會(huì)觸發(fā)YoungGC
FullGC
[Full GC (Ergonomics) [PSYoungGen: 384K->0K(92160K)] [ParOldGen: 102331K->5368K(102400K)] 102715K->5368K(194560K), [Metaspace: 16941K->16914K(1064960K)], 0.0213953 secs] [Times: user=0.02 sys=0.00, real=0.02 secs]
解釋:
[GC前年輕代0.375M->GC后年輕代0M(年輕代總大小90M)][GC前老年代99.93M->GC后老年代5.24M(老年代總大小100M)]GC前堆100.3M->GC后堆5.24M(堆總大小190M),[元數(shù)據(jù)區(qū):GC前16.5,GC后16.5(元數(shù)據(jù)區(qū)總大小1040M)],用時(shí)]
可以推測(cè)出此次FullGC原因是年輕代晉升老年代空間不足導(dǎo)致
利用可視化工具分析
這里我們利用gceasy.io/分析一下
(1)統(tǒng)計(jì)年輕代、老年代、元數(shù)據(jù)區(qū)最大可用空間以及峰值,這里元數(shù)據(jù)區(qū)大小在我們的虛擬機(jī)參數(shù)沒有配置,所以取的是默認(rèn)值
(2)吞吐量、GC平均延遲、最大延遲以及延遲區(qū)間的統(tǒng)計(jì)
(3)堆所用大小的實(shí)時(shí)分析,紅色位置是發(fā)生了FullGC使得堆總量直線下降
會(huì)發(fā)現(xiàn)虛擬機(jī)在剛啟動(dòng)不久的階段觸發(fā)大量的FULLGC,我的理解是我們申請(qǐng)的對(duì)象都隨機(jī)睡眠一秒以內(nèi),剛啟動(dòng)時(shí)大部分還存在線程的引用,GCRoot可達(dá)。在剛啟動(dòng)的時(shí)候觸發(fā)FULLGC并不會(huì)完整清理掉老年代空間并由于空間不足不斷觸發(fā)FULLGC。
(4)GC空間總量和時(shí)間的統(tǒng)計(jì)
(5)各類GC時(shí)間、GC次數(shù)、GC總量等指標(biāo)
GC日志分析可以幫助我們宏觀的監(jiān)控GC運(yùn)行情況。一方面如果頻繁的FullGC會(huì)有嚴(yán)重的性能問題(STW),另一方面過于頻繁的GC,即GC占用系統(tǒng)正常運(yùn)行的比重過多,吞吐量低,則是一定程度上的性能資源浪費(fèi)。若系統(tǒng)存在性能問題,根據(jù)GC分析各項(xiàng)指標(biāo)的作為參考,我們也可以適當(dāng)?shù)脑诔绦蚶锘蛱摂M機(jī)參數(shù)做些調(diào)優(yōu)。
以上就是關(guān)于千鋒扣丁學(xué)堂Java培訓(xùn)之深入學(xué)習(xí)GC日志解讀的全部?jī)?nèi)容,希望對(duì)大家的學(xué)習(xí)有所幫助,
想要了解更多關(guān)于Java開發(fā)方面內(nèi)容的小伙伴,請(qǐng)關(guān)注扣丁學(xué)堂Java培訓(xùn)官網(wǎng)、微信等平臺(tái),扣丁學(xué)堂IT職業(yè)在線學(xué)習(xí)教育有專業(yè)的Java講師為您指導(dǎo),此外扣丁學(xué)堂老師精心推出的Java視頻教程定能讓你快速掌握J(rèn)ava從入門到精通開發(fā)實(shí)戰(zhàn)技能??鄱W(xué)堂Java技術(shù)交流群:850353792。
【關(guān)注微信公眾號(hào)獲取更多學(xué)習(xí)資料】 【掃碼進(jìn)入HTML5前端開發(fā)VIP免費(fèi)公開課】
查看更多關(guān)于“Java開發(fā)資訊”的相關(guān)文章>>
標(biāo)簽:
Java培訓(xùn)
Java視頻教程
Java多線程
Java面試題
Java學(xué)習(xí)視頻
Java開發(fā)