Outdated: GC Test - JDK 1.4.0 vs. JDK 1.3.1

This section provides a tutorial example on testing garbage collection by comparing performances between JDK 1.4.0 and JDK 1.3.1.

The next group of tests were conducted under JDK 1.3.1_01:

java -Xms2m -Xmx8m GCTest 16 1 > tail_16_01.out
java -Xms2m -Xmx8m GCTest 16 8 > tail_16_08.out
java -Xms2m -Xmx8m GCTest 16 16 > tail_16_16.out
java -Xms2m -Xmx8m GCTest 16 24 > tail_16_24.out

Here was the output of tail_16_01.out:

Time   Total   Free   Free   Total   Act.   Dead   Over
sec.    Mem.   Mem.   Per.    Obj.   Obj.   Obj.   Head

   0    1984   1816    91%       0      0      0    168
   1    1984   1682    84%     128    128      0    174
   1    1984   1553    78%     256    256      0    175
   2    1984   1503    75%     384    384      0     97
   2    1984   1373    69%     512    512      0     99
.....
   6    1984    604    30%    1280   1280      0    100
   6    1984    474    23%    1408   1408      0    102
   7    2116    482    22%    1536   1536      0     98
   7    2116    352    16%    1664   1664      0    100
   8    2116    222    10%    1792   1792      0    102
   8    3088   1070    34%    1920   1920      0     98
   9    3088    942    30%    2048   2048      0     98
   9    3088    812    26%    2176   2176      0    100
  10    3088    810    26%    2176   2048    128    102
  10    3088    680    22%    2304   2176    128    104
  11    3088    678    21%    2304   2048    256    106
  11    3088    558    18%    2432   2176    256     98
  12    3088    556    18%    2432   2048    384    100
  12    3088    426    13%    2560   2176    384    102
  13    3088    424    13%    2560   2048    512    104
  13    3088    294     9%    2688   2176    512    106
  14    3088    292     9%    2688   2048    640    108
  14    3484    569    16%    2816   2176    640     99
  15    3484    567    16%    2816   2048    768    101
  15    3484    438    12%    2944   2176    768    102
  16    3484    436    12%    2944   2048    896    104
  16    3484    306     8%    3072   2176    896    106
  17    3484    304     8%    3072   2048   1024    108
  17    5220   1921    36%    2176   2176      0   1123
  18    5220   1919    36%    2176   2048    128   1125
  18    5220   1793    34%    2304   2176    128   1123
  19    5220   1791    34%    2304   2048    256   1125
....
  31    5484    389     7%    3968   2176   1792   1127
  32    5484    387     7%    3968   2048   1920   1129
  32    5484    257     4%    4096   2176   1920   1131
  33    5484    255     4%    4096   2048   2048   1133
  33    7568   3245    42%    2176   2176      0   2147
  34    7568   3243    42%    2176   2048    128   2149
  34    7568   3113    41%    2304   2176    128   2151
  35    7568   3111    41%    2304   2048    256   2153
....
  58    7964    435     5%    5376   2176   3200   2153
  59    7964    434     5%    5376   2048   3328   2154
  59    7964    304     3%    5504   2176   3328   2156
  60    7964    302     3%    5504   2048   3456   2158
  61    8128   2396    29%    2176   2048    128   3556
  61    8128   2266    27%    2304   2176    128   3558
  62    8128   2264    27%    2304   2048    256   3560
....
  77    8128    341     4%    4224   2176   2048   3563
  77    8128    339     4%    4224   2048   2176   3565
  78    8128    210     2%    4352   2176   2176   3566
  78    8128    208     2%    4352   2048   2304   3568
  79    8128   3549    43%    2176   2176      0   2403
  79    8128   3547    43%    2176   2048    128   2405
  80    8128   3417    42%    2304   2176    128   2407
  80    8128   3415    42%    2304   2048    256   2409
  81    8128   3285    40%    2432   2176    256   2411
  81    8128   3283    40%    2432   2048    384   2413

Comparing with the same test with JDK 1.4.0, JDK 1.3.1 increased the total memory in smaller amounts. Other than this the output seems to be identical.

Outputs tail_16_08 and tail_16_16 were also very similar to JDK 1.4.0.

However, tail_16_24 had a surprise for me. The program ran to the end without any memory problem:

Time   Total   Free   Free   Total   Act.   Dead   Over
sec.    Mem.   Mem.   Per.    Obj.   Obj.   Obj.   Head

   0    1984   1815    91%       0      0      0    169
   1    1984   1682    84%     128    128      0    174
   1    1984   1552    78%     256    256      0    176
....
  31    5484    220     4%    5120   2304   2816    144
  32    5484    218     3%    5120   2176   2944    146
  32    5484    216     3%    5120   2048   3072    148
  33    8128   2780    34%    2176   2176      0   3172
  33    8128   2780    34%    2304   2176    128   3044
  34    8128   2651    32%    2304   2304      0   3173
  34    8128   2521    31%    2432   2432      0   3175
....
  41    8128    856    10%    4096   4096      0   3176
  42    8128    731     8%    4224   4224      0   3173
  42    8128    601     7%    4352   4352      0   3175
  43    8128    472     5%    4480   4480      0   3176
  43    8128   3421    42%    4608   4608      0     99
  44    8128   3291    40%    4736   4736      0    101
  44    8128   3161    38%    4864   4864      0    103
  45    8128   3036    37%    4992   4992      0    100
  45    8128   2906    35%    5120   5120      0    102
  46    8128   2905    35%    5120   4992    128    103
  46    8128   2903    35%    5120   4864    256    105
....
  65    8128    855    10%    7168   4096   3072    105
  66    8128    731     8%    7296   4224   3072    101
  66    8128    601     7%    7424   4352   3072    103
  67    8128    471     5%    7552   4480   3072    105
  67    8128    347     4%    4608   4608      0   3173
  68    8128    217     2%    4736   4736      0   3175
  68    8128   3164    38%    4864   4864      0    100
  69    8128   3034    37%    4992   4992      0    102
  69    8128   2905    35%    5120   5120      0    103
  70    8128   2903    35%    5120   4992    128    105
  70    8128   2901    35%    5120   4864    256    107
....
  89    8128    855    10%    7168   4096   3072    105
  90    8128    731     8%    7296   4224   3072    101
  90    8128    601     7%    7424   4352   3072    103
  91    8128    471     5%    7552   4480   3072    105
  91    8128    347     4%    4608   4608      0   3173
  92    8128    217     2%    4736   4736      0   3175
  92    8128   3164    38%    4864   4864      0    100
  93    8128   3034    37%    4992   4992      0    102
  93    8128   2905    35%    5120   5120      0    103
  94    8128   2903    35%    5120   4992    128    105
  94    8128   2901    35%    5120   4864    256    107
  95    8128   2899    35%    5120   4736    384    109
  95    8128   2897    35%    5120   4608    512    111
....

One thing different in JDK 1.3.1 is that the memory recovered by the garbage collector at second 67 was not immediately given to the application as free memory until second 68.

It seemed to me that JDK 1.3.1 had a better garbage collection process. So I tried two tests with higher memory requirements:

java -Xms2m -Xmx8m GCTest 16 32 > tail_16_32.out
java -Xms2m -Xmx8m GCTest 16 40 > tail_16_40.out

Amazingly, both tests ran to the end without any problem. Let's look at tail_16_40.out:

Time   Total   Free   Free   Total   Act.   Dead   Over
sec.    Mem.   Mem.   Per.    Obj.   Obj.   Obj.   Head

   0    1984   1815    91%       0      0      0    169
   1    1984   1682    84%     128    128      0    174
....
  20    5484    390     7%    4992   4992      0    102
  21    5484    260     4%    5120   5120      0    104
  21    8128   2780    34%    5248   5248      0    100
  22    8128   2652    32%    5376   5376      0    100
....
  49    8128    731     8%    7296   2176   5120    101
  50    8128    601     7%    7424   2304   5120    103
  50    8128    471     5%    7552   2432   5120    105
  51    8128    347     4%    2560   2560      0   5221
  51    8128    217     2%    2688   2688      0   5223
  52    8128   4957    60%    2816   2816      0    355
  52    8128   4828    59%    2944   2944      0    356
  53    8128   4698    57%    3072   3072      0    358
....
  89    8128    530     6%    7168   2048   5120    430
  90    8128    400     4%    7296   2176   5120    432
  90    8128    270     3%    7424   2304   5120    434
  91    8128    475     5%    2432   2432      0   5221
  91    8128    345     4%    2560   2560      0   5223
  92    8128    215     2%    2688   2688      0   5225
  92    8128   5213    64%    2816   2816      0     99
  93    8128   5084    62%    2944   2944      0    100
  93    8128   4954    60%    3072   3072      0    102
