一、如何打印出JVM GC日志

需要在系統(tǒng)的JVM參數(shù)中加入GC日志的打印選型，jvm參數(shù)如下所示：

-XX:NewSize=5242880
-XX:MaxNewSize=5242880
-XX:InitialHeapSize=10485760
-XX:MaxHeapSize=10485760
-XX:SurvivorRatio=8
-XX:PretenureSizeThreshold=10485760
-XX:+UseParNewGC
-XX:+UseConcMarkSweepGC
-XX:+PrintGCDetails
-XX:+PrintGCTimeStamps
-Xloggc:gc.log

解析：

• -XX:InitialHeapSize : 初始堆大小
• -XX:MaxHeapSize : 最大堆大小
• -XX:NewSize : 初始新生代大小
• -XX:MaxNewSize : 最大新生代大小
• -XX:PretenureSizeThreshold=10485760 : 指定了大對(duì)象閾值是10MB。
• -XX:+PrintGCDetils：打印詳細(xì)的gc日志
• -XX:+PrintGCTimeStamps：這個(gè)參數(shù)可以打印出來(lái)每次GC發(fā)生的時(shí)間
• -Xloggc:gc.log：這個(gè)參數(shù)可以設(shè)置將gc日志寫(xiě)入一個(gè)磁盤(pán)文件

示例程序代碼

對(duì)象是如何分配在Eden區(qū)內(nèi)的
上面的這段代碼非常簡(jiǎn)單，先通過(guò)“new byte[1024 * 1024]”這樣的代碼連續(xù)分配了3個(gè)數(shù)組，每個(gè)數(shù)組都是1MB，然后通過(guò)array1這個(gè)局部變量依次引用這三個(gè)對(duì)象，最后還把a(bǔ)rray1這個(gè)局部變量指向了null，那么在JVM中上述代碼是如何運(yùn)行的呢？首先我們來(lái)看第一行代碼：byte[] array1 = new byte[1024 * 1024];。
這行代碼一旦運(yùn)行，就會(huì)在JVM的Eden區(qū)內(nèi)放入一個(gè)1MB的對(duì)象，同時(shí)在main線程的虛擬機(jī)棧中會(huì)壓入一個(gè)main()方法的棧幀，在main()方法的棧幀內(nèi)部，會(huì)有一個(gè)“array1”變量，這個(gè)變量是指向堆內(nèi)存Eden區(qū)的那個(gè)1MB的數(shù)組，如下圖。

接著我們看第二行代碼：array1 = new byte[1024 * 1024];
此時(shí)會(huì)在堆內(nèi)存的Eden區(qū)中創(chuàng)建第二個(gè)數(shù)組，并且讓局部變量指向第二個(gè)數(shù)組，然后第一個(gè)數(shù)組就沒(méi)人引用了，此時(shí)第一個(gè)數(shù)組就成了沒(méi)人引用的“垃圾對(duì)象”了，如下圖所示。

然后看第三行代碼：byte[] array1 = new byte[1024 * 1024];。
這行代碼在堆內(nèi)存的Eden區(qū)內(nèi)創(chuàng)建了第三個(gè)數(shù)組，同時(shí)讓array1變量指向了第三個(gè)數(shù)組，此時(shí)前面兩個(gè)數(shù)組都沒(méi)有人引用了，就都成了垃圾對(duì)象，如下圖所示。

接著我們來(lái)看第四行代碼：array1 = null;。
這行代碼一執(zhí)行，就讓array1這個(gè)變量什么都不指向了，此時(shí)會(huì)導(dǎo)致之前創(chuàng)建的3個(gè)數(shù)組全部變成垃圾對(duì)象，如下圖。

最后看第五行代碼：byte[] array2 = new byte[2 * 1024 * 1024];。
此時(shí)會(huì)分配一個(gè)2MB大小的數(shù)組，嘗試放入Eden區(qū)中，因?yàn)镋den區(qū)總共就4MB大小，而且里面已經(jīng)放入了3個(gè)1MB的數(shù)組了，所以剩余空間只有1MB了，此時(shí)你放一個(gè)2MB的數(shù)組是放不下的。所以這個(gè)時(shí)候就會(huì)觸發(fā)年輕代的Young GC。

• 獲得 gc.log 日志

打開(kāi)gc.log文件，我們會(huì)看到如下所示的gc日志：

