JDK-8291919 : [11u] High compiler native memory consumption after JDK-8279219
  • Type: Bug
  • Component: hotspot
  • Sub-Component: compiler
  • Affected Version: 11.0.16
  • Priority: P3
  • Status: Closed
  • Resolution: Duplicate
  • Submitted: 2022-08-04
  • Updated: 2022-08-19
  • Resolved: 2022-08-04
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
11-poolResolved
Related Reports
Duplicate :  
JDK-8291665 - C2: assert compiling SSLEngineInputRecord::decodeInputRecord
Relates :  
JDK-8279219 - [REDO] C2 crash when allocating array of size too large
Relates :  
JDK-8280799 - С2: assert(false) failed: cyclic dependency prevents range check elimination
Relates :  
JDK-8292260 - [BACKOUT] JDK-8279219: [REDO] C2 crash when allocating array of size too large
Relates :  
JDK-8292301 - [REDO v2] C2 crash when allocating array of size too large
Description
We saw an application in a container quickly go out of memory.
With NMT we saw unusual high memory consumption of PhaseIdealLoop::split_if() in C2. I'll paste the NMT report to a comment, as well as a part of a hs_err file showing the coresponding stack.
There are two backports to that function in 11.0.16. We narrowed it down to 
JDK-8280799: С2: assert(false) failed: cyclic dependency prevents range check elimination

The problem reproduces with this change, but not with the change below. 