....
 129    8128    785     9%    7168   2048   5120    175
 130    8128    655     8%    7296   2176   5120    177
 130    8128    526     6%    7424   2304   5120    178
 131    8128    475     5%    2432   2432      0   5221
 131    8128    345     4%    2560   2560      0   5223
 132    8128    215     2%    2688   2688      0   5225
 132    8128   5213    64%    2816   2816      0     99
 133    8128   5084    62%    2944   2944      0    100
 133    8128   4954    60%    3072   3072      0    102
....
 169    8128    785     9%    7168   2048   5120    175
 170    8128    655     8%    7296   2176   5120    177
 170    8128    526     6%    7424   2304   5120    178
 171    8128    475     5%    2432   2432      0   5221
 171    8128    345     4%    2560   2560      0   5223
 172    8128    215     2%    2688   2688      0   5225
 172    8128   5213    64%    2816   2816      0     99
 173    8128   5084    62%    2944   2944      0    100
 173    8128   4954    60%    3072   3072      0    102
....

As you can see, the garbage collector worked perfectly.

I also tried to reach 7.5 MB, but failed:

java -Xms2m -Xmx8m GCTest 16 44 > tail_16_44.out
Time   Total   Free   Free   Total   Act.   Dead   Over
sec.    Mem.   Mem.   Per.    Obj.   Obj.   Obj.   Head

   0    1984   1815    91%       0      0      0    169
   0    1984   1682    84%     128    128      0    174
   1    1984   1552    78%     256    256      0    176
....
  20    5484    390     7%    4992   4992      0    102
  20    5484    260     4%    5120   5120      0    104
  21    8128   2780    34%    5248   5248      0    100
  21    8128   2652    32%    5376   5376      0    100
....
  51    8128    272     3%    7680   2432   5248    176
  51    8128    270     3%    7680   2304   5376    178
  52    8128    268     3%    7680   2176   5504    180
  52    8128    266     3%    7680   2048   5632    182
  53    8128    136     1%    7808   2176   5632    184
Exception in thread "main" java.lang.OutOfMemoryError

It is very interesting to see that the JVM died out of memory, but there was 5632KB memory as garbage. Why did the JVM not collect garbage at that time?

Comparing with JDK 1.4.0, JDK 1.3.1 did a good job in collecting garbage. JDK 1.3.1 allowed GCTest to use up to 88% of the total memory, while JDK 1.4.0 crashed when GCTest tring to get 63% of the total memory.

Table of Contents

 About This Book

 JVM (Java Virtual Machine) Specification

 Java HotSpot VM - JVM by Oracle/Sun

 java.lang.Runtime Class - The JVM Instance

 java.lang.System Class - The Operating System

 ClassLoader Class - Class Loaders

 Class Class - Class Reflections

 JVM Runtime Data Areas

 JVM Stack, Frame and Stack Overflow

 Thread Testing Program and Result

 CPU Impact of Multi-Thread Applications

 I/O Impact of Multi-Thread Applications

 CDS (Class Data Sharing)

 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

 Micro Benchmark Tests on "float" and "double" Operations

 OpenJ9 by Eclipse Foundation

 JRockit JVM 28.2.7 by Oracle Corporation

Outdated Tutorials

 Outdated: Download and Install JDK 1.8.0 on Windows

 Outdated: Download and Install JDK 1.7.0 on Windows

 Outdated: Download and Install Java SE 1.6 Update 2

 Outdated: Installing JRockit JVM 8.0

 Outdated: Testing with LongWhile.java

 Outdated: Testing with LongSleep.java

 Outdated: GCTest.java - Garbage Collection Test Program

 Outdated: GC Test - Constant Memory Requirement

 Outdated: GC Test - Periodical Memory Requirement

 Outdated: GC Test - Releasing Old vs. New Objects

Outdated: GC Test - JDK 1.4.0 vs. JDK 1.3.1

 Outdated: GC Test - Client vs. Server

 Outdated: StringBuffer Testing Program

 Outdated: Installing JRockit JVM 7.0

 Outdated: Running JRockit JVM with Management Console

 References

 Full Version in PDF/EPUB