Java HotSpot(TM) 64-Bit Server VM (25.151-b12) for windows-amd64 JRE (1.8.0_151-b12), built on Sep 5 2017 19:33:46 by "java_re" with MS VC++ 10.0 (VS2010) Memory: 4k page, physical 33450456k(25709200k free), swap 38431192k(29814656k free) CommandLine flags: -XX:InitialHeapSize=10485760 -XX:MaxHeapSize=10485760 -XX:MaxNewSize=5242880 -XX:NewSize=5242880 -XX:OldPLABSize=16 -XX:PretenureSizeThreshold=10485760 -XX:+PrintGC -XX:+PrintGCDetails -XX:+PrintGCTimeStamps -XX:SurvivorRatio=8 -XX:+UseCompressedClassPointers -XX:+UseCompressedOops -XX:+UseConcMarkSweepGC -XX:-UseLargePagesIndividualAllocation -XX:+UseParNewGC 0.268: [GC (Allocation Failure) 0.269: [ParNew: 4030K->512K(4608K), 0.0015734 secs] 4030K->574K(9728K), 0.0017518 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] Heap par new generation total 4608K, used 2601K [0x00000000ff600000, 0x00000000ffb00000, 0x00000000ffb00000) eden space 4096K, 51% used [0x00000000ff600000, 0x00000000ff80a558, 0x00000000ffa00000) from space 512K, 100% used [0x00000000ffa80000, 0x00000000ffb00000, 0x00000000ffb00000) to space 512K, 0% used [0x00000000ffa00000, 0x00000000ffa00000, 0x00000000ffa80000) concurrent mark-sweep generation total 5120K, used 62K [0x00000000ffb00000, 0x0000000100000000, 0x0000000100000000) Metaspace used 2782K, capacity 4486K, committed 4864K, reserved 1056768K class space used 300K, capacity 386K, committed 512K, reserved 1048576K

二、高級(jí)工程師的硬核技能：JVM的Young GC日志應(yīng)該怎么看

• 程序運(yùn)行采用的默認(rèn)JVM參數(shù)如何查看

在GC日志中，可以看到如下內(nèi)容：

CommandLine flags: -XX:InitialHeapSize=10485760 -XX:MaxHeapSize=10485760 -XX:MaxNewSize=5242880 .........

這就是告訴你這次運(yùn)行程序采取的JVM參數(shù)是什么，基本都是我們?cè)O(shè)置的，同時(shí)還有一些參數(shù)默認(rèn)就給設(shè)置了，不過(guò)一般關(guān)系不大。

• 一次GC的概要說(shuō)明

接著我們看GC日志中的如下一行：

0.268: [GC (Allocation Failure) 0.269: [ParNew: 4030K->512K(4608K), 0.0015734 secs] 4030K->574K(9728K), 0.0017518 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]解析： 0.268 :系統(tǒng)運(yùn)行以后過(guò)了多少秒發(fā)生了本次GC GC (Allocation Failure) :對(duì)象分配失敗，此時(shí)就要觸發(fā)一次Young GCParNew: 4030K->512K(4608K), 0.0015734 secs ParNew: 觸發(fā)的是年輕代的Young GC，所以是用我們指定的ParNew垃圾回收器執(zhí)行的 GC (4608K): 年輕代可用空間是4608KB，也就是4.5MB。Eden區(qū)是4MB，兩個(gè)Survivor中只有一個(gè)是可以放存活對(duì)象的，另外一個(gè)是必須一直保持空閑的，所以他考慮年輕代的可用空間，就是Eden+1個(gè)Survivor的大小，也就是4.5MB。4030K->512K: 意思就是對(duì)年輕代執(zhí)行了一次GC，GC之前都使用了4030KB了，但是GC之后只有512KB的對(duì)象是存活下來(lái) 0.0015734 secs: 這個(gè)就是本次gc耗費(fèi)的時(shí)間，看這里來(lái)說(shuō)大概耗費(fèi)了1.5ms，僅僅是回收3MB的對(duì)象而已。

• 圖解GC執(zhí)行過(guò)程
  第一個(gè)問(wèn)題，看這行日志，ParNew: 4030K->512K(4608K), 0.0015734 secs
  大家很奇怪，我們?cè)贕C之前，明明在Eden區(qū)里就放了3個(gè)1MB的數(shù)組，一共是3MB，也就是3072KB的對(duì)象，那么GC之前年輕代應(yīng)該是使用了3072KB的內(nèi)存啊，為啥是使用了4030KB的內(nèi)存呢？其實(shí)你創(chuàng)建的數(shù)組本身雖然是1MB，但是為了存儲(chǔ)這個(gè)數(shù)組，JVM內(nèi)置還會(huì)附帶一些其他信息，所以每個(gè)數(shù)組實(shí)際占用的內(nèi)存是大于1MB的；除了你自己創(chuàng)建的對(duì)象以外，可能還有一些你看不見(jiàn)的對(duì)象在Eden區(qū)里，至于這些看不見(jiàn)的未知對(duì)象是什么，后面我們有專(zhuān)門(mén)的工具可以分析堆內(nèi)存快照，以后會(huì)帶你看到這些對(duì)象是什么。所以如下圖所示，GC之前，三個(gè)數(shù)組和其他一些未知對(duì)象加起來(lái)，就是占據(jù)了4030KB的內(nèi)存。
  

接著你想要在Eden分配一個(gè)2MB的數(shù)組，此時(shí)肯定觸發(fā)了“Allocation Failure“，對(duì)象分配失敗，就觸發(fā)了Young GC，然后ParNew執(zhí)行垃圾回收，回收掉之前我們創(chuàng)建的三個(gè)數(shù)組，此時(shí)因?yàn)樗麄兌紱](méi)人引用了，一定是垃圾對(duì)象，如下圖所示。

