JVM Tutorials - Herong's Tutorial Examples
Dr. Herong Yang, Version 4.10

GC Test - Periodical Memory Requirement

This section provides a tutorial example on testing garbage collection with a periodical memory requirement.

In this test, I ran the same program un J2SDK 1.4.0_02 with a different parameter:

java -Xms2m -Xmx8m GCTest 16 8 > tail_16_08.out

I got the following output:

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

   0    1984   1727    87%       0      0      0    257 
   0    1984   1593    80%     128    128      0    263 
   1    1984   1464    73%     256    256      0    264 
   1    1984   1334    67%     384    384      0    266 
....                                                  
   5    1984    425    21%    1280   1280      0    279 
   5    1984    296    14%    1408   1408      0    280 
   6    3124   1451    46%    1536   1408    128    137 
   6    3124   1450    46%    1536   1536      0    138 
....                                                  
  10    3124    412    13%    2560   2560      0    152 
  11    3124    282     9%    2688   2688      0    154 
  11    5256   2303    43%    2816   2816      0    137 
  12    5256   2173    41%    2944   2944      0    139 
  12    5256   2043    38%    3072   3072      0    141 
....                                                  
  27    5256    329     6%    4736   2688   2048    191 
  27    5256    199     3%    4864   2816   2048    193 
  28    8128   2998    36%    2944   2944      0   2186
  28    8128   2868    35%    3072   3072      0   2188
  29    8128   2866    35%    3072   2944    128   2190
  29    8128   2864    35%    3072   2816    256   2192
  30    8128   2863    35%    3072   2688    384   2193
  30    8128   2861    35%    3072   2560    512   2195
....

  47    8128    754     9%    5120   2304   2816   2254
  48    8128    752     9%    5120   2176   2944   2256
  48    8128    750     9%    5120   2048   3072   2258
  49    8128    620     7%    5248   2176   3072   2260
  49    8128    491     6%    5376   2304   3072   2261
  50    8128    361     4%    5504   2432   3072   2263
  50    8128    231     2%    5632   2560   3072   2265
  51    8128   2230    27%    2688   2688      0   3210
  51    8128   2100    25%    2816   2816      0   3212
  52    8128   1970    24%    2944   2944      0   3214
  52    8128   1840    22%    3072   3072      0   3216
  53    8128   1839    22%    3072   2944    128   3217
  53    8128   1837    22%    3072   2816    256   3219
  54    8128   1835    22%    3072   2688    384   3221
  54    8128   1833    22%    3072   2560    512   3223
....
  66    8128    385     4%    4480   2432   2048   3263
  66    8128    256     3%    4608   2560   2048   3264
  67    8128   3254    40%    2688   2688      0   2186
  67    8128   3124    38%    2816   2816      0   2188
  68    8128   2995    36%    2944   2944      0   2189
  68    8128   2865    35%    3072   3072      0   2191
  69    8128   2863    35%    3072   2944    128   2193
  69    8128   2861    35%    3072   2816    256   2195
  70    8128   2860    35%    3072   2688    384   2196
  70    8128   2858    35%    3072   2560    512   2198
....
  90    8128    358     4%    5504   2432   3072   2266
  90    8128    228     2%    5632   2560   3072   2268
  91    8128   2230    27%    2688   2688      0   3210
  91    8128   2100    25%    2816   2816      0   3212
  92    8128   1970    24%    2944   2944      0   3214
  92    8128   1840    22%    3072   3072      0   3216
  93    8128   1839    22%    3072   2944    128   3217
  93    8128   1837    22%    3072   2816    256   3219
  94    8128   1835    22%    3072   2688    384   3221
  94    8128   1833    22%    3072   2560    512   3223
....

This time, the program allocated 2048KB of objects during the initialization phase. Then it started the test loop phase of allocating 1024KB of objects before release the same amount of objects.

By looking at the output, the periodic change of memory requirement between 2048KB and 3072KB had no impact on the garbage collection process.

Then I increased the memory requirement with:

java -Xms2m -Xmx8m GCTest 16 16 > tail_16_16.out

I got the following output:

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

   0    1984   1727    87%       0      0      0    257 
   0    1984   1593    80%     128    128      0    263 
   1    1984   1464    73%     256    256      0    264 
   1    1984   1334    67%     384    384      0    266 
   2    1984   1204    60%     512    512      0    268 
   2    1984   1074    54%     640    640      0    270 
