JDK-8226536 : Catch OOM from deopt that fails rematerializing objects
  • Type: Bug
  • Component: hotspot
  • Sub-Component: compiler
  • Affected Version: 11,13,14
  • Priority: P2
  • Status: Resolved
  • Resolution: Fixed
  • OS: generic
  • CPU: generic
  • Submitted: 2019-06-20
  • Updated: 2022-10-07
  • Resolved: 2019-07-10
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.
JDK 11 JDK 13 JDK 14
11.0.10-oracleFixed 13 b30Fixed 14Fixed
Related Reports
Relates :  
JDK-8273095 - vmTestbase/vm/mlvm/anonloader/stress/oome/heap/Test.java fails with "wrong OOME"
Relates :  
JDK-8227309 - Handle OOM when rematerializing objects less surprising
Relates :  
JDK-8192647 - GClocker induced GCs can starve threads requiring memory leading to OOME
Description
A couple of test failed in the JDK-13 CI:

vmTestbase/gc/lock/malloc/malloclock02/TestDescription.java
vmTestbase/gc/lock/jniref/jnireflock01/TestDescription.java

with messages that look like this:

Exception in
gc.lock.LockerTest$Worker@16e53b61
Exception in
gc.lock.LockerTest$Worker@7440ac46
java.lang.OutOfMemoryError: Java heap space: failed reallocation of scalar replaced objects
Exception in
java.lang.OutOfMemoryError: Java heap space: failed reallocation of scalar replaced objects
Exception in
gc.lock.LockerTest$Worker@486b1597
java.lang.OutOfMemoryError: Java heap space: failed reallocation of scalar replaced objects
Exception in
gc.lock.LockerTest$Worker@7043894b
java.lang.OutOfMemoryError: Java heap space: failed reallocation of scalar replaced objects
Exception in
gc.lock.LockerTest$Worker@6086e1b3
java.lang.OutOfMemoryError: Java heap space: failed reallocation of scalar replaced objects
gc.lock.LockerTest$Worker@2c310598
Exception in
gc.lock.LockerTest$Worker@ce338b5
java.lang.OutOfMemoryError: Java heap space: failed reallocation of scalar replaced objects
Exception in
gc.lock.LockerTest$Worker@1c9d5925
java.lang.OutOfMemoryError: Java heap space: failed reallocation of scalar replaced objects
java.lang.OutOfMemoryError: Java heap space: failed reallocation of scalar replaced objects
Failures summary:
java.lang.OutOfMemoryError: Java heap space: failed reallocation of scalar replaced objects
java.lang.OutOfMemoryError: Java heap space: failed reallocation of scalar replaced objects
java.lang.OutOfMemoryError: Java heap space: failed reallocation of scalar replaced objects
java.lang.OutOfMemoryError: Java heap space: failed reallocation of scalar replaced objects
java.lang.OutOfMemoryError: Java heap space: failed reallocation of scalar replaced objects
java.lang.OutOfMemoryError: Java heap space: failed reallocation of scalar replaced objects
java.lang.OutOfMemoryError: Java heap space: failed reallocation of scalar replaced objects
java.lang.OutOfMemoryError: Java heap space: failed reallocation of scalar replaced objects 