然后我們繼續(xù)看gc日志，ParNew: 4030K->512K(4608K), 0.0015734 secs
gc回收之后，從4030KB內(nèi)存使用降低到了512KB的內(nèi)存使用，也就是說(shuō)這次gc日志有512KB的對(duì)象存活了下來(lái)，從Eden區(qū)轉(zhuǎn)移到了Survivor1區(qū)，其實(shí)我們可以把稱(chēng)呼改改，叫做Survivor From區(qū)，另外一個(gè)Survivor叫做Survivor To區(qū)，如下圖。

• GC過(guò)后的堆內(nèi)存使用情況

接著我們看下面的GC日志：

Heap par new generation total 4608K, used 2601K [0x00000000ff600000, 0x00000000ffb00000, 0x00000000ffb00000) eden space 4096K, 51% used [0x00000000ff600000, 0x00000000ff80a558, 0x00000000ffa00000) from space 512K, 100% used [0x00000000ffa80000, 0x00000000ffb00000, 0x00000000ffb00000) to space 512K, 0% used [0x00000000ffa00000, 0x00000000ffa00000, 0x00000000ffa80000) concurrent mark-sweep generation total 5120K, used 62K [0x00000000ffb00000, 0x0000000100000000, 0x0000000100000000) Metaspace used 2782K, capacity 4486K, committed 4864K, reserved 1056768K class space used 300K, capacity 386K, committed 512K, reserved 1048576K

這段日志是在JVM退出的時(shí)候打印出來(lái)的當(dāng)前堆內(nèi)存的使用情況，其實(shí)也很簡(jiǎn)單，一點(diǎn)點(diǎn)看一下，先看下面這段。

par new generation total 4608K, used 2601K，這就是說(shuō)“ParNew”垃圾回收器負(fù)責(zé)的年輕代總共有4608KB（4.5MB）可用內(nèi)存，目前是使用了2601KB（2.5MB）。

gc之后，我們這不是通過(guò)如下代碼又分配了一個(gè)2MB的數(shù)組嗎：byte[] array2 = new byte[2 * 1024 * 1024];所以此時(shí)在Eden區(qū)中一定會(huì)有一個(gè)2MB的數(shù)組，也就是2048KB，然后上次gc之后在From Survivor區(qū)中存活了一個(gè)512KB的對(duì)象，大家也不知道是啥，先不用管他。但是此時(shí)你疑惑了，2048KB + 512KB = 2560KB。那為什么說(shuō)年輕代使用了2601KB呢？因?yàn)橹罢f(shuō)過(guò)了每個(gè)數(shù)組他會(huì)額外占據(jù)一些內(nèi)存來(lái)存放一些自己這個(gè)對(duì)象的元數(shù)據(jù)，所以你可以認(rèn)為多出來(lái)的41KB可以是數(shù)組對(duì)象額外使用的內(nèi)存空間。如下圖所示。

接著我們繼續(xù)看GC日志：

eden space 4096K, 51% used [0x00000000ff600000, 0x00000000ff80a558, 0x00000000ffa00000) from space 512K, 100% used [0x00000000ffa80000, 0x00000000ffb00000, 0x00000000ffb00000) to space 512K, 0% used [0x00000000ffa00000, 0x00000000ffa00000, 0x00000000ffa80000)

通過(guò)GC日志就能驗(yàn)證我們的推測(cè)是完全準(zhǔn)確的，這里說(shuō)的很清晰了，Eden區(qū)此時(shí)4MB的內(nèi)存被使用了51%，就是因?yàn)橛幸粋€(gè)2MB的數(shù)組在里面。然后From Survivor區(qū)，512KB是100%的使用率，此時(shí)被之前gc后存活下來(lái)的512KB的未知對(duì)象給占據(jù)了。

• 接著看GC日志：

concurrent mark-sweep generation total 5120K, used 62K，這個(gè)很簡(jiǎn)單，就是說(shuō)Concurrent Mark-Sweep垃圾回收器，也就是CMS垃圾回收器，管理的老年代內(nèi)存空間一共是5MB，此時(shí)使用了62KB的空間，這個(gè)是啥你也先不用管了，可以先忽略不計(jì)，以后我們有內(nèi)存分析工具了，你都能看到。Metaspace used 2782K, capacity 4486K, committed 4864K, reserved 1056768K class space used 300K, capacity 386K, committed 512K, reserved 1048576K 上述兩段日志就是 Metaspace元數(shù)據(jù)空間 和 Class空間，存放一些類(lèi)信息、常量池之類(lèi)的東西，此時(shí)他們的總?cè)萘?#xff0c;使用內(nèi)存，等等。

三、動(dòng)手實(shí)驗(yàn)：自己動(dòng)手模擬出對(duì)象進(jìn)入老年代的場(chǎng)景體驗(yàn)一下（上）

