Skip to content

Enable bigCallee size adjustment during ECS for JDK8 and 11 #21978

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Open
wants to merge 1 commit into
base: master
Choose a base branch
from

Conversation

nbhuiyan
Copy link
Member

@nbhuiyan nbhuiyan commented May 29, 2025

During EstimateCodeSize, if we came across a callee method that was deemed too big, and therefore, set to be discarded as an inlining candidate, a size adjustment for other methods above such methods is necessary to ensure the entire call graph does not get marked as too big. For JDK8 and 11, this adjustment was disabled due to a functional issue that was exposed due to the different inlining outcome from this adjustment. This change removes the restriction that was in place as a workaround, and fixes performance issues resulting from early ECS termination in JDK8 and 11.

The restriction placed to avoid any functional issues until JDK8 and 11 builds switch to using OpenJDK MethodHandle implementation is to terminate recursive ECS once we reach a MethodHandle thunk archetype.

With the initial attempt to have this be in effect across all Java versions, we ran into test failures across several platforms with JDK8 and 11, detailed in #21397. Test failures reported in #21397 are no longer reproducible with the current set of inliner changes that have been contributed over the past few months. Attempting to reproduce those test failures with the change in this PR has been unsuccessful in 60X Grinder on Aarch64 Linux (JDK11). Furthermore, no failures were seen in a 100X Grinder job on X86_64 Linux (JDK11), in which over half of the test iterations have completed as of now.

Recently, the WAS perf team observed a regression using IBM Java 8 caused by the ECS issue that this PR is going to address. In addition to fixing the perf regression, an additional 2.8% performance gain was observed compared to the pre-regression baseline build. Given the significant perf impact this change has, I would like to propose that this change is double-delivered for the 0.53 release branch. @vijaysun-omr @vij-singh @pshipton Please let me know your thoughts on whether we have enough justification to double deliver this.

@vijaysun-omr Also, requesting your review of this change.

@vijaysun-omr
Copy link
Contributor

The IBM JDK8 regression from WAS perf was significant in some cases, in the 5-7% throughput range. If a formal issue has not been opened by them, it could be (if that makes the decision to double deliver any easier). I would say we should consider double delivering it, since it is a fix for a performance regression, but will also wait for @vij-singh and @pshipton opinions.

@pshipton
Copy link
Member

It's past DCUT for 0.53, only bug fixes are allowed now.

@vijaysun-omr
Copy link
Contributor

"This is a performance bug" was what my comment was saying

@vij-singh
Copy link

Given this is to fix a significant performance bug (regression) that has been hit by WAS Perf, and that the change has already been in place for Java >11, I vote for this to be allowed into 0.53 and 8.0.8.50.

@nbhuiyan
Copy link
Member Author

I have observed a fairly reproducible intermittent failure using a JDK8 Windows build with this change. The failure output suggests that it may be related to OpenJ9 MethodHandles. I am investigating the cause of that failure. We may need to restrict ECS along OpenJ9 MethodHandle thunks due to the various functional issues that keep showing up with changes to inliner behaviour.

Failure output:

01:49:23    java/util/stream/test/org/openjdk/tests/java/util/stream/StreamSpliteratorTest.java
01:49:23  
01:49:23  config java.util.stream.LoggingTestCase.before(): success
01:49:23  STDERR:
01:49:23  Unhandled exception
01:49:23  Type=Segmentation error vmState=0x000501ff
01:49:23  Windows_ExceptionCode=c0000005 J9Generic_Signal=00000004 ExceptionAddress=00007FFE6E641284 ContextFlags=0010005f
01:49:23  Handler1=00007FFE6E65F740 Handler2=00007FFE7408AEC0 InaccessibleReadAddress=0000000000000070
01:49:23  RDI=00007FF4D10F8390 RSI=00007FF4D1050000 RAX=0000000000000400 RBX=00007FF4D11129D0
01:49:23  RCX=0000000000000000 RDX=000000000029FE00 R8=000000000029FE00 R9=00007FFE6E6AA3F0
01:49:23  R10=00007FF4D1050000 R11=0000001AA35F99F8 R12=0000000000000000 R13=00007FF4D1130780
01:49:23  R14=00007FF4D11024E0 R15=00007FF4D1112A30
01:49:23  RIP=00007FFE6E641284 RSP=0000001AA35F9940 RBP=000000000029FE00 EFLAGS=0000000000010287
01:49:23  FS=0053 ES=002B DS=002B
01:49:23  XMM0=0000000000000000 (f: 0.000000, d: 0.000000e+00)
01:49:23  XMM1=0000000000000000 (f: 0.000000, d: 0.000000e+00)
01:49:23  XMM2=000000003f400000 (f: 1061158912.000000, d: 5.242822e-315)
01:49:23  XMM3=000000003f400000 (f: 1061158912.000000, d: 5.242822e-315)
01:49:23  XMM4=0000000000000000 (f: 0.000000, d: 0.000000e+00)
01:49:23  XMM5=7362412473726f74 (f: 1936879488.000000, d: 6.381687e+247)
01:49:23  XMM6=000000003f8ccccd (f: 1066192064.000000, d: 5.267689e-315)
01:49:23  XMM7=0000000000000000 (f: 0.000000, d: 0.000000e+00)
01:49:23  XMM8=0000000000000000 (f: 0.000000, d: 0.000000e+00)
01:49:23  XMM9=0000000000000000 (f: 0.000000, d: 0.000000e+00)
01:49:23  XMM10=0000000000000000 (f: 0.000000, d: 0.000000e+00)
01:49:23  XMM11=0000000000000000 (f: 0.000000, d: 0.000000e+00)
01:49:23  XMM12=0000000000000000 (f: 0.000000, d: 0.000000e+00)
01:49:23  XMM13=0000000000000000 (f: 0.000000, d: 0.000000e+00)
01:49:23  XMM14=0000000000000000 (f: 0.000000, d: 0.000000e+00)
01:49:23  XMM15=0000000000000000 (f: 0.000000, d: 0.000000e+00)
01:49:23  Module=C:\Users\jenkins\workspace\Grinder_iteration_0\jdkbinary\j2sdk-image\jre\bin\default\j9jit29.dll
01:49:23  Module_base_address=00007FFE6E5F0000 Offset_in_DLL=0000000000051284
01:49:23  
01:49:23  Method_being_compiled=java/util/stream/StreamSpliterators$AbstractWrappingSpliterator.getComparator()Ljava/util/Comparator;
01:49:23  Target=2_90_20250528_1167 (Windows Server 2019 10.0 build 17763)
01:49:23  CPU=amd64 (4 logical CPUs) (0x1fff78000 RAM)
01:49:23  ----------- Stack Backtrace -----------
01:49:23  (0x00007FFE6E641284 [j9jit29+0x51284])
01:49:23  Java_java_lang_invoke_ThunkTuple_initialInvokeExactThunk+0x253a1f (0x00007FFE6E9153EF [j9jit29+0x3253ef])
01:49:23  Java_java_lang_invoke_ThunkTuple_initialInvokeExactThunk+0xeaaaa (0x00007FFE6E7AC47A [j9jit29+0x1bc47a])
01:49:23  Java_java_lang_invoke_ThunkTuple_initialInvokeExactThunk+0x30422c (0x00007FFE6E9C5BFC [j9jit29+0x3d5bfc])
01:49:23  Java_java_lang_invoke_ThunkTuple_initialInvokeExactThunk+0x301e59 (0x00007FFE6E9C3829 [j9jit29+0x3d3829])
01:49:23  Java_java_lang_invoke_ThunkTuple_initialInvokeExactThunk+0xeac4c (0x00007FFE6E7AC61C [j9jit29+0x1bc61c])
01:49:23  Java_java_lang_invoke_ThunkTuple_initialInvokeExactThunk+0xc313a (0x00007FFE6E784B0A [j9jit29+0x194b0a])
01:49:23  Java_java_lang_invoke_ThunkTuple_initialInvokeExactThunk+0x300415 (0x00007FFE6E9C1DE5 [j9jit29+0x3d1de5])
01:49:23  Java_java_lang_invoke_ThunkTuple_initialInvokeExactThunk+0xc1da4 (0x00007FFE6E783774 [j9jit29+0x193774])
01:49:23  Java_java_lang_invoke_ThunkTuple_initialInvokeExactThunk+0x3bc99e (0x00007FFE6EA7E36E [j9jit29+0x48e36e])
01:49:23  Java_java_lang_invoke_ThunkTuple_initialInvokeExactThunk+0x3b9346 (0x00007FFE6EA7AD16 [j9jit29+0x48ad16])
01:49:23  Java_java_lang_invoke_ThunkTuple_initialInvokeExactThunk+0x25602f (0x00007FFE6E9179FF [j9jit29+0x3279ff])
01:49:23  (0x00007FFE6E64CC43 [j9jit29+0x5cc43])
01:49:23  (0x00007FFE6E650225 [j9jit29+0x60225])
01:49:23  j9port_isCompatible+0x18e76 (0x00007FFE7408B946 [j9prt29+0x1b946])
01:49:23  j9port_isCompatible+0x1a5f3 (0x00007FFE7408D0C3 [j9prt29+0x1d0c3])
01:49:23  (0x00007FFE6E64C39C [j9jit29+0x5c39c])
01:49:23  (0x00007FFE6E6527CA [j9jit29+0x627ca])
01:49:23  (0x00007FFE6E65219F [j9jit29+0x6219f])
01:49:23  (0x00007FFE6E65F570 [j9jit29+0x6f570])
01:49:23  j9port_isCompatible+0x1a62e (0x00007FFE7408D0FE [j9prt29+0x1d0fe])
01:49:23  (0x00007FFE6E65F268 [j9jit29+0x6f268])
01:49:23  omrthread_get_category+0xa15 (0x00007FFE743C4375 [j9thr29+0x4375])
01:49:23  _o_exp+0x5a (0x00007FFE8514268A [ucrtbase+0x2268a])
01:49:23  BaseThreadInitThunk+0x14 (0x00007FFE85407AC4 [KERNEL32+0x17ac4])
01:49:23  RtlUserThreadStart+0x21 (0x00007FFE8815A8C1 [ntdll+0x5a8c1])
01:49:23  ---------------------------------------
01:49:23  JVMDUMP039I Processing dump event "gpf", detail "" at 2025/05/28 22:48:59 - please wait.
01:49:23  JVMDUMP032I JVM requested System dump using 'C:\Users\jenkins\workspace\Grinder_iteration_0\aqa-tests\TKG\output_17484929054091\jdk_util_0\work\java\util\stream\test\org\openjdk\tests\java\util\stream\StreamSpliteratorTest\core.20250528.224859.1652.0001.dmp' in response to an event
01:49:23  JVMDUMP010I System dump written to C:\Users\jenkins\workspace\Grinder_iteration_0\aqa-tests\TKG\output_17484929054091\jdk_util_0\work\java\util\stream\test\org\openjdk\tests\java\util\stream\StreamSpliteratorTest\core.20250528.224859.1652.0001.dmp
01:49:23  JVMDUMP032I JVM requested Java dump using 'C:\Users\jenkins\workspace\Grinder_iteration_0\aqa-tests\TKG\output_17484929054091\jdk_util_0\work\java\util\stream\test\org\openjdk\tests\java\util\stream\StreamSpliteratorTest\javacore.20250528.224859.1652.0002.txt' in response to an event
01:49:23  JVMDUMP010I Java dump written to C:\Users\jenkins\workspace\Grinder_iteration_0\aqa-tests\TKG\output_17484929054091\jdk_util_0\work\java\util\stream\test\org\openjdk\tests\java\util\stream\StreamSpliteratorTest\javacore.20250528.224859.1652.0002.txt
01:49:23  JVMDUMP032I JVM requested Snap dump using 'C:\Users\jenkins\workspace\Grinder_iteration_0\aqa-tests\TKG\output_17484929054091\jdk_util_0\work\java\util\stream\test\org\openjdk\tests\java\util\stream\StreamSpliteratorTest\Snap.20250528.224859.1652.0003.trc' in response to an event
01:49:23  JVMDUMP010I Snap dump written to C:\Users\jenkins\workspace\Grinder_iteration_0\aqa-tests\TKG\output_17484929054091\jdk_util_0\work\java\util\stream\test\org\openjdk\tests\java\util\stream\StreamSpliteratorTest\Snap.20250528.224859.1652.0003.trc
01:49:23  JVMDUMP032I JVM requested JIT dump using 'C:\Users\jenkins\workspace\Grinder_iteration_0\aqa-tests\TKG\output_17484929054091\jdk_util_0\work\java\util\stream\test\org\openjdk\tests\java\util\stream\StreamSpliteratorTest\jitdump.20250528.224859.1652.0004.dmp' in response to an event
01:49:23  JVMDUMP051I JIT dump occurred in 'JIT Compilation Thread-001' thread 0x000000000001E900
01:49:23  JVMDUMP049I JIT dump notified all waiting threads of the current method to be compiled
01:49:23  JVMDUMP054I JIT dump is tracing the IL of the method on the crashed compilation thread
01:49:23  JVMDUMP048I JIT dump method being compiled is an ordinary method
01:49:23  JVMDUMP053I JIT dump is recompiling java/util/stream/StreamSpliterators$AbstractWrappingSpliterator.getComparator()Ljava/util/Comparator;
01:49:23  JVMDUMP052I JIT dump recursive crash occurred on diagnostic thread
01:49:23  JVMDUMP010I JIT dump written to C:\Users\jenkins\workspace\Grinder_iteration_0\aqa-tests\TKG\output_17484929054091\jdk_util_0\work\java\util\stream\test\org\openjdk\tests\java\util\stream\StreamSpliteratorTest\jitdump.20250528.224859.1652.0004.dmp
01:49:23  JVMDUMP013I Processed dump event "gpf", detail "".
01:49:23  rerun:
01:49:23  cd 'C:\Users\jenkins\workspace\Grinder_iteration_0\aqa-tests\TKG\output_17484929054091\jdk_util_0\work\java\util\stream\test\org\openjdk\tests\java\util\stream\StreamSpliteratorTest' && \

