JDK-6405799 : JVM Exits with OutOfMemoryError for vm\utilities\growableArray.cpp
  • Type: Bug
  • Component: hotspot
  • Sub-Component: gc
  • Affected Version: 6
  • Priority: P3
  • Status: Closed
  • Resolution: Duplicate
  • OS: generic
  • CPU: generic
  • Submitted: 2006-03-29
  • Updated: 2010-08-19
  • Resolved: 2006-05-10
Related Reports
Duplicate :  
Relates :  
Description
A DESCRIPTION OF THE REGRESSION :
When the application runs out of memory, it fails with an Out Of Memory error and the JVM exits.

REPRODUCIBLE TESTCASE OR STEPS TO REPRODUCE:

The following classes should be compiled and run with the option:

java -Xmx1000M oom.TimestampParser

The app will run and the JVM will exit with the OOM error, shown in the Actual Result section of this form.

Note that running this same test with the VMArg -Xmx800M causes the app to run forever.  I don't see the OOM crash, and debug shows no further objects put into the mapTimestamp object.

Running with VMArg -Xmx200M causes the following 'normal' stack trace:

Exception in thread "main" java.lang.OutOfMemoryError: Java heap space
	at java.util.Arrays.copyOf(Arrays.java:2361)
	at java.util.Arrays.copyOf(Arrays.java:2335)
	at java.util.ArrayList.ensureCapacity(ArrayList.java:167)
	at java.util.ArrayList.add(ArrayList.java:351)
	at oom.TimestampParser.parse(TimestampParser.java:28)
	at oom.TimestampParser.main(TimestampParser.java:13)


===================
File oom/TimestampParser.java
===================

package oom;

import java.util.ArrayList;
import java.util.StringTokenizer;
import java.util.TreeMap;

public class TimestampParser {

    public static void main(String[] args) {

        TimestampParser parser = new TimestampParser();

        parser.parse();

    }

    public void parse() {

        String line = "1140584661015 : AFANDONBRD : PP10085 : PP10085, 2006/02/22 05:04:22:234, null, null, AFANDONBRD:Rep, EquipmentDataConvertor.format1(AFANDONBRD:Rep), 1140584662234";
        TreeMap<String, ArrayList<Timestamp>> mapTimestamp = new TreeMap<String, ArrayList<Timestamp>>();
        Timestamp ts = new Timestamp(new StringTokenizer(line, ","));

        mapTimestamp.put(ts.appID, new ArrayList<Timestamp>());

        do {
            ts = new Timestamp(new StringTokenizer(line, ","));
            ArrayList<Timestamp> al = mapTimestamp.get(ts.appID);
            al.add(ts);

        } while (true);
    }

}

=======================
File oom/Timestamp.java
=======================

package oom;

import java.util.NoSuchElementException;
import java.util.StringTokenizer;


public class Timestamp {
    
    private String threadID;
    private String date;
    private String reqType;
    protected String appID;
    private long threadStartTime;

    /**
     *
     */
    public Timestamp(StringTokenizer st) {
        super();
        try {
            // Trace ID
            threadID = st.nextToken();
            threadStartTime = Long.parseLong(threadID.substring(0,13));
            
            date = st.nextToken();
            reqType = st.nextToken();
            appID = st.nextToken().trim();
        } catch (NumberFormatException ex ) {
            System.out.println("WARNING: Cannot format number.  Current line date is " + date);
        } catch (NoSuchElementException ex ) {
            System.out.println("WARNING: No token or token problem.  Current line date is " + date);
        }
    }

}


=======================================================

System Information report written at: 27/02/2006 16:37:27
[System Summary]

Item	Value
OS Name	Microsoft Windows 2000 Professional
Version	5.0.2195 Service Pack 4 Build 2195
OS Manufacturer	Microsoft Corporation
System Manufacturer	IBM
System Model	830531G
System Type	X86-based PC
Processor	x86 Family 15 Model 2 Stepping 4 GenuineIntel ~2259 Mhz
BIOS Version	PhoenixBIOS 4.0 Release 6.0 for IBM NetVista.
Windows Directory	C:\WINNT
System Directory	C:\WINNT\system32
Boot Device	\Device\Harddisk0\Partition1
Locale	United States
Time Zone	GMT Standard Time
  Total Physical Memory	2,095,088 KB
Available Physical Memory	1,537,484 KB
  Total Virtual Memory	5,056,304 KB
Available Virtual Memory	3,552,464 KB
Page File Space	2,961,216 KB
Page File	D:\pagefile.sys


RELEASE LAST WORKED:
5.0 Update 6

RELEASE TEST FAILS:
mustang-beta

