JDK-4158673 : Garbage Collection Algorithm Flaws
  • Type: Bug
  • Component: hotspot
  • Sub-Component: runtime
  • Affected Version: 1.1.5,1.1.6
  • Priority: P4
  • Status: Closed
  • Resolution: Fixed
  • OS: windows_nt
  • CPU: x86
  • Submitted: 1998-07-20
  • Updated: 2012-10-08
  • Resolved: 1999-12-01
The Version table provides details related to the release that this issue/RFE will be addressed.

Unresolved : Release in which this issue/RFE will be addressed.
Resolved: Release in which this issue/RFE has been resolved.
Fixed : Release in which this issue/RFE has been fixed. The release containing this fix may be available for download as an Early Access Release or a General Availability Release.

To download the current JDK release, click here.
Other
1.3.0 kestrelFixed
Related Reports
Relates :  
JDK-4065018 - (gc) Require heap compaction (return memory to OS)
Description

Name: mf23781			Date: 07/20/98


The following test program demonstrates several design and 
implementation flaws in the Win32 JVM garbage collector.  
All the test program does is try to allocate all possible memory first,
then return about one fifth of them back to the JVM, then try
to allocate all memory again.

---------- start of MemTest.java

public class MemTest {
    byte[] buf; //buffer
    MemTest next;   //points to next object in the list


    MemTest(int size, MemTest next) {
        buf = new byte[size];   //allocate requested size of memory
        this.next = next;   //add to the list

    }


