Java GC Tutorials - Herong's Tutorial Examples - v1.11, by Dr. Herong Yang
"-Xlog:gc+heap=trace" - GC+HEAP Log Messages
This section describes the garbage collection logging option, '-Xlog:gc+heap=trace', which prints two snapshots of the heap of each GC, one before the GC and another after the GC. It also prints heap changes of each GC.
In this tutorial, let's try the "-Xlog:gc+heap=trace" garbage collection logging option to see what we will get in the log file:
herong> java -Xms2m -Xmx64m -Xlog:gc+heap=trace:gc.log GarbageCollection Step/TotalMemory/FreeMemory/UsedMemory: 1 2031616 698408 1333208 2 3874816 1472824 2401992 3 3874816 424944 3449872 4 8970240 4441352 4528888 ... (Ctrl-C) herong> more gc.log [0.011s][info][gc,heap] Heap region size: 1M -- Default region size is 1M for each heap region [0.011s][debug][gc,heap] Minimum heap 2097152 Initial heap 2097152 Maximum heap 67108864 -- Heap starts with 2 regions [0.056s][debug][gc,heap] GC(0) Heap before GC invocations=0 (full 0): garbage-first heap total 2048K, used 1024K [... [0.056s][debug][gc,heap] GC(0) region size 1024K, 1 young (1024K), 0 survivors (0K) [0.056s][debug][gc,heap] GC(0) Metaspace used 325K, capacity 4515K, committed 4864K, reserved 1056768K [0.056s][debug][gc,heap] GC(0) class space used 30K, capacity 398K, committed 512K, reserved 1048576K -- Heap status before GC #1 [0.058s][info ][gc,heap] GC(0) Eden regions: 1->0(1) [0.058s][trace][gc,heap] GC(0) Used: 0K, Waste: 0K [0.058s][info ][gc,heap] GC(0) Survivor regions: 0->1(1) [0.058s][trace][gc,heap] GC(0) Used: 566K, Waste: 457K [0.059s][info ][gc,heap] GC(0) Old regions: 0->0 [0.059s][trace][gc,heap] GC(0) Used: 0K, Waste: 0K [0.059s][info ][gc,heap] GC(0) Archive regions: 0->0 [0.059s][trace][gc,heap] GC(0) Used: 0K, Waste: 0K [0.059s][info ][gc,heap] GC(0) Humongous regions: 0->0 [0.059s][trace][gc,heap] GC(0) Used: 0K, Waste: 0K -- What was done in GC #1 [0.059s][debug][gc,heap] GC(0) Heap after GC invocations=1 (full 0): garbage-first heap total 2048K, used 566K [... [0.059s][debug][gc,heap] GC(0) region size 1024K, 1 young (1024K), 1 survivors (1024K) [0.059s][debug][gc,heap] GC(0) Metaspace used 325K, capacity 4515K, committed 4864K, reserved 1056768K [0.059s][debug][gc,heap] GC(0) class space used 30K, capacity 398K, committed 512K, reserved 1048576K -- Heap status after GC #1 [0.113s][debug][gc,heap] GC(1) Heap before GC invocations=1 (full 0... [0.113s][debug][gc,heap] GC(1) region size 1024K, 2 young (2048K)... [0.113s][debug][gc,heap] GC(1) Metaspace used 1344K, capacit... [0.113s][debug][gc,heap] GC(1) class space used 160K, capacity... [0.115s][info ][gc,heap] GC(1) Eden regions: 1->0(1) -- Heap status before GC #2 [0.115s][trace][gc,heap] GC(1) Used: 0K, Waste: 0K [0.115s][info ][gc,heap] GC(1) Survivor regions: 1->1(1) [0.116s][trace][gc,heap] GC(1) Used: 457K, Waste: 566K [0.116s][info ][gc,heap] GC(1) Old regions: 0->1 [0.116s][trace][gc,heap] GC(1) Used: 545K, Waste: 478K [0.116s][info ][gc,heap] GC(1) Archive regions: 0->0 [0.116s][trace][gc,heap] GC(1) Used: 0K, Waste: 0K [0.116s][info ][gc,heap] GC(1) Humongous regions: 0->0 [0.116s][trace][gc,heap] GC(1) Used: 0K, Waste: 0K -- What was done in GC #2 [0.116s][debug][gc,heap] GC(1) Heap after GC invocations=2 (full 0)... [0.116s][debug][gc,heap] GC(1) region size 1024K, 1 young (1024K)... [0.116s][debug][gc,heap] GC(1) Metaspace used 1344K, capacit... [0.116s][debug][gc,heap] GC(1) class space used 160K, capacity... -- Heap status after GC #2 ...
The log messages show that the "-Xlog:gc+heap=trace" option provides 3 chunks of information for each GC instance:
Obviously, "--Xlog:gc+heap=trace" option is very useful to understand how each GC is performed.
Table of Contents
Heap Memory Area and Size Control
►JVM Garbage Collection Logging
Garbage Collection Demo Program
Garbage Collection Logging Options
"-Xlog:gc" - Default GC Logging Level: INFO
"-Xlog:gc=trace" - Lowest GC Logging Level: TRACE
►"-Xlog:gc+heap=trace" - GC+HEAP Log Messages
"-Xlog:gc*=trace" - Maximum GC Logging
"-XX:+PrintFlagsFinal" - Print JVM Options
Introduction of Garbage Collectors
Serial Collector - "+XX:+UseSerialGC"
Parallel Collector - "+XX:+UseParallelGC"
Concurrent Mark-Sweep (CMS) Collector - "+XX:+UseConcMarkSweepGC"
Garbage First (G1) Collector - "+XX:+UseG1GC"
The Z Garbage Collector (ZGC) - "+XX:+UseZGC"
Object References and Garbage Collection
Garbage Collection Performance Test Program
Performance Tests on Serial Collector
Performance Tests on Parallel collector
Performance Tests on Concurrent collector
Performance Tests on G1 collector