• 動(dòng)態(tài)年齡判定規(guī)則
  之前我們給大家總結(jié)過(guò)對(duì)象進(jìn)入老年代的4個(gè)常見(jiàn)的時(shí)機(jī)：

• 躲過(guò)15次gc，達(dá)到15歲高齡之后進(jìn)入老年代；
• 動(dòng)態(tài)年齡判定規(guī)則，如果Survivor區(qū)域內(nèi)年齡1+年齡2+年齡3+年齡n的對(duì)象總和大于Survivor區(qū)的50%，此時(shí)年齡n以上的對(duì)象會(huì)進(jìn)入老年代，不一定要達(dá)到15歲
• 如果一次Young GC后存活對(duì)象太多無(wú)法放入Survivor區(qū)，此時(shí)直接計(jì)入老年代
• 大對(duì)象直接進(jìn)入老年代

首先我們先通過(guò)代碼給大家模擬出來(lái)最常見(jiàn)的一種進(jìn)入老年代的情況，如果Survivor區(qū)域內(nèi)年齡1+年齡2+年齡3+年齡n的對(duì)象總和大于Survivor區(qū)的50%，此時(shí)年齡n以上的對(duì)象會(huì)進(jìn)入老年代，也就是所謂的動(dòng)態(tài)年齡判定規(guī)則。
先來(lái)看看我們這次示例程序的JVM參數(shù)：

• XX:NewSize=10485760
• XX:MaxNewSize=10485760
• XX:InitialHeapSize=20971520
• XX:MaxHeapSize=20971520
• XX:SurvivorRatio=8
• XX:MaxTenuringThreshold=15
• XX:PretenureSizeThreshold=10485760
• XX:+UseParNewGC
• XX:+UseConcMarkSweepGC
• XX:+PrintGCDetails
• XX:+PrintGCTimeStamps
• Xloggc:gc.log

在這些參數(shù)里我們注意幾點(diǎn)，新生代我們通過(guò)“-XX:NewSize”設(shè)置為10MB了，然后其中Eden區(qū)是8MB，每個(gè)Survivor區(qū)是1MB，Java堆總大小是20MB，老年代是10MB，大對(duì)象必須超過(guò)10MB才會(huì)直接進(jìn)入老年代，但是我們通過(guò)“-XX:MaxTenuringThreshold=15”設(shè)置了，只要對(duì)象年齡達(dá)到15歲才會(huì)直接進(jìn)入老年代。一切準(zhǔn)備就緒，先看看我們當(dāng)前的內(nèi)存分配情況，如下圖，然后接下來(lái)我們開(kāi)始來(lái)看看我們的示例代碼。

動(dòng)態(tài)年齡判定規(guī)則的部分示例代碼

• 部分示例代碼運(yùn)行后產(chǎn)生的gc日志

接著我們把上述示例代碼以及我們給出的JVM參數(shù)配合起來(lái)運(yùn)行，此時(shí)會(huì)看到如下的GC日志，接著我們就開(kāi)始一步一步分析一下這部分代碼運(yùn)行后的gc日志。

0.297: [GC (Allocation Failure) 0.297: [ParNew: 7260K->715K(9216K), 0.0012641 secs] 7260K->715K(19456K), 0.0015046 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] Heap par new generation total 9216K, used 2845K [0x00000000fec00000, 0x00000000ff600000, 0x00000000ff600000) eden space 8192K, 26% used [0x00000000fec00000, 0x00000000fee14930, 0x00000000ff400000) from space 1024K, 69% used [0x00000000ff500000, 0x00000000ff5b2e10, 0x00000000ff600000) to space 1024K, 0% used [0x00000000ff400000, 0x00000000ff400000, 0x00000000ff500000) concurrent mark-sweep generation total 10240K, used 0K [0x00000000ff600000, 0x0000000100000000, 0x0000000100000000) Metaspace used 2782K, capacity 4486K, committed 4864K, reserved 1056768K class space used 300K, capacity 386K, committed 512K, reserved 1048576K

• 部分代碼的GC日志分析

首先我們先看下述幾行代碼：

在這里連續(xù)創(chuàng)建了3個(gè)2MB的數(shù)組，最后還把局部變量array1設(shè)置為了null，所以此時(shí)的內(nèi)存如下圖所示：

接著執(zhí)行了這行代碼：byte[] array2 = new byte[128 * 1024];。此時(shí)會(huì)在Eden區(qū)創(chuàng)建一個(gè)128KB的數(shù)組同時(shí)由array2變量來(lái)引用，如下圖。

然后會(huì)執(zhí)行下面的代碼：byte[] array3 = new byte[2 * 1024 * 1024];此時(shí)Eden區(qū)里已經(jīng)有3個(gè)2MB的數(shù)組和1個(gè)128KB的數(shù)組，大小都超過(guò)6MB了，Eden總共才8MB，此時(shí)是不可能讓你創(chuàng)建2MB的數(shù)組的。因此此時(shí)一定會(huì)觸發(fā)一次Young GC，接著我們開(kāi)始看GC日志。