    static StringBuffer s = new StringBuffer(200);  //preallocated message
buffer, not affected by OutOfMemory
    static void println(String header, int n, int size) {
        s.setLength(0); //reset buffer
        s.append(header); s.append(n); s.append(" Objects, approximate size
= "); s.append(size);

        System.out.println(s.toString());

    }


    // run "java -msNm -mxNm -verbosegc MemTest [size]" to test
    public static void main(String[] args) {
        MemTest list = null;    //all allocated objects are in one list
        int size = args.length > 0 ? Integer.parseInt(args[0]) : 1000;   
//buffer size

        int n1 = 0, n2, n3 = 0;



        try {
            for (n1 = 0; ; ++n1) //allocate all possible memory
                list = new MemTest(size, list);
        } catch (OutOfMemoryError e) {
            System.out.println("----- step1: Allocate and Out of Memory");
        }


        for (n2 = n1/5; --n2 >= 0;)    //delete and unreference n1/5 objects
from the list

            list = list.next;
        System.out.println("----- step2: n2 Objects Deleted");


        try {
            for (n3 = 0; ; ++n3) //allocate all possible memory again
                list = new MemTest(size, list);
        } catch (OutOfMemoryError e) {
            System.out.println("----- step3: Allocate and Out of Memory");
        }


        System.out.println("----- n1 = " + n1 + ", n2 = " + n1/5 + ", n3 = "
+ n3);

    }

}

---------- start of MemTest.java

[1] First, run "java -verbosegc MemTest", this generates the 
output below (This occurs on 1.1.6 and 1.1.7D):

java -verbosegc MemTest

<GC: managing allocation failure. need 1008 bytes, type=1, action=1>
<GC: freeing class java.lang.Compiler>

<GC: unloaded and freed 1 class>

<GC: freed 201 objects, 6480 bytes in 9 ms, 0% free (7216/838856)>
  <GC: init&scan: 5 ms, scan handles: 4 ms, sweep: 0 ms, compact: 0
ms>

<GC: managing allocation failure. need 1008 bytes, type=1,
action=2>
<GC: managing allocation failure. need 1008 bytes, type=1, action=3>
<GC: managing allocation failure. need 1008 bytes, type=1, action=4>
<GC: expanded object space by 274432 to 1113288 bytes, 25% free>
<GC: managing allocation failure. need 1008 bytes, type=1, action=1>
<GC: freed 5 objects, 872 bytes in 25 ms, 0% free (7216/1113288)>
  <GC: init&scan: 0 ms, scan handles: 4 ms, sweep: 1 ms, compact: 20
ms>

<GC: managing allocation failure. need 1008 bytes, type=1,
action=2>
<GC: managing allocation failure. need 1008 bytes, type=1, action=3>
<GC: managing allocation failure. need 1008 bytes, type=1, action=4>
<GC: expanded object space by 364544 to 1477832 bytes, 25% free>
<GC: managing allocation failure. need 1008 bytes, type=1, action=1>
<GC: freed 6 objects, 400 bytes in 15 ms, 0% free (1072/1477832)>
  <GC: init&scan: 1 ms, scan handles: 5 ms, sweep: 0 ms, compact: 9
ms>

<GC: managing allocation failure. need 1008 bytes, type=1,
action=2>
<GC: managing allocation failure. need 1008 bytes, type=1, action=3>
<GC: managing allocation failure. need 1008 bytes, type=1, action=4>
<GC: expanded object space by 495616 to 1973448 bytes, 25% free>
<GC: managing allocation failure. need 1008 bytes, type=1, action=1>
<GC: freed 8 objects, 512 bytes in 20 ms, 0% free (1072/1973448)>
  <GC: init&scan: 2 ms, scan handles: 5 ms, sweep: 1 ms, compact: 12
ms>

<GC: managing allocation failure. need 1008 bytes, type=1,
action=2>
<GC: managing allocation failure. need 1008 bytes, type=1, action=3>
<GC: managing allocation failure. need 1008 bytes, type=1, action=4>
<GC: expanded object space by 659456 to 2632904 bytes, 25% free>
<GC: managing allocation failure. need 1008 bytes, type=1, action=1>
<GC: freed 11 objects, 1048 bytes in 24 ms, 0% free (1072/2632904)>
  <GC: init&scan: 2 ms, scan handles: 6 ms, sweep: 0 ms, compact: 16
ms>

<GC: managing allocation failure. need 1008 bytes, type=1,
action=2>
<GC: managing allocation failure. need 1008 bytes, type=1, action=3>
<GC: managing allocation failure. need 1008 bytes, type=1, action=4>
<GC: expanded object space by 880640 to 3513544 bytes, 25% free>
<GC: managing allocation failure. need 1008 bytes, type=1, action=1>
<GC: freed 14 objects, 688 bytes in 32 ms, 0% free (1072/3513544)>
  <GC: init&scan: 2 ms, scan handles: 7 ms, sweep: 1 ms, compact: 22
ms>

<GC: managing allocation failure. need 1008 bytes, type=1,
action=2>
<GC: managing allocation failure. need 1008 bytes, type=1, action=3>
<GC: managing allocation failure. need 1008 bytes, type=1, action=4>
<GC: expanded object space by 1171456 to 4685000 bytes, 25% free>
<GC: managing allocation failure. need 1008 bytes, type=1, action=1>
<GC: freed 18 objects, 272 bytes in 43 ms, 0% free (1072/4685000)>
  <GC: init&scan: 6 ms, scan handles: 8 ms, sweep: 1 ms, compact: 28
ms>

<GC: managing allocation failure. need 1008 bytes, type=1,
action=2>
<GC: managing allocation failure. need 1008 bytes, type=1, action=3>
<GC: managing allocation failure. need 1008 bytes, type=1, action=4>
<GC: expanded object space by 1564672 to 6249672 bytes, 25% free>
<GC: managing allocation failure. need 1008 bytes, type=1, action=1>
<GC: freed 24 objects, 320 bytes in 56 ms, 0% free (1072/6249672)>
  <GC: init&scan: 5 ms, scan handles: 10 ms, sweep: 1 ms, compact: 40
ms>

<GC: managing allocation failure. need 1008 bytes, type=1,
action=2>
<GC: managing allocation failure. need 1008 bytes, type=1, action=3>
<GC: managing allocation failure. need 1008 bytes, type=1, action=4>
<GC: expanded object space by 2084864 to 8334536 bytes, 25% free>
<GC: managing allocation failure. need 1008 bytes, type=1, action=1>
<GC: freed 32 objects, 448 bytes in 73 ms, 0% free (1072/8334536)>
  <GC: init&scan: 4 ms, scan handles: 12 ms, sweep: 1 ms, compact: 56
ms>

<GC: managing allocation failure. need 1008 bytes, type=1,
action=2>
<GC: managing allocation failure. need 1008 bytes, type=1, action=3>
<GC: managing allocation failure. need 1008 bytes, type=1, action=4>
<GC: expanded object space by 2781184 to 11115720 bytes, 25% free>
<GC: managing allocation failure. need 1008 bytes, type=1, action=1>
<GC: freed 43 objects, 920 bytes in 91 ms, 0% free (1072/11115720)>
  <GC: init&scan: 3 ms, scan handles: 16 ms, sweep: 1 ms, compact: 71
ms>

<GC: managing allocation failure. need 1008 bytes, type=1,
action=2>
<GC: managing allocation failure. need 1008 bytes, type=1, action=3>
<GC: managing allocation failure. need 1008 bytes, type=1, action=4>
<GC: tried to expand object space over limit>
<GC: managing allocation failure. need 1008 bytes, type=1, action=5>
<GC: totally out of heap space>

----- step1: Allocate and Out of
Memory

----- step2: n2 Objects Deleted
<GC: managing allocation failure. need 1008 bytes, type=1, action=1>
<GC: freed 4307 objects, 2202008 bytes in 19 ms, 19% free
(2202048/11115720)>
  <GC: init&scan: 3 ms, scan handles: 13 ms, sweep: 3 ms, compact: 0
ms>

<GC: managing allocation failure. need 1008 bytes, type=1,
action=2>
<GC: managing allocation failure. need 1008 bytes, type=1, action=3>
<GC: managing allocation failure. need 1008 bytes, type=1, action=4>
<GC: expanded object space by 774144 to 11889864 bytes, 25% free>
<GC: managing allocation failure. need 1008 bytes, type=1, action=1>
<GC: freed 46 objects, 992 bytes in 100 ms, 0% free (1472/11889864)>
  <GC: init&scan: 5 ms, scan handles: 17 ms, sweep: 1 ms, compact: 77
ms>

<GC: managing allocation failure. need 1008 bytes, type=1,
action=2>
<GC: managing allocation failure. need 1008 bytes, type=1, action=3>
<GC: managing allocation failure. need 1008 bytes, type=1, action=4>
<GC: tried to expand object space over limit>
<GC: managing allocation failure. need 1008 bytes, type=1, action=5>
<GC: totally out of heap space>

----- step3: Allocate and Out of
Memory

----- n1 = 10753, n2 = 2150, n3 = 2905


It shows that the GC does not expand the memory all the way to 
the maximum mapped object heap memory (= 80% of 16M = 13421772.8 
by default).  It also shows that the object heap can still be 
expanded from 11115720 to 11889864 after the first
OutOfMemory error.
That means the first OutOfMemory is not really out of memory yet.

[2] To fully utilize the memory, one should set the -ms value 
to the same as -mx.
For example, run "java -ms16m -verbosegc MemTest" will use up 
all the default object heap spave available as shown by the 
output below:

java -ms16m -verbosegc MemTest

<GC: managing allocation failure. need 1008 bytes, type=1, action=1>
<GC: freeing class java.lang.Compiler>

<GC: unloaded and freed 1
class>
<GC: freed 393 objects, 8032 bytes in 65 ms, 0% free (8240/13421768)>
  <GC: init&scan: 7 ms, scan handles: 38 ms, sweep: 20 ms, compact: 0
ms>

<GC: managing allocation failure. need 1008 bytes, type=1,
action=2>
<GC: managing allocation failure. need 1008 bytes, type=1, action=3>
<GC: managing allocation failure. need 1008 bytes, type=1, action=4>
<GC: tried to expand object space over limit>
<GC: managing allocation failure. need 1008 bytes, type=1, action=5>
<GC: totally out of heap space>

----- step1: Allocate and Out of
Memory

----- step2: n2 Objects Deleted
<GC: managing allocation failure. need 1008 bytes, type=1, action=1>
<GC: freed 5205 objects, 2661784 bytes in 60 ms, 19% free
(2668992/13421768)>
  <GC: init&scan: 3 ms, scan handles: 34 ms, sweep: 23 ms, compact: 0
ms>

<GC: managing allocation failure. need 1008 bytes, type=1,
action=2>
<GC: managing allocation failure. need 1008 bytes, type=1, action=3>
<GC: managing allocation failure. need 1008 bytes, type=1, action=4>
<GC: tried to expand object space over limit>
<GC: managing allocation failure. need 1008 bytes, type=1, action=5>
<GC: totally out of heap space>

----- step3: Allocate and Out of
Memory

----- n1 = 12998, n2 = 2599, n3 = 0


Here we do see the object heap is expanded to its maximum.  
However, it shows that we can not allocate any MemTest 
object (n3 = 0) even after we returned 2599 objects
back to the heap.  Therefore we failed to allocate 1008 bytes 
while there are 2668992 bytes available!  The situation is 
worse with higher -ms and -mx values.
For example, when both are 32m we failed with 5344152 bytes of 
free space!!


This bug is due to Win32 JVM's 25% pre-allocation policy.  The 
GC will not succeed if the free memory collected is less than 
25% of the maximum object heap memory.
In the case of -mx=16m, the required free memory is 
13421768*0.25 = 3355442.

As we can see, the higher the -mx the higher the
requirement.

[3] In the code of the 25% pre-allocation policy mentioned above 
(see manageAllocFailure() of src\share\java\runtime\gc.c), 
FreeObjectCtr is used for the measurement. 
However, it is possible that, due to pinned blocks, even though 
the total free memory is larger than 25% of the max object heap, 
there is no one free block larger than the requested block size.
In this case, gc() will return successfully, but the allocation 
will fail again and gc() is called again, and again, which 
leads to an infinite loop.  It is not easy to create
a test case for this scenario, but we indeed have seen this 
happened before.

This was raised by the San Francisco project.

======================================================================
Comments
CONVERTED DATA BugTraq+ Release Management Values COMMIT TO FIX: generic FIXED IN: kestrel INTEGRATED IN: kestrel
14-06-2004
EVALUATION In an ideal world, we want the GC to realize that if expanding by 25% will put us beyond -mx, then the GC must expand to whatever -mx value is. Unforunately this leads to a consequence where a program that is in this "last zone" will keep repeadetly garbage collecting. For now the workaround is to use a bigger heap size. Another issue is that 25% is a little too much for handles. We should consistently define (note that I am not using the word specify) when the classic VM will produce OutOfMemoryExceptions. anand.palaniswamy@Eng 1998-08-08 The pre-allocation factor can now be user-modifiable through use of the -minf command option in 1.1.8, and -Xminf command option in 1.2, as implemented in the fix for bug 4065018 ((gc) Require heap compaction (return memory to OS)). As a result, the problem noted in Part [2] ( a fixed 25% pre-allocation policy), has been fixed. carolyn.lowenthal@Eng 1999-02-17 Here's a comment from Steffen: -------------------------- Seems to work fine on HotSpot but not on Classic (Kestrel P build) : >java -classic -version java version "1.3.0" Java(TM) 2 Runtime Environment, Standard Edition (build 1.3.0-P) Classic VM (build 1.3.0-P, native threads, nojit) >java -classic -ms32m -mx32m MemTest ----- step1: Allocate and Out of Memory ----- step2: n2 Objects Deleted ----- step3: Allocate and Out of Memory ----- n1 = 25970, n2 = 5194, n3 = 66 >java -version java version "1.3.0" Java(TM) 2 Runtime Environment, Standard Edition (build 1.3.0-P) Java HotSpot(TM) Client VM (build 1.3-P, mixed mode) >java -ms32m -mx32m MemTest ----- step1: Allocate and Out of Memory ----- step2: n2 Objects Deleted ----- step3: Allocate and Out of Memory ----- n1 = 32227, n2 = 6445, n3 = 6445 n2 == n3 meaning that all space for released objects was reallocated. --------------------------------------- This issue will never be fixed in Classic because we're not supporting that, but it isn't a problem with HotSpot, which is the new default VM implementation. I'm going to mark this as fixed on the basis the the HotSpot client VM doesn't exhibit this behavior.
11-06-2004