EXPECTED VERSUS ACTUAL BEHAVIOR :
EXPECTED -
A normal java.lang.OutOfMemory error.  The JVM and application should still be running.
ACTUAL -
#
# An unexpected error has been detected by Java Runtime Environment:
#
# java.lang.OutOfMemoryError: requested 167772160 bytes for GrET in C:\BUILD_AREA\jdk6\hotspot\src\share\vm\utilities\growableArray.cpp. Out of swap space?
#
#  Internal Error (414C4C4F434154494F4E0E494E4C494E450E4850500017), pid=2540, tid=2564
#
# Java VM: Java HotSpot(TM) Client VM (1.6.0-beta2-b73 mixed mode)
# An error report file with more information is saved as hs_err_pid2540.log
#
# If you would like to submit a bug report, please visit:
#   http://java.sun.com/webapps/bugreport/crash.jsp
#

hs_err_pid2540.log contains:

#
# An unexpected error has been detected by Java Runtime Environment:
#
# java.lang.OutOfMemoryError: requested 167772160 bytes for GrET in C:\BUILD_AREA\jdk6\hotspot\src\share\vm\utilities\growableArray.cpp. Out of swap space?
#
#  Internal Error (414C4C4F434154494F4E0E494E4C494E450E4850500017), pid=2540, tid=2564
#
# Java VM: Java HotSpot(TM) Client VM (1.6.0-beta2-b73 mixed mode)
# If you would like to submit a bug report, please visit:
#   http://java.sun.com/webapps/bugreport/crash.jsp
#

---------------  T H R E A D  ---------------

Current thread (0x471c0c00):  VMThread [id=2564]

Stack: [0x471e0000,0x47230000)
[error occurred during error reporting, step 110, id 0xc0000005]

VM_Operation (0x0080f9c0): generation collection for allocation, mode: safepoint, requested by thread 0x00249000


---------------  P R O C E S S  ---------------

Java Threads: ( => current thread )
  0x471d9000 JavaThread "Low Memory Detector" daemon [_thread_blocked, id=2932]
  0x471d6800 JavaThread "CompilerThread0" daemon [_thread_blocked, id=2396]
  0x471d5800 JavaThread "Attach Listener" daemon [_thread_blocked, id=1776]
  0x471d4800 JavaThread "Signal Dispatcher" daemon [_thread_blocked, id=2728]
  0x471c8000 JavaThread "Finalizer" daemon [_thread_blocked, id=1100]
  0x471c3c00 JavaThread "Reference Handler" daemon [_thread_blocked, id=724]
  0x00249000 JavaThread "main" [_thread_blocked, id=2364]

Other Threads:
=>0x471c0c00 VMThread [id=2564]
  0x47428400 WatcherThread [id=2868]

VM state:at safepoint (normal execution)

VM Mutex/Monitor currently owned by a thread:  ([mutex/lock_event])
[0x00247b00/0x0000230c] Threads_lock - owner thread: 0x471c0c00
[0x00247c80/0x000022d0] Heap_lock - owner thread: 0x00249000

Heap
 def new generation   total 58240K, used 6464K [0x028c0000, 0x067f0000, 0x075a0000)
  eden space 51776K,   0% used [0x028c0000, 0x028c0000, 0x05b50000)
  from space 6464K, 100% used [0x061a0000, 0x067f0000, 0x067f0000)
  to   space 6464K,   0% used [0x05b50000, 0x05b50000, 0x061a0000)
 tenured generation   total 799360K, used 799304K [0x075a0000, 0x38240000, 0x410c0000)
   the space 799360K,  99% used [0x075a0000, 0x38232010, 0x38232200, 0x38240000)
 compacting perm gen  total 12288K, used 1664K [0x410c0000, 0x41cc0000, 0x450c0000)
   the space 12288K,  13% used [0x410c0000, 0x412602d8, 0x41260400, 0x41cc0000)
No shared spaces configured.

Dynamic libraries:
0x00400000 - 0x00411000 	D:\java\jdk1.6.0\bin\javaw_impl.exe
0x77f80000 - 0x77ffc000 	C:\WINNT\system32\ntdll.dll
0x6d010000 - 0x6d01a000 	D:\java\jdk1.6.0\bin\jli.dll
0x7c340000 - 0x7c396000 	D:\java\jdk1.6.0\bin\MSVCR71.dll
0x7c570000 - 0x7c623000 	C:\WINNT\system32\KERNEL32.dll
0x7c2d0000 - 0x7c335000 	C:\WINNT\system32\ADVAPI32.dll
0x77d30000 - 0x77da8000 	C:\WINNT\system32\RPCRT4.dll
0x77e10000 - 0x77e79000 	C:\WINNT\system32\USER32.dll
0x77f40000 - 0x77f7c000 	C:\WINNT\system32\GDI32.dll
0x75e60000 - 0x75e7a000 	C:\WINNT\system32\IMM32.DLL
0x6d790000 - 0x6d9ca000 	D:\java\jdk1.6.0\jre\bin\client\jvm.dll
0x77570000 - 0x775a0000 	C:\WINNT\system32\WINMM.dll
0x6d300000 - 0x6d308000 	D:\java\jdk1.6.0\jre\bin\hpi.dll
0x690a0000 - 0x690ab000 	C:\WINNT\system32\PSAPI.DLL
0x6d740000 - 0x6d74c000 	D:\java\jdk1.6.0\jre\bin\verify.dll
0x6d390000 - 0x6d3af000 	D:\java\jdk1.6.0\jre\bin\java.dll
0x6d780000 - 0x6d78f000 	D:\java\jdk1.6.0\jre\bin\zip.dll