@nbhuiyan nbhuiyan force-pushed the bigcallees-oj9mh branch from 9ca3233 to 0200798 Compare June 2, 2025 21:31
@nbhuiyan
Copy link
Member Author

nbhuiyan commented Jun 2, 2025

@vijaysun-omr I have a workaround in place to avoid running into functional issues with OpenJ9 MethodHandle inlining behavioural changes we get from the big callees adjustment. Requesting review.

@@ -1817,7 +1817,11 @@ TR_J9EstimateCodeSize::realEstimateCodeSize(TR_CallTarget *calltarget, TR_CallSt
int32_t origRealSize = _realSize;
int32_t origBigCalleesSize = _bigCalleesSize;
bool prevNonColdCalls = _hasNonColdCalls;
bool estimateSuccess = estimateCodeSize(targetCallee, &callStack, /* recurseDown */ true, analyzedSizeThreshold);
bool estimateSuccess = false;
// Terminate recursive ECS along archetypes due to functional issues resulting from continuing ECS in Java 8 and 11.
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

On the face of it, this seems like we won't inline past an archetype call, which could risk regressions on MH heavy workloads. I know this change has worked well in a non-MH heavy workload (Liberty) but have you tested this on MH heavy benchmarks ? If it has not regressed there, is there an intuitive reason for why ?

Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I have tested this on MethodHandle-heavy workloads, and did not observe any regression when comparing just the impact of this bit of change, on top of having big callee size adjustment enabled in both builds. Even with ECS getting terminated upon hitting a MethodHandle thunk archetype, we would still inline them during targeted inlining that happens later as part of methodHandleInvokeInliningGroup. As part of inlineCallTarget2, we would perform checks for the existence of the MH thunks and enable targeted inlining that would handle MH thunks. This is only enabled for OpenJ9 MethodHandle builds.

TR_J9InlinerUtil::requestAdditionalOptimizations(TR_CallTarget *calltarget)
{
#if !defined(J9VM_OPT_OPENJDK_METHODHANDLE)
if (calltarget->_myCallSite->getDepth() == -1 // only do this for top level callee to prevent exponential walk of inlined trees
&& checkForRemainingInlineableJSR292(comp(), calltarget->_calleeSymbol))
{
_inliner->getOptimizer()->setRequestOptimization(OMR::methodHandleInvokeInliningGroup);
if (comp()->trace(OMR::inlining))
heuristicTrace(tracer(),"Requesting one more pass of targeted inlining due to method handle invoke in %s\n", tracer()->traceSignature(calltarget->_calleeSymbol));
}
#endif

Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Thanks, maybe that is why we do not see any performance regression on those workloads using the old MH implementation

Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Yes. Furthermore, inlining along MH thunks would also continue through late inlining triggered by Global ValuePropagation. That has been my observation in some small MH operations I tested. VP handles inlining along all MH thunks for baseline build (current main branch), and the 2 builds I mentioned in the last comment.

@vijaysun-omr
Copy link
Contributor

Jenkins test sanity all jdk8,jdk11

@nbhuiyan
Copy link
Member Author

nbhuiyan commented Jun 3, 2025

JDK8 32-bit Windows failure is due to a warning being treated as error. Not related to the changes in this PR.

16:47:08  [ 65%] Building CXX object runtime/gc_base/CMakeFiles/j9gcbase.dir/OwnableSynchronizerObjectList.cpp.obj
16:47:09  F:\Users\jenkins\workspace\Build_JDK8_x86-32_windows_Personal\openj9\runtime\gc_base\modronapi.cpp(1034): error C2220: the following warning is treated as an error
16:47:09  F:\Users\jenkins\workspace\Build_JDK8_x86-32_windows_Personal\openj9\runtime\gc_base\modronapi.cpp(1034): warning C4244: 'return': conversion from 'U_64' to 'UDATA', possible loss of data
16:47:09  make[4]: *** [runtime/gc_base/CMakeFiles/j9gcbase.dir/build.make:272: runtime/gc_base/CMakeFiles/j9gcbase.dir/modronapi.cpp.obj] Error 2
16:47:09  make[4]: *** Waiting for unfinished jobs....

@nbhuiyan
Copy link
Member Author

nbhuiyan commented Jun 3, 2025

Another error seen in the 32 bit windows build:

16:47:01  GCExtensions.cpp
16:47:01  F:\Users\jenkins\workspace\Build_JDK8_x86-32_windows_Personal\openj9\runtime\compiler\optimizer\J9RecognizedCallTransformer.cpp(636): error C2039: 'generateDataAddrLoadTrees': is not a member of 'TR::TransformUtil'
16:47:01  F:\Users\jenkins\workspace\Build_JDK8_x86-32_windows_Personal\openj9\runtime\compiler\optimizer/TransformUtil.hpp(30): note: see declaration of 'TR::TransformUtil'
16:47:01  F:\Users\jenkins\workspace\Build_JDK8_x86-32_windows_Personal\openj9\runtime\compiler\optimizer\J9RecognizedCallTransformer.cpp(636): error C3861: 'generateDataAddrLoadTrees': identifier not found
16:47:01  make[4]: *** [runtime/compiler/CMakeFiles/j9jit.dir/build.make:1617: runtime/compiler/CMakeFiles/j9jit.dir/optimizer/J9RecognizedCallTransformer.cpp.obj] Error 2
16:47:01  make[4]: *** Waiting for unfinished jobs....

generateDataAddrLoadTrees is only defined for #if defined(OMR_GC_SPARSE_HEAP_ALLOCATION). That seems to not be the case, probably due to the GC build job not completing.

@nbhuiyan
Copy link
Member Author

nbhuiyan commented Jun 3, 2025

JDK11 sanity.functional failure on ppc64le linux:

17:56:38  Testing: Test SSL Success Case
17:56:38  Test start time: 2025/06/03 21:56:36 Coordinated Universal Time
17:56:38  Running command: bash /home/jenkins/workspace/Test_openjdk11_j9_sanity.functional_ppc64le_linux_Personal_testList_0/aqa-tests/TKG/../../jvmtest/functional/cmdLineTests/criu/criuJitServerScript.sh /home/jenkins/workspace/Test_openjdk11_j9_sanity.functional_ppc64le_linux_Personal_testList_0/aqa-tests/TKG/../../jvmtest/functional/cmdLineTests/criu /home/jenkins/workspace/Test_openjdk11_j9_sanity.functional_ppc64le_linux_Personal_testList_0/jdkbinary/j2sdk-image/bin " -Xjit:vlog=vlog " org.openj9.criu.OptionsFileTest "JitOptionsTest -XX:+UseJITServer -XX:JITServerSSLRootCerts=cert.pem -Xjit:verbose={compilePerformance},verbose={CheckpointRestore},verbose={JITServer},verbose={JITServerConns},vlog=sslVlog1" 1 false true
17:56:38  Time spent starting: 2 milliseconds
17:56:38  Time spent executing: 2291 milliseconds
17:56:38  Test result: FAILED
17:56:38  Output from test:
17:56:38   [OUT] start running script
17:56:38   [OUT] export GLIBC_TUNABLES=glibc.cpu.hwcaps=-XSAVEC,-XSAVE,-AVX2,-ERMS,-AVX,-AVX_Fast_Unaligned_Load
17:56:38   [OUT] export LD_BIND_NOT=on
17:56:38   [OUT] Generate SSL certificates
17:56:38   [OUT] Certificates generated
17:56:38   [OUT] Starting /home/jenkins/workspace/Test_openjdk11_j9_sanity.functional_ppc64le_linux_Personal_testList_0/jdkbinary/j2sdk-image/bin/jitserver -XX:JITServerPort=56534 -XX:JITServerHealthProbePort=50627 -XX:JITServerSSLKey=key.pem -XX:JITServerSSLCert=cert.pem -Xjit:verbose={JITServer}
17:56:38   [OUT] JITSERVER DOES NOT EXIST
17:56:38   [OUT] finished script
17:56:38   [ERR] /home/jenkins/workspace/Test_openjdk11_j9_sanity.functional_ppc64le_linux_Personal_testList_0/aqa-tests/TKG/../../jvmtest/functional/cmdLineTests/criu/jitserverconfig.sh: line 30: lsof: command not found
17:56:38   [ERR] /home/jenkins/workspace/Test_openjdk11_j9_sanity.functional_ppc64le_linux_Personal_testList_0/aqa-tests/TKG/../../jvmtest/functional/cmdLineTests/criu/jitserverconfig.sh: line 30: lsof: command not found
17:56:38   [ERR] .+.........+......+..+++++++++++++++++++++++++++++++++++++++*..............+......+...+....+...........+.+...+..+...+.......+++++++++++++++++++++++++++++++++++++++*.+...............+...+..+.+.....+.......+..+...............+...............+......+............+..........+..+..........+......+......+.........+..+.......+..+....+.....+.......+...+.........+..+...+..........+......+...........+.+.....+.........+....+.....+.+...+.....+............+...............+......+...+.+........+...+...+.+.........+.........+...+...+......+.........+..+...+.......+........+.+...+...........+.+.....+...+...+............+...+.........+.....................+....+.....+...+......+.+...+............+...+..+....+.....+.+......+...+......+.....+.+.....+...++++++
17:56:38   [ERR] .+.+.....+....+++++++++++++++++++++++++++++++++++++++*.....+...+.+......+............+..+.+...+.........+...+.....+.........+...+++++++++++++++++++++++++++++++++++++++*..+.....+............+...............+.......+...............+...+...+.........+........+.......+...+...+...........+.........+.......+..+.+......+.....+...+................+...........+...+..........+..+...+...+..........+.........+........+.+......+......+........+.......+............+..+....+.....+.......+..+...+....+...............+...+......+.....+..........+.....+......+.+...+..+..........+.....+....+...+...........+............+....+.....+..........+...+......+.....+......+...+.+.....+.+.....+...+.......+........+.............+...+..+......................+..+....+......+...............+...+...+..+.+..............+...+....+...+...........+.+...+...+........+....+..+...+.+......+...+........+....+.....................+...+......+...........+.......+........+...+....+........+...+............+..................+..........+..+.......+..+.+..+............+.+...+..............+......+.+.....+....+..+..............................+...+..........+......+...+...+........+..........+..+....+...+..+.+.........+.....+....+...............+..............+..........+.....+......+.+.....+...+............+.+..+............+......+...+..........+..+...+......+.+..................+..+.......+.................+....+.....+.......+...+.....+......+..........+.....+......+.........+.+.....+.......+..+...+......+................+........+......+.......+........+.........+......+.......+............+..+.+............+..+......+...+....+...+............+..+.+........+.+.....+..........+...+.....+...+...+............+.......+..+...............+.........+.......+..+......+....+..+.+..+.......+.........+.................+..........+............+............+.....................+.....+...+......+...+.+......+......+..+.+.....+......+...+..........+......+.........+...+..+.+...........+......+....+........+.+.....................+........+.+..+....+......+..................+...........+...+.+..+....+...............+...........+.............+......+......+...+..+.........+.+.....+....+...+..+....+.....+....+..+.+.........+...+.....+...+...+.......+..+.............+.........+........+.+......++++++
17:56:38   [ERR] -----
17:56:38   [ERR] #JITServer: JITServer version: 1.80.0
17:56:38   [ERR] #JITServer: JITServer Server Mode. Port: 56534. Connection Timeout 30000ms
17:56:38   [ERR] #JITServer: Built against (OpenSSL 3.5.0 8 Apr 2025); Loaded with (OpenSSL 3.5.0 8 Apr 2025)
17:56:38   [ERR] #INFO:  StartTime: Jun 03 21:56:36 2025
17:56:38   [ERR] #INFO:  TimeZone: UTC (UTC)
17:56:38   [ERR] #JITServer: Started JITServer listener thread: 00000000001D8300 
17:56:38   [ERR] 
17:56:38   [ERR] JITServer is ready to accept incoming requests
17:56:38   [ERR] #JITServer: Successfully initialized SSL context (OpenSSL 3.5.0 8 Apr 2025)
17:56:38   [ERR] can't bind server address: Address already in use
17:56:38   [ERR] Failed to open server socket on port 56534
17:56:38  >> Success condition was not found: [Output match: Killed]
17:56:38  >> Required condition was not found: [Output match: Pre-checkpoint]
17:56:38  >> Success condition was not found: [Output match: Post-checkpoint]
17:56:38  >> Failure condition was not found: [Output match: CRIU is not enabled]
17:56:38  >> Failure condition was not found: [Output match: Operation not permitted]
17:56:38  >> Required condition was found: [Output match: Successfully initialized SSL context]
17:56:38  >> Success condition was not found: [Output match: Thread pid mismatch]
17:56:38  >> Success condition was not found: [Output match: do not match expected]
17:56:38  >> Success condition was not found: [Output match: Unable to create a thread:]
17:56:38  >> Success condition was not found: [Output match: JITSERVER EXISTS]
17:56:38  >> Success condition was not found: [Output match: JITSERVER STILL EXISTS]
17:56:38  >> Failure condition was found: [Output match: JITSERVER DOES NOT EXIST]
17:56:38  >> Failure condition was not found: [Output match: JITSERVER NO LONGER EXISTS]

It is a known failure: #18599

x86_64 linux JDK8 sanity.functional test failure:

18:40:41  FAILED: testServerUnreachableForAWhile
18:40:41  java.lang.AssertionError: The process is still alive after waiting for 60000ms.
18:40:41  	at org.testng.AssertJUnit.fail(AssertJUnit.java:59)
18:40:41  	at jit.test.jitserver.JITServerTest.destroyAndCheckProcess(JITServerTest.java:347)
....

there are many such instances across several tests. It is a known problem: #14594

@nbhuiyan
Copy link
Member Author

nbhuiyan commented Jun 4, 2025

X86_64 JDK8 Windows sanity.openjdk test failure looks similar to the test failure I have seen in my personal builds, which seemed to have gone away after restricting ECS along MH thunks. With this failure showing up here, I am not sure that second change was an effective workaround.

19:54:05  [TestNG] Running:
19:54:05    java/util/stream/test/org/openjdk/tests/java/util/stream/StreamSpliteratorTest.java
19:54:05  
19:54:05  config java.util.stream.LoggingTestCase.before(): success
19:54:05  STDERR:
19:54:05  Unhandled exception
19:54:05  Type=Segmentation error vmState=0x000501ff
19:54:05  Windows_ExceptionCode=c0000005 J9Generic_Signal=00000004 ExceptionAddress=00007FFBDED816EE ContextFlags=0010005f
19:54:05  Handler1=00007FFBDED9FAB0 Handler2=00007FFBED83A900 InaccessibleReadAddress=0000000000000070
19:54:05  RDI=00007FF47CD38390 RSI=00007FF47CC90000 RAX=0000000000000400 RBX=00007FF47CD529D0
19:54:05  RCX=0000000000000000 RDX=000002B31AB3E400 R8=000002B31AB3E400 R9=00007FFBDF41B910
19:54:05  R10=00007FFBDF414A78 R11=000000BDBF7F8ED8 R12=0000000000000000 R13=00007FF47CD70780
19:54:05  R14=00007FF47CD424E0 R15=00007FF47CD424E0
19:54:05  RIP=00007FFBDED816EE RSP=000000BDBF7F8E20 RBP=000002B31AB3E400 EFLAGS=0000000000010287
19:54:05  FS=0053 ES=002B DS=002B
19:54:05  XMM0=0000000000000000 (f: 0.000000, d: 0.000000e+00)
19:54:05  XMM1=0000000000000000 (f: 0.000000, d: 0.000000e+00)
19:54:05  XMM2=000000003f400000 (f: 1061158912.000000, d: 5.242822e-315)
19:54:05  XMM3=000000003f400000 (f: 1061158912.000000, d: 5.242822e-315)
19:54:05  XMM4=0000000000000000 (f: 0.000000, d: 0.000000e+00)
19:54:05  XMM5=7362412473726f74 (f: 1936879488.000000, d: 6.381687e+247)
19:54:05  XMM6=000000003f8ccccd (f: 1066192064.000000, d: 5.267689e-315)
19:54:05  XMM7=0000000000000000 (f: 0.000000, d: 0.000000e+00)
19:54:05  XMM8=0000000000000000 (f: 0.000000, d: 0.000000e+00)
19:54:05  XMM9=0000000000000000 (f: 0.000000, d: 0.000000e+00)
19:54:05  XMM10=0000000000000000 (f: 0.000000, d: 0.000000e+00)
19:54:05  XMM11=0000000000000000 (f: 0.000000, d: 0.000000e+00)
19:54:05  XMM12=0000000000000000 (f: 0.000000, d: 0.000000e+00)
19:54:05  XMM13=0000000000000000 (f: 0.000000, d: 0.000000e+00)
19:54:05  XMM14=0000000000000000 (f: 0.000000, d: 0.000000e+00)
19:54:05  XMM15=0000000000000000 (f: 0.000000, d: 0.000000e+00)
19:54:05  Module=F:\Users\jenkins\workspace\Test_openjdk8_j9_sanity.openjdk_x86-64_windows_Personal_testList_2\jdkbinary\j2sdk-image\jre\bin\default\j9jit29.dll
19:54:05  Module_base_address=00007FFBDED30000 Offset_in_DLL=00000000000516ee
19:54:05  
19:54:05  Method_being_compiled=java/util/stream/StreamSpliterators$AbstractWrappingSpliterator.getComparator()Ljava/util/Comparator;
19:54:05  Target=2_90_20250603_1430 (Windows Server 2019 10.0 build 17763)
19:54:05  CPU=amd64 (8 logical CPUs) (0x3ffb9c000 RAM)
19:54:05  ----------- Stack Backtrace -----------
19:54:05  (0x00007FFBDED816EE [j9jit29+0x516ee])
19:54:05  Java_java_lang_invoke_ThunkTuple_initialInvokeExactThunk+0x253fab (0x00007FFBDF05531B [j9jit29+0x32531b])
19:54:05  Java_java_lang_invoke_ThunkTuple_initialInvokeExactThunk+0xeab5c (0x00007FFBDEEEBECC [j9jit29+0x1bbecc])
19:54:05  Java_java_lang_invoke_ThunkTuple_initialInvokeExactThunk+0x3043a0 (0x00007FFBDF105710 [j9jit29+0x3d5710])
19:54:05  Java_java_lang_invoke_ThunkTuple_initialInvokeExactThunk+0x30203f (0x00007FFBDF1033AF [j9jit29+0x3d33af])
19:54:05  Java_java_lang_invoke_ThunkTuple_initialInvokeExactThunk+0xeacff (0x00007FFBDEEEC06F [j9jit29+0x1bc06f])
19:54:05  Java_java_lang_invoke_ThunkTuple_initialInvokeExactThunk+0xc2eba (0x00007FFBDEEC422A [j9jit29+0x19422a])
19:54:05  Java_java_lang_invoke_ThunkTuple_initialInvokeExactThunk+0x300511 (0x00007FFBDF101881 [j9jit29+0x3d1881])
19:54:05  Java_java_lang_invoke_ThunkTuple_initialInvokeExactThunk+0xc1b66 (0x00007FFBDEEC2ED6 [j9jit29+0x192ed6])
19:54:05  Java_java_lang_invoke_ThunkTuple_initialInvokeExactThunk+0x3bcc44 (0x00007FFBDF1BDFB4 [j9jit29+0x48dfb4])
19:54:05  Java_java_lang_invoke_ThunkTuple_initialInvokeExactThunk+0x3b95b5 (0x00007FFBDF1BA925 [j9jit29+0x48a925])
19:54:05  Java_java_lang_invoke_ThunkTuple_initialInvokeExactThunk+0x2565a7 (0x00007FFBDF057917 [j9jit29+0x327917])
19:54:05  (0x00007FFBDED8D1BA [j9jit29+0x5d1ba])
19:54:05  (0x00007FFBDED90742 [j9jit29+0x60742])
19:54:05  j9port_isCompatible+0x187a6 (0x00007FFBED83B386 [j9prt29+0x1b386])
19:54:05  j9port_isCompatible+0x19ee0 (0x00007FFBED83CAC0 [j9prt29+0x1cac0])
19:54:05  (0x00007FFBDED8C91C [j9jit29+0x5c91c])
19:54:05  (0x00007FFBDED92C90 [j9jit29+0x62c90])
19:54:05  (0x00007FFBDED9267A [j9jit29+0x6267a])
19:54:05  (0x00007FFBDED9F8E0 [j9jit29+0x6f8e0])
19:54:05  j9port_isCompatible+0x19f1b (0x00007FFBED83CAFB [j9prt29+0x1cafb])
19:54:05  (0x00007FFBDED9F5D6 [j9jit29+0x6f5d6])
19:54:05  omrthread_get_category+0xa42 (0x00007FFBED914242 [j9thr29+0x4242])
19:54:05  _o_exp+0x5a (0x00007FFBF7BF268A [ucrtbase+0x2268a])
19:54:05  BaseThreadInitThunk+0x14 (0x00007FFBF7F37AC4 [KERNEL32+0x17ac4])
19:54:05  RtlUserThreadStart+0x21 (0x00007FFBFAB0A8C1 [ntdll+0x5a8c1])
19:54:05  ---------------------------------------
19:54:05  JVMDUMP039I Processing dump event "gpf", detail "" at 2025/06/03 19:53:01 - please wait.

This failure is also being reported in #22001, with a very similar reported backtrace, in a JDK version that does not even use MH thunks. In light of this, I think we need to understand what is going wrong during the compilation of StreamSpliterators$AbstractWrappingSpliterator.getComparator in the first place before deciding whether to have the workaround in place for MH thunks. All that workaround might be doing is changing the likelihood of the test failure from occurring, and so probably not a good enough justification to have this workaround in place.

@vijaysun-omr
Copy link
Contributor

Assigning to @hzongaro for committing and his awareness since Nazim may run out of time in debugging this.

During EstimateCodeSize, if we came across a callee method that
was deemed too big, and therefore, set to be discarded as an inlining
candidate, a size adjustment for other methods above such methods is
necessary to ensure the entire call graph does not get marked as
too big. For JDK8 and 11, this adjustment was disabled due to
a functional issue that was exposed due to the different inlining
outcome from this adjustment. This change removes the restriction
that was in place as a workaround, and fixes performance issues
resulting from early ECS termination in JDK8 and 11.

Signed-off-by: Nazim Bhuiyan <[email protected]>
@nbhuiyan nbhuiyan force-pushed the bigcallees-oj9mh branch from 0200798 to 0f4d58a Compare June 4, 2025 16:31
@nbhuiyan
Copy link
Member Author

nbhuiyan commented Jun 5, 2025

With big callees adjustment in ECS enabled for JDK8/11, the frequency of the failure is about 3/5 iterations running java/util/stream/test/org/openjdk/tests/java/util/stream/StreamSpliteratorTest.java. Therefore, proceeding with this PR would require that #22001 is investigated and fixed. I will share some of my initial findings in that issue.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

5 participants