JDK-8316361 : C2: assert(!failure) failed: Missed optimization opportunity in PhaseIterGVN with -XX:VerifyIterativeGVN=10
  • Type: Bug
  • Component: hotspot
  • Sub-Component: compiler
  • Affected Version: 21,22
  • Priority: P4
  • Status: Resolved
  • Resolution: Fixed
  • Submitted: 2023-09-15
  • Updated: 2024-07-05
  • Resolved: 2023-10-02
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 21 JDK 22
21.0.5-oracleFixed 22 b18Fixed
Related Reports
Relates :  
JDK-8298176 - remove OpaqueZeroTripGuardPostLoop once main-loop disappears
Relates :  
JDK-8298952 - All nodes should have type(n) == Value(n) after IGVN
Relates :  
JDK-8318049 - C2: assert(!failure) failed: Missed optimization opportunity in PhaseIterGVN
Description
A fuzzy test have crashed with the following error:

assert(!failure) failed: Missed optimization opportunity in PhaseIterGVN

Missed Value optimization:
dist dump
---------------------------------------------
   1  524  OpaqueZeroTripGuard  === _ 233  [[ 525 ]] 
   1  491  AddI  === _ 501 32  [[ 490 501 510 525 ]]  !orig=422,[242] !jvms: Test::vMeth @ bci:180 (line 274)
   0  525  CmpI  === _ 491 524  [[ 526 ]] 
Current type:
int:-1..1
Optimized type:
int:1


Stack:

Native frames: (J=compiled Java code, j=interpreted, Vv=VM code, C=native code)
V  [libjvm.dylib+0x13ccb00]  VMError::report_and_die(int, char const*, char const*, char*, Thread*, unsigned char*, void*, void*, char const*, int, unsigned long)+0x4bc  (phaseX.cpp:1080)
V  [libjvm.dylib+0x13cd4a8]  VMError::report_and_die(Thread*, void*, char const*, int, char const*, char const*, char*)+0x40
V  [libjvm.dylib+0x6bbc4c]  report_vm_error(char const*, int, char const*, char const*, ...)+0x6c
V  [libjvm.dylib+0x10c2a94]  PhaseIterGVN::verify_optimize()+0x480
V  [libjvm.dylib+0x6191bc]  PhaseIdealLoop::optimize(PhaseIterGVN&, LoopOptsMode)+0x124
V  [libjvm.dylib+0x6195b4]  Compile::optimize_loops(PhaseIterGVN&, LoopOptsMode)+0x70
V  [libjvm.dylib+0x6125dc]  Compile::Optimize()+0xa0c
V  [libjvm.dylib+0x610678]  Compile::Compile(ciEnv*, ciMethod*, int, Options, DirectiveSet*)+0x1474
V  [libjvm.dylib+0x4c3488]  C2Compiler::compile_method(ciEnv*, ciMethod*, int, bool, DirectiveSet*)+0x1dc
V  [libjvm.dylib+0x631110]  CompileBroker::invoke_compiler_on_method(CompileTask*)+0xa00
V  [libjvm.dylib+0x630450]  CompileBroker::compiler_thread_loop()+0x3c8
V  [libjvm.dylib+0xa3dfcc]  JavaThread::thread_main_inner()+0x334
V  [libjvm.dylib+0x12f4128]  Thread::call_run()+0x134
V  [libjvm.dylib+0x1055654]  thread_native_entry(Thread*)+0x160
C  [libsystem_pthread.dylib+0x706c]  _pthread_start+0x94

The test was started on macosx-aarch64 (have also been spotted on linux-x64) with the following stress flags:

-XX:RepeatCompilation=81 -Xmx1G -XX:+IgnoreUnrecognizedVMOptions -XX:CompileOnly=*Test*::* -XX:CompileCommand=quiet -XX:-TieredCompilation -Xcomp -XX:+UnlockDiagnosticVMOptions -XX:+StressLCM -XX:+StressGCM -XX:+StressIGVN -XX:+StressCCP -XX:StressSeed=578462776 -XX:+UnlockExperimentalVMOptions -XX:PerMethodSpecTrapLimit=0 -XX:PerMethodTrapLimit=0 -XX:+VerifyLoopOptimizations -XX:VerifyIterativeGVN=10 -XX:MaxRAMPercentage=6.25

Please find hs_err and the test files attached.
Comments
jdk21u-dev backport request I would like to have the patch in OpenJDk 21u-dev as well, for parity with OracleJDK. The backport is clean and low-to-medium risk.
05-07-2024
A pull request was submitted for review. URL: https://git.openjdk.org/jdk21u-dev/pull/820 Date: 2024-07-04 08:12:19 +0000
04-07-2024
The fix for this bug is integrated in jdk-22+18-1378.
02-10-2023
Changeset: eeb63cd0 Author: Emanuel Peter <epeter@openjdk.org> Date: 2023-10-02 08:03:10 +0000 URL: https://git.openjdk.org/jdk/commit/eeb63cd0fad9de1f7182ab97d0f25ac67745aa9e
02-10-2023
Here's a log file snippet from the jdk-22+18-1369-tier8 sighting: applications/javafuzzer/BigTest.java #section:driver ----------messages:(7/309)---------- command: driver applications.javafuzzer.JavaFuzzerRunner -NT 300 reason: User specified action: run driver/timeout=100000 applications.javafuzzer.JavaFuzzerRunner -NT 300 started: Sun Oct 01 03:51:01 UTC 2023 Mode: agentvm Agent id: 2 finished: Sun Oct 01 12:05:39 UTC 2023 elapsed time (seconds): 29677.929 ----------configuration:(16/2434)---------- <snip> ----------System.out:(53/3758)---------- For random generator using seed: 8000374035869827031 To re-run test with same seed value please add "-Djdk.test.lib.random.seed=8000374035869827031" to command line. Using JRuby executable: /opt/mach5/mesos/work_dir/jib-master/install/org/jruby/jruby-dist/9.2.12.0/jruby-dist-9.2.12.0-bin.zip/jruby-9.2.12.0/bin/jruby Starting JavaFuzzer: '/bin/bash /opt/mach5/mesos/work_dir/jib-master/install/com/oracle/jpg/bigapps/javafuzzer/javafuzzer/2.0/javafuzzer-2.0.zip/mrt.sh -R /opt/mach5/mesos/work_dir/slaves/cd627e65-f015-4fb1-a1d2-b6c9b8127f98-S202949/frameworks/1735e8a2-a1db-478c-8104-60c8b0af87dd-0196/executors/97fd2739-4dfc-4c46-8e5f-aadbdd6e9a9b/runs/a39f0df2-aeba-4006-822b-acf32866d689/testoutput/test-support/jtreg_closed_test_hotspot_jtreg_applications_javafuzzer_BigTest_java/scratch/0 -NT 300 -NP 12 -A -conf config.yml' [2023-10-01T03:51:06.646334428Z] Gathering output for process 6534 [2023-10-01T12:05:38.779453713Z] Waiting for completion for process 6534 [2023-10-01T12:05:38.779755506Z] Waiting for completion finished for process 6534 Output and diagnostic info for process 6534 was saved into 'pid-6534-output.log' Summary of the JavaFuzzer run: ------------------------------ Host: ol7-x64-165599 Tests: 12 x 300 Args: -conf config.yml Started at: Sun Oct 1 03:51:06 UTC 2023 r6- 300: 195 passed, 1 crashes, 0 fails, 0 hangs, 0 incorrect tests, 104 Reference Java failures r3- 300: 188 passed, 0 crashes, 0 fails, 0 hangs, 0 incorrect tests, 112 Reference Java failures r12- 300: 197 passed, 0 crashes, 0 fails, 0 hangs, 0 incorrect tests, 103 Reference Java failures r9- 300: 180 passed, 0 crashes, 0 fails, 0 hangs, 0 incorrect tests, 120 Reference Java failures r5- 300: 168 passed, 0 crashes, 0 fails, 0 hangs, 0 incorrect tests, 132 Reference Java failures r2- 300: 191 passed, 0 crashes, 0 fails, 0 hangs, 0 incorrect tests, 109 Reference Java failures r7- 300: 184 passed, 0 crashes, 0 fails, 0 hangs, 0 incorrect tests, 116 Reference Java failures r10- 300: 179 passed, 0 crashes, 0 fails, 0 hangs, 0 incorrect tests, 121 Reference Java failures r8- 300: 181 passed, 0 crashes, 0 fails, 0 hangs, 0 incorrect tests, 119 Reference Java failures r1- 300: 175 passed, 0 crashes, 0 fails, 0 hangs, 0 incorrect tests, 125 Reference Java failures r11- 300: 180 passed, 0 crashes, 0 fails, 0 hangs, 0 incorrect tests, 120 Reference Java failures r4- 300: 173 passed, 0 crashes, 0 fails, 0 hangs, 0 incorrect tests, 127 Reference Java failures Finished at: Sun Oct 1 12:05:38 UTC 2023 # # A fatal error has been detected by the Java Runtime Environment: # # Internal Error (/opt/mach5/mesos/work_dir/slaves/cd627e65-f015-4fb1-a1d2-b6c9b8127f98-S202615/frameworks/1735e8a2-a1db-478c-8104-60c8b0af87dd-0196/executors/8e55b3a4-6c35-4a62-ba3a-9b6622c7013e/runs/074bcfa6-aeef-4998-ab03-4240c3258975/workspace/open/src/hotspot/share/opto/phaseX.cpp:1087), pid=4220, tid=4329 # assert(!failure) failed: Missed optimization opportunity in PhaseIterGVN # # JRE version: Java(TM) SE Runtime Environment (22.0+18) (fastdebug build 22-ea+18-1369) # Java VM: Java HotSpot(TM) 64-Bit Server VM (fastdebug 22-ea+18-1369, compiled mode, sharing, compressed oops, compressed class ptrs, g1 gc, linux-amd64) # Problematic frame: # V [libjvm.so+0x152942e] PhaseIterGVN::verify_optimize() [clone .part.0]+0x69e # # Core dump will be written. Default location: Core dumps may be processed with "/opt/core.sh %p" (or dumping to /tmp/fuzzer.tmp.nNgnof6xdP/core.4220) # # If you would like to submit a bug report, please visit: # https://bugreport.java.com/bugreport/crash.jsp # [2023-10-01T12:05:39.052194012Z] Waiting for completion for process 6534 [2023-10-01T12:05:39.052392279Z] Waiting for completion finished for process 6534 ----------System.err:(15/908)---------- java.lang.RuntimeException: assertEquals: expected 1 to equal 2 at jdk.test.lib.Asserts.fail(Asserts.java:594) at jdk.test.lib.Asserts.assertEquals(Asserts.java:205) at jdk.test.lib.Asserts.assertEquals(Asserts.java:189) at applications.javafuzzer.JavaFuzzerRunner.reportResults(JavaFuzzerRunner.java:247) at applications.javafuzzer.JavaFuzzerRunner.runWithConfigurations(JavaFuzzerRunner.java:268) at applications.javafuzzer.JavaFuzzerRunner.main(JavaFuzzerRunner.java:290) at java.base/jdk.internal.reflect.DirectMethodHandleAccessor.invoke(DirectMethodHandleAccessor.java:103) at java.base/java.lang.reflect.Method.invoke(Method.java:580) at com.sun.javatest.regtest.agent.MainActionHelper$AgentVMRunnable.run(MainActionHelper.java:333) at java.base/java.lang.Thread.run(Thread.java:1570) JavaTest Message: Test threw exception: java.lang.RuntimeException JavaTest Message: shutting down test result: Failed. Execution failed: `main' threw exception: java.lang.RuntimeException: assertEquals: expected 1 to equal 2 Here's the crashing thread's stack: --------------- T H R E A D --------------- Current thread (0x00007fa1cc33ec30): JavaThread "C2 CompilerThread0" daemon [_thread_in_native, id=4329, stack(0x00007fa1bc228000,0x00007fa1bc328000) (1024K)] Current CompileTask: C2: 1601 81 b Test::iMeth (250 bytes) Stack: [0x00007fa1bc228000,0x00007fa1bc328000], sp=0x00007fa1bc323150, free space=1004k Native frames: (J=compiled Java code, j=interpreted, Vv=VM code, C=native code) V [libjvm.so+0x152942e] PhaseIterGVN::verify_optimize() [clone .part.0]+0x69e (phaseX.cpp:1087) V [libjvm.so+0x152a5b8] PhaseIterGVN::optimize()+0x328 (phaseX.cpp:1058) V [libjvm.so+0x9f2efa] PhaseIdealLoop::optimize(PhaseIterGVN&, LoopOptsMode)+0x64a (loopnode.hpp:1198) V [libjvm.so+0x9ee214] Compile::Optimize()+0xe14 (compile.cpp:2362) V [libjvm.so+0x9f1a30] Compile::Compile(ciEnv*, ciMethod*, int, Options, DirectiveSet*)+0x1bb0 (compile.cpp:854) V [libjvm.so+0x84ac5b] C2Compiler::compile_method(ciEnv*, ciMethod*, int, bool, DirectiveSet*)+0x13b (c2compiler.cpp:119) V [libjvm.so+0x9fd9e0] CompileBroker::invoke_compiler_on_method(CompileTask*)+0x980 (compileBroker.cpp:2282) V [libjvm.so+0x9fe768] CompileBroker::compiler_thread_loop()+0x508 (compileBroker.cpp:1943) V [libjvm.so+0xebc7bc] JavaThread::thread_main_inner()+0xcc (javaThread.cpp:720) V [libjvm.so+0x17a3e5a] Thread::call_run()+0xba (thread.cpp:220) V [libjvm.so+0x14a90da] thread_native_entry(Thread*)+0x12a (os_linux.cpp:786)
01-10-2023
A pull request was submitted for review. URL: https://git.openjdk.org/jdk/pull/15886 Date: 2023-09-22 10:47:00 +0000
22-09-2023
Reduced1: ./java -XX:RepeatCompilation=81 -Xmx1G -XX:+IgnoreUnrecognizedVMOptions -XX:CompileOnly=*Reduced1*::* -XX:CompileCommand=quiet -XX:-TieredCompilation -Xcomp -XX:+UnlockDiagnosticVMOptions -XX:+StressLCM -XX:+StressGCM -XX:+StressIGVN -XX:+StressCCP -XX:StressSeed=578462776 -XX:+UnlockExperimentalVMOptions -XX:PerMethodSpecTrapLimit=0 -XX:PerMethodTrapLimit=0 -XX:+VerifyLoopOptimizations -XX:VerifyIterativeGVN=10 -XX:MaxRAMPercentage=6.25 Reduced1.java Reduced2 ./java -XX:CompileCommand=compileonly,Reduced2::test -Xcomp -XX:VerifyIterativeGVN=10 Reduced2.java
21-09-2023
Seems to fail since the introduction of the VerifyIterativeGVN flag in JDK 21. The problem most likely exists in earlier JDK versions as well.
15-09-2023
ILW = C2 assertion failure in IGVN verification only affecting debug, single fuzzer test and only with -XX:VerifyIterativeGVN=10, use different value for -XX:VerifyIterativeGVN = MLM = P4
15-09-2023