JDK-8291665 : C2: assert compiling SSLEngineInputRecord::decodeInputRecord
  • Type: Bug
  • Component: hotspot
  • Sub-Component: compiler
  • Affected Version: 11.0.16
  • Priority: P3
  • Status: Closed
  • Resolution: Duplicate
  • OS: generic
  • CPU: generic
  • Submitted: 2022-07-28
  • Updated: 2022-09-27
  • Resolved: 2022-08-15
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-8291919 - [11u] High compiler native memory consumption after JDK-8279219
Duplicate :  
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
Relates :  
JDK-8279219 - [REDO] C2 crash when allocating array of size too large
Description
ADDITIONAL SYSTEM INFORMATION :
Host: Intel(R) Xeon(R) Platinum 8259CL CPU @ 2.50GHz, 8 cores, 30G, CentOS Linux release 7.9.2009 (Core)
JRE version: OpenJDK Runtime Environment Zulu11.58+15-CA (11.0.16+8) (build 11.0.16+8-LTS)
Java VM: OpenJDK 64-Bit Server VM Zulu11.58+15-CA (11.0.16+8-LTS, mixed mode, tiered, compressed oops, parallel gc, linux-amd64)

A DESCRIPTION OF THE PROBLEM :
After upgrading systems from 11.0.15 to 11.0.16 (July release) linux x86_64, services have begun crashing frequently upon startup with the following. This has been reproducible across many servers using 11.0.16, which all fail within C2 compilation of sun.security.ssl.SSLEngineInputRecord::decodeInputRecord, and only after the jdk upgrade.

In particular, this segment from the native-memory-tracking section showing compiler memory is particularly concerning:

-                  Compiler (reserved=26335956KB, committed=26335956KB)
                            (malloc=1218KB #3043) 
                            (arena=26334738KB #28)

#
# There is insufficient memory for the Java Runtime Environment to continue.
# Native memory allocation (malloc) failed to allocate 2147483664 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 Zero Based Compressed Oops mode in which the Java heap is
#     placed in the first 32GB 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 32GB virtual address.
# This output file may be truncated or incomplete.
#
#  Out of Memory Error (arena.cpp:197), pid=30772, tid=31459
#
# JRE version: OpenJDK Runtime Environment Zulu11.58+15-CA (11.0.16+8) (build 11.0.16+8-LTS)
# Java VM: OpenJDK 64-Bit Server VM Zulu11.58+15-CA (11.0.16+8-LTS, mixed mode, tiered, compressed oops, parallel gc, linux-amd64)
# No core dump will be written. Core dumps have been disabled. To enable core dumping, try "ulimit -c unlimited" before starting Java again
#

---------------  S U M M A R Y ------------

Command Line: -XX:+CrashOnOutOfMemoryError -Djava.io.tmpdir=var/data/tmp -XX:ErrorFile=var/log/hs_err_pid%p.log -XX:HeapDumpPath=var/log -Dsun.net.inetaddr.ttl=20 -XX:NativeMemoryTracking=summary -XX:FlightRecorderOptions=stackdepth=256 -XX:-UseBiasedLocking -XX:+UseParallelGC -XX:+HeapDumpOnOutOfMemoryError -XX:+UseParallelOldGC -Xms4g -Xmx4g com.MyServer

Host: Intel(R) Xeon(R) Platinum 8259CL CPU @ 2.50GHz, 8 cores, 30G, CentOS Linux release 7.9.2009 (Core)
Time: Tue Jul 26 18:35:44 2022 UTC elapsed time: 68.889468 seconds (0d 0h 1m 8s)

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

Current thread (0x00007f4b3015aa30):  JavaThread "C2 CompilerThread2" daemon [_thread_in_native, id=31459, stack(0x00007f4afba9c000,0x00007f4afbb9d000)]


Current CompileTask:
C2:  68890 17228   !   4       sun.security.ssl.SSLEngineInputRecord::decodeInputRecord (812 bytes)

Stack: [0x00007f4afba9c000,0x00007f4afbb9d000],  sp=0x00007f4afbb974c0,  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+0xe7fd76]  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+0xe80ceb]  VMError::report_and_die(Thread, char const, int, unsigned long, VMErrorType, char const, __va_list_tag)+0x2b
V  [libjvm.so+0x69f165]  report_vm_out_of_memory(char const, int, unsigned long, VMErrorType, char const, ...)+0xc5
V  [libjvm.so+0x4436f6]  Arena::grow(unsigned long, AllocFailStrategy::AllocFailEnum)+0x156
V  [libjvm.so+0x443902]  Arena::Arealloc(void, unsigned long, unsigned long, AllocFailStrategy::AllocFailEnum)+0x142
V  [libjvm.so+0xba7479]  Node_Array::grow(unsigned int)+0x59
V  [libjvm.so+0xc31f97]  PhaseIterGVN::register_new_node_with_optimizer(Node, Node)+0x107
V  [libjvm.so+0xd71afc]  PhaseIdealLoop::register_new_node(Node, Node)+0x2c
V  [libjvm.so+0xd7252f]  PhaseIdealLoop::split_up(Node, Node, Node) [clone .part.46]+0x92f
V  [libjvm.so+0xd74c65]  PhaseIdealLoop::do_split_if(Node)+0x895
V  [libjvm.so+0xa99daf]  PhaseIdealLoop::split_if_with_blocks(VectorSet&, Node_Stack&, bool)+0x1af
V  [libjvm.so+0xa936bb]  PhaseIdealLoop::build_and_optimize()+0xcab
V  [libjvm.so+0x63bd2c]  Compile::optimize_loops(int&, PhaseIterGVN&, LoopOptsMode) [clone .part.371]+0x23c
V  [libjvm.so+0x63ec26]  Compile::Optimize()+0x566
V  [libjvm.so+0x640271]  Compile::Compile(ciEnv, C2Compiler, ciMethod, int, bool, bool, bool, bool, DirectiveSet)+0xd41
V  [libjvm.so+0x5694b4]  C2Compiler::compile_method(ciEnv, ciMethod, int, DirectiveSet)+0xd4
V  [libjvm.so+0x649869]  CompileBroker::invoke_compiler_on_method(CompileTask)+0x539
V  [libjvm.so+0x64ac08]  CompileBroker::compiler_thread_loop()+0x438
V  [libjvm.so+0xe1edf9]  JavaThread::thread_main_inner()+0x1e9
V  [libjvm.so+0xe1ae99]  Thread::call_run()+0x149
V  [libjvm.so+0xbdca36]  thread_native_entry(Thread*)+0xe6