I originally added these sightings to JDK-8214584, but Dean Long
requested that I move them to JDK-8192647. Steffan Karlsson does
not think these sightings match JDK-8192647 so I'm putting them
into their own bug.
Comments
Fix Request (11u) This backport makes testing more reliable and keeps codebases in sync (I see 11.0.10-oracle). Patch applies cleanly to 11u, passes vmTestbase_vm_gc.
30-07-2020
URL: https://hg.openjdk.java.net/jdk/jdk13/rev/fe5dcb38a26a User: neliasso Date: 2019-07-10 16:50:13 +0000
10-07-2019
http://cr.openjdk.java.net/~neliasso/8226536/webrev.04
05-07-2019
This bug will be used for fiing the test failures. Another one will be opened to track the general OOM in deopt issue.
04-07-2019
http://cr.openjdk.java.net/~neliasso/8226536/webrev.02
04-07-2019
This is a well known behaviour caused by scalar replacement and nothing new in 13. When encountering an OOM we can't recover from, we might have to consider this fatal.
01-07-2019
Talked to [~rbackman], who acknowledged the problem. Moving this over to hotspot/compiler to decide what to do about this bug.
26-06-2019
It's seems like ZGC triggers OOMEs x10 faster than G1. CMS is somewhere in-between. I've managed to reproduce the problem the original test with CMS by increasing the -stressTime and running with -Xmx100m. Ran a bit longer (~700 seconds) until it reproduced with G1. At this point I'm ready to hand this bug over to the compiler team.
26-06-2019
A big question is: what's the expected behavior if we fail to rematerialize scalar replaced objects? Can we really throw an OOME? What should happen if the code looks like this?: --- Simple s; try { s = new Simple(); s.a = 1; // Do something that triggers deoptimization } catch (OutOfMemoryError e) { // Use s dummy = s.a + System.identityHashCode(s); } --- Inside the try statement the code looked like it had an object s, but in the catch block we wouldn't have it.
25-06-2019
ZGC might trigger this failure more often than other GCs, but the fundamental problem seems to be specific to any GC. What seems to happen is that an object has been scalar replaced, and when we deoptimize we must allocate objects in the heap. If those allocations fail, we try to throw an OutOfMemoryError, but that error isn't caught where expected. I've created a reproducer that intermittently fails the same way as the original test. I've gotten it to fail with both G1 and ZGC. Reproducer command line: $ fastdebug/jdk//bin/java -XX:+UseG1GC -XX:+TraceDeoptimization -Xlog:gc -Xmx500m -cp /tmp/ Test 10000000 1 Output: --- Deoptimizing thread 0x00007f1ae8024800 [3,896s][info][gc] GC(46) Concurrent Cycle 513,804ms [3,897s][info][gc] GC(52) Pause Young (Normal) (G1 Evacuation Pause) 425M->425M(500M) 0,553ms [4,017s][info][gc] GC(53) Pause Full (G1 Evacuation Pause) 425M->425M(500M) 113,045ms [4,148s][info][gc] GC(54) Pause Full (G1 Evacuation Pause) 425M->425M(500M) 116,822ms [4,157s][info][gc] GC(55) Pause Young (Concurrent Start) (G1 Evacuation Pause) 425M->425M(500M) 1,043ms [4,157s][info][gc] GC(56) Concurrent Cycle [4,286s][info][gc] GC(57) Pause Full (G1 Evacuation Pause) 425M->425M(500M) 121,041ms [4,424s][info][gc] GC(58) Pause Full (G1 Evacuation Pause) 425M->425M(500M) 124,332ms [4,433s][info][gc] GC(59) Pause Young (Normal) (G1 Evacuation Pause) 425M->425M(500M) 0,771ms [4,562s][info][gc] GC(60) Pause Full (G1 Evacuation Pause) 425M->425M(500M) 122,297ms [4,699s][info][gc] GC(61) Pause Full (G1 Evacuation Pause) 425M->425M(500M) 121,811ms [4,706s][info][gc] GC(56) Concurrent Cycle 549,352ms REALLOC OBJECTS in thread 0x00007f1ae8024800 object <0x0000000000000000> of type 'Test$Simple' allocation failed DEOPT UNPACKING thread 0x00007f1ae8024800 vframeArray 0x00007f1ae87c39d0 mode 1 {method} {0x00007f1ac9786a50} 'oomeLoopInner' '()V' in 'Test' - invokestatic @ bci 8 sp = 0x00007f1aef495840 {method} {0x00007f1ac9786938} 'oomeLoopDummyAllocator' '()V' in 'Test' - newarray @ bci 9 sp = 0x00007f1aef4957e8 [4,708s][info][gc] GC(62) Pause Young (Normal) (G1 Evacuation Pause) 425M->425M(500M) 0,830ms [4,826s][info][gc] GC(63) Pause Full (G1 Evacuation Pause) 425M->401M(500M) 110,065ms Java heap space: failed reallocation of scalar replaced objects --- Current revision of the reproducer: --- import java.util.*; public class Test { public static byte[] dummy = new byte[1024]; public static byte[] preAllocated; public static byte[] reinstateDummy = new byte[1]; // Retainers of memory - preallocate backing array to prevent OOME when array is growing public static ArrayList loadStoneAllocThread = new ArrayList(1000000); public static ArrayList loadStoneMain = new ArrayList(1000000); public static int count; public static int size; public static int exitCode = 0; public static void main(String [] args) { // Start by filling the heap preAllocated = new byte[Integer.parseInt(args[0])]; size = Integer.parseInt(args[1]); // Print something and load System classes System.err.println("Starting with: " + args[0] + ", " + args[1]); // Eat memory and retain memory Thread t = new Thread() { public void run() { try { // Eat fast while (true) { // TLAB Object o = new byte[262128]; loadStoneAllocThread.add(o); } } catch (OutOfMemoryError e) { try { // Eat slow and precise while (true) { Object o = new Object(); loadStoneAllocThread.add(o); } } catch (OutOfMemoryError e2) { // Ignore - swallow } } } }; try { t.start(); } catch (OutOfMemoryError e) { exitCode = -1; } // Run alloc loop that will fail realloc_objects try { oomeLoop(); } catch (OutOfMemoryError e) { // Dump allocated memory, and hope that System.err.print will // be able to allocate. loadStoneMain = null; exitCode = -2; System.err.println(e.getMessage()); } // Dump memory to allow System.exit to work loadStoneMain = null; System.exit(exitCode); } public static void oomeLoop() { oomeLoopInner(); } // Largish class to increase likelyhood of OOME when rematerializing Simple s. public static class Simple { public int a; public int a0; public int a1; public int a2; public int a3; public int a4; public int a5; public int a6; public int a7; public int a8; public int a9; public int b0; public int b1; public int b2; public int b3; public int b4; public int b5; public int b6; public int b7; public int b8; public int b9; public int c0; public int c1; public int c2; public int c3; public int c4; public int c5; public int c6; public int c7; public int c8; public int c9; public int d0; public int d1; public int d2; public int d3; public int d4; public int d5; public int d6; public int d7; public int d8; public int d9; } public static void oomeLoopDummyAllocator() { // Tickle the deoptimizer when dummy becomes null dummy[0] = 1; dummy = new byte[size]; // Continue filling up the heap to loadStoneMain.add(dummy); } public static void oomeLoopInner() { while (true) { // Non-escaping nad stack allocated object, // that needs to be rematerialized when the method // is deoptimized Simple s = new Simple(); try { oomeLoopDummyAllocator(); s.a++; } catch (NullPointerException e) { // Keep running dummy = reinstateDummy; } catch (OutOfMemoryError e) { count++; final int limit = 10; if (count % limit == limit -1) { // Got enough OOME - trip the deoptimizer dummy = null; } // Needed to keep s alive? if (s.a == 1000000) { exitCode = -4; } } } } } ---
25-06-2019
JDK-8170182 is a sighting of this with G1.
25-06-2019
I've been testing and reproducing with the malloc test (which doesn't use the gc locker). This is the call stack of this failure: nsk.share.gc.gp.array.ByteArrayProducer.create(ByteArrayProducer.java:36) nsk.share.gc.gp.array.ByteArrayProducer.create(ByteArrayProducer.java:34) nsk.share.gc.gp.GarbageUtils.eatMemory(GarbageUtils.java:231) nsk.share.gc.gp.GarbageUtils.eatMemory(GarbageUtils.java:143) gc.lock.LockerTest$Worker.run(LockerTest.java:62) nsk.share.runner.ThreadsRunner$ManagedThread.run(ThreadsRunner.java:83) (I've modified the source, so the line numbers won't match) The weird thing is that OOME happens inside the try { ... } catch (OutOfMemory e) { no rethrow } block, but it seems like we still propagate the OOME. Needs to investigate this more.
24-06-2019
[~kbarrett] Could you elaborate what you mean? Deoptimization::realloc_object can throw OOME, but I don't see why this would be caused by the GC locker.
24-06-2019
Added zgc label - all of the failures of this kind seem to be associated with that collector. The error message is for out_of_memory_error_realloc_objects. The only throw of that error is Deoptimization::realloc_objects. There are some failures linked to JDK-8192647 that might belong here. In a comment for that bug [~stefank] said ZGC "does not throw OOME because of the GC locker. " This throw in deoptimization seems to be a counter-example, and that might be a problem.
21-06-2019
Moved to JDK-8192647 from JDK-8214584 at Dean Long's request. Moved here from JDK-8192647 at Stefan Karlsson's request. Here's a log snippet for the vmTestbase/gc/lock/jniref/jnireflock01/TestDescription.java failure: ----------System.out:(45/2326)---------- Stress time: 30 seconds Stress iterations factor: 1 Stress threads factor: 1 Stress runs factor: 1 Max memory: 1826619392 Sleep time: 500 Iterations: 0 Number of threads: 16 Seed: 1560392143790 Run GC thread: false Run mem diag thread: false Run forever: false Starting Thread[gc.lock.LockerTest$Worker@6b7d0b58,5,MainThreadGroup] Starting Thread[gc.lock.LockerTest$Worker@40119ef9,5,MainThreadGroup] Starting Thread[gc.lock.LockerTest$Worker@43356a68,5,MainThreadGroup] Starting Thread[gc.lock.LockerTest$Worker@83d33b0,5,MainThreadGroup] Starting Thread[gc.lock.LockerTest$Worker@3ce93e79,5,MainThreadGroup] Starting Thread[gc.lock.LockerTest$Worker@7043894b,5,MainThreadGroup] Starting Thread[gc.lock.LockerTest$Worker@184dcb01,5,MainThreadGroup] Starting Thread[gc.lock.LockerTest$Worker@798cdb0b,5,MainThreadGroup] Starting Thread[gc.lock.LockerTest$Worker@ce338b5,5,MainThreadGroup] Starting Thread[gc.lock.LockerTest$Worker@6086e1b3,5,MainThreadGroup] Starting Thread[gc.lock.LockerTest$Worker@16e53b61,5,MainThreadGroup] Starting Thread[gc.lock.LockerTest$Worker@9aeee35,5,MainThreadGroup] Starting Thread[gc.lock.LockerTest$Worker@1c9d5925,5,MainThreadGroup] Starting Thread[gc.lock.LockerTest$Worker@4b41a87c,5,MainThreadGroup] Starting Thread[gc.lock.LockerTest$Worker@7440ac46,5,MainThreadGroup] Starting Thread[gc.lock.LockerTest$Worker@ae13bbd,5,MainThreadGroup] Exception in gc.lock.LockerTest$Worker@43356a68 java.lang.OutOfMemoryError: Java heap space: failed reallocation of scalar replaced objects Exception in Exception in gc.lock.LockerTest$Worker@7440ac46 gc.lock.LockerTest$Worker@ce338b5 java.lang.OutOfMemoryError: Java heap space: failed reallocation of scalar replaced objects Exception in gc.lock.LockerTest$Worker@3ce93e79 java.lang.OutOfMemoryError: Java heap space: failed reallocation of scalar replaced objects java.lang.OutOfMemoryError: Java heap space: failed reallocation of scalar replaced objects Failures summary: java.lang.OutOfMemoryError: Java heap space: failed reallocation of scalar replaced objects java.lang.OutOfMemoryError: Java heap space: failed reallocation of scalar replaced objects java.lang.OutOfMemoryError: Java heap space: failed reallocation of scalar replaced objects java.lang.OutOfMemoryError: Java heap space: failed reallocation of scalar replaced objects ----------System.err:(16/938)---------- nsk.share.TestFailure: Test exit code: 97 at nsk.share.test.Tests$TestRunner.execute(Tests.java:90) at nsk.share.test.Tests$TestRunner.run(Tests.java:96) at nsk.share.gc.GC.runTest(GC.java:114) at gc.lock.LockerTest.main(LockerTest.java:77) at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.base/java.lang.reflect.Method.invoke(Method.java:567) at com.sun.javatest.regtest.agent.MainWrapper$MainThread.run(MainWrapper.java:127) at java.base/java.lang.Thread.run(Thread.java:830) JavaTest Message: Test threw exception: nsk.share.TestFailure: Test exit code: 97 JavaTest Message: shutting down test STATUS:Failed.`main' threw exception: nsk.share.TestFailure: Test exit code: 97 ----------rerun:(37/6973)*----------
20-06-2019
Moved to JDK-8192647 from JDK-8214584 at Dean Long's request. Moved here from JDK-8192647 at Stefan Karlsson's request. Here a log snippet for the vmTestbase/gc/lock/malloc/malloclock02/TestDescription.java failure: ----------System.out:(61/3259)---------- Stress time: 30 seconds Stress iterations factor: 1 Stress threads factor: 1 Stress runs factor: 1 Max memory: 1826619392 Sleep time: 500 Iterations: 0 Number of threads: 16 Seed: 1560392637817 Run GC thread: false Run mem diag thread: false Run forever: false Starting Thread[gc.lock.LockerTest$Worker@7043894b,5,MainThreadGroup] Starting Thread[gc.lock.LockerTest$Worker@ce338b5,5,MainThreadGroup] Starting Thread[gc.lock.LockerTest$Worker@6086e1b3,5,MainThreadGroup] Starting Thread[gc.lock.LockerTest$Worker@16e53b61,5,MainThreadGroup] Starting Thread[gc.lock.LockerTest$Worker@9aeee35,5,MainThreadGroup] Starting Thread[gc.lock.LockerTest$Worker@1c9d5925,5,MainThreadGroup] Starting Thread[gc.lock.LockerTest$Worker@4b41a87c,5,MainThreadGroup] Starting Thread[gc.lock.LockerTest$Worker@7440ac46,5,MainThreadGroup] Starting Thread[gc.lock.LockerTest$Worker@ae13bbd,5,MainThreadGroup] Starting Thread[gc.lock.LockerTest$Worker@7c431fb5,5,MainThreadGroup] Starting Thread[gc.lock.LockerTest$Worker@3a074a09,5,MainThreadGroup] Starting Thread[gc.lock.LockerTest$Worker@4b54e393,5,MainThreadGroup] Starting Thread[gc.lock.LockerTest$Worker@486b1597,5,MainThreadGroup] Starting Thread[gc.lock.LockerTest$Worker@2c310598,5,MainThreadGroup] Starting Thread[gc.lock.LockerTest$Worker@2ce65515,5,MainThreadGroup] Starting Thread[gc.lock.LockerTest$Worker@40c27361,5,MainThreadGroup] Exception in gc.lock.LockerTest$Worker@16e53b61 Exception in gc.lock.LockerTest$Worker@7440ac46 java.lang.OutOfMemoryError: Java heap space: failed reallocation of scalar replaced objects Exception in java.lang.OutOfMemoryError: Java heap space: failed reallocation of scalar replaced objects Exception in gc.lock.LockerTest$Worker@486b1597 java.lang.OutOfMemoryError: Java heap space: failed reallocation of scalar replaced objects Exception in gc.lock.LockerTest$Worker@7043894b java.lang.OutOfMemoryError: Java heap space: failed reallocation of scalar replaced objects Exception in gc.lock.LockerTest$Worker@6086e1b3 java.lang.OutOfMemoryError: Java heap space: failed reallocation of scalar replaced objects gc.lock.LockerTest$Worker@2c310598 Exception in gc.lock.LockerTest$Worker@ce338b5 java.lang.OutOfMemoryError: Java heap space: failed reallocation of scalar replaced objects Exception in gc.lock.LockerTest$Worker@1c9d5925 java.lang.OutOfMemoryError: Java heap space: failed reallocation of scalar replaced objects java.lang.OutOfMemoryError: Java heap space: failed reallocation of scalar replaced objects Failures summary: java.lang.OutOfMemoryError: Java heap space: failed reallocation of scalar replaced objects java.lang.OutOfMemoryError: Java heap space: failed reallocation of scalar replaced objects java.lang.OutOfMemoryError: Java heap space: failed reallocation of scalar replaced objects java.lang.OutOfMemoryError: Java heap space: failed reallocation of scalar replaced objects java.lang.OutOfMemoryError: Java heap space: failed reallocation of scalar replaced objects java.lang.OutOfMemoryError: Java heap space: failed reallocation of scalar replaced objects java.lang.OutOfMemoryError: Java heap space: failed reallocation of scalar replaced objects java.lang.OutOfMemoryError: Java heap space: failed reallocation of scalar replaced objects ----------System.err:(16/938)---------- nsk.share.TestFailure: Test exit code: 97 at nsk.share.test.Tests$TestRunner.execute(Tests.java:90) at nsk.share.test.Tests$TestRunner.run(Tests.java:96) at nsk.share.gc.GC.runTest(GC.java:114) at gc.lock.LockerTest.main(LockerTest.java:77) at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.base/java.lang.reflect.Method.invoke(Method.java:567) at com.sun.javatest.regtest.agent.MainWrapper$MainThread.run(MainWrapper.java:127) at java.base/java.lang.Thread.run(Thread.java:830) JavaTest Message: Test threw exception: nsk.share.TestFailure: Test exit code: 97 JavaTest Message: shutting down test STATUS:Failed.`main' threw exception: nsk.share.TestFailure: Test exit code: 97 ----------rerun:(37/6984)*----------
20-06-2019