VM Arguments:
jvm_args: -Xmx1000M
java_command: oom.TimestampParser
Launcher Type: SUN_STANDARD

Environment Variables:
JAVA_HOME=d:\java\jdk1.5.0_06
CLASSPATH=D:\Program Files\IBM\WebSphere MQ\Java\lib\providerutil.jar;D:\Program Files\IBM\WebSphere MQ\Java\lib\com.ibm.mqjms.jar;D:\Program Files\IBM\WebSphere MQ\Java\lib\ldap.jar;D:\Program Files\IBM\WebSphere MQ\Java\lib\jta.jar;D:\Program Files\IBM\WebSphere MQ\Java\lib\jndi.jar;D:\Program Files\IBM\WebSphere MQ\Java\lib\jms.jar;D:\Program Files\IBM\WebSphere MQ\Java\lib\connector.jar;D:\Program Files\IBM\WebSphere MQ\Java\lib\fscontext.jar;D:\Program Files\IBM\WebSphere MQ\Java\lib\com.ibm.mq.jar;.;D:\PROGRA~1\SQLLIB\java\db2java.zip;D:\PROGRA~1\SQLLIB\java\db2jcc.jar;D:\PROGRA~1\SQLLIB\java\sqlj.zip;D:\PROGRA~1\SQLLIB\bin;D:\PROGRA~1\SQLLIB\java\common.jar;D:\PROGRA~1\SQLLIB\java\db2jcc_license_cisuz.jar;D:\PROGRA~1\SQLLIB\java\db2jcc_license_cu.jar
PATH=D:\Perl\bin\;D:\Program Files\IBM\WebSphere MQ\Java\lib;d:\Program Files\IBM\LDAP\bin;C:\WINNT\system32;C:\WINNT;C:\WINNT\System32\Wbem;d:\Program Files\cvsnt;D:\Program Files\IBM\WebSphere MQ\bin;D:\Program Files\IBM\WebSphere MQ\tools\c\samples\bin;D:\PROGRA~1\SQLLIB\BIN;D:\PROGRA~1\SQLLIB\FUNCTION;D:\PROGRA~1\SQLLIB\SAMPLES\REPL;D:\PROGRA~1\ATT\Graphviz\bin;D:\PROGRA~1\ATT\Graphviz\bin\tools;D:\PROGRA~1\XRay;d:\Program Files\ZipGenius 6\;d:\Program Files\Subversion\bin;d:\Program Files\Rational\common;d:\Program Files\Win 2000 Support Tools\;C:\Program Files\CVSNT\;D:\Program Files\CVSNT\;d:\cygwin\bin;
USERNAME=edwyerk
OS=Windows_NT
PROCESSOR_IDENTIFIER=x86 Family 15 Model 2 Stepping 4, GenuineIntel



---------------  S Y S T E M  ---------------

OS: Windows 2000 Build 2195 Service Pack 4

CPU:total 1 family 15, cmov, cx8, fxsr, mmx, sse, sse2

Memory: 4k page, physical 2095088k(396976k free), swap 2961216k(850896k free)

vm_info: Java HotSpot(TM) Client VM (1.6.0-beta2-b73) for windows-x86, built on Feb 23 2006 00:25:11 by "java_re" with unknown MS VC++:1310





OBSERVED APPLICATION IMPACT:
The application should fail gracefully with an OOM error, but still be visible to the user.  When running under javaw, the application will exit with no visible reason.

Comments
EVALUATION This is *not* a regression. The code has always behaved like this. The particular points at which a given shape and size of heap will fall over may have moved from release to release, but the underlying problem has been there for years.
09-05-2006

EVALUATION Well, this fix turned out not to be as well understood as I had hoped. By adding the call to follow_stack to mark_and_follow, we trade recursion for marking stack space. That's a good trade for the sample program, but a bad trade for (a) other adversarial programs and (b) real applications. The change worked fine on x86, where the C++ stack frames are small, but failed with stack overflows on SPARC, where the C++ stack frames are huge relative to marking stack entries. Basically we are back to 4396719, a previously unsolved problem. I think we need to rethink the use of GrowableArray<T> for the marking stack. In particular, we could be using a small chunked data structure as a stack, since we know we only push and pop from one end of it. There's no reason to use the growth policy of GrowableArray, which causes us waste lots of memory (25% of the GrowableArray is unused), and to need large contiguous pieces of address space. Writing a new data structure for the marking stack will have to wait for Dolphin, in order to get the kind of testing a change like this merits. I've opened 6423256 to track that change.
08-05-2006

EVALUATION I think we are missing a call to follow_stack() in MarkSweep::mark_and_follow(oop*) and friends.
18-04-2006