< cutting out some cruft >

Native Memory Tracking:

Total: reserved=32716409KB, committed=31356453KB
-                 Java Heap (reserved=4194304KB, committed=4194304KB)
                            (mmap: reserved=4194304KB, committed=4194304KB) 
 
-                     Class (reserved=1296409KB, committed=282193KB)
                            (classes #46659)
                            (  instance classes #44335, array classes #2324)
                            (malloc=10265KB #145784) 
                            (mmap: reserved=1286144KB, committed=271928KB) 
                            (  Metadata:   )
                            (    reserved=237568KB, committed=236760KB)
                            (    used=229499KB)
                            (    free=7261KB)
                            (    waste=0KB =0.00%)
                            (  Class space:)
                            (    reserved=1048576KB, committed=35168KB)
                            (    used=31052KB)
                            (    free=4116KB)
                            (    waste=0KB =0.00%)
 
-                    Thread (reserved=200000KB, committed=21772KB)
                            (thread #194)
                            (stack: reserved=199392KB, committed=21164KB)
                            (malloc=319KB #1166) 
                            (arena=288KB #385)
 
-                      Code (reserved=255488KB, committed=87976KB)
                            (malloc=7800KB #24416) 
                            (mmap: reserved=247688KB, committed=80176KB) 
 
-                        GC (reserved=183400KB, committed=183400KB)
                            (malloc=30156KB #7999) 
                            (mmap: reserved=153244KB, committed=153244KB) 
 
-                  Compiler (reserved=26335956KB, committed=26335956KB)
                            (malloc=1218KB #3043) 
                            (arena=26334738KB #28)
 
-                  Internal (reserved=10147KB, committed=10147KB)
                            (malloc=10115KB #77992) 
                            (mmap: reserved=32KB, committed=32KB) 
 
-                     Other (reserved=128033KB, committed=128033KB)
                            (malloc=128033KB #219) 
 
-                    Symbol (reserved=65939KB, committed=65939KB)
                            (malloc=62319KB #699226) 
                            (arena=3620KB #1)
 
-    Native Memory Tracking (reserved=22008KB, committed=22008KB)
                            (malloc=50KB #633) 
                            (tracking overhead=21959KB)
 
-               Arena Chunk (reserved=8018KB, committed=8018KB)
                            (malloc=8018KB) 
 
-                   Tracing (reserved=14457KB, committed=14457KB)
                            (malloc=14457KB #120) 
 
-                   Logging (reserved=4KB, committed=4KB)
                            (malloc=4KB #193) 
 
-                 Arguments (reserved=21KB, committed=21KB)
                            (malloc=21KB #537) 
 
-                    Module (reserved=1121KB, committed=1121KB)
                            (malloc=1121KB #6233) 
 
-              Synchronizer (reserved=1095KB, committed=1095KB)
                            (malloc=1095KB #9266) 
 
-                 Safepoint (reserved=8KB, committed=8KB)
                            (mmap: reserved=8KB, committed=8KB)

REGRESSION : Last worked in version 11

STEPS TO FOLLOW TO REPRODUCE THE PROBLEM :
Unfortunately I do not have steps to reproduce prepared, and have not been successful in reproducing in my development environment.

EXPECTED VERSUS ACTUAL BEHAVIOR :
EXPECTED -
Ideally the jvm does not crash.
ACTUAL -
jvm crash with the provided hs_err_pid crash file

CUSTOMER SUBMITTED WORKAROUND :
Roll back to the previous openjdk release

FREQUENCY : often
Comments
I'm closing this as duplicate of the backout (JDK-8292260).
15-08-2022
[~xliu] Thank you for your investigation. Please, add your information to JDK-8292301 which is [REDO v2] for the original issue.
12-08-2022
1766 IfNode is a klassPtr comparison (see the attachment unswithch_iff_1766). It checks a var of ByteBuffer* is DirectByteBuffer* and has 39% possibility. I guess that's why it depends on a certain profiling data to trigger it.
12-08-2022
hi, ~kvn, It's hard to reproduce this in the tip of jdk because the replay file is not portable. but I believe the newer JDKs have the same problem. I checked SSLEngineInputRecord.decodeInputRecord(ByteBuffer packet) in newer JDKs, it's almost same as jdk11. I think the problem is from combining JDK-8279219 and LoopUnswitching. The former introduces a boolean input "ValidLengthTest" of AllocateArray. The later happens to clone the loop body which contains AllocateArray and A phi node is created to merge the boolean values from 2 different loops. In this replay, it happens in the first unswitching over 1766. Unswitch 1 Loop: N2469/N1477 limit_check profile_predicated predicated has_call has_sfpt Loop unswitching orig: 2469 @ 1766 new: 2789 @ 2799 As a result, the original loop( N2469/N1477 ) is not safe to do split_if anymore.
12-08-2022
Backout JBS entry is filed: JDK-8292260. That should be P1. Did anyone reproduced the issue with JDK 19? JDK 19 is in RC phase but we can still do back out if it is P1. And in JDK 20 too.
12-08-2022
Should we raise priority to P1 given the reported impact on 11.0.16 rollouts?
11-08-2022
OK, thanks for checking!
11-08-2022
I just checked and I can actually reproduce this issue with Oracle JDK 11.0.16+11. It reproduces reliably with "-XX:+ReplayCompiles -XX:ReplayDataFile=replay.log -XX:+ReplayIgnoreInitErrors" and the replay file from https://gist.github.com/carterkozak/4aff21e72e74d42320b4427953a56385. So both Oracle JDK and OpenJDK are affected by this.
11-08-2022
That seems to suggest that the additional backport we have in 11.0.16 (JDK-8280799) might be the reason for this difference. [~thartmann] Could you please check with your 11.0.17-oracle dev tree which also has JDK-8280799, is it reproducible there?
11-08-2022
I just checked and can confirm that the backports are equivalent. The difference in behavior must be caused by something else.
11-08-2022
Hi [~dlong], You mentioned that you can't reproduce this problem with Oracle JDK 11.0.16. Now, that several parties have confirmed that this issue is caused by https://bugs.openjdk.org/browse/JDK-8279219 this seems a little bit strange because according to JBS, Oracle JDK 11.0.16 also contains a downport of JDK-8279219 (see https://bugs.openjdk.org/browse/JDK-8284138). So I wonder if you could be so kind to quickly check your internal downport against the OpenJDK one and let us know if there are any obvious problems with OpenJDK's version of the downport? Thanks a lot and best regards, Volker
11-08-2022
We can confirm excluding the method from compiling fixes our customer problem (https://bugs.openjdk.org/browse/JDK-8291919).
11-08-2022
One reason why this could potentially not be happening with Oracle JDK is JDK-8280799 not being in 11.0.16 of their release (only in 11.0.17). The problem seen in JDK-8291919 pointed out that backing out JDK-8280799 fixes the problem. Also note that JDK-8288184 is open and affects almost all releases. Is that the same issue?
11-08-2022
AFAICS the JDK-8279219 brings in TestFailedAllocationBadGraph.java. https://github.com/openjdk/jdk11u/commit/9ce8530c5d5f179fa42e1060447aead887570124#diff-4593d9db5bd76ee640e4576d476203fed36a8a2737edff390fa0218dd2cce3a3 So it's reasonable that reverting the fix makes related reg test fail. A clean revert of the patch should also remove the problematic test. My fastdebug build of jdk-11.0.15-ga crashes with the same assert on the TestFailedAllocationBadGraph.java as well. Release build of jdk-11.0.15-ga crashes in {code} # V [libjvm.so+0xaa3142] PhaseIdealLoop::build_loop_late_post(Node*)+0x122 {code} So reverting JDK-8279219 would make the potential 11.0.16.1 as good as 11.0.15 w.r.t. the TestFailedAllocationBadGraph. The condition created in the problematic test (new long[-1]) appears less frequently than the JDK code that triggers the crash, so I support reverting the change.
11-08-2022
Has anyone explored a work-around of trying to disable compilation of the affected method? I.e. -XX:CompileCommand="exclude,sun.security.ssl.SSLEngineInputRecord::decodeInputRecord()"
11-08-2022
'-XX:CompileCommand=exclude,sun/security/ssl/SSLEngineInputRecord.decodeInputRecord' helps with the example provided in this Issue. Whether this helps with all sightings of this bug I don't know. We are currently testing our internal failing systems with the exclude.
11-08-2022
> I confirmed locally on Linux x64 that backing out JDK-8279219 resolves the OOM crashes but causes a new assertion in compiler/allocation/TestFailedAllocationBadGraph.java . Not sure what to do here. I think it's expected behavior. By reverting JDK-8279219, c2 can't correctly handle bad allocation such as "new long[-1]" or "new long[Integer.MAX_VALUE]". Perhaps we need to problem-list 'TestFailedAllocationBadGraph.java'
11-08-2022
This crash is also somehow related to ''unswitching" of loopopts. By default, c2 will do "loop unswitching" twice before CCP and IGVN2 and then default LoopOpts. Default LoopOpts conducted Split-if on 3 loops and failed! Loop: N0/N0 has_call has_sfpt Loop: N2469/N1477 limit_check profile_predicated predicated has_call has_sfpt Loop: N0/N0 has_call has_sfpt Loop: N2469/N1477 limit_check profile_predicated predicated has_call has_sfpt SplitIf SplitIf SplitIf Loop: N0/N0 has_call has_sfpt Loop: N2469/N1477 limit_check profile_predicated predicated has_call has_sfpt Unswitch 1 Loop: N2469/N1477 limit_check profile_predicated predicated has_call has_sfpt Loop unswitching orig: 2469 @ 1766 new: 2789 @ 2799 Poor node estimate: 2794 >> 540 Loop: N0/N0 has_call has_sfpt Loop: N2789/N2788 limit_check profile_predicated predicated has_call has_sfpt Loop: N2469/N1477 limit_check profile_predicated predicated has_call has_sfpt Unswitch 2 Loop: N2789/N2788 limit_check profile_predicated predicated has_call has_sfpt Loop unswitching orig: 2789 @ 2723 new: 3555 @ 3455 Poor node estimate: 1830 >> 481 Loop: N0/N0 has_call has_sfpt Loop: N3555/N3554 limit_check profile_predicated predicated has_call has_sfpt Loop: N2789/N2788 limit_check profile_predicated predicated has_call has_sfpt Loop: N2469/N1477 limit_check profile_predicated predicated has_call has_sfpt SplitIf # To suppress the following error report, specify this argument # after -XX: or in .hotspotrc: SuppressErrorAt=/split_if.cpp:131 # # A fatal error has been detected by the Java Runtime Environment: # # Internal Error (/local/home/xxinliu/Devel/ws-openjdk11/src/OpenJDK11Src/src/hotspot/share/opto/split_if.cpp:131), pid=118265, tid=118278 # assert(use->is_If() || use->is_CMove() || use->Opcode() == Op_Opaque1 || use->is_AllocateArray()) failed: unexpected node type If we skip unswitching using -XX:+TraceLoopOpts -XX:-LoopUnswitching, it's safe to pass the last pass of LoopOpts. Loop: N0/N0 has_call has_sfpt Loop: N2469/N1477 limit_check profile_predicated predicated has_call has_sfpt Loop: N0/N0 has_call has_sfpt Loop: N2469/N1477 limit_check profile_predicated predicated has_call has_sfpt SplitIf SplitIf SplitIf Loop: N0/N0 has_call has_sfpt Loop: N2469/N1477 limit_check profile_predicated predicated has_call has_sfpt Loop: N0/N0 has_call has_sfpt Loop: N2469/N1477 limit_check profile_predicated predicated has_call has_sfpt Loop: N0/N0 has_call has_sfpt Loop: N2469/N1477 limit_check profile_predicated predicated has_call has_sfpt PredicatesOff Loop: N0/N0 has_call has_sfpt Loop: N2469/N1477 has_call has_sfpt
11-08-2022
I confirmed locally on Linux x64 that backing out JDK-8279219 resolves the OOM crashes but causes a new assertion in compiler/allocation/TestFailedAllocationBadGraph.java . Not sure what to do here.
11-08-2022
From what Xin wrote: "If I suppress all assertions, c2 compiler thread will get stuck with a dead loop which keeps consuming memory. After 1 minute, I see that hotspot takes over 2.6g." the error will, when it happens, always result in OOM crashes. But it did not show up as test errors before we shipped 11.0.16, so either it is not very widespread or our tests are not sufficient.
11-08-2022
We can confirm that the backout of JDK-8279219 resolves this OOM. However, I ran the backout-patch through our CI tonight and I saw new crashes in compiler/allocation/TestFailedAllocationBadGraph.java on MacOS intel and aarch64 and linux s390x at least (rest of the tests is still running), Crash shows: # Internal Error (/sapmnt/sapjvm_work/openjdk/nb/darwinaarch64/jdk11u-dev/src/hotspot/share/opto/loopnode.cpp:4666), pid=72056, tid=42755 # assert(real_LCA != __null) failed: must always find an LCA What tests have you run? Goetz has vacation, so I spoke with aph yesterday about the possible backout. He adviced caution here. Roland Westrelin will be back next week, so he could take a look then.
11-08-2022
We are advocating for a patch release (11.0.16.1) to address this: https://mail.openjdk.org/pipermail/jdk-updates-dev/2022-August/016460.html
11-08-2022
We have validated that reverting JDK-8279219 solves the crashes we were seeing
11-08-2022
865 AllocateArray @bci:590 should come from here. https://github.com/corretto/corretto-11/blob/develop/src/java.base/share/classes/sun/security/ssl/SSLEngineInputRecord.java#L313
11-08-2022
in the uploaded ideal graph, c2 has trouble to split ifnode 2797. in PhaseIdealLoop::split_up( Node *n, Node *blk1, Node *blk2), n is 2648 CmpU and 'use' at line 131 is 3699 Phi please note the path 3599 Phi->2933 PHI-> 865 AllocateArray. it connects to https://bugs.openjdk.org/browse/JDK-8279219, which change AllocateArray handling.
10-08-2022
I can see the crash(hit an assertion) with slowdebug build of 11.0.16 and https://gist.github.com/carterkozak/4aff21e72e74d42320b4427953a56385 If I suppress all assertions, c2 compiler thread will get stuck with a dead loop which keeps consuming memory. After 1 minute, I see that hotspot takes over 2.6g. here is the problematic frame. The crash happens in split-if optimization of LoopOpts. -XX:-SplitIfBlocks can skip this phase. The function split_up doesn't expect to meet a phi node. #6 0x00007ffff66757b7 in PhaseIdealLoop::split_up (this=0x7fffca60aa40, n=0x7fffa03ef250, blk1=0x7fffa03f5920, blk2=0x7fffa03f59d8) at /local/home/xxinliu/Devel/ws-openjdk11/src/OpenJDK11Src/src/hotspot/share/opto/split_if.cpp:131 131 assert(use->is_If() || use->is_CMove() || use->Opcode() == Op_Opaque1 || use->is_AllocateArray(), "unexpected node type"); (gdb) call use->dump() 3699 Phi === 3633 3437 3898 [[ 2933 ]] #bool !jvms: Buffer::nextGetIndex @ bci:10 DirectByteBuffer::get @ bci:5 SSLEngineInputRecord::decodeInputRecord @ bci:-
10-08-2022
We have also confirmed that replaying the replay file succeeds with https://bugs.openjdk.org/browse/JDK-8279219 backed out. We are seeing this crash randomly, not long after startup in approximately 1% of the hosts in a large fleet so this is having quite an impact.
10-08-2022
We are also having reports of this crash: ``` Current CompileTask: C2: 52065 28701 ! 4 sun.security.ssl.SSLEngineInputRecord::decodeInputRecord (812 bytes) Stack: [0x00007f8a5a0d7000,0x00007f8a5a1d8000], sp=0x00007f8a5a1d24f0, 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+0xf46f3a] VMError::report_and_die(int, char const*, char const*, __va_list_tag*, Thread*, unsigned char*, void*, void*, char const*, int, unsigned long)+0x1ca V [libjvm.so+0xf47dfb] VMError::report_and_die(Thread*, char const*, int, unsigned long, VMErrorType, char const*, __va_list_tag*)+0x2b V [libjvm.so+0x6d52a5] report_vm_out_of_memory(char const*, int, unsigned long, VMErrorType, char const*, ...)+0xd5 V [libjvm.so+0x44ffd1] Arena::grow(unsigned long, AllocFailStrategy::AllocFailEnum)+0x141 V [libjvm.so+0x4502e2] Arena::Arealloc(void*, unsigned long, unsigned long, AllocFailStrategy::AllocFailEnum)+0x202 V [libjvm.so+0xc39f27] Node_Array::grow(unsigned int)+0x57 V [libjvm.so+0xe1e8bc] PhaseIdealLoop::register_new_node(Node*, Node*)+0xdc V [libjvm.so+0xe1f098] PhaseIdealLoop::split_up(Node*, Node*, Node*) [clone .part.47]+0x788 V [libjvm.so+0xe2131e] PhaseIdealLoop::do_split_if(Node*)+0x2ce V [libjvm.so+0xb0cc47] PhaseIdealLoop::split_if_with_blocks(VectorSet&, Node_Stack&, bool)+0x187 V [libjvm.so+0xb061f3] PhaseIdealLoop::build_and_optimize()+0xcf3 V [libjvm.so+0x672f29] Compile::optimize_loops(int&, PhaseIterGVN&, LoopOptsMode) [clone .part.357]+0x259 V [libjvm.so+0x67600e] Compile::Optimize()+0x101e V [libjvm.so+0x676d05] Compile::Compile(ciEnv*, C2Compiler*, ciMethod*, int, bool, bool, bool, bool, DirectiveSet*)+0xcb5 V [libjvm.so+0x58aa14] C2Compiler::compile_method(ciEnv*, ciMethod*, int, DirectiveSet*)+0xd4 V [libjvm.so+0x6810da] CompileBroker::invoke_compiler_on_method(CompileTask*)+0x3ca V [libjvm.so+0x682808] CompileBroker::compiler_thread_loop()+0x5a8 V [libjvm.so+0xed985f] JavaThread::run()+0x29f V [libjvm.so+0xed61af] Thread::call_run()+0x14f V [libjvm.so+0xc74356] thread_native_entry(Thread*)+0xe6 ```
10-08-2022
Additional Information from submitter: ============================ I have reproduced this failure on all jdk variants I have tried, and have a compiler replay log that also reproduces the issue in an entirely synthetic environment. An assertion is being violated here: https://github.com/openjdk/jdk11u-dev/commit/9ce8530c5d5f179fa42e1060447aead887570124#diff-f53abeb59fc4f74e2760d2ea7b0ebf2dd470c499d5f25ef1b7196e254dcea7adR131 Openjdk from source at the jdk-11.0.16-ga tag azul 11.0.16 corretto 11.0.16 $ ./linux-x86_64-normal-server-fastdebug-jdk-11.0.16-ga/bin/java -XX:+ReplayCompiles -XX:ReplayDataFile=replay.log Resolving klass java/lang/StringBuilder at 1 Resolving klass java/lang/CloneNotSupportedException at 41 Resolving klass java/lang/InterruptedException at 47 Resolving klass java/lang/Throwable at 55 Resolving klass java/lang/Class at 66 <...etc...> Resolving klass sun/security/ssl/Authenticator$TLS10Authenticator at 1 Resolving klass [B at 7 Resolving klass sun/security/ssl/Authenticator$SSLAuthenticator at 13 Resolving klass sun/security/ssl/Authenticator at 41 Resolving klass sun/security/ssl/ProtocolVersion at 45 Resolving klass [B at 48 Resolving klass javax/crypto/spec/IvParameterSpec at 7 Resolving klass javax/crypto/spec/GCMParameterSpec at 28 Resolving klass javax/crypto/Cipher at 30 Resolving klass sun/security/ssl/Plaintext at 60 Resolving klass java/lang/Exception at 69 Resolving klass sun/security/ssl/SSLCipher$T12GcmReadCipherGenerator$GcmReadCipher at 70 Resolving klass sun/security/ssl/SSLCipher$SSLReadCipher at 71 Resolving klass java/nio/ByteBuffer at 127 Resolving klass sun/security/ssl/SSLCipher at 138 Resolving klass sun/security/ssl/JsseJce at 140 Resolving klass java/util/Objects at 143 Resolving klass java/util/Arrays at 166 Resolving klass sun/security/ssl/Authenticator at 179 Resolving klass sun/security/ssl/SSLLogger at 196 Resolving klass sun/security/ssl/ProtocolVersion at 204 # To suppress the following error report, specify this argument # after -XX: or in .hotspotrc: SuppressErrorAt=/split_if.cpp:131 # # A fatal error has been detected by the Java Runtime Environment: # # Internal Error (/home/ckozak/code/openjdk/jdk11u-dev/src/hotspot/share/opto/split_if.cpp:131), pid=352679, tid=352691 # assert(use->is_If() || use->is_CMove() || use->Opcode() == Op_Opaque1 || use->is_AllocateArray()) failed: unexpected node type # # JRE version: OpenJDK Runtime Environment (11.0.16) (fastdebug build 11.0.16-internal+0-adhoc.ckozak.jdk11u-dev) # Java VM: OpenJDK 64-Bit Server VM (fastdebug 11.0.16-internal+0-adhoc.ckozak.jdk11u-dev, mixed mode, tiered, compressed oops, g1 gc, linux-amd64) Building jdk-11.0.15-ga with fastdebug (Identical process to the 11.0.16 configuration, but using the prior release tag) does not crash: $ ./linux-x86_64-normal-server-fastdebug-jdk-11.0.15-ga/bin/java -XX:+ReplayCompiles -XX:ReplayDataFile=replay.log Resolving klass java/lang/StringBuilder at 1 Resolving klass java/lang/CloneNotSupportedException at 41 Resolving klass java/lang/InterruptedException at 47 Resolving klass java/lang/Throwable at 55 Resolving klass java/lang/Class at 66 <...etc...> Resolving klass sun/security/ssl/Authenticator$TLS10Authenticator at 1 Resolving klass [B at 7 Resolving klass sun/security/ssl/Authenticator$SSLAuthenticator at 13 Resolving klass sun/security/ssl/Authenticator at 41 Resolving klass sun/security/ssl/ProtocolVersion at 45 Resolving klass [B at 48 Resolving klass javax/crypto/spec/IvParameterSpec at 7 Resolving klass javax/crypto/spec/GCMParameterSpec at 28 Resolving klass javax/crypto/Cipher at 30 Resolving klass sun/security/ssl/Plaintext at 60 Resolving klass java/lang/Exception at 69 Resolving klass sun/security/ssl/SSLCipher$T12GcmReadCipherGenerator$GcmReadCipher at 70 Resolving klass sun/security/ssl/SSLCipher$SSLReadCipher at 71 Resolving klass java/nio/ByteBuffer at 127 Resolving klass sun/security/ssl/SSLCipher at 138 Resolving klass sun/security/ssl/JsseJce at 140 Resolving klass java/util/Objects at 143 Resolving klass java/util/Arrays at 166 Resolving klass sun/security/ssl/Authenticator at 179 Resolving klass sun/security/ssl/SSLLogger at 196 Resolving klass sun/security/ssl/ProtocolVersion at 204 <success>
08-08-2022
[~roland], please take a look.
04-08-2022
The cause of the assert is that "use" is a Phi node.
04-08-2022
With the replay file I can reproduce the assert (but not the OOM) with OpenJDK 11u. It did not reproduce with Oracle JDK 11u.
04-08-2022
Additional details from email from Carter Kozak <ckozak@ckozak.net>: Hi, I filed JDK-8291665 [1] which was originally closed as “This is not a java bug, the crash is on zulu build”; however, I've since been able to reproduce the issue on standard OpenJDK builds consistently with a compiler replay log [2]. Unfortunately I lack the permissions to update the ticket myself, so I'd like to share my findings here, and hopefully work toward a solution. This impacts OpenJDK jdk-11.0.16-ga [3] (Latest OpenJDK 11 hotfix which resolves a cvss 9.8 vulnerability) observed using public builds as well as a build I created from source. The crash impacted dozens of applications repeatedly within the first day of rollout, as the pattern which triggers the failure exists within the JDK itself, used within TLS. The failure presents as a jvm crash after the compiler consumes all physical memory. Some applications crash after 50-90 seconds around ~30% of launches, while others crash less frequently. In all cases I've observed, the failure has been within C2 compilation of SSLEngineInputRecord::decodeInputRecord The failure is reproducible using the compiler replay log with a debug-enabled jdk-11.0.16-ga and produces an hs_err_pid log as seen below: ./linux-x86_64-normal-server-fastdebug-jdk-11.0.16-ga/bin/java -XX:+ReplayCompiles -XX:ReplayDataFile=replay.log I have verified that the failure is not reproducible using the previous release jdk-11.0.15-ga. The failure appears to be the result of commit 9ce8530c [4] (JDK-8279219 [REDO] C2 crash when allocating array of size too large [5]), reverting this commit allows the replay to complete successfully (not to imply the commit itself should be reverted as I don't have context on what it resolves, but it should help narrow the search space). Thanks, Carter Kozak [1] https://bugs.openjdk.org/browse/JDK-8291665 [2] Compiler replay log can be found here: https://gist.github.com/carterkozak/4aff21e72e74d42320b4427953a56385 [3] https://github.com/openjdk/jdk11u/releases/tag/jdk-11.0.16-ga [4] https://github.com/openjdk/jdk11u/commit/9ce8530c5d5f179fa42e1060447aead887570124 [5] https://bugs.openjdk.org/browse/JDK-8279219 # To suppress the following error report, specify this argument # after -XX: or in .hotspotrc: SuppressErrorAt=/split_if.cpp:131 # # A fatal error has been detected by the Java Runtime Environment: # # Internal Error (/home/user/code/openjdk/jdk11u-dev/src/hotspot/share/opto/split_if.cpp:131), pid=165552, tid=165579 # assert(use->is_If() || use->is_CMove() || use->Opcode() == Op_Opaque1 || use->is_AllocateArray()) failed: unexpected node type # # JRE version: OpenJDK Runtime Environment (11.0.16) (fastdebug build 11.0.16-internal+0-adhoc.user.jdk11u-dev) # Java VM: OpenJDK 64-Bit Server VM (fastdebug 11.0.16-internal+0-adhoc.user.jdk11u-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 /home/user/jvm-debugging/core.165552) # # An error report file with more information is saved as: # /home/user/jvm-debugging/hs_err_pid165552.log # # If you would like to submit a bug report, please visit: # https://bugreport.java.com/bugreport/crash.jsp # Current thread is 165579 Dumping core ... zsh: abort (core dumped) ./linux-x86_64-normal-server-fastdebug-jdk-11.0.16-ga/bin/jav # # A fatal error has been detected by the Java Runtime Environment: # # Internal Error (/home/user/code/openjdk/jdk11u-dev/src/hotspot/share/opto/split_if.cpp:131), pid=165552, tid=165579 # assert(use->is_If() || use->is_CMove() || use->Opcode() == Op_Opaque1 || use->is_AllocateArray()) failed: unexpected node type # # JRE version: OpenJDK Runtime Environment (11.0.16) (fastdebug build 11.0.16-internal+0-adhoc.user.jdk11u-dev) # Java VM: OpenJDK 64-Bit Server VM (fastdebug 11.0.16-internal+0-adhoc.user.jdk11u-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 /home/user/jvm-debugging/core.165552) # # If you would like to submit a bug report, please visit: # https://bugreport.java.com/bugreport/crash.jsp # --------------- S U M M A R Y ------------ Command Line: -XX:+ReplayCompiles -XX:ReplayDataFile=replay.log Host: linux, Intel(R) Xeon(R) W-2175 CPU @ 2.50GHz, 28 cores, 62G, Ubuntu 20.04.4 LTS Time: Thu Aug 4 08:27:42 2022 EDT elapsed time: 0.606943 seconds (0d 0h 0m 0s) --------------- T H R E A D --------------- Current thread (0x00007f75003c8800): JavaThread "C2 CompilerThread0" daemon [_thread_in_native, id=165579, stack(0x00007f74b6434000,0x00007f74b6535000)] Current CompileTask: C2: 606 27 !b 4 sun.security.ssl.SSLEngineInputRecord::decodeInputRecord (812 bytes) Stack: [0x00007f74b6434000,0x00007f74b6535000], sp=0x00007f74b652e030, free space=1000k Native frames: (J=compiled Java code, A=aot compiled Java code, j=interpreted, Vv=VM code, C=native code) V [libjvm.so+0x1a6ea5a] VMError::report_and_die(int, char const*, char const*, __va_list_tag*, Thread*, unsigned char*, void*, void*, char const*, int, unsigned long)+0x1ca V [libjvm.so+0x1a6fbc5] VMError::report_and_die(Thread*, void*, char const*, int, char const*, char const*, __va_list_tag*)+0x35 V [libjvm.so+0xc302aa] report_vm_error(char const*, int, char const*, char const*, ...)+0x10a V [libjvm.so+0x187b68d] PhaseIdealLoop::split_up(Node*, Node*, Node*) [clone .part.0]+0x173d V [libjvm.so+0x187f8e3] PhaseIdealLoop::do_split_if(Node*)+0x763 V [libjvm.so+0x1442420] PhaseIdealLoop::split_if_with_blocks_post(Node*, bool)+0xf20 V [libjvm.so+0x144267d] PhaseIdealLoop::split_if_with_blocks(VectorSet&, Node_Stack&, bool)+0x20d V [libjvm.so+0x14378a3] PhaseIdealLoop::build_and_optimize()+0x1133 V [libjvm.so+0xb3f881] Compile::optimize_loops(int&, PhaseIterGVN&, LoopOptsMode) [clone .part.0]+0x311 V [libjvm.so+0xb4418f] Compile::Optimize()+0xd1f V [libjvm.so+0xb46116] Compile::Compile(ciEnv*, C2Compiler*, ciMethod*, int, bool, bool, bool, bool, DirectiveSet*)+0x1ae6 V [libjvm.so+0x915c24] C2Compiler::compile_method(ciEnv*, ciMethod*, int, DirectiveSet*)+0x334 V [libjvm.so+0xb57250] CompileBroker::invoke_compiler_on_method(CompileTask*)+0x540 V [libjvm.so+0xb588f8] CompileBroker::compiler_thread_loop()+0x678 V [libjvm.so+0x19a4c52] JavaThread::thread_main_inner()+0x252 V [libjvm.so+0x199d62b] Thread::call_run()+0x7b V [libjvm.so+0x1693926] thread_native_entry(Thread*)+0x106 --------------- P R O C E S S --------------- uid : 1000 euid : 1000 gid : 1000 egid : 1000 umask: 0002 (-------w-) Threads class SMR info: _java_thread_list=0x00007f7500885270, length=9, elements={ 0x00007f7500032000, 0x00007f750039e000, 0x00007f75003a0800, 0x00007f75003c3800, 0x00007f75003c6000, 0x00007f75003c8800, 0x00007f75003cb000, 0x00007f75003cd800, 0x00007f7500886000 } _java_thread_list_alloc_cnt=10, _java_thread_list_free_cnt=9, _java_thread_list_max=9, _nested_thread_list_max=0 _tlh_cnt=34, _tlh_times=0, avg_tlh_time=0.00, _tlh_time_max=0 _delete_lock_wait_cnt=0, _delete_lock_wait_max=0 _to_delete_list_cnt=0, _to_delete_list_max=1 Java Threads: ( => current thread ) 0x00007f7500032000 JavaThread "main" [_thread_blocked, id=165553, stack(0x00007f7505585000,0x00007f7505686000)] 0x00007f750039e000 JavaThread "Reference Handler" daemon [_thread_blocked, id=165573, stack(0x00007f74b6da8000,0x00007f74b6ea9000)] 0x00007f75003a0800 JavaThread "Finalizer" daemon [_thread_blocked, id=165574, stack(0x00007f74b6ca7000,0x00007f74b6da8000)] 0x00007f75003c3800 JavaThread "Signal Dispatcher" daemon [_thread_blocked, id=165577, stack(0x00007f74b6636000,0x00007f74b6737000)] 0x00007f75003c6000 JavaThread "Service Thread" daemon [_thread_blocked, id=165578, stack(0x00007f74b6535000,0x00007f74b6636000)] =>0x00007f75003c8800 JavaThread "C2 CompilerThread0" daemon [_thread_in_native, id=165579, stack(0x00007f74b6434000,0x00007f74b6535000)] 0x00007f75003cb000 JavaThread "C1 CompilerThread0" daemon [_thread_blocked, id=165580, stack(0x00007f74b6333000,0x00007f74b6434000)] 0x00007f75003cd800 JavaThread "Sweeper thread" daemon [_thread_blocked, id=165581, stack(0x00007f74b6232000,0x00007f74b6333000)] 0x00007f7500886000 JavaThread "Common-Cleaner" daemon [_thread_blocked, id=165612, stack(0x00007f74b59d1000,0x00007f74b5ad2000)] Other Threads: 0x00007f7500388000 VMThread "VM Thread" [stack: 0x00007f74b6eab000,0x00007f74b6fab000] [id=165572] 0x00007f75004c1800 WatcherThread [stack: 0x00007f74b6132000,0x00007f74b6232000] [id=165586] 0x00007f7500052000 GCTaskThread "GC Thread#0" [stack: 0x00007f750521e000,0x00007f750531e000] [id=165558] 0x00007f7500091000 ConcurrentGCThread "G1 Main Marker" [stack: 0x00007f74e8218000,0x00007f74e8318000] [id=165563] 0x00007f7500093000 ConcurrentGCThread "G1 Conc#0" [stack: 0x00007f74e8116000,0x00007f74e8216000] [id=165564] 0x00007f750026b800 ConcurrentGCThread "G1 Refine#0" [stack: 0x00007f74b79fb000,0x00007f74b7afb000] [id=165566] 0x00007f750026e000 ConcurrentGCThread "G1 Young RemSet Sampling" [stack: 0x00007f74b78f9000,0x00007f74b79f9000] [id=165567] Threads with active compile tasks: C2 CompilerThread0 614 27 !b 4 sun.security.ssl.SSLEngineInputRecord::decodeInputRecord (812 bytes)
04-08-2022
This is not a java bug, the crash is on zulu build: JRE version: OpenJDK Runtime Environment Zulu11.58+15-CA (11.0.16+8) (build 11.0.16+8-LTS) Submitter can report this crash to Azul
02-08-2022