ParNew: 7260K->715K(9216K), 0.0012641 secs

這行日志清晰表明了，在GC之前年輕代占用了7260KB的內(nèi)存，這里大概就是6MB的3個(gè)數(shù)組 + 128KB的1個(gè)數(shù)組 + 幾百KB的一些未知對(duì)象
如下圖所示：

接著看這里，7260K->715K(9216K)，一次Young GC過(guò)后，剩余的存活對(duì)象大概是715KB，大家還記得我們上面分析的GC日志嗎？之前就說(shuō)過(guò)大概年輕代剛開(kāi)始會(huì)有512KB左右的未知對(duì)象，此時(shí)再加上我們自己的128KB的數(shù)組，大家想想，是不是差不多就是700KB？

接著看GC日志如下：

par new generation total 9216K, used 2845K [0x00000000fec00000, 0x00000000ff600000, 0x00000000ff600000) eden space 8192K, 26% used [0x00000000fec00000, 0x00000000fee14930, 0x00000000ff400000) from space 1024K, 69% used [0x00000000ff500000, 0x00000000ff5b2e10, 0x00000000ff600000) to space 1024K, 0% used [0x00000000ff400000, 0x00000000ff400000, 0x00000000ff500000) concurrent mark-sweep generation total 10240K, used 0K [0x00000000ff600000, 0x0000000100000000, 0x0000000100000000)

從上面的日志可以清晰看出，此時(shí)From Survivor區(qū)域被占據(jù)了69%的內(nèi)存，大概就是700KB左右，這就是一次Young GC后存活下來(lái)的對(duì)象，他們都進(jìn)入From Survivor區(qū)了。同時(shí)Eden區(qū)域內(nèi)被占據(jù)了26%的空間，大概就是2MB左右，這就是byte[] array3 = new byte[2 * 1024 * 1024]，這行代碼在gc過(guò)后分配在Eden區(qū)域內(nèi)的數(shù)組
如下圖所示：

現(xiàn)在Survivor From區(qū)里的那700kb的對(duì)象，是幾歲呢？答案是：1歲他熬過(guò)一次gc，年齡就會(huì)增長(zhǎng)1歲。而且此時(shí)Survivor區(qū)域總大小是1MB，此時(shí)Survivor區(qū)域中的存活對(duì)象已經(jīng)有700KB了，絕對(duì)超過(guò)了50%。

• 完善示例代碼

接著我們把示例代碼給完善一下，變成上述的樣子，我們要觸發(fā)出來(lái)第二次Young GC，然后看看Survivor區(qū)域內(nèi)的動(dòng)態(tài)年齡判定規(guī)則能否生效。
先看下面幾行代碼:

這幾行代碼運(yùn)行過(guò)后，實(shí)際上會(huì)接著分配2個(gè)2MB的數(shù)組，然后再分配一個(gè)128KB的數(shù)組，最后是讓array3變量指向null，如下圖所示。

此時(shí)接著會(huì)運(yùn)行下面的代碼：byte[] array4 = new byte[2 * 1024 * 1024]，這個(gè)時(shí)候，大家會(huì)發(fā)現(xiàn)，Eden區(qū)如果要再次放一個(gè)2MB數(shù)組下去，是放不下的了，所以此時(shí)必然會(huì)觸發(fā)一次Young GC。大家使用上述的JVM參數(shù)運(yùn)行這段程序會(huì)看到如下的GC日志：

