JVM Tutorials - Herong's Tutorial Examples - v5.13, by Herong Yang
Archived: GC Test - Constant Memory Requirement
This section provides a tutorial example on testing garbage collection with a constant memory requirement.
I compiled GCTest.java with J2SDK 1.4.0_02, and executed it with:
herong> java -Xms2m -Xmx8m GCTest 16 1 > tail_16_01.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 1592 80% 128 128 0 264 1 1984 1462 73% 256 256 0 266 2 1984 1332 67% 384 384 0 268 2 1984 1202 60% 512 512 0 270 .... 8 3124 1062 33% 1920 1920 0 142 8 3124 932 29% 2048 2048 0 144 9 3124 803 25% 2176 2176 0 145 9 3124 801 25% 2176 2048 128 147 10 3124 671 21% 2304 2176 128 149 10 3124 669 21% 2304 2048 256 151 11 3124 540 17% 2432 2176 256 152 11 3124 538 17% 2432 2048 384 154 12 3124 408 13% 2560 2176 384 156 12 3124 406 12% 2560 2048 512 158 13 3124 277 8% 2688 2176 512 159 13 3124 275 8% 2688 2048 640 161 14 5256 2303 43% 2176 2176 0 777 14 5256 2301 43% 2176 2048 128 779 15 5256 2171 41% 2304 2176 128 781 15 5256 2170 41% 2304 2048 256 782 16 5256 2040 38% 2432 2176 256 784 16 5256 2038 38% 2432 2048 384 786 .... 29 5256 330 6% 4096 2176 1920 830 29 5256 329 6% 4096 2048 2048 831 30 5256 199 3% 4224 2176 2048 833 30 5256 197 3% 4224 2048 2176 835 31 7848 3358 42% 2176 2176 0 2314 31 7848 3357 42% 2176 2048 128 2315 32 7848 3227 41% 2304 2176 128 2317 32 7848 3225 41% 2304 2048 256 2319 33 7848 3095 39% 2432 2176 256 2321 33 7848 3094 39% 2432 2048 384 2322 .... 54 7848 334 4% 5120 2176 2944 2394 55 7848 332 4% 5120 2048 3072 2396 55 7848 203 2% 5248 2176 3072 2397 56 7848 201 2% 5248 2048 3200 2399 56 8128 2614 32% 2176 2176 0 3338 57 8128 2612 32% 2176 2048 128 3340 57 8128 2482 30% 2304 2176 128 3342 58 8128 2481 30% 2304 2048 256 3343 58 8128 2351 28% 2432 2176 256 3345 59 8128 2349 28% 2432 2048 384 3347 .... 73 8128 378 4% 4352 2176 2176 3398 74 8128 377 4% 4352 2048 2304 3399 74 8128 247 3% 4480 2176 2304 3401 75 8128 245 3% 4480 2048 2432 3403 75 8128 3382 41% 2176 2176 0 2570 76 8128 3381 41% 2176 2048 128 2571 76 8128 3251 39% 2304 2176 128 2573 77 8128 3249 39% 2304 2048 256 2575 77 8128 3119 38% 2432 2176 256 2577 78 8128 3118 38% 2432 2048 384 2578 .... 98 8128 358 4% 5120 2176 2944 2650 99 8128 356 4% 5120 2048 3072 2652 99 8128 226 2% 5248 2176 3072 2654 100 8128 225 2% 5248 2048 3200 2655 100 8128 2614 32% 2176 2176 0 3338 101 8128 2612 32% 2176 2048 128 3340 101 8128 2482 30% 2304 2176 128 3342 102 8128 2481 30% 2304 2048 256 3343 102 8128 2351 28% 2432 2176 256 3345 103 8128 2349 28% 2432 2048 384 3347 .... 117 8128 378 4% 4352 2176 2176 3398 118 8128 376 4% 4352 2048 2304 3400 118 8128 247 3% 4480 2176 2304 3401 119 8128 245 3% 4480 2048 2432 3403 119 8128 3382 41% 2176 2176 0 2570 120 8128 3380 41% 2176 2048 128 2572 120 8128 3251 39% 2304 2176 128 2573 121 8128 3249 39% 2304 2048 256 2575 121 8128 3119 38% 2432 2176 256 2577 122 8128 3117 38% 2432 2048 384 2579 .... 142 8128 358 4% 5120 2176 2944 2650 143 8128 356 4% 5120 2048 3072 2652 143 8128 226 2% 5248 2176 3072 2654 144 8128 224 2% 5248 2048 3200 2656 144 8128 2614 32% 2176 2176 0 3338 145 8128 2612 32% 2176 2048 128 3340 145 8128 2482 30% 2304 2176 128 3342 146 8128 2481 30% 2304 2048 256 3343 146 8128 2351 28% 2432 2176 256 3345 147 8128 2349 28% 2432 2048 384 3347 .... 161 8128 378 4% 4352 2176 2176 3398 162 8128 376 4% 4352 2048 2304 3400 162 8128 247 3% 4480 2176 2304 3401 163 8128 245 3% 4480 2048 2432 3403 163 8128 3382 41% 2176 2176 0 2570 164 8128 3380 41% 2176 2048 128 2572 164 8128 3251 39% 2304 2176 128 2573 165 8128 3249 39% 2304 2048 256 2575 165 8128 3119 38% 2432 2176 256 2577 166 8128 3117 38% 2432 2048 384 2579 .... 186 8128 358 4% 5120 2176 2944 2650 187 8128 356 4% 5120 2048 3072 2652 187 8128 226 2% 5248 2176 3072 2654 188 8128 224 2% 5248 2048 3200 2656 188 8128 2614 32% 2176 2176 0 3338 189 8128 2612 32% 2176 2048 128 3340 189 8128 2482 30% 2304 2176 128 3342 190 8128 2481 30% 2304 2048 256 3343 190 8128 2351 28% 2432 2176 256 3345 191 8128 2349 28% 2432 2048 384 3347 .... 250 8128 376 4% 4352 2048 2304 3400 250 8128 247 3% 4480 2176 2304 3401 251 8128 245 3% 4480 2048 2432 3403 251 8128 3382 41% 4608 2048 2560 138 252 8128 3380 41% 2176 2176 0 2572 252 8128 3379 41% 2176 2048 128 2573 253 8128 3249 39% 2304 2176 128 2575 253 8128 3247 39% 2304 2048 256 2577 254 8128 3117 38% 2432 2176 256 2579 254 8128 3116 38% 2432 2048 384 2580 ....
As the output shows, the JVM (HotSpot) started with 2MB of total memory, with about 87% of free memory. As the program starts to allocate objects during the initialization phase, free memory starts to decrease. I don't know why.
When the free memory decreased to 14%, about 294KB, still enough for 2 more objects, the JVM decided to request more total memory from the operating system.
At second 8, the program finished the initialization phase, and entered into the loop testing phase. It started to allocate one object, then release the oldest object from the list. The released objects became dead objects and waiting to be collected as garbage.
As you can see from the output, the dead objects were not immediately collected by the garbage collector. The first collection of dead objects happened at second 14, when free memory decreased to 8%, about 275KB. The JVM collected the dead objects and request more total memory at about the same time. I don't know why.
As the program continued to repeatedly allocate and release objects, dead objects were accumulated again, and the free memory continued to decrease. When free memory decreased to 3%, 197KB, at second 30, the JVM decided to collect dead objects and request more total memory again.
The next time the JVM decided to collect dead objects and request more total memory happened at second 56. Total memory reached 8128KB, about the same as the maximum memory size specified by the command line option, -Xmx8m.
When the free memory decreased again to 3% at second 75, the JVM could not get any more total memory. It only collected the dead objects, and raised the free memory back to 41%.
While reviewing the rest of the output, I noticed that at second 100, the JVM collected the dead objects with 3200KB of memory. However, the free memory reported by the JVM only increased by 2389KB (2614KB-225KB). So where is the other 800KB collected from the dead objects? Can any one explain this?
19 seconds later, the JVM collected only 2432KB of dead objects, but the free memory increased by 3137KB. This time, about 700KB more memory comes out from nowhere. May be certain amount of memory was reserved at the previous garbage collection time.
After looking at the over head memory size, I found that each time the JVM collected garbage, it also reserved the same amount of memory as the garbage collected. This explains well why at second 100, 800KB of collected memory was not giving back as free memory. At that time, 8128 (total memory) - 2176 (active objects) - 3338 (reserved memory) = 2614 (free memory), where the reserved memory (3338KB) is about the same as the collected memory (3200KB).
Couple of quick observations:
Table of Contents
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 Stack, Frame and Stack Overflow
Thread Testing Program and Result
CPU Impact of Multi-Thread Applications
I/O Impact of Multi-Thread Applications
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
JRockit JVM 28.2.7 by Oracle Corporation
archived: Download and Install JDK 14 on macOS
Archived: Download and Install Latest JDK 10 on Windows
Archived: Download and Install JDK 1.8.0 on Windows
Archived: Download and Install JDK 1.7.0 on Windows
Archived: Download and Install Java SE 1.6 Update 2
Archived: Installing JRockit JVM 8.0
Archived: Testing with LongWhile.java
Archived: Testing with LongSleep.java
Archived: GCTest.java - Garbage Collection Test Program
►Archived: GC Test - Constant Memory Requirement
Archived: GC Test - Periodical Memory Requirement
Archived: GC Test - Releasing Old vs. New Objects
Archived: GC Test - JDK 1.4.0 vs. JDK 1.3.1
Archived: GC Test - Client vs. Server
Archived: StringBuffer Testing Program
Archived: Installing JRockit JVM 7.0