....                                                 
  15    5256   1265    24%    3840   3840      0    151 
  16    5256   1135    21%    3968   3968      0    153 
  16    5256   1005    19%    4096   4096      0    155 
  17    5256   1003    19%    4096   3968    128    157 
  17    5256   1002    19%    4096   3840    256    158 
....                                                  
  26    5256    588    11%    4480   2432   2048    188 
  26    5256    459     8%    4608   2560   2048    189 
  27    5256    329     6%    4736   2688   2048    191 
  27    5256    199     3%    4864   2816   2048    193 
  28    8128   2998    36%    2944   2944      0   2186
  28    8128   2868    35%    3072   3072      0   2188
  29    8128   2738    33%    3200   3200      0   2190
  29    8128   2608    32%    3328   3328      0   2192
....                                                  
  45    8128    634     7%    5248   3200   2048   2246
  45    8128    504     6%    5376   3328   2048   2248
  46    8128    375     4%    5504   3456   2048   2249
  46    8128    245     3%    5632   3584   2048   2251
  47    8128   2230    27%    3712   3712      0   2186
  47    8128   2100    25%    3840   3840      0   2188
  48    8128   1970    24%    3968   3968      0   2190
  48    8128   1840    22%    4096   4096      0   2192
....
  61    8128    645     7%    5248   3200   2048   2235
  62    8128    515     6%    5376   3328   2048   2237
  62    8128    385     4%    5504   3456   2048   2239
  63    8128    256     3%    5632   3584   2048   2240
  63    8128   2230    27%    3712   3712      0   2186
  64    8128   2100    25%    3840   3840      0   2188
  64    8128   1970    24%    3968   3968      0   2190
  65    8128   1840    22%    4096   4096      0   2192
....                                                  
  77    8128    645     7%    5248   3200   2048   2235
  78    8128    515     6%    5376   3328   2048   2237
  78    8128    385     4%    5504   3456   2048   2239
  79    8128    256     3%    5632   3584   2048   2240
  79    8128   2230    27%    3712   3712      0   2186
  80    8128   2100    25%    3840   3840      0   2188
  80    8128   1970    24%    3968   3968      0   2190
  81    8128   1840    22%    4096   4096      0   2192
....                                                  
  93    8128    645     7%    5248   3200   2048   2235
  94    8128    515     6%    5376   3328   2048   2237
  94    8128    385     4%    5504   3456   2048   2239
  95    8128    256     3%    5632   3584   2048   2240
  95    8128   2230    27%    3712   3712      0   2186
  96    8128   2100    25%    3840   3840      0   2188
  96    8128   1970    24%    3968   3968      0   2190
  97    8128   1840    22%    4096   4096      0   2192
....                                                  
 109    8128    645     7%    5248   3200   2048   2235
 110    8128    515     6%    5376   3328   2048   2237
 110    8128    385     4%    5504   3456   2048   2239
 111    8128    255     3%    5632   3584   2048   2241
 111    8128   2230    27%    3712   3712      0   2186
 112    8128   2100    25%    3840   3840      0   2188
 112    8128   1970    24%    3968   3968      0   2190
 113    8128   1840    22%    4096   4096      0   2192
....

The garbage collection had no problem with the memory requirement changing between 2048KB and 4096KB.

Notice that the free memory right garbage collection is also 27%.

Then I increased the memory requirement again with:

java -Xms2m -Xmx8m GCTest 16 24 > tail_16_24.out

I got the following output:

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

   0    1984   1727    87%       0      0      0   257
   0    1984   1593    80%     128    128      0   263
   1    1984   1464    73%     256    256      0   264
   1    1984   1334    67%     384    384      0   266
....                                             
  10    3124    541    17%    2432   2432      0   151
  10    3124    412    13%    2560   2560      0   152
  11    3124    282     9%    2688   2688      0   154
  11    5256   2303    43%    2816   2816      0   137
  12    5256   2173    41%    2944   2944      0   139