0.269: [GC (Allocation Failure) 0.269: [ParNew: 7260K->713K(9216K), 0.0013103 secs] 7260K->713K(19456K), 0.0015501 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 0.271: [GC (Allocation Failure) 0.271: [ParNew: 7017K->0K(9216K), 0.0036521 secs] 7017K->700K(19456K), 0.0037342 secs] [Times: user=0.06 sys=0.00, real=0.00 secs] Heap par new generation total 9216K, used 2212K [0x00000000fec00000, 0x00000000ff600000, 0x00000000ff600000) eden space 8192K, 27% used [0x00000000fec00000, 0x00000000fee290e0, 0x00000000ff400000) from space 1024K, 0% used [0x00000000ff400000, 0x00000000ff400000, 0x00000000ff500000) to space 1024K, 0% used [0x00000000ff500000, 0x00000000ff500000, 0x00000000ff600000) concurrent mark-sweep generation total 10240K, used 700K [0x00000000ff600000, 0x0000000100000000, 0x0000000100000000) Metaspace used 2782K, capacity 4486K, committed 4864K, reserved 1056768K class space used 300K, capacity 386K, committed 512K, reserved 1048576K

• 分析最終版的GC日志
  首先第一次GC的日志如下：

0.269: [GC (Allocation Failure) 0.269: [ParNew: 7260K->713K(9216K), 0.0013103 secs] 7260K->713K(19456K), 0.0015501 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]

接著第二次GC的日志如下：

0.271: [GC (Allocation Failure) 0.271: [ParNew: 7017K->0K(9216K), 0.0036521 secs] 7017K->700K(19456K), 0.0037342 secs] [Times: user=0.06 sys=0.00, real=0.00 secs]

第二次觸發(fā)Yuong GC，就是我們上述代碼執(zhí)行的時(shí)候，此時(shí)大家發(fā)現(xiàn)

ParNew: 7017K->0K(9216K)

這行日志表明，這次GC過(guò)后，年輕代直接就沒(méi)有對(duì)象了，也就是說(shuō)沒(méi)有任何存活對(duì)象，你覺(jué)得可能嗎？要是這么簡(jiǎn)單的想，絕對(duì)是侮辱自己的智商了，大家還記得array2這個(gè)變量一直引用著一個(gè)128KB的數(shù)組，他絕對(duì)是存活對(duì)象，還有那500多KB的未知對(duì)象，此時(shí)都去哪里了呢？首先我們先看看上面的圖，在Eden區(qū)里有3個(gè)2MB的數(shù)組和1個(gè)128KB的數(shù)組，這絕對(duì)是會(huì)被回收掉的，如下圖所示。

接著其實(shí)此時(shí)會(huì)發(fā)現(xiàn)Survivor區(qū)域中的對(duì)象都是存活的，而且總大小超過(guò)50%了，而且年齡都是1歲。此時(shí)根據(jù)動(dòng)態(tài)年齡判定規(guī)則：年齡1+年齡2+年齡n的對(duì)象總大小超過(guò)了Survivor區(qū)域的50%，年齡n以上的對(duì)象進(jìn)入老年代。當(dāng)然這里的對(duì)象都是年齡1的，所以直接全部進(jìn)入老年代了，如下圖。

大家看下面的日志可以確認(rèn)這一點(diǎn)：

concurrent mark-sweep generation total 10240K, used 700K [0x00000000ff600000, 0x0000000100000000, 0x0000000100000000)

CMS管理的老年代，此時(shí)使用空間剛好是700KB，證明此時(shí)Survivor里的對(duì)象觸發(fā)了動(dòng)態(tài)年齡判定規(guī)則，雖然沒(méi)有達(dá)到15歲，但是全部進(jìn)入老年代了。包括我們自己的那個(gè)array2變量一直引用的128KB的數(shù)組。然后array4變量引用的那個(gè)2MB的數(shù)組，此時(shí)就會(huì)分配到Eden區(qū)域中，如下圖所示。

此時(shí)大家看下面的日志：

eden space 8192K, 27% used [0x00000000fec00000, 0x00000000fee290e0, 0x00000000ff400000)

這里就說(shuō)明Eden區(qū)當(dāng)前就是有一個(gè)2MB的數(shù)組。
然后再看下面的日志：

from space 1024K, 0% used [0x00000000ff400000, 0x00000000ff400000, 0x00000000ff500000) to space 1024K, 0% used [0x00000000ff500000, 0x00000000ff500000, 0x00000000ff600000)

兩個(gè)Survivor區(qū)域都是空的，因?yàn)橹按婊畹?00KB的對(duì)象都進(jìn)入老年代了，所以當(dāng)然現(xiàn)在Survivor里都是空的了。
如果你每次Young GC過(guò)后存活的對(duì)象太多進(jìn)入Survivor，特別是超過(guò)了Survivor 50%的空間，很可能下次Young GC的時(shí)候就會(huì)讓一些對(duì)象觸發(fā)動(dòng)態(tài)年齡判定規(guī)則進(jìn)入老年代中。

• 動(dòng)手實(shí)驗(yàn)：自己動(dòng)手模擬出對(duì)象進(jìn)入老年代的場(chǎng)景體驗(yàn)一下（下）
  示例代碼
  先來(lái)看看下面的示例代碼：

• GC日志

然后我們使用之前的JVM參數(shù)來(lái)跑一下上面的程序，可以看到下面的GC日志：

0.421: [GC (Allocation Failure) 0.421: [ParNew: 7260K->573K(9216K), 0.0024098 secs] 7260K->2623K(19456K), 0.0026802 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] Heap par new generation total 9216K, used 2703K [0x00000000fec00000, 0x00000000ff600000, 0x00000000ff600000) eden space 8192K, 26% used [0x00000000fec00000, 0x00000000fee14930, 0x00000000ff400000) from space 1024K, 55% used [0x00000000ff500000, 0x00000000ff58f570, 0x00000000ff600000) to space 1024K, 0% used [0x00000000ff400000, 0x00000000ff400000, 0x00000000ff500000) concurrent mark-sweep generation total 10240K, used 2050K [0x00000000ff600000, 0x0000000100000000, 0x0000000100000000) Metaspace used 2782K, capacity 4486K, committed 4864K, reserved 1056768K class space used 300K, capacity 386K, committed 512K, reserved 1048576K

