Serial GC Tracing - Plenty of Heap

This section provides a tutorial of tracing how Serial GC works with a huge heap size, plenty of memory in 'new' generation.

We know that our test program GarbageCollection.java uses Tenured generation collector only if we gave 40 MB of heap, Let's run with a size of 1200 MB and watch how the Serial GC does garbage collections.

"-XX:+PrintHeapAtGC" and "-XX:+PrintTenuringDistribution" options are used print GC tracing information:

herong> \progra~1\java\jdk1.8.0\bin\java -Xms1200m -Xmx1200m \
   -XX:+UseSerialGC -XX:+PrintGCDetails -XX:+PrintHeapAtGC \
   -XX:+PrintTenuringDistribution GarbageCollection

The first GC happened after 306 iterations, because the "eden" space was full with 327426K new objects:

Step/TotalMemory/FreeMemory/UsedMemory:
1   1216348160   1202926208   13421952
...
306   1216348160   881325864   335022296
{Heap before GC invocations=0 (full 0):
 def new generation   total 368640K, used 327426K [0x04800000, ...
  eden space 327680K,  99% used [...
  from space 40960K,   0% used [...
  to   space 40960K,   0% used [...
 tenured generation   total 819200K, used 0K [0x1d800000, ...
   the space 819200K,   0% used [0x1d800000, 0x1d800000, ...

[GC (Allocation Failure) [DefNew...

Desired survivor size 20971520 bytes, new threshold 1 (max 15)
- age   1:   33531432 bytes,   33531432 total

   ...: 327426K->32745K(368640K), 0.0293776 secs]
   327426K->32745K(1187840K), 0.0294134 secs]
   [Times: user=0.02 sys=0.00, real=0.02 secs]

Heap after GC invocations=1 (full 0):
 def new generation   total 368640K, used 32745K [0x04800000, ...
  eden space 327680K,   0% used [...
  from space 40960K,  79% used [...
  to   space 40960K,   0% used [...
 tenured generation   total 819200K, used 0K [0x1d800000, ...
   the space 819200K,   0% used [0x1d800000, 0x1d800000, ...
}

This was a simple Young generation GC, which removed all dead objects and left 32745K live objects in "from" space. The size of live objects matches my expectation, the test application only uses 32MB in the array.

The second GC happened at 613rd iteration, because the "eden" space was full again with new objects.

307   1216348160   1175994264   40353896
...
613   1216348160   847272408   369075752
{Heap before GC invocations=1 (full 0):
 def new generation   total 368640K, used 360425K [0x04800000, ...
  eden space 327680K, 100% used [...
  from space 40960K,  79% used [...
  to   space 40960K,   0% used [...
 tenured generation   total 819200K, used 0K [0x1d800000, ...
   the space 819200K,   0% used [0x1d800000, 0x1d800000, ...

[GC (Allocation Failure) [DefNew...

Desired survivor size 20971520 bytes, new threshold 1 (max 15)
- age   1:   33543536 bytes,   33543536 total

   ...: 360425K->32757K(368640K), 0.0308081 secs]
   360425K->33001K(1187840K), 0.0308329 secs]
   [Times: user=0.00 sys=0.03, real=0.03 secs]

Heap after GC invocations=2 (full 0):
 def new generation   total 368640K, used 32757K [0x04800000, ...
  eden space 327680K,   0% used [...
  from space 40960K,  79% used [...
  to   space 40960K,   0% used [...
 tenured generation   total 819200K, used 243K [0x1d800000, ...
   the space 819200K,   0% used [0x1d800000, 0x1d83cfa8, ...
}

This was also a simple Young generation GC, which removed all dead objects and left 32757K live objects in "from" space as I expected.

Also note that, "age 1" objects left from the first GC were all dead objects, so no objects were labeled as "age 2".

The 3rd GC happened at 923rd iteration, because the "eden" space was full again with new objects.

614   1216348160   1175679688   40668472
...
923   1216348160   847010536   369337624
{Heap before GC invocations=2 (full 0):
 def new generation   total 368640K, used 360437K [0x04800000, ...
  eden space 327680K, 100% used [...
  from space 40960K,  79% used [...
  to   space 40960K,   0% used [...
 tenured generation   total 819200K, used 243K [0x1d800000, ...
   the space 819200K,   0% used [0x1d800000, 0x1d83cfa8, ...
[GC (Allocation Failure) [DefNew...

Desired survivor size 20971520 bytes, new threshold 1 (max 15)
- age   1:   33871264 bytes,   33871264 total

   ...: 360437K->33077K(368640K), 0.0113341 secs]
   360681K->33321K(1187840K), 0.0113593 secs]
   [Times: user=0.02 sys=0.00, real=0.02 secs]

Heap after GC invocations=3 (full 0):
 def new generation   total 368640K, used 33077K [0x04800000, ...
  eden space 327680K,   0% used [...
  from space 40960K,  80% used [...
  to   space 40960K,   0% used [...
 tenured generation   total 819200K, used 244K [0x1d800000, ...
   the space 819200K,   0% used [0x1d800000, 0x1d83d068, ...
}

This was also a simple Young generation GC, which removed all dead objects and left 33077K live objects in "from" space as I expected.

Also note that, "age 1" objects left from the second GC were all dead objects, so no objects were labeled as "age 2".

All subsequent GCs were behaved similar the 3rd GC.

Conclusion:

Table of Contents

 About This Book

 Heap Memory Area and Size Control

 JVM Garbage Collection Logging

 Introduction of Garbage Collectors

Serial Collector - "+XX:+UseSerialGC"

 What Is Serial Collector

 GC Log Message Format for Serial Collector

 GC Log Message Examples of Serial Collector

 Log Message Types from Serial Collector

 Serial Collector Stops Application for Minor/Major GC

 Usage Report on Heap Memory Areas

 Default NewRatio - Old vs. New Generation

 "-XX:NewRatio" - Ratio of Tenured and "new" Generation

 "-XX:SurvivorRatio" - Ratio of Eden and Survivor Space

 Serial GC Tracing - Tight Heap

Serial GC Tracing - Plenty of Heap

 Serial GC Tracing - Aged Live Objects

 Serial GC Tracing - Tenuring Threshold

 "-XX:TargetSurvivorRatio" - Second Tenuring Condition

 Serial GC Tracing - Tenuring Threshold Controlled

 "-XX:+NeverTenure" and "-XX:+AlwaysTenure" not Working

 Minor GC Triggering Condition of Serial Collector

 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

 Garbage Collection Performance Test Summary

 Archived Tutorials

 References

 Full Version in PDF/EPUB