當前位置：首頁 > 编程资源 > 编程问答 >内容正文

编程问答

JVM查看GC日志

發布時間：2025/3/15 编程问答 20 豆豆

生活随笔收集整理的這篇文章主要介紹了 JVM查看GC日志小編覺得挺不錯的,現在分享給大家,幫大家做個參考.

一、如何打印出JVM GC日志

需要在系統的JVM參數中加入GC日志的打印選型，jvm參數如下所示：

-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 : 指定了大對象閾值是10MB。
-XX:+PrintGCDetils：打印詳細的gc日志
-XX:+PrintGCTimeStamps：這個參數可以打印出來每次GC發生的時間
-Xloggc:gc.log：這個參數可以設置將gc日志寫入一個磁盤文件

示例程序代碼

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

接著我們看第二行代碼：array1 = new byte[1024 * 1024];
此時會在堆內存的Eden區中創建第二個數組，并且讓局部變量指向第二個數組，然后第一個數組就沒人引用了，此時第一個數組就成了沒人引用的“垃圾對象”了，如下圖所示。

然后看第三行代碼：byte[] array1 = new byte[1024 * 1024];。
這行代碼在堆內存的Eden區內創建了第三個數組，同時讓array1變量指向了第三個數組，此時前面兩個數組都沒有人引用了，就都成了垃圾對象，如下圖所示。

接著我們來看第四行代碼：array1 = null;。
這行代碼一執行，就讓array1這個變量什么都不指向了，此時會導致之前創建的3個數組全部變成垃圾對象，如下圖。

最后看第五行代碼：byte[] array2 = new byte[2 * 1024 * 1024];。
此時會分配一個2MB大小的數組，嘗試放入Eden區中，因為Eden區總共就4MB大小，而且里面已經放入了3個1MB的數組了，所以剩余空間只有1MB了，此時你放一個2MB的數組是放不下的。所以這個時候就會觸發年輕代的Young GC。

獲得 gc.log 日志

打開gc.log文件，我們會看到如下所示的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

二、高級工程師的硬核技能：JVM的Young GC日志應該怎么看

程序運行采用的默認JVM參數如何查看

在GC日志中，可以看到如下內容：

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

這就是告訴你這次運行程序采取的JVM參數是什么，基本都是我們設置的，同時還有一些參數默認就給設置了，不過一般關系不大。

一次GC的概要說明

接著我們看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 :系統運行以后過了多少秒發生了本次GC GC (Allocation Failure) :對象分配失敗，此時就要觸發一次Young GCParNew: 4030K->512K(4608K), 0.0015734 secs ParNew: 觸發的是年輕代的Young GC，所以是用我們指定的ParNew垃圾回收器執行的 GC (4608K): 年輕代可用空間是4608KB，也就是4.5MB。Eden區是4MB，兩個Survivor中只有一個是可以放存活對象的，另外一個是必須一直保持空閑的，所以他考慮年輕代的可用空間，就是Eden+1個Survivor的大小，也就是4.5MB。4030K->512K: 意思就是對年輕代執行了一次GC，GC之前都使用了4030KB了，但是GC之后只有512KB的對象是存活下來 0.0015734 secs: 這個就是本次gc耗費的時間，看這里來說大概耗費了1.5ms，僅僅是回收3MB的對象而已。

圖解GC執行過程
第一個問題，看這行日志，ParNew: 4030K->512K(4608K), 0.0015734 secs
大家很奇怪，我們在GC之前，明明在Eden區里就放了3個1MB的數組，一共是3MB，也就是3072KB的對象，那么GC之前年輕代應該是使用了3072KB的內存啊，為啥是使用了4030KB的內存呢？其實你創建的數組本身雖然是1MB，但是為了存儲這個數組，JVM內置還會附帶一些其他信息，所以每個數組實際占用的內存是大于1MB的；除了你自己創建的對象以外，可能還有一些你看不見的對象在Eden區里，至于這些看不見的未知對象是什么，后面我們有專門的工具可以分析堆內存快照，以后會帶你看到這些對象是什么。所以如下圖所示，GC之前，三個數組和其他一些未知對象加起來，就是占據了4030KB的內存。

接著你想要在Eden分配一個2MB的數組，此時肯定觸發了“Allocation Failure“，對象分配失敗，就觸發了Young GC，然后ParNew執行垃圾回收，回收掉之前我們創建的三個數組，此時因為他們都沒人引用了，一定是垃圾對象，如下圖所示。

然后我們繼續看gc日志，ParNew: 4030K->512K(4608K), 0.0015734 secs
gc回收之后，從4030KB內存使用降低到了512KB的內存使用，也就是說這次gc日志有512KB的對象存活了下來，從Eden區轉移到了Survivor1區，其實我們可以把稱呼改改，叫做Survivor From區，另外一個Survivor叫做Survivor To區，如下圖。

GC過后的堆內存使用情況

接著我們看下面的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退出的時候打印出來的當前堆內存的使用情況，其實也很簡單，一點點看一下，先看下面這段。

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

gc之后，我們這不是通過如下代碼又分配了一個2MB的數組嗎：byte[] array2 = new byte[2 * 1024 * 1024];所以此時在Eden區中一定會有一個2MB的數組，也就是2048KB，然后上次gc之后在From Survivor區中存活了一個512KB的對象，大家也不知道是啥，先不用管他。但是此時你疑惑了，2048KB + 512KB = 2560KB。那為什么說年輕代使用了2601KB呢？因為之前說過了每個數組他會額外占據一些內存來存放一些自己這個對象的元數據，所以你可以認為多出來的41KB可以是數組對象額外使用的內存空間。如下圖所示。

接著我們繼續看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)

通過GC日志就能驗證我們的推測是完全準確的，這里說的很清晰了，Eden區此時4MB的內存被使用了51%，就是因為有一個2MB的數組在里面。然后From Survivor區，512KB是100%的使用率，此時被之前gc后存活下來的512KB的未知對象給占據了。

接著看GC日志：

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

三、動手實驗：自己動手模擬出對象進入老年代的場景體驗一下（上）

動態年齡判定規則
之前我們給大家總結過對象進入老年代的4個常見的時機：

躲過15次gc，達到15歲高齡之后進入老年代；
動態年齡判定規則，如果Survivor區域內年齡1+年齡2+年齡3+年齡n的對象總和大于Survivor區的50%，此時年齡n以上的對象會進入老年代，不一定要達到15歲
如果一次Young GC后存活對象太多無法放入Survivor區，此時直接計入老年代
大對象直接進入老年代

首先我們先通過代碼給大家模擬出來最常見的一種進入老年代的情況，如果Survivor區域內年齡1+年齡2+年齡3+年齡n的對象總和大于Survivor區的50%，此時年齡n以上的對象會進入老年代，也就是所謂的動態年齡判定規則。
先來看看我們這次示例程序的JVM參數：

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

在這些參數里我們注意幾點，新生代我們通過“-XX:NewSize”設置為10MB了，然后其中Eden區是8MB，每個Survivor區是1MB，Java堆總大小是20MB，老年代是10MB，大對象必須超過10MB才會直接進入老年代，但是我們通過“-XX:MaxTenuringThreshold=15”設置了，只要對象年齡達到15歲才會直接進入老年代。一切準備就緒，先看看我們當前的內存分配情況，如下圖，然后接下來我們開始來看看我們的示例代碼。

動態年齡判定規則的部分示例代碼

部分示例代碼運行后產生的gc日志

接著我們把上述示例代碼以及我們給出的JVM參數配合起來運行，此時會看到如下的GC日志，接著我們就開始一步一步分析一下這部分代碼運行后的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日志分析

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

在這里連續創建了3個2MB的數組，最后還把局部變量array1設置為了null，所以此時的內存如下圖所示：

接著執行了這行代碼：byte[] array2 = new byte[128 * 1024];。此時會在Eden區創建一個128KB的數組同時由array2變量來引用，如下圖。

然后會執行下面的代碼：byte[] array3 = new byte[2 * 1024 * 1024];此時Eden區里已經有3個2MB的數組和1個128KB的數組，大小都超過6MB了，Eden總共才8MB，此時是不可能讓你創建2MB的數組的。因此此時一定會觸發一次Young GC，接著我們開始看GC日志。

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

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

接著看這里，7260K->715K(9216K)，一次Young GC過后，剩余的存活對象大概是715KB，大家還記得我們上面分析的GC日志嗎？之前就說過大概年輕代剛開始會有512KB左右的未知對象，此時再加上我們自己的128KB的數組，大家想想，是不是差不多就是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)

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

現在Survivor From區里的那700kb的對象，是幾歲呢？答案是：1歲他熬過一次gc，年齡就會增長1歲。而且此時Survivor區域總大小是1MB，此時Survivor區域中的存活對象已經有700KB了，絕對超過了50%。

完善示例代碼

接著我們把示例代碼給完善一下，變成上述的樣子，我們要觸發出來第二次Young GC，然后看看Survivor區域內的動態年齡判定規則能否生效。
先看下面幾行代碼:

這幾行代碼運行過后，實際上會接著分配2個2MB的數組，然后再分配一個128KB的數組，最后是讓array3變量指向null，如下圖所示。

此時接著會運行下面的代碼：byte[] array4 = new byte[2 * 1024 * 1024]，這個時候，大家會發現，Eden區如果要再次放一個2MB數組下去，是放不下的了，所以此時必然會觸發一次Young GC。大家使用上述的JVM參數運行這段程序會看到如下的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]

第二次觸發Yuong GC，就是我們上述代碼執行的時候，此時大家發現

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

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

接著其實此時會發現Survivor區域中的對象都是存活的，而且總大小超過50%了，而且年齡都是1歲。此時根據動態年齡判定規則：年齡1+年齡2+年齡n的對象總大小超過了Survivor區域的50%，年齡n以上的對象進入老年代。當然這里的對象都是年齡1的，所以直接全部進入老年代了，如下圖。

大家看下面的日志可以確認這一點：

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

CMS管理的老年代，此時使用空間剛好是700KB，證明此時Survivor里的對象觸發了動態年齡判定規則，雖然沒有達到15歲，但是全部進入老年代了。包括我們自己的那個array2變量一直引用的128KB的數組。然后array4變量引用的那個2MB的數組，此時就會分配到Eden區域中，如下圖所示。

此時大家看下面的日志：

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

這里就說明Eden區當前就是有一個2MB的數組。
然后再看下面的日志：

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

兩個Survivor區域都是空的，因為之前存活的700KB的對象都進入老年代了，所以當然現在Survivor里都是空的了。
如果你每次Young GC過后存活的對象太多進入Survivor，特別是超過了Survivor 50%的空間，很可能下次Young GC的時候就會讓一些對象觸發動態年齡判定規則進入老年代中。

動手實驗：自己動手模擬出對象進入老年代的場景體驗一下（下）
示例代碼
先來看看下面的示例代碼：

GC日志

然后我們使用之前的JVM參數來跑一下上面的程序，可以看到下面的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

一步一圖來分析GC日志
接著我們一點點來分析一下，首先看如下幾行代碼：

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

此時如下圖所示：

接著會執行如下代碼：byte[] array3 = new byte[2 * 1024 * 1024];。此時想要在Eden區里再創建一個2MB的數組，肯定是不行的，所以此時必然觸發一次Young GC。
先看如下日志：

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

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

那么此時剩下來的2MB的數組和500KB的未知對象能放入From Survivor區嗎？答案是：不能
因為Survivor區僅僅只有1MB。根據我們之前說過的規則，此時是不是要把這些存活對象全部放入老年代？答案：也不是
大家看如下日志：

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

首先Eden區內一定放入了一個新的2MB的數組，就是剛才最后想要分配的那個數組，由array3變量引用，如下圖。

其次，看下面的日志：

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

大家發現此時From Survivor區中有500KB的對象，其實就是那500KB的未知對象！
所以在這里并不是讓2MB的數組和500KB的未知對象都進入老年代，而是把500KB的未知對象放入From Survivor區中！但是現在結合GC日志，大家可以清晰的看到，在這種情況下，是會把部分對象放入Survivor區的。
此時如下圖所示。

接著我們看如下日志：

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

此時老年代里確有2MB的數組，因此可以認為，Young GC過后，發現存活下來的對象有2MB的數組和500KB的未知對象。此時把500KB的未知對象放入Survivor中，然后2MB的數組直接放入老年代，如下圖。

四、高級工程師的硬核技能：JVM的Full GC日志應該怎么看？

示例代碼

GC日志
采用如下參數來運行上述程序：

"-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"

這里最關鍵一個參數，就是“-XX:PretenureSizeThreshold=3145728”

這個參數要設置大對象閾值為3MB，也就是超過3MB，就直接進入老年代。

運行之后會得到如下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”

一步一圖分析日志

首先我們看如下代碼：

這行代碼直接分配了一個4MB的大對象，此時這個對象會直接進入老年代，接著array1不再引用這個對象
此時如下圖所示。

接著看下面的代碼：

連續分配了4個數組，其中3個是2MB的數組，1個是128KB的數組，如下圖所示，全部會進入Eden區域中

接著會執行如下代碼：byte[] array6 = new byte[2 * 1024 * 1024];。此時還能放得下2MB的對象嗎？不可能了，因為Eden區已經放不下了。因此此時會直接觸發一次Young GC。
我們看下面的GC日志：

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

這行日志顯示了，Eden區原來是有7000多KB的對象，但是回收之后發現一個都回收不掉，因為上述幾個數組都被變量引用了。
所以此時大家都知道，一定會直接把這些對象放入到老年代里去，但是此時老年代里已經有一個4MB的數組了，還能放的下3個2MB的數組和1個128KB的數組嗎？
明顯是不行的，此時一定會超過老年代的10MB大小。
所以此時我們看gc日志：

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

大家可以清晰看到，此時執行了CMS垃圾回收器的Full GC，我們之前講過Full GC其實就是會對老年代進行Old GC，同時一般會跟一次Young GC關聯，還會觸發一次元數據區（永久代）的GC。在CMS Full GC之前，就已經觸發過Young GC了，此時大家可以看到此時Young GC就已經有了，接著就是執行針對老年代的Old GC，也就是如下日志：

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

這里看到老年代從8MB左右的對象占用，變成了6MB左右的對象占用，這是怎么個過程呢？
很簡單，一定是在Young GC之后，先把2個2MB的數組放入了老年代，如下圖。

此時要繼續放1個2MB的數組和1個128KB的數組到老年代，一定會放不下，所以此時就會觸發CMS的Full GC然后此時就會回收掉其中的一個4MB的數組，因為他已經沒人引用了，如下圖所示。

接著放入進去1個2MB的數組和1個128KB的數組，如下圖所示。

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

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

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

文章轉自

總結

以上是生活随笔為你收集整理的JVM查看GC日志的全部內容，希望文章能夠幫你解決所遇到的問題。

如果覺得生活随笔網站內容還不錯，歡迎將生活随笔推薦給好友。

上一篇： 2021奢侈品营销启示录
下一篇： 2021快手奢侈品行业数据价值报告