一步一圖來(lái)分析GC日志
接著我們一點(diǎn)點(diǎn)來(lái)分析一下，首先看如下幾行代碼：

上面的代碼中，首先分配了3個(gè)2MB的數(shù)組，然后最后讓array1變量指向了第三個(gè)2MB數(shù)組接著創(chuàng)建了一個(gè)128K的數(shù)組，但是確讓array2指向了null，同時(shí)我們一直都知道，Eden區(qū)里會(huì)有500KB左右的未知對(duì)象

此時(shí)如下圖所示：

接著會(huì)執(zhí)行如下代碼：byte[] array3 = new byte[2 * 1024 * 1024];。此時(shí)想要在Eden區(qū)里再創(chuàng)建一個(gè)2MB的數(shù)組，肯定是不行的，所以此時(shí)必然觸發(fā)一次Young GC。
先看如下日志：

ParNew: 7260K->573K(9216K), 0.0024098 secs。

這里清晰說(shuō)明了，本次GC過(guò)后，年輕代里就剩下了500多KB的對(duì)象，這是為什么呢？此時(shí)明明array1變量是引用了一個(gè)2MB的數(shù)組的啊！其實(shí)道理很簡(jiǎn)單，大家可以想一下，這次GC的時(shí)候，會(huì)回收掉上圖中的2個(gè)2MB的數(shù)組和1個(gè)128KB的數(shù)組，然后留下一個(gè)2MB的數(shù)組和1個(gè)未知的500KB的對(duì)象,如下圖所示。

那么此時(shí)剩下來(lái)的2MB的數(shù)組和500KB的未知對(duì)象能放入From Survivor區(qū)嗎？答案是：不能
因?yàn)镾urvivor區(qū)僅僅只有1MB。根據(jù)我們之前說(shuō)過(guò)的規(guī)則，此時(shí)是不是要把這些存活對(duì)象全部放入老年代？答案：也不是
大家看如下日志：

eden space 8192K, 26% used [0x00000000fec00000, 0x00000000fee14930, 0x00000000ff400000)

首先Eden區(qū)內(nèi)一定放入了一個(gè)新的2MB的數(shù)組，就是剛才最后想要分配的那個(gè)數(shù)組，由array3變量引用，如下圖。

其次，看下面的日志：

from space 1024K, 55% used [0x00000000ff500000, 0x00000000ff58f570, 0x00000000ff600000)

大家發(fā)現(xiàn)此時(shí)From Survivor區(qū)中有500KB的對(duì)象，其實(shí)就是那500KB的未知對(duì)象！
所以在這里并不是讓2MB的數(shù)組和500KB的未知對(duì)象都進(jìn)入老年代，而是把500KB的未知對(duì)象放入From Survivor區(qū)中！但是現(xiàn)在結(jié)合GC日志，大家可以清晰的看到，在這種情況下，是會(huì)把部分對(duì)象放入Survivor區(qū)的。
此時(shí)如下圖所示。

接著我們看如下日志：

concurrent mark-sweep generation total 10240K, used 2050K [0x00000000ff600000, 0x0000000100000000, 0x0000000100000000)

此時(shí)老年代里確有2MB的數(shù)組，因此可以認(rèn)為，Young GC過(guò)后，發(fā)現(xiàn)存活下來(lái)的對(duì)象有2MB的數(shù)組和500KB的未知對(duì)象。此時(shí)把500KB的未知對(duì)象放入Survivor中，然后2MB的數(shù)組直接放入老年代，如下圖。

四、高級(jí)工程師的硬核技能：JVM的Full GC日志應(yīng)該怎么看？

示例代碼

• GC日志
  采用如下參數(shù)來(lái)運(yùn)行上述程序：

"-XX:NewSize=10485760 -XX:MaxNewSize=10485760 -XX:InitialHeapSize=20971520 -XX:MaxHeapSize=20971520 -XX:SurvivorRatio=8 -XX:MaxTenuringThreshold=15 -XX:PretenureSizeThreshold=3145728 -XX:+UseParNewGC -XX:+UseConcMarkSweepGC -XX:+PrintGCDetails -XX:+PrintGCTimeStamps -Xloggc:gc.log"

• 這里最關(guān)鍵一個(gè)參數(shù)，就是“-XX:PretenureSizeThreshold=3145728”

這個(gè)參數(shù)要設(shè)置大對(duì)象閾值為3MB，也就是超過(guò)3MB，就直接進(jìn)入老年代。

運(yùn)行之后會(huì)得到如下GC日志：