....                                               
  19    5256    356     6%    4736   4736      0   164
  19    5256    226     4%    4864   4864      0   166
  20    8128   2998    36%    4992   4992      0   138
  20    8128   2868    35%    5120   5120      0   140
  21    8128   2866    35%    5120   4992    128   142
  21    8128   2864    35%    5120   4864    256   144
  22    8128   2863    35%    5120   4736    384   145
  22    8128   2861    35%    5120   4608    512   147
  23    8128   2859    35%    5120   4480    640   149
  23    8128   2858    35%    5120   4352    768   150
  24    8128   2856    35%    5120   4224    896   152
  24    8128   2854    35%    5120   4096   1024   154
  25    8128   2852    35%    5120   3968   1152   156
  25    8128   2851    35%    5120   3840   1280   157
  26    8128   2849    35%    5120   3712   1408   159
  26    8128   2847    35%    5120   3584   1536   161
  27    8128   2846    35%    5120   3456   1664   162
  27    8128   2844    34%    5120   3328   1792   164
  28    8128   2842    34%    5120   3200   1920   166
  28    8128   2840    34%    5120   3072   2048   168
  29    8128   2839    34%    5120   2944   2176   169
  29    8128   2837    34%    5120   2816   2304   171
  30    8128   2835    34%    5120   2688   2432   173
  30    8128   2834    34%    5120   2560   2560   174
  31    8128   2832    34%    5120   2432   2688   176
  31    8128   2830    34%    5120   2304   2816   178
  32    8128   2828    34%    5120   2176   2944   180
  32    8128   2827    34%    5120   2048   3072   181
  33    8128   2697    33%    5248   2176   3072   183
  33    8128   2567    31%    5376   2304   3072   185
  34    8128   2437    29%    5504   2432   3072   187
  34    8128   2308    28%    5632   2560   3072   188
  35    8128   2178    26%    5760   2688   3072   190
  35    8128   2048    25%    5888   2816   3072   192
  36    8128   1918    23%    6016   2944   3072   194
  36    8128   1788    21%    6144   3072   3072   196
  37    8128   1659    20%    6272   3200   3072   197
  37    8128   1529    18%    6400   3328   3072   199
  38    8128   1399    17%    6528   3456   3072   201
  38    8128   1269    15%    6656   3584   3072   203
  39    8128   1140    14%    6784   3712   3072   204
  39    8128   1010    12%    6912   3840   3072   206
  40    8128    880    10%    7040   3968   3072   208
  40    8128    750     9%    7168   4096   3072   210
  41    8128    620     7%    7296   4224   3072   212
  41    8128    491     6%    7424   4352   3072   213
  42    8128    361     4%    7552   4480   3072   215
  42    8128    231     2%    7680   4608   3072   217
Exception in thread "main" java.lang.OutOfMemoryError

Obviously, we had a problem here. My program crashed at second 42 with the "out of memory" exception. At that time, the free memory decreased to 2%. But there were 3072KB of dead objects that could be collected to gain more free memory.

Why the JVM did not collect the dead objects? Can anyone help to explain?

I believe the answer is related my guessed rule that the JVM will reserve the same amount of memory as collected garbages. At second 42 in our test, 8128 (total memory) - 4608 (active objects) - 3072 (reserved memory) = 448 (free memory), not enough to work with.

Last update: 2003.

Table of Contents

 About This Book

 Download and Install Java SE 1.6 Update 2

 java.lang.Runtime Class - The JVM Instance

 java.lang.System Class - The Operating System

 ClassLoader Class - Class Loaders

 Class Class - Class Reflections

 Sun's JVM - Java HotSpot VM

 JRockit JVM 7.0 by BEA Systems

 JRockit JVM 8.0 by BEA Systems

 Memory Management Rules and Tests

Garbage Collection Tests

 GCTest.java - Garbage Collection Test Program

 GC Test - Constant Memory Requirement

GC Test - Periodical Memory Requirement

 GC Test - Releasing Old vs. New Objects

 GC Test - JDK 1.4.0 vs. JDK 1.3.1

 GC Test - Client vs. Server

 GC Test - JDK 1.6.0 vs. JDK 1.4.0

 Stack Overflow Tests

 Thread Testing Program and Result

 StringBuffer Testing Program and Result

 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

 References

 PDF Printing Version

Dr. Herong Yang, updated in 2010
GC Test - Periodical Memory Requirement