1. 程式人生 > >理解Java的GC日誌

理解Java的GC日誌

一、日誌分析 
理解GC日誌是處理Java虛擬機器記憶體問題的基本技能,下面我們具體來看看。

通過在java命令種加入引數來指定對應的gc型別,列印gc日誌資訊並輸出至檔案等策略。

1、編寫java程式碼

public class ReferenceCountingGC {
    public Object instance = null;
    private static final int ONE_MB = 1024 * 1024;

    private byte[] bigSize = new byte[2 * ONE_MB];

    public static void
main(String[] args) { testGC(); } public static void testGC() { ReferenceCountingGC objA = new ReferenceCountingGC(); ReferenceCountingGC objB = new ReferenceCountingGC(); objA.instance = objB; objB.instance = objA; objA = null
; objB = null; System.gc(); } }
  • 1
  • 2
  • 3
  • 4
  • 5
  • 6
  • 7
  • 8
  • 9
  • 10
  • 11
  • 12
  • 13
  • 14
  • 15
  • 16
  • 17
  • 18
  • 19
  • 20
  • 21
  • 22
  • 23
  • 24
  • 25

2、編譯java檔案

javac ReferenceCountingGC.java  
  • 1

3、執行class檔案

java -XX:+PrintGCDateStamps -XX:+PrintGCDetails ReferenceCountingGC
  • 1

對應的引數列表

-XX:+PrintGC 輸出GC日誌
-XX:+PrintGCDetails 輸出GC的詳細日誌
-XX:+PrintGCTimeStamps
輸出GC的時間戳(以基準時間的形式)
-XX:+PrintGCDateStamps 輸出GC的時間戳(以日期的形式,如 2013-05-04T21:53:59.234+0800-XX:+PrintHeapAtGC 在進行GC的前後打印出堆的資訊 -Xloggc:../logs/gc.log 日誌檔案的輸出路徑
  • 1
  • 2
  • 3
  • 4
  • 5
  • 6

結果輸出:

2016-03-20T14:34:55.118-0800: [GC [PSYoungGen: 6123K->400K(38912K)] 6123K->400K(125952K), 0.0012070 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
2016-03-20T14:34:55.119-0800: [Full GC [PSYoungGen: 400K->0K(38912K)] [ParOldGen: 0K->282K(87040K)] 400K->282K(125952K) [PSPermGen: 2622K->2621K(21504K)], 0.0084640 secs] [Times: user=0.01 sys=0.00, real=0.01 secs] 
Heap
 PSYoungGen      total 38912K, used 1013K [0x00000007d5500000, 0x00000007d8000000, 0x0000000800000000)
  eden space 33792K, 3% used [0x00000007d5500000,0x00000007d55fd7d0,0x00000007d7600000)
  from space 5120K, 0% used [0x00000007d7600000,0x00000007d7600000,0x00000007d7b00000)
  to   space 5120K, 0% used [0x00000007d7b00000,0x00000007d7b00000,0x00000007d8000000)
 ParOldGen       total 87040K, used 282K [0x0000000780000000, 0x0000000785500000, 0x00000007d5500000)
  object space 87040K, 0% used [0x0000000780000000,0x0000000780046bf8,0x0000000785500000)
 PSPermGen       total 21504K, used 2628K [0x000000077ae00000, 0x000000077c300000, 0x0000000780000000)
  object space 21504K, 12% used [0x000000077ae00000,0x000000077b091380,0x000000077c300000)
  • 1
  • 2
  • 3
  • 4
  • 5
  • 6
  • 7
  • 8
  • 9
  • 10
  • 11
  • 12

PSYoungGen表示新生代,這個名稱由收集器決定,這裡的收集器是Parallel Scavenge。老年代為ParOldGen,永久代為PSPermGen 
如果收集器為ParNew收集器,新生代為ParNew,Parallel New Generation 
如果收集器是Serial收集器,新生代為DefNew,Default New Generation

可以看到上面有兩種GC型別:GC和Full GC,有Full表示這次GC是發生了Stop-The-World的。

新生代GC(Minor GC):指發生在新生代的垃圾收集動作,因為Java物件大多都具備朝生夕滅的特性,所以Minor GC非常頻繁,一般回收速度非常快。

老年代GC(Major GC/Full GC):指發生在老年代的GC,出現了Major GC,經常會伴隨至少一次的Minor GC,Major GC的速度一般會比Minor GC慢10倍以上。

[GC [PSYoungGen: 6123K->400K(38912K)] 6123K->400K(125952K), 0.0012070 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]

上面方括號內部的6123K->400K(38912K),表示GC前該記憶體區域已使用容量->GC後該記憶體區域已使用容量,後面圓括號裡面的38912K為該記憶體區域的總容量。

方括號外面的6123K->400K(125952K),表示GC前Java堆已使用容量->GC後Java堆已使用容量,後面圓括號裡面的125952K為Java堆總容量。

[Times: user=0.00 sys=0.00, real=0.00 secs]分別表示使用者消耗的CPU時間,核心態消耗的CPU時間和操作從開始到結束所經過的牆鍾時間(Wall Clock Time),CPU時間和牆鍾時間的差別是,牆鍾時間包括各種非運算的等待耗時,例如等待磁碟I/O、等待執行緒阻塞,而CPU時間不包括這些耗時。

二、GC日誌的離線分析