“0.308: [GC (Allocation Failure) 0.308: [ParNew (promotion failed): 7260K->7970K(9216K), 0.0048975 secs]0.314: [CMS: 8194K->6836K(10240K), 0.0049920 secs] 11356K->6836K(19456K), [Metaspace: 2776K->2776K(1056768K)], 0.0106074 secs] [Times: user=0.00 sys=0.00, real=0.01 secs] Heap par new generation total 9216K, used 2130K [0x00000000fec00000, 0x00000000ff600000, 0x00000000ff600000) eden space 8192K, 26% used [0x00000000fec00000, 0x00000000fee14930, 0x00000000ff400000) from space 1024K, 0% used [0x00000000ff500000, 0x00000000ff500000, 0x00000000ff600000) to space 1024K, 0% used [0x00000000ff400000, 0x00000000ff400000, 0x00000000ff500000) concurrent mark-sweep generation total 10240K, used 6836K [0x00000000ff600000, 0x0000000100000000, 0x0000000100000000) Metaspace used 2782K, capacity 4486K, committed 4864K, reserved 1056768K class space used 300K, capacity 386K, committed 512K, reserved 1048576K”

• 一步一圖分析日志

首先我們看如下代碼：

這行代碼直接分配了一個(gè)4MB的大對(duì)象，此時(shí)這個(gè)對(duì)象會(huì)直接進(jìn)入老年代，接著array1不再引用這個(gè)對(duì)象
此時(shí)如下圖所示。

接著看下面的代碼：

連續(xù)分配了4個(gè)數(shù)組，其中3個(gè)是2MB的數(shù)組，1個(gè)是128KB的數(shù)組，如下圖所示，全部會(huì)進(jìn)入Eden區(qū)域中

接著會(huì)執(zhí)行如下代碼：byte[] array6 = new byte[2 * 1024 * 1024];。此時(shí)還能放得下2MB的對(duì)象嗎？不可能了，因?yàn)镋den區(qū)已經(jīng)放不下了。因此此時(shí)會(huì)直接觸發(fā)一次Young GC。
我們看下面的GC日志：

ParNew (promotion failed): 7260K->7970K(9216K), 0.0048975 secs

這行日志顯示了，Eden區(qū)原來(lái)是有7000多KB的對(duì)象，但是回收之后發(fā)現(xiàn)一個(gè)都回收不掉，因?yàn)樯鲜鰩讉€(gè)數(shù)組都被變量引用了。
所以此時(shí)大家都知道，一定會(huì)直接把這些對(duì)象放入到老年代里去，但是此時(shí)老年代里已經(jīng)有一個(gè)4MB的數(shù)組了，還能放的下3個(gè)2MB的數(shù)組和1個(gè)128KB的數(shù)組嗎？
明顯是不行的，此時(shí)一定會(huì)超過(guò)老年代的10MB大小。
所以此時(shí)我們看gc日志：

[CMS: 8194K->6836K(10240K), 0.0049920 secs] 11356K->6836K(19456K), [Metaspace: 2776K->2776K(1056768K)], 0.0106074 secs]

大家可以清晰看到，此時(shí)執(zhí)行了CMS垃圾回收器的Full GC，我們之前講過(guò)Full GC其實(shí)就是會(huì)對(duì)老年代進(jìn)行Old GC，同時(shí)一般會(huì)跟一次Young GC關(guān)聯(lián)，還會(huì)觸發(fā)一次元數(shù)據(jù)區(qū)（永久代）的GC。在CMS Full GC之前，就已經(jīng)觸發(fā)過(guò)Young GC了，此時(shí)大家可以看到此時(shí)Young GC就已經(jīng)有了，接著就是執(zhí)行針對(duì)老年代的Old GC，也就是如下日志：

CMS: 8194K->6836K(10240K), 0.0049920 secs

這里看到老年代從8MB左右的對(duì)象占用，變成了6MB左右的對(duì)象占用，這是怎么個(gè)過(guò)程呢？
很簡(jiǎn)單，一定是在Young GC之后，先把2個(gè)2MB的數(shù)組放入了老年代，如下圖。

此時(shí)要繼續(xù)放1個(gè)2MB的數(shù)組和1個(gè)128KB的數(shù)組到老年代，一定會(huì)放不下，所以此時(shí)就會(huì)觸發(fā)CMS的Full GC然后此時(shí)就會(huì)回收掉其中的一個(gè)4MB的數(shù)組，因?yàn)樗呀?jīng)沒(méi)人引用了，如下圖所示。

接著放入進(jìn)去1個(gè)2MB的數(shù)組和1個(gè)128KB的數(shù)組，如下圖所示。

所以大家再看CMS的垃圾回收日志：

CMS: 8194K->6836K(10240K), 0.0049920 secs

他是從回收前的8MB變成了6MB，就是上圖所示。最后在CMS Full GC執(zhí)行完畢之后，其實(shí)年輕代的對(duì)象都進(jìn)入了老年代，此時(shí)最后一行代碼要在年輕代分配2MB的數(shù)組就可以成功了，如下圖。

文章轉(zhuǎn)自

總結(jié)

以上是生活随笔為你收集整理的JVM查看GC日志的全部?jī)?nèi)容，希望文章能夠幫你解決所遇到的問(wèn)題。

如果覺(jué)得生活随笔網(wǎng)站內(nèi)容還不錯(cuò)，歡迎將生活随笔推薦給好友。