We can not reproduce this problem with arbitrary Java programs, but it reproduces in every run of the problematic application.
Comments
[~dlong] thanks for checking
19-08-2022
[~roland], your patch works for me.
19-08-2022
[~roland], the infinite memory use happens when JDK-8291665 is reproduced in a product build, because we don't hit the asserts. Unfortunately, the easiest way to reproduce JDK-8291665 is with the replay file, which doesn't work in a product build, so I think what I did before was use a debug build with the replay file but comment out the asserts that hit. The alternative it to use a lot of -XX:SuppressErrorAt flags.
19-08-2022
I can't find a way to reproduce this in the bug description. Would someone who can reproduce it be willing to try the fix here: https://bugs.openjdk.org/browse/JDK-8292301?focusedCommentId=14518576&page=com.atlassian.jira.plugin.system.issuetabpanels%3Acomment-tabpanel#comment-14518576 on top of an 11 build for which this reproduces?
19-08-2022
This seems to happen in a product build. In a debug build, we hit the assert in JDK-8291665 first.
04-08-2022
[~roland], please take a look.
04-08-2022
Thanks [~goetz]
04-08-2022
# # There is insufficient memory for the Java Runtime Environment to continue. # Native memory allocation (malloc) failed to allocate 268435472 bytes for Chunk::new # Possible reasons: # The system is out of physical RAM or swap space # The process is running with CompressedOops enabled, and the Java Heap may be blocking the growth of the native heap # Possible solutions: # Reduce memory load on the system # Increase physical memory or swap space # Check if swap backing store is full # Decrease Java heap size (-Xmx/-Xms) # Decrease number of Java threads # Decrease Java thread stack sizes (-Xss) # Set larger code cache with -XX:ReservedCodeCacheSize= # JVM is running with Unscaled Compressed Oops mode in which the Java heap is # placed in the first 4GB address space. The Java Heap base address is the # maximum limit for the native heap growth. Please use -XX:HeapBaseMinAddress # to set the Java Heap base and to place the Java Heap above 4GB virtual address. # This output file may be truncated or incomplete. # # Out of Memory Error (arena.cpp:197), pid=57882, tid=57894 # # JRE version: OpenJDK Runtime Environment (11.0.16) (build 11.0.16-internal+0-adhoc.d045726.backports-dev) # Java VM: OpenJDK 64-Bit Server VM (11.0.16-internal+0-adhoc..backports-dev, mixed mode, tiered, compressed oops, g1 gc, linux-amd64) # Core dump will be written. Default location: Core dumps may be processed with "/usr/share/apport/apport -p%p -s%s -c%c -d%d -P%P -u%u -g%g -- %E" (or dumping to ...compiler_oom/cloud-ci-service/modules/api/target/core.57882) # --------------- S U M M A R Y ------------ Command Line: -Xmx330575K -Xss1M -XX:ReservedCodeCacheSize=240M -XX:MaxDirectMemorySize=10M -XX:MaxMetaspaceSize=206000K -XX:NativeMemoryTracking=summary api.jar Host: Intel(R) Xeon(R) CPU E5-2660 v3 @ 2.60GHz, 40 cores, 125G, Ubuntu 20.04.4 LTS Time: Thu Aug 4 15:31:23 2022 CEST elapsed time: 235.048159 seconds (0d 0h 3m 55s) --------------- T H R E A D --------------- Current thread (0x00007f0db8295800): JavaThread "C2 CompilerThread0" daemon [_thread_in_native, id=57894, stack(0x00007f0d91017000,0x00007f0d91118000)] Current CompileTask: C2: 235048 21240 ! 4 sun.security.ssl.SSLEngineInputRecord::decodeInputRecord (812 bytes) Stack: [0x00007f0d91017000,0x00007f0d91118000], sp=0x00007f0d911124f0, free space=1005k Native frames: (J=compiled Java code, A=aot compiled Java code, j=interpreted, Vv=VM code, C=native code) V [libjvm.so+0xe36426] VMError::report_and_die(int, char const*, char const*, __va_list_tag*, Thread*, unsigned char*, void*, void*, char const*, int, unsigned long)+0x1c6 V [libjvm.so+0xe3739b] VMError::report_and_die(Thread*, char const*, int, unsigned long, VMErrorType, char const*, __va_list_tag*)+0x2b V [libjvm.so+0x65db95] report_vm_out_of_memory(char const*, int, unsigned long, VMErrorType, char const*, ...)+0xc5 V [libjvm.so+0x409f66] Arena::grow(unsigned long, AllocFailStrategy::AllocFailEnum)+0x156 V [libjvm.so+0x40a172] Arena::Arealloc(void*, unsigned long, unsigned long, AllocFailStrategy::AllocFailEnum)+0x142 V [libjvm.so+0xb5f370] Node::out_grow(unsigned int)+0x70 V [libjvm.so+0xb5f820] Node::clone() const+0x250 V [libjvm.so+0xd2a66e] PhaseIdealLoop::split_up(Node*, Node*, Node*)+0xe0e V [libjvm.so+0xd2c615] PhaseIdealLoop::do_split_if(Node*)+0x705 V [libjvm.so+0xa5469f] PhaseIdealLoop::split_if_with_blocks(VectorSet&, Node_Stack&, bool)+0x1af V [libjvm.so+0xa4df3e] PhaseIdealLoop::build_and_optimize(LoopOptsMode)+0xd4e V [libjvm.so+0x603536] Compile::optimize_loops(int&, PhaseIterGVN&, LoopOptsMode) [clone .part.371]+0x236 V [libjvm.so+0x60643f] Compile::Optimize()+0x56f V [libjvm.so+0x607941] Compile::Compile(ciEnv*, C2Compiler*, ciMethod*, int, bool, bool, bool, bool, DirectiveSet*)+0xca1 V [libjvm.so+0x52f974] C2Compiler::compile_method(ciEnv*, ciMethod*, int, DirectiveSet*)+0xd4 V [libjvm.so+0x6122ed] CompileBroker::invoke_compiler_on_method(CompileTask*)+0x46d V [libjvm.so+0x613578] CompileBroker::compiler_thread_loop()+0x438 V [libjvm.so+0xdd5070] JavaThread::thread_main_inner()+0x110 V [libjvm.so+0xdd0da9] Thread::call_run()+0x149 V [libjvm.so+0xb97236] thread_native_entry(Thread*)+0xe6 ... Native Memory Tracking: Total: reserved=4837484KB, committed=4276856KB - Java Heap (reserved=331776KB, committed=331776KB) (mmap: reserved=331776KB, committed=331776KB) - Class (reserved=325510KB, committed=145198KB) (classes #25754) ( instance classes #24136, array classes #1618) (malloc=4822KB #76459) (mmap: reserved=320688KB, committed=140376KB) ( Metadata: ) ( reserved=122880KB, committed=122072KB) ( used=119271KB) ( free=2801KB) ( waste=0KB =0,00%) ( Class space:) ( reserved=197808KB, committed=18304KB) ( used=16449KB) ( free=1855KB) ( waste=0KB =0,00%) - Thread (reserved=219806KB, committed=20674KB) (thread #213) (stack: reserved=218800KB, committed=19668KB) (malloc=761KB #1280) (arena=245KB #421) - Code (reserved=253030KB, committed=71846KB) (malloc=5342KB #19912) (mmap: reserved=247688KB, committed=66504KB) - GC (reserved=106467KB, committed=106467KB) (malloc=61139KB #31048) (mmap: reserved=45328KB, committed=45328KB) - Compiler (reserved=3552577KB, committed=3552577KB) (malloc=477KB #2390) (arena=3552100KB #13) - Internal (reserved=5105KB, committed=5105KB) (malloc=5073KB #3426) (mmap: reserved=32KB, committed=32KB) - Other (reserved=3571KB, committed=3571KB) (malloc=3571KB #156) - Symbol (reserved=29168KB, committed=29168KB) (malloc=26219KB #331077) (arena=2949KB #1) - Native Memory Tracking (reserved=8337KB, committed=8337KB) (malloc=55KB #746) (tracking overhead=8281KB) - Arena Chunk (reserved=934KB, committed=934KB) (malloc=934KB) - Logging (reserved=4KB, committed=4KB) (malloc=4KB #192) - Arguments (reserved=18KB, committed=18KB) (malloc=18KB #489) - Module (reserved=631KB, committed=631KB) (malloc=631KB #4208) - Synchronizer (reserved=542KB, committed=542KB) (malloc=542KB #4545) - Safepoint (reserved=8KB, committed=8KB) (mmap: reserved=8KB, committed=8KB)
04-08-2022
Hi Dean, it is definitely a bug. See also the other issue opened for the same problem. From the trace above you see split_up allocates 600MB alone at one underlying allocation, that is definitely not good. It sums up to > 1,5G. I added the NMT dump part to the comment with the hs_err snippet above.
04-08-2022
ILW = container runs out of memory; with customer app in container; disable compilation of affected method = MMM = P3
04-08-2022
[~goetz], could you provide more information, like how much memory NMT reports C2 is using, and the memory limit of your container? It's hard to tell if this is a bug. If the recent change puts your app over the memory limit, how close to the memory limit did your app go before?
04-08-2022
The NMT printout of SapMachine 11.0.16 hinting there is a memory problem with split_if() 0x00007f6ea4b42e6d] ChunkPool::allocate(unsigned long, AllocFailStrategy::AllocFailEnum)+0x10d [0x00007f6ea4b42732] Arena::grow(unsigned long, AllocFailStrategy::AllocFailEnum)+0x42 [0x00007f6ea529d31d] Node::clone() const+0x27d [0x00007f6ea53bb7ce] PhaseIdealLoop::split_up(Node*, Node*, Node*) [clone .part.45]+0x91e (malloc=671348KB type=Arena Chunk #20995) [0x00007f6ea4b42e6d] ChunkPool::allocate(unsigned long, AllocFailStrategy::AllocFailEnum)+0x10d [0x00007f6ea4b42732] Arena::grow(unsigned long, AllocFailStrategy::AllocFailEnum)+0x42 [0x00007f6ea529d08f] Node::out_grow(unsigned int)+0xef [0x00007f6ea53bc41c] PhaseIdealLoop::split_up(Node*, Node*, Node*) [clone .part.45]+0x156c (malloc=671092KB type=Arena Chunk #20987) [0x00007f6ea4b42a52] Arena::Arealloc(void*, unsigned long, unsigned long, AllocFailStrategy::AllocFailEnum)+0x142 [0x00007f6ea52a00d9] Node_Array::grow(unsigned int)+0x59 [0x00007f6ea5325827] PhaseIterGVN::register_new_node_with_optimizer(Node*, Node*)+0x107 [0x00007f6ea53badac] PhaseIdealLoop::register_new_node(Node*, Node*)+0x2c (malloc=262112KB type=Arena Chunk #13) [0x00007f6ea4b42a52] Arena::Arealloc(void*, unsigned long, unsigned long, AllocFailStrategy::AllocFailEnum)+0x142 [0x00007f6ea529d010] Node::out_grow(unsigned int)+0x70 [0x00007f6ea529d2f0] Node::clone() const+0x250 [0x00007f6ea53bb7ce] PhaseIdealLoop::split_up(Node*, Node*, Node*) [clone .part.45]+0x91e (malloc=262112KB type=Arena Chunk #13) [0x00007f6ea4b42a52] Arena::Arealloc(void*, unsigned long, unsigned long, AllocFailStrategy::AllocFailEnum)+0x142 [0x00007f6ea5323479] Type_Array::grow(unsigned int)+0x59 [0x00007f6ea532580c] PhaseIterGVN::register_new_node_with_optimizer(Node*, Node*)+0xec [0x00007f6ea53badac] PhaseIdealLoop::register_new_node(Node*, Node*)+0x2c (malloc=262016KB type=Arena Chunk #11) [0x00007f6ea4b42a52] Arena::Arealloc(void*, unsigned long, unsigned long, AllocFailStrategy::AllocFailEnum)+0x142 [0x00007f6ea52a00d9] Node_Array::grow(unsigned int)+0x59 [0x00007f6ea53bae4c] PhaseIdealLoop::register_new_node(Node*, Node*)+0xcc [0x00007f6ea53bb7df] PhaseIdealLoop::split_up(Node*, Node*, Node*) [clone .part.45]+0x92f (malloc=262016KB type=Arena Chunk #11)
04-08-2022