Java 8 GC Tutorials - Herong's Tutorial Examples - v1.03, by Dr. Herong Yang
"-XX:+PrintHeapAtGC" - Print Heap Summary per GC
This section describes the garbage collection logging option, '-XX:+PrintHeapAtGC', which prints two snapshots of the heap memory for each GC, one before the GC and another after the GC.
In this tutorial, let's try the "-XX:+PrintHeapAtGC" garbage collection logging option to see what we will get in the log file:
herong> \progra~1\java\jdk1.8.0\bin\java -Xms2m -Xmx64m \ -XX:+PrintHeapAtGC -Xloggc: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 {Heap before GC invocations=0 (full 0): -- invocations=0: 0 GCs (Minor and Major) have been performed -- full 0: 0 Major GCs have been performed -- Major GC is referred as Full GC in log messages def new generation total 960K, used 878K [... eden space 896K, 98% used [... from space 64K, 0% used [... to space 64K, 0% used [... tenured generation total 1024K, used 0K [... the space 1024K, 0% used [... Metaspace used 1555K, capacity 2242K, committed 2368K, reserved 4480K -- The "eden" space is almost full, 98%. Time for Minor GC. 0.113: [GC (Allocation Failure) 878K->756K(1984K), 0.0016854 secs] Heap after GC invocations=1 (full 0): -- 1 GCs (Minor and Major) have been performed -- 0 Major (referred as full here) GCs have been performed def new generation total 960K, used 64K [... eden space 896K, 0% used [... from space 64K, 100% used [... to space 64K, 0% used [... tenured generation total 1024K, used 692K [... the space 1024K, 67% used [... Metaspace used 1555K, capacity 2242K, committed 2368K, reserved 4480K } -- The Minor GC moved 64K of objects to the "from" space from "eden", -- and 832K of objects to the "tenured" generation ... {Heap before GC invocations=1 (full 0): def new generation total 960K, used 865K [... eden space 896K, 89% used [... from space 64K, 100% used [... to space 64K, 0% used [... tenured generation total 1024K, used 692K [... the space 1024K, 67% used [... Metaspace used 1555K, capacity 2242K, committed 2368K, reserved 4480K -- The "eden" space is almost full, 98%. Time for Minor GC again. 1.126: [GC (Allocation Failure) 1557K->1540K(2500K), 0.0027685 secs] 1.129: [Full GC (Allocation Failure) 1540K->1540K(2500K), 0.0031179 secs] -- Minor GC is not enough. Time for Major GC Heap after GC invocations=2 (full 1): -- 2 GCs (Minor and Major) have been performed -- 1 Major GCs have been performed def new generation total 1216K, used 0K [... eden space 1088K, 0% used [... from space 128K, 0% used [... to space 128K, 0% used [... tenured generation total 2568K, used 1539K [... the space 2568K, 59% used [... Metaspace used 1555K, capacity 2242K, committed 2368K, reserved 4480K } -- Heap size was expanded during the GC ...
Notes on the output:
Table of Contents
Heap Memory Area and Size Control
►JVM Garbage Collection Logging
Garbage Collection Demo Program
Garbage Collection Logging Options
"-XX:+PrintGC" - GC Logging Option for Short Messages
"-XX:+PrintGCDetails" - Option for Detailed GC Messages
"-XX:+PrintGCDateStamps" - Calendar Timestamp on GC Messages
"-XX:+PrintGCApplicationStoppedTime" - Application Pause Durations
"-XX:+PrintGCApplicationConcurrentTime" - Application Running Durations
►"-XX:+PrintHeapAtGC" - Print Heap Summary per GC
"-XX:+PrintTenuringDistribution" - Tunuring Distribution
"-XX:+PrintReferenceGC" - Reference Counts per GC
"-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"
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