JVM Tutorials - Herong's Tutorial Examples - Version 4.23, by Dr. Herong Yang
Garbage First GC Log Message Format
This section provides examples of Garbage First (G) GC log messages.
As a comparison, here is an example of log messages generated by the Garbage First (G1) Collector:
C:\>\progra~1\java\jdk1.8.0\bin\java -Xms2m -Xmx64m -XX:+UseG1GC -XX:+PrintGCDetails GarbageCollection Step/TotalMemory/FreeMemory/UsedMemory: [GC pause (G1 Evacuation Pause) (young), 0.0020591 secs] [Parallel Time: 1.8 ms, GC Workers: 4] [GC Worker Start (ms): Min: 106.9, Avg: 107.1, Max: 107.5, Diff: ... [Ext Root Scanning (ms): Min: 0.0, Avg: 0.1, Max: 0.2, Diff: 0.2,... [Update RS (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.... [Processed Buffers: Min: 0, Avg: 0.0, Max: 0, Diff: 0, Sum: 0]... [Scan RS (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0]... [Code Root Scanning (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0... [Object Copy (ms): Min: 0.6, Avg: 1.0, Max: 1.6, Diff: 1.0, Sum: ... [Termination (ms): Min: 0.0, Avg: 0.4, Max: 0.8, Diff: 0.8, Sum: ... [GC Worker Other (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, S... [GC Worker Total (ms): Min: 1.2, Avg: 1.5, Max: 1.8, Diff: 0.6, S... [GC Worker End (ms): Min: 108.7, Avg: 108.7, Max: 108.7, Diff: 0.0] [Code Root Fixup: 0.0 ms] [Code Root Migration: 0.0 ms] [Clear CT: 0.0 ms] [Other: 0.2 ms] [Choose CSet: 0.0 ms] [Ref Proc: 0.1 ms] [Ref Enq: 0.0 ms] [Free CSet: 0.0 ms] [Eden: 1024.0K(1024.0K)->0.0B(1024.0K) Survivors: 0.0B->1024.0K Heap: 1024.0K(2048.0K)->800.1K(2048.0K)] [Times: user=0.00 sys=0.00, real=0.00 secs] 1 2097152 714064 1383088 [GC pause (G1 Evacuation Pause) (young), 0.0096376 secs] ... 2 4194304 1730264 2464040 [GC pause (G1 Evacuation Pause) (young), 0.0060770 secs] ... [GC pause (G1 Evacuation Pause) (young), 0.0081144 secs] ... 3 6291456 2522720 3768736 [GC pause (G1 Evacuation Pause) (young) (initial-mark), 0.0084628 s... [Parallel Time: 7.5 ms, GC Workers: 4] [GC Worker Start (ms): Min: 3141.4, Avg: 3144.9, Max: 3148.5, Dif... [Ext Root Scanning (ms): Min: 0.0, Avg: 0.1, Max: 0.2, Diff: 0.2,... [Code Root Marking (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0,... [Update RS (ms): Min: 0.0, Avg: 0.2, Max: 0.8, Diff: 0.8, Sum: 0.... [Processed Buffers: Min: 0, Avg: 1.0, Max: 3, Diff: 3, Sum: 4] [Scan RS (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0] [Code Root Scanning (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0... [Object Copy (ms): Min: 0.0, Avg: 2.8, Max: 5.8, Diff: 5.8, Sum: ... [Termination (ms): Min: 0.0, Avg: 0.5, Max: 1.6, Diff: 1.6, Sum: ... [GC Worker Other (ms): Min: 0.0, Avg: 0.0, Max: 0.1, Diff: 0.0, S... [GC Worker Total (ms): Min: 0.0, Avg: 3.7, Max: 7.3, Diff: 7.3, S... [GC Worker End (ms): Min: 3148.5, Avg: 3148.6, Max: 3148.8, Diff:... [Code Root Fixup: 0.0 ms] [Code Root Migration: 0.0 ms] [Clear CT: 0.1 ms] [Other: 0.9 ms] [Choose CSet: 0.0 ms] [Ref Proc: 0.7 ms] [Ref Enq: 0.0 ms] [Free CSet: 0.0 ms] [Eden: 1024.0K(1024.0K)->0.0B(1024.0K) Survivors: 1024.0K->1024.0K Heap: 4640.4K(6144.0K)->5376.0K(8192.0K)] [Times: user=0.02 sys=0.00, real=0.01 secs] [GC concurrent-root-region-scan-start] 4 8388608 2794984 5593624 [GC concurrent-root-region-scan-end, 0.0004590 secs] [GC concurrent-mark-start] [GC concurrent-mark-end, 0.0053633 secs] [GC remark [GC ref-proc, 0.0001586 secs], 0.0014682 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] [GC cleanup 5462K->5462K(8192K), 0.0005145 secs] [Times: user=0.00 sys=0.02, real=0.00 secs] [GC pause (G1 Evacuation Pause) (young), 0.0057705 secs] ... ... [GC concurrent-root-region-scan-start] 36 46137344 2241664 43895680 [GC concurrent-root-region-scan-end, 0.0005227 secs] [GC concurrent-mark-start] [GC concurrent-mark-end, 0.0271747 secs] [GC remark [GC ref-proc, 0.0000945 secs], 0.0012640 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] [GC cleanup 41M->38M(44M), 0.0002753 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] [GC concurrent-cleanup-start] [GC concurrent-cleanup-end, 0.0000419 secs] ... Heap garbage-first heap total 46080K, used 41087K [0x04000000, 0x06d0... region size 1024K, 2 young (2048K), 1 survivors (1024K) Metaspace used 45K, capacity 2242K, committed 2368K, reserved 4480K
The Garbage First (G1) Collector also generates many new types of log messages. To fully understand those new messages, we need to learn more details about the G1 algorithm.
Last update: 2014.
Table of Contents
Downloading and Installing JDK 1.8.0 on Windows
Downloading and Installing JDK 1.7.0 on Windows
java.lang.Runtime Class - The JVM Instance
java.lang.System Class - The Operating System
ClassLoader Class - Class Loaders
Class Class - Class Reflections
JRockit JVM 28.2.7 by Oracle Corporation
►Memory Management and Garbage Collectors
Memory Management General Rules
Java Exception: "java.lang.OutOfMemoryError: Java heap space"
OutOfMemoryError Comparison of HotSpot and JRockit
Garbage Collection Demonstration
JVM Memory Manager - Garbage Collector
Generational Garbage Collection in HotSpot
Young Generation Collection - Minor Collection
Tenured Generation Collection - Full Collection
HotSpot Default Garbage Collector - Serial Collector
"-XX:+PrintGCDetails" - Garbage Collection Logging
GC Log Messages on GarbageCollection.java
Serial, Parallel, Concurrent, and Regionalized Collectors
Parallel Collector GC Log Message Format
Parallel Compacting Collector GC Log Message Format
Concurrent Mark-Sweep Collector GC Log Message Format
►Garbage First GC Log Message Format
JVM Stack, Frame and Stack Overflow
Thread Testing Program and Result
CPU Impact of Multi-Thread Applications
I/O Impact of Multi-Thread Applications
Micro Benchmark Runner and JVM Options
Micro Benchmark Tests on "int" Operations
Micro Benchmark Tests on "long" Operations
Micro Benchmark Tests in JIT Compilation Mode