三分鐘帶你看懂 GC 日志!
01、背景介紹
那么如何分析當(dāng)前虛擬機(jī)性能呢?其中 GC 日志起到至關(guān)重要的作用。
實際上,每種垃圾收集器都有它獨立的日志格式,盡管如此,虛擬機(jī)為了方便用戶閱讀,將各個收集器的日志都維持在一定的共性狀態(tài)。
下面我們一起來看看不同的垃圾收集器,相關(guān)的 GC 日志內(nèi)容。
本文是基于 JDK 1.8 版本運行,可能不同的版本各個內(nèi)存區(qū)域的名稱略有不同,對知識的理解不會產(chǎn)生明顯的誤區(qū)。
02、觸發(fā)GC時機(jī)
通常,GC 觸發(fā)的條件有兩種:
1.程序調(diào)用System.gc時可能會觸發(fā),此時會建議 JVM 進(jìn)行垃圾回收,但不代表一定會進(jìn)行 GC 動作;
2.系統(tǒng)自身來決定 GC 觸發(fā)的時機(jī),比如年輕代空間不足、老年代空間不足等就會主動觸發(fā) GC 動作
以上兩種行為都會產(chǎn)生 GC 日志。
03、GC日志
在介紹之前,我們先看一段代碼,下文的 GC 日志都會基于這段代碼來分析。
/**
* 虛擬機(jī)參數(shù):-verbose:gc
*/
public class GCObjectTest {
public Object instance = null;
/**
* 設(shè)置成員屬性占用一點內(nèi)存,2M
*/
public byte[] bigSize = new byte[2 * 1024 * 1024];
public static void main(String[] args) {
GCObjectTest objectA = new GCObjectTest();
GCObjectTest objectB = new GCObjectTest();
// 設(shè)置兩個對象互相引用
objectA.instance = objectB;
objectB.instance = objectA;
objectB = null;
objectA = null;
// 觸發(fā) GC,不一定實時生效
System.gc();
}
}
運行時加上-verbose:gc參數(shù),以便簡要的查看程序的 GC 情況,運行后的輸出結(jié)果如下!
[GC (System.gc()) 6101K->520K(125952K), 0.0022878 secs]
[Full GC (System.gc()) 520K->408K(125952K), 0.0049120 secs]
以上代碼是一段對象相互引用的場景,但是 JVM 還是將對象回收了,也應(yīng)證了一點,HotSpot 虛擬機(jī)并不是通過引用計數(shù)法來判定對象是否存活的。
下面我們還是以上面的代碼為例,設(shè)置不同的虛擬機(jī)參數(shù),看看 GC 日志情況。
3.1、Serial 和 Serial Old 組合垃圾收集器
Serial 和 Serial Old 組合的垃圾收集器,可以在運行時設(shè)置如下參數(shù)來開啟。
-XX:+PrintGCDetails
-XX:+UseSerialGC
運行之后,輸出結(jié)果如下!
[Full GC (System.gc()) [Tenured: 0K->393K(87424K), 0.0104804 secs] 6891K->393K(126720K), [Metaspace: 3052K->3052K(1056768K)], 0.0105689 secs] [Times: user=0.00 sys=0.00, real=0.01 secs]
Heap
def new generation total 39424K, used 351K [0x0000000740000000, 0x0000000742ac0000, 0x000000076aaa0000)
eden space 35072K, 1% used [0x0000000740000000, 0x0000000740057c58, 0x0000000742240000)
from space 4352K, 0% used [0x0000000742240000, 0x0000000742240000, 0x0000000742680000)
to space 4352K, 0% used [0x0000000742680000, 0x0000000742680000, 0x0000000742ac0000)
tenured generation total 87424K, used 393K [0x000000076aaa0000, 0x0000000770000000, 0x00000007c0000000)
the space 87424K, 0% used [0x000000076aaa0000, 0x000000076ab02608, 0x000000076ab02800, 0x0000000770000000)
Metaspace used 3062K, capacity 4496K, committed 4864K, reserved 1056768K
class space used 336K, capacity 388K, committed 512K, reserved 1048576K
各個參數(shù)描述介紹:
- def new generation:表示年輕代的內(nèi)存使用情況,其中eden space表示Eden空間的內(nèi)存使用情況;from space表示From Survivor空間的內(nèi)存使用情況;to space表示To Survivor空間的內(nèi)存使用情況;
- tenured generation:表示老年代的內(nèi)存使用情況
- Metaspace:表示元空間的內(nèi)存使用情況,在 JDK1.7 中稱為永久代
3.2、ParNew 和 Serial Old 組合垃圾收集器
ParNew 和 Serial Old 組合的垃圾收集器,可以在運行時設(shè)置如下參數(shù)來開啟。
-XX:+PrintGCDetails
-XX:+UseParNewGC
運行之后,輸出結(jié)果如下!
[Full GC (System.gc()) [Tenured: 0K->395K(87424K), 0.0044216 secs] 6891K->395K(126720K), [Metaspace: 3058K->3058K(1056768K)], 0.0044869 secs] [Times: user=0.01 sys=0.01, real=0.00 secs]
Heap
par new generation total 39424K, used 1052K [0x0000000740000000, 0x0000000742ac0000, 0x000000076aaa0000)
eden space 35072K, 3% used [0x0000000740000000, 0x0000000740107228, 0x0000000742240000)
from space 4352K, 0% used [0x0000000742240000, 0x0000000742240000, 0x0000000742680000)
to space 4352K, 0% used [0x0000000742680000, 0x0000000742680000, 0x0000000742ac0000)
tenured generation total 87424K, used 395K [0x000000076aaa0000, 0x0000000770000000, 0x00000007c0000000)
the space 87424K, 0% used [0x000000076aaa0000, 0x000000076ab02d70, 0x000000076ab02e00, 0x0000000770000000)
Metaspace used 3064K, capacity 4496K, committed 4864K, reserved 1056768K
class space used 336K, capacity 388K, committed 512K, reserved 1048576K
其中par new generation表示年輕代的內(nèi)存使用情況,其它表達(dá)的內(nèi)容與上相同。
3.3、Parallel Scavenge 和 Parallel Old 組合垃圾收集器
Parallel Scavenge 和 Parallel Old 組合的垃圾收集器,可以在運行時設(shè)置如下參數(shù)來開啟。
-XX:+PrintGCDetails
-XX:+UseParallelOldGC
需要注意的是,在 jdk1.8 及之后的版本中,-XX:+UseParallelGC和-XX:+UseParallelOldGC參數(shù)效果是一樣的,都是用的 Parallel Old 作為老年代收集器;而在 jdk1.7 及之后的版本中,-XX:+UseParallelGC參數(shù)用的是 Serial Old 作為老年代收集器。
運行之后,輸出結(jié)果如下!
[GC (System.gc()) [PSYoungGen: 6767K->496K(38400K)] 6767K->504K(125952K), 0.0014375 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]
[Full GC (System.gc()) [PSYoungGen: 496K->0K(38400K)] [ParOldGen: 8K->390K(87552K)] 504K->390K(125952K), [Metaspace: 3008K->3008K(1056768K)], 0.0045268 secs] [Times: user=0.01 sys=0.00, real=0.00 secs]
Heap
PSYoungGen total 38400K, used 998K [0x0000000795580000, 0x0000000798000000, 0x00000007c0000000)
eden space 33280K, 3% used [0x0000000795580000,0x0000000795679b20,0x0000000797600000)
from space 5120K, 0% used [0x0000000797600000,0x0000000797600000,0x0000000797b00000)
to space 5120K, 0% used [0x0000000797b00000,0x0000000797b00000,0x0000000798000000)
ParOldGen total 87552K, used 390K [0x0000000740000000, 0x0000000745580000, 0x0000000795580000)
object space 87552K, 0% used [0x0000000740000000,0x0000000740061b10,0x0000000745580000)
Metaspace used 3042K, capacity 4496K, committed 4864K, reserved 1056768K
class space used 333K, capacity 388K, committed 512K, reserved 1048576K
其中PSYoungGen表示年輕代的內(nèi)存使用情況;ParOldGen表示老年代的內(nèi)存使用情況,其它表達(dá)的內(nèi)容與上相同。
3.4、ParNew 和 CMS + Serial Old 組合垃圾收集器
ParNew 和 CMS + Serial Old 組合的垃圾收集器,可以在運行時設(shè)置如下參數(shù)來開啟。
-XX:+PrintGCDetails
-XX:+UseConcMarkSweepGC
運行之后,輸出結(jié)果如下!
[Full GC (System.gc()) [CMS: 0K->388K(87424K), 0.0214068 secs] 6192K->388K(126720K), [Metaspace: 2925K->2925K(1056768K)], 0.0214982 secs] [Times: user=0.01 sys=0.01, real=0.03 secs]
Heap
par new generation total 39424K, used 1052K [0x0000000740000000, 0x0000000742ac0000, 0x0000000754cc0000)
eden space 35072K, 3% used [0x0000000740000000, 0x0000000740107280, 0x0000000742240000)
from space 4352K, 0% used [0x0000000742240000, 0x0000000742240000, 0x0000000742680000)
to space 4352K, 0% used [0x0000000742680000, 0x0000000742680000, 0x0000000742ac0000)
concurrent mark-sweep generation total 87424K, used 388K [0x0000000754cc0000, 0x000000075a220000, 0x00000007c0000000)
Metaspace used 2932K, capacity 4496K, committed 4864K, reserved 1056768K
class space used 319K, capacity 388K, committed 512K, reserved 1048576K
其中par new generation表示年輕代的內(nèi)存使用情況;concurrent mark-sweep generation表示老年代的內(nèi)存使用情況,其它表達(dá)的內(nèi)容與上相同。
3.5、G1 垃圾收集器
G1 垃圾收集器,可以在運行時設(shè)置如下參數(shù)來開啟。
-XX:+PrintGCDetails
-XX:+UseG1GC
運行之后,輸出結(jié)果如下!
[Full GC (System.gc()) 5985K->395K(8192K), 0.0083534 secs]
[Eden: 2048.0K(14.0M)->0.0B(4096.0K) Survivors: 0.0B->0.0B Heap: 5985.1K(128.0M)->395.9K(8192.0K)], [Metaspace: 3059K->3059K(1056768K)]
[Times: user=0.01 sys=0.00, real=0.01 secs]
Heap
garbage-first heap total 8192K, used 395K [0x0000000740000000, 0x0000000740100040, 0x00000007c0000000)
region size 1024K, 1 young (1024K), 0 survivors (0K)
Metaspace used 3066K, capacity 4496K, committed 4864K, reserved 1056768K
class space used 336K, capacity 388K, committed 512K, reserved 1048576K
G1 收集器與以上收集器都不同,它會把整個 Java 堆分成若干個大小相等的獨立區(qū)域,也是日志中的 Region,然后針對優(yōu)先級高的 Region 區(qū)域進(jìn)行收集。Region 區(qū)域可能存放的是年輕代的對象,也可能是老年代的對象。
04、小結(jié)
以上的日志輸出,會發(fā)現(xiàn)很多的共性。
比如,以“GC”開頭的,通常表示年輕代的收集情況;以“Full GC”開頭的,表示整個堆的收集情況,其中帶有“(System.gc()) ”信息的表示調(diào)用System.gc()方法所觸發(fā)的 GC。
以下面這個日志為例,來解讀一下相關(guān)信息。
[Full GC (System.gc()) [PSYoungGen: 496K->0K(38400K)] [ParOldGen: 8K->390K(87552K)] 504K->390K(125952K), [Metaspace: 3008K->3008K(1056768K)], 0.0045268 secs] [Times: user=0.01 sys=0.00, real=0.00 secs]
1.Full GC (System.gc()表示 Full GC 類型的 GC 動作,通過調(diào)用System.gc()方法而觸發(fā);
2.PSYoungGen: 496K->0K(38400K)表示年輕代 GC 前使用的容量為 496K,GC 后該內(nèi)存區(qū)域使用的容量為 0K,年輕代總?cè)萘繛?38400K;
3.ParOldGen: 8K->390K(87552K)表示老年代 GC 前使用的容量為 8K,GC 后該內(nèi)存區(qū)域使用的容量為 390K,老年代總?cè)萘繛?87552K;
4.504K->390K(125952K)表示整個堆 GC 前使用的容量為 504K,GC 后該內(nèi)存區(qū)域使用的容量為 390K,整個堆總?cè)萘繛?125952K;
5.Metaspace: 3008K->3008K(1056768K)表示元空間 GC 前使用的容量為 3008K,GC 后該內(nèi)存區(qū)域使用的容量為 3008K,整個元空間總?cè)萘繛?1056768K;
6.0.0045268 secs表示 Full GC 耗時為 0.0045268 秒;
7.Times: user=0.01 sys=0.00, real=0.00 secs表示 Full GC 期間用戶的耗時、系統(tǒng)的耗時、實際操作的耗時,單位秒;
Heap 后面列舉的是堆的內(nèi)存使用情況。