Skip to content
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

OpenJDK java/foreign/TestDowncallScope.java NoSuchMethodError MethodHandle.invokeBasic #16161

Closed
pshipton opened this issue Oct 21, 2022 · 43 comments · Fixed by #16556
Closed
Assignees
Labels
comp:jit jdk19 project:panama Used to track Project Panama related work test failure
Milestone

Comments

@pshipton
Copy link
Member

https://openj9-jenkins.osuosl.org/job/Test_openjdk19_j9_sanity.openjdk_x86-64_linux_Nightly/31
java/foreign/TestDowncallScope.java

00:40:09  java.lang.NoSuchMethodError: java/lang/invoke/MethodHandle.invokeBasic(Ljava/lang/Object;Ljava/lang/Object;Ljava/lang/Object;Ljava/lang/Object;Ljava/lang/Object;Ljava/lang/Object;Ljava/lang/Object;Ljava/lang/Object;Ljava/lang/Object;)Ljava/lang/Object; (loaded from jrt:/java.base by <Bootstrap Loader>) called from class java.lang.invoke.BoundMethodHandle$Species_LLLLLL (loaded from <Unknown> by <Bootstrap Loader>).
00:40:09  	at java.lang.invoke.BoundMethodHandle$Species_LLLLLL.copyWithExtendL(java/lang/invoke/BoundMethodHandle$Species_LLLLLL)
00:40:09  	at java.base/java.lang.invoke.MethodHandles.filterReturnValue(MethodHandles.java:5870)
00:40:09  	at java.base/openj9.internal.foreign.abi.InternalDowncallHandler.permuteMH(InternalDowncallHandler.java:421)
00:40:09  	at java.base/openj9.internal.foreign.abi.InternalDowncallHandler.getBoundMethodHandle(InternalDowncallHandler.java:396)
00:40:09  	at java.base/jdk.internal.foreign.abi.DowncallLinker.getBoundMethodHandle(DowncallLinker.java:45)
00:40:09  	at java.base/jdk.internal.foreign.abi.x64.sysv.CallArranger.arrangeDowncall(CallArranger.java:130)
00:40:09  	at java.base/jdk.internal.foreign.abi.x64.sysv.SysVx64Linker.arrangeDowncall(SysVx64Linker.java:54)
00:40:09  	at java.base/jdk.internal.foreign.abi.AbstractLinker.lambda$downcallHandle$0(AbstractLinker.java:62)
00:40:09  	at java.base/jdk.internal.foreign.abi.SoftReferenceCache$Node.get(SoftReferenceCache.java:52)
00:40:09  	at java.base/jdk.internal.foreign.abi.SoftReferenceCache.get(SoftReferenceCache.java:38)
00:40:09  	at java.base/jdk.internal.foreign.abi.AbstractLinker.downcallHandle(AbstractLinker.java:60)
00:40:09  	at java.base/java.lang.foreign.Linker.downcallHandle(Linker.java:221)
00:40:09  	at CallGeneratorHelper.downcallHandle(CallGeneratorHelper.java:463)
00:40:09  	at TestDowncallBase.doCall(TestDowncallBase.java:40)
00:40:09  	at TestDowncallScope.testDowncall(TestDowncallScope.java:72)
@pshipton
Copy link
Member Author

@ChengJin01 @tajila fyi

@tajila tajila added comp:vm project:panama Used to track Project Panama related work labels Oct 21, 2022
@ChengJin01
Copy link

This doesn't make any sense to me as it always works fine till https://openj9-jenkins.osuosl.org/job/Test_openjdk19_j9_sanity.openjdk_x86-64_linux_Nightly/ and there is no updated code related to downcall.

I will double-check locally to see how it goes.

@ChengJin01
Copy link

ChengJin01 commented Oct 21, 2022

  1. Looking at the report of the failing build at https://openj9-jenkins.osuosl.org/job/Test_openjdk19_j9_sanity.openjdk_x86-64_linux_Nightly/31/tapTestReport/
16 - - jdk_foreign_0  	3 min 41 sec	NOT OK	No	No
17 - - jdk_foreign_1  	2 min 38 sec	OK	No	No

which seems odd to me jdk_foreign_0 failed while jdk_foreign_1 passed given the FFI invocation has nothing to do with JIT/GC, in which case jdk_foreign_0 and jdk_foreign_1 should end up with the same result.

  1. I compiled a build on one of Jenkins Linux/x86_64 machines and verified with TestDowncallScope.java which works good as expected:
==============================================
test/jdk/java/foreign/TestDowncallScope.java
Total tests run: 712, Passes: 712, Failures: 0, Skips: 0
===============================================
  1. Looking at the java stacktrace in the description:
00:40:09  java.lang.NoSuchMethodError: java/lang/invoke/MethodHandle.invokeBasic(Ljava/lang/Object;Ljava/lang/Object;
Ljava/lang/Object;Ljava/lang/Object;Ljava/lang/Object;Ljava/lang/Object;Ljava/lang/Object;Ljava/lang/Object;Ljava
/lang/Object;)Ljava/lang/Object; (loaded from jrt:/java.base by <Bootstrap Loader>) called from class 
java.lang.invoke.BoundMethodHandle$Species_LLLLLL (loaded from <Unknown> by <Bootstrap Loader>).
00:40:09  	at java.lang.invoke.BoundMethodHandle$Species_LLLLLL.copyWithExtendL(java/lang/invoke/BoundMethodHandle$Species_LLLLLL)
00:40:09  	at java.base/java.lang.invoke.MethodHandles.filterReturnValue(MethodHandles.java:5870)

in which NoSuchMethodError was thrown out from OpenJDK MH.

I'm wondering whether there was any change merged in OpenJDK MH recently given the issue never occurs on other supported platforms.

@ChengJin01
Copy link

FYI: @fengxue-IS

@fengxue-IS
Copy link
Contributor

I am not aware of any changes related to method handle invocation that was merged.
The exception doesnt seem possible as invokeBasic is implemented as an INL in the vm and resolution ignores any signature since the method is polymorphoic. There should be no reason for a NoSuchMethodError unless the methodhandle class is changed/corrupted

@ChengJin01
Copy link

ChengJin01 commented Oct 21, 2022

Launched a Grinder (x10) at https://openj9-jenkins.osuosl.org/job/Grinder/1434/ on other x86_64 machines to see how it goes.

@ChengJin01
Copy link

All tests passed on the Grinder at https://openj9-jenkins.osuosl.org/job/Grinder/1434/tapTestReport/ and no issue was detected. So I suspect the issue was caused a corrupted nightly build or some platform dependent issue in there.

@ChengJin01
Copy link

ChengJin01 commented Oct 24, 2022

This is the same issue in JIT which was detected a long while ago in #14483 and #14135 (still not yet resolved).

@ChengJin01
Copy link

FYI: @nbhuiyan, @0xdaryl

@ChengJin01
Copy link

Hi @nbhuiyan & @0xdaryl, is there any plan when to get this issue resolved as it is an intermittent failure on JDK17/18/19+?

@nbhuiyan
Copy link
Member

nbhuiyan commented Nov 3, 2022

I have been working on investigating this test failure over the past few days. It can be reproduced in Grinder or locally within 20-30 iterations. However, using -Xdump option to generate a core dump when NoSuchMethodError is thrown hides the problem entirely both in Grinder runs as well as locally. Therefore, I only had the core dumps from #14135 to revisit, where we saw that the frames leading up to the crash have been JIT-compiled. Investigating the compiled code of the methods did not indicate anything strange, and therefore not sufficient to identify the cause. To continue that investigation, I needed to obtain JIT compilation logs of the methods leading up to the crash. Similar the problem I faced with #14135, I am not able to reproduce the problem with any JIT options applied to the methods leading up to the crash. I have also constructed a small test case trying to mimic TestDowncallScope.java, but have not been able to reproduce the exception with or without -Xdump/-Xjit options.

To answer your question @ChengJin01 , there are a few more things I am currently trying, but given the intermittent nature of this failure and the lack of success in generating JIT logs from a failed run, it is difficult to estimate when this can be resolved.

@pshipton
Copy link
Member Author

pshipton commented Nov 7, 2022

https://openj9-jenkins.osuosl.org/job/Test_openjdk19_j9_sanity.openjdk_x86-64_linux_Nightly/42
jdk_foreign_0
java/foreign/TestDowncallScope.java

23:04:22  test TestDowncallScope.testDowncall(11356, "f18_S_SPF_DP", NON_VOID, [STRUCT, POINTER, FLOAT], [DOUBLE, POINTER]): failure
23:04:22  java.lang.NoSuchMethodError: java/lang/invoke/MethodHandle.invokeBasic(Ljava/lang/Object;Ljava/lang/Object;Ljava/lang/Object;Ljava/lang/Object;Ljava/lang/Object;Ljava/lang/Object;Ljava/lang/Object;Ljava/lang/Object;Ljava/lang/Object;)Ljava/lang/Object; (loaded from jrt:/java.base by <Bootstrap Loader>) called from class java.lang.invoke.BoundMethodHandle$Species_LLLLLL (loaded from <Unknown> by <Bootstrap Loader>).
23:04:22  	at java.lang.invoke.BoundMethodHandle$Species_LLLLLL.copyWithExtendL(java/lang/invoke/BoundMethodHandle$Species_LLLLLL)
23:04:22  	at java.base/java.lang.invoke.MethodHandles.filterReturnValue(MethodHandles.java:5870)
23:04:22  	at java.base/openj9.internal.foreign.abi.InternalDowncallHandler.permuteMH(InternalDowncallHandler.java:421)
23:04:22  	at java.base/openj9.internal.foreign.abi.InternalDowncallHandler.getBoundMethodHandle(InternalDowncallHandler.java:396)
23:04:22  	at java.base/jdk.internal.foreign.abi.DowncallLinker.getBoundMethodHandle(DowncallLinker.java:45)
23:04:22  	at java.base/jdk.internal.foreign.abi.x64.sysv.CallArranger.arrangeDowncall(CallArranger.java:130)
23:04:22  	at java.base/jdk.internal.foreign.abi.x64.sysv.SysVx64Linker.arrangeDowncall(SysVx64Linker.java:54)
23:04:22  	at java.base/jdk.internal.foreign.abi.AbstractLinker.lambda$downcallHandle$0(AbstractLinker.java:62)
23:04:22  	at java.base/jdk.internal.foreign.abi.SoftReferenceCache$Node.get(SoftReferenceCache.java:52)
23:04:22  	at java.base/jdk.internal.foreign.abi.SoftReferenceCache.get(SoftReferenceCache.java:38)
23:04:22  	at java.base/jdk.internal.foreign.abi.AbstractLinker.downcallHandle(AbstractLinker.java:60)
23:04:22  	at java.base/java.lang.foreign.Linker.downcallHandle(Linker.java:221)
23:04:22  	at CallGeneratorHelper.downcallHandle(CallGeneratorHelper.java:463)
23:04:22  	at TestDowncallBase.doCall(TestDowncallBase.java:40)
23:04:22  	at TestDowncallScope.testDowncall(TestDowncallScope.java:79)

@tajila
Copy link
Contributor

tajila commented Nov 10, 2022

@nbhuiyan Do you think this will be resolved within 2 weeks?

@pshipton
Copy link
Member Author

https://openj9-jenkins.osuosl.org/job/Test_openjdk19_j9_sanity.openjdk_x86-64_linux_Nightly/46
jdk_foreign_1
java/foreign/TestDowncallScope.java

00:15:49  test TestDowncallScope.testDowncall(11356, "f18_S_SPF_DP", NON_VOID, [STRUCT, POINTER, FLOAT], [DOUBLE, POINTER]): failure
00:15:49  java.lang.NoSuchMethodError: java/lang/invoke/MethodHandle.invokeBasic(Ljava/lang/Object;Ljava/lang/Object;Ljava/lang/Object;Ljava/lang/Object;Ljava/lang/Object;Ljava/lang/Object;Ljava/lang/Object;Ljava/lang/Object;Ljava/lang/Object;)Ljava/lang/Object; (loaded from jrt:/java.base by <Bootstrap Loader>) called from class java.lang.invoke.BoundMethodHandle$Species_LLLLLL (loaded from <Unknown> by <Bootstrap Loader>).
00:15:49  	at java.lang.invoke.BoundMethodHandle$Species_LLLLLL.copyWithExtendL(java/lang/invoke/BoundMethodHandle$Species_LLLLLL)
00:15:49  	at java.base/java.lang.invoke.MethodHandles.filterReturnValue(MethodHandles.java:5870)
00:15:49  	at java.base/openj9.internal.foreign.abi.InternalDowncallHandler.permuteMH(InternalDowncallHandler.java:421)
00:15:49  	at java.base/openj9.internal.foreign.abi.InternalDowncallHandler.getBoundMethodHandle(InternalDowncallHandler.java:396)
00:15:49  	at java.base/jdk.internal.foreign.abi.DowncallLinker.getBoundMethodHandle(DowncallLinker.java:45)
00:15:49  	at java.base/jdk.internal.foreign.abi.x64.sysv.CallArranger.arrangeDowncall(CallArranger.java:130)
00:15:49  	at java.base/jdk.internal.foreign.abi.x64.sysv.SysVx64Linker.arrangeDowncall(SysVx64Linker.java:54)
00:15:49  	at java.base/jdk.internal.foreign.abi.AbstractLinker.lambda$downcallHandle$0(AbstractLinker.java:62)
00:15:49  	at java.base/jdk.internal.foreign.abi.SoftReferenceCache$Node.get(SoftReferenceCache.java:52)
00:15:49  	at java.base/jdk.internal.foreign.abi.SoftReferenceCache.get(SoftReferenceCache.java:38)
00:15:49  	at java.base/jdk.internal.foreign.abi.AbstractLinker.downcallHandle(AbstractLinker.java:60)
00:15:49  	at java.base/java.lang.foreign.Linker.downcallHandle(Linker.java:221)
00:15:49  	at CallGeneratorHelper.downcallHandle(CallGeneratorHelper.java:463)
00:15:49  	at TestDowncallBase.doCall(TestDowncallBase.java:40)
00:15:49  	at TestDowncallScope.testDowncall(TestDowncallScope.java:79)

@nbhuiyan
Copy link
Member

@tajila

Do you think this will be resolved within 2 weeks?

unfortunately that is difficult to say because we do not know what the problem is and unable to get the JIT logs necessary to examine what may be going wrong during compilation. I will continue working on this and will provide updates on the progress.

@pshipton
Copy link
Member Author

https://openj9-jenkins.osuosl.org/job/Test_openjdk19_j9_sanity.openjdk_x86-64_linux_Nightly/54/
jdk_foreign_1
java/foreign/TestDowncallScope.java

00:15:57  test TestDowncallScope.testDowncall(11764, "f19_S_SSF_P", NON_VOID, [STRUCT, STRUCT, FLOAT], [POINTER]): failure
00:15:57  java.lang.NoSuchMethodError: java/lang/invoke/MethodHandle.invokeBasic(Ljava/lang/Object;Ljava/lang/Object;Ljava/lang/Object;Ljava/lang/Object;Ljava/lang/Object;Ljava/lang/Object;Ljava/lang/Object;Ljava/lang/Object;)Ljava/lang/Object; (loaded from jrt:/java.base by <Bootstrap Loader>) called from class java.lang.invoke.BoundMethodHandle$Species_LLLLL (loaded from <Unknown> by <Bootstrap Loader>).
00:15:57  	at java.lang.invoke.BoundMethodHandle$Species_LLLLL.copyWithExtendL(java/lang/invoke/BoundMethodHandle$Species_LLLLL)
00:15:57  	at java.base/java.lang.invoke.MethodHandles.filterReturnValue(MethodHandles.java:5870)
00:15:57  	at java.base/openj9.internal.foreign.abi.InternalDowncallHandler.permuteMH(InternalDowncallHandler.java:421)
00:15:57  	at java.base/openj9.internal.foreign.abi.InternalDowncallHandler.getBoundMethodHandle(InternalDowncallHandler.java:396)
00:15:57  	at java.base/jdk.internal.foreign.abi.DowncallLinker.getBoundMethodHandle(DowncallLinker.java:45)
00:15:57  	at java.base/jdk.internal.foreign.abi.x64.sysv.CallArranger.arrangeDowncall(CallArranger.java:130)
00:15:57  	at java.base/jdk.internal.foreign.abi.x64.sysv.SysVx64Linker.arrangeDowncall(SysVx64Linker.java:54)
00:15:57  	at java.base/jdk.internal.foreign.abi.AbstractLinker.lambda$downcallHandle$0(AbstractLinker.java:62)
00:15:57  	at java.base/jdk.internal.foreign.abi.SoftReferenceCache$Node.get(SoftReferenceCache.java:52)
00:15:57  	at java.base/jdk.internal.foreign.abi.SoftReferenceCache.get(SoftReferenceCache.java:38)
00:15:57  	at java.base/jdk.internal.foreign.abi.AbstractLinker.downcallHandle(AbstractLinker.java:60)
00:15:57  	at java.base/java.lang.foreign.Linker.downcallHandle(Linker.java:221)
00:15:57  	at CallGeneratorHelper.downcallHandle(CallGeneratorHelper.java:463)
00:15:57  	at TestDowncallBase.doCall(TestDowncallBase.java:40)
00:15:57  	at TestDowncallScope.testDowncall(TestDowncallScope.java:79)

@nbhuiyan
Copy link
Member

Update: I have managed to obtain a core dump for this failure locally that I am currently investigating.

@nbhuiyan
Copy link
Member

There was no new information I could obtain from the core dump than what I already did in #14135. Since attempting to obtain JIT logs hide the problem, I experimented on turning off some transformations we do in the JIT for invokeBasic call, to rule out the possibility of the JIT transforming it into something that causes incorrect behaviour. There should be no issues with dispatching into either the invokeBasic INL handler or the compiled target method. invokeBasic calls get transformed by the JIT into a conditional branch if the target method cannot be determined at compile-time. This allows faster dispatch into the target method if it is compiled, skipping j2i and i2j transitions. This is done in RecognizedCallTransformer. There is a simpler mechanism in MethodHandleTransformer if the target method is known, where the solution is simply transforming the call into the target method. I experimented with several builds with one or both these transformations disabled. In all cases, I was able to reproduce the failure, so it rules out any of these transformations doing something wrong.

@nbhuiyan
Copy link
Member

The failure seems more easily reproducible with my build that disables the JIT transformations done to invokeBasic calls. I have been able to reproduce the crash today with a non-consequential JIT option in the command line, which means it may be possible to obtain a compilation log of a failed run. While I try to obtain the JIT logs, I am focusing on comparing the differences between the generated code of a failed run (from the core dump) vs what is normally generated in a passing run.

@pshipton
Copy link
Member Author

@nbhuiyan
Copy link
Member

While I have not been able to obtain a JIT log for a failed run yet, here is a summary of some info gathered so far:

  • In every crash I have seen, InternalDowncallHandler.permuteMH was compiled with both filterReturnValue and copyWithExtendL we see in the call stack inlined
  • With JIT tracing options enabled, what I observed was that copyWithExtendL was not getting inlined in permuteMH, due to the call being considered cold or unresolved
  • The NoSuchMethodError is always thrown when we try to resolve the MethodHandle.invokeBasic call (invokevirtual bytecode) in copyWithExtendL, and the native stack leading up to the exception looked like this for every crash I have observed:
#11 0x00007f20d078b9b5 in setCurrentExceptionWithUtfCause (currentThread=<optimized out>,
    exceptionNumber=<optimized out>, detailMessage=<optimized out>, utfMessage=<optimized out>,
    cause=<optimized out>) at /root/builds/openj9-openjdk-jdk19/openj9/runtime/vm/exceptionsupport.c:807
#12 0x00007f20d07c046a in javaLookupMethodImpl (currentThread=currentThread@entry=0x21e400,
    targetClass=targetClass@entry=0x4d700, nameAndSig=0x7f2075b99968, senderClass=senderClass@entry=0x364700,
    lookupOptions=lookupOptions@entry=262289, foundDefaultConflicts=foundDefaultConflicts@entry=0x0)
    at /root/builds/openj9-openjdk-jdk19/openj9/runtime/vm/lookupmethod.c:914
#13 0x00007f20d07c05a8 in javaLookupMethod (currentThread=currentThread@entry=0x21e400,
    targetClass=targetClass@entry=0x4d700, nameAndSig=<optimized out>, senderClass=senderClass@entry=0x364700,
    lookupOptions=lookupOptions@entry=262289)
    at /root/builds/openj9-openjdk-jdk19/openj9/runtime/vm/lookupmethod.c:595
#14 0x00007f20d07cf8a1 in resolveSpecialMethodRefInto (vmStruct=0x21e400, ramCP=<optimized out>,
    cpIndex=<optimized out>, resolveFlags=0, ramCPEntry=0x364ba0)
    at /root/builds/openj9-openjdk-jdk19/openj9/runtime/vm/resolvesupport.cpp:1344
#15 0x00007f20caf3b0b6 in old_slow_jitResolveSpecialMethod (currentThread=0x21e400)
    at /root/builds/openj9-openjdk-jdk19/openj9/runtime/codert_vm/cnathelp.cpp:2288
#16 0x00007f20caf4c376 in jitResolveSpecialMethod ()
    at /root/builds/openj9-openjdk-jdk19/build/linux-x86_64-server-release/vm/runtime/codert_vm/xnathelp.s:436
  • In all cases,javaLookupMethodImpl fails to handle the invokeBasic lookup that should have resulted in landing in the invokebasic VM INL helper
  • Here is the code (corresponding to inlined body of copyWithExtend) leading up to a NoSuchMethodError:
0x7f20afe24428 {openj9/.../InternalDowncallHandler.permuteMH} +2112           |   48c785f00000000a000000 mov       qword ptr [rbp + 0xf0], 0xa
0x7f20afe24433 {openj9/.../InternalDowncallHandler.permuteMH} +2123           |   4c896c2428           mov       qword ptr [rsp + 0x28], r13
0x7f20afe24438 {openj9/.../InternalDowncallHandler.permuteMH} +2128           |   4c89642420           mov       qword ptr [rsp + 0x20], r12
0x7f20afe2443d {openj9/.../InternalDowncallHandler.permuteMH} +2133           |   4c895c2418           mov       qword ptr [rsp + 0x18], r11
0x7f20afe24442 {openj9/.../InternalDowncallHandler.permuteMH} +2138           |   4c89542410           mov       qword ptr [rsp + 0x10], r10
0x7f20afe24447 {openj9/.../InternalDowncallHandler.permuteMH} +2143           |   4c894c2408           mov       qword ptr [rsp + 8], r9
0x7f20afe2444c {openj9/.../InternalDowncallHandler.permuteMH} +2148           |   48891c24             mov       qword ptr [rsp], rbx
0x7f20afe24450 {openj9/.../InternalDowncallHandler.permuteMH} +2152  41:34    |   e8891d0000           call      0x7f20afe261de 
  • The JIT code above does not look any different from a passing case.
  • When we see a failure in TestDowncallScope test, most cases pass, and the failure is seen in these cases (8 failures out of 712 cases):
test TestDowncallScope.testDowncall(11458, "f19_S_SPD_IPF", NON_VOID, [STRUCT, POINTER, DOUBLE], [INT, POINTER, FLOAT]): failure
test TestDowncallScope.testDowncall(11475, "f19_S_SPD_FPD", NON_VOID, [STRUCT, POINTER, DOUBLE], [FLOAT, POINTER, DOUBLE]): failure
test TestDowncallScope.testDowncall(11492, "f19_S_SPD_DPP", NON_VOID, [STRUCT, POINTER, DOUBLE], [DOUBLE, POINTER, POINTER]): failure
test TestDowncallScope.testDowncall(11594, "f19_S_SPS_F", NON_VOID, [STRUCT, POINTER, STRUCT], [FLOAT]): failure
test TestDowncallScope.testDowncall(11611, "f19_S_SPS_PD", NON_VOID, [STRUCT, POINTER, STRUCT], [POINTER, DOUBLE]): failure
test TestDowncallScope.testDowncall(11628, "f19_S_SPS_IPP", NON_VOID, [STRUCT, POINTER, STRUCT], [INT, POINTER, POINTER]): failure
test TestDowncallScope.testDowncall(11645, "f19_S_SPS_DII", NON_VOID, [STRUCT, POINTER, STRUCT], [DOUBLE, INT, INT]): failure
test TestDowncallScope.testDowncall(11662, "f19_S_SPS_PIF", NON_VOID, [STRUCT, POINTER, STRUCT], [POINTER, INT, FLOAT]): failure

  • Not sure what is common between the failed cases, except they all share the same method signature that resulted in the NoSuchMethodError:
java/lang/invoke/MethodHandle.invokeBasic(Ljava/lang/Object;Ljava/lang/Object;Ljava/lang/Object;Ljava/lang/Object;Ljava/lang/Object;Ljava/lang/Object;Ljava/lang/Object;Ljava/lang/Object;Ljava/lang/Object;)Ljava/lang/Object;

@ChengJin01
Copy link

ChengJin01 commented Nov 30, 2022

except they all share the same method signature that resulted in the NoSuchMethodError.

That might be what was happening in these failing tests.

e.g.

test TestDowncallScope.testDowncall(11458, "f19_S_SPD_IPF", NON_VOID, [STRUCT, POINTER, DOUBLE], [INT, POINTER, FLOAT]): failure
test TestDowncallScope.testDowncall(11475, "f19_S_SPD_FPD", NON_VOID, [STRUCT, POINTER, DOUBLE], [FLOAT, POINTER, DOUBLE]): failure
test TestDowncallScope.testDowncall(11492, "f19_S_SPD_DPP", NON_VOID, [STRUCT, POINTER, DOUBLE], [DOUBLE, POINTER, POINTER]): failure

For f19_S_SPD_IPF, the arguments of this method is [STRUCT, POINTER, DOUBLE] or (SPD) while [INT, POINTER, FLOAT] or (IPF) in test 11458 are the elements in this STRUCT argument, So the signature of 11458 is the same as test 11475 and 11492 except the difference in the struct elements (which are invisible in terms of signature).

@nbhuiyan
Copy link
Member

nbhuiyan commented Dec 1, 2022

Seems like this error happens only when permuteMH is AOT compiled at warm opt level with filterReturnValue and copyWithExtendL inlined. Normally copyWithExtendL does not get inlined because it was a cold call, but sometimes we manage to inline that anyway, which is when we see the failure. When we disable AOT compilations using -Xnoaot, permuteMH gets JIT-compiled at cold opt level that skips trying to inline the two methods we see in the failing java stack. I have not seen the JIT compiling that method at warm. However, when I do force the JIT to compile permuteMH at warm, and force inlining of filterReturnValue and copyWithExtend, the failure does not happen. I am trying to examine what happens during AOT compilations of permuteMH. Yesterday I was able to confirm that -Xnoaot prevents the failure with 100x passing Grinder runs of _jdk_foreign_0.

@nbhuiyan
Copy link
Member

Since my last update, the focus has been on investigating the AOT compilation of permuteMH. However, any attempt to try to trace AOT compilation of permuteMH changes the behaviour such that copyWithExtendL method does not get inlined, so the failure does not get reproduced and I am unable to get the AOT compilation log of a failed run. Trying to force the inlining of copyWithExtendL in the AOT similar to how I did it in JIT compilation mode of permuteMH did not work. Therefore, I have been trying to find other ways to track what goes wrong when copyWithExtendL gets inlined during AOT compilation.

@pshipton
Copy link
Member Author

https://openj9-jenkins.osuosl.org/job/Test_openjdk17_j9_sanity.functional_x86-64_linux_OMR_testList_0/253
Jep389Tests_testClinkerFfi_DownCall_0

FAILED: test_add2IntStructs_returnStruct_2
java.lang.NoSuchMethodError: java/lang/invoke/MethodHandle.invokeBasic(Ljava/lang/Object;Ljava/lang/Object;Ljava/lang/Object;Ljava/lang/Object;Ljava/lang/Object;Ljava/lang/Object;Ljava/lang/Object;)Ljava/lang/Object; (loaded from jrt:/java.base by <Bootstrap Loader>) called from class java.lang.invoke.BoundMethodHandle$Species_LLLL (loaded from <Unknown> by <Bootstrap Loader>).
	at java.lang.invoke.BoundMethodHandle$Species_LLLL.copyWithExtendL(java/lang/invoke/BoundMethodHandle$Species_LLLL)
	at java.base/java.lang.invoke.MethodHandles.filterReturnValue(MethodHandles.java:5851)
	at jdk.incubator.foreign/openj9.internal.foreign.abi.InternalDowncallHandler.permuteMH(InternalDowncallHandler.java:421)
	at jdk.incubator.foreign/openj9.internal.foreign.abi.InternalDowncallHandler.getBoundMethodHandle(InternalDowncallHandler.java:396)
	at jdk.incubator.foreign/jdk.internal.foreign.abi.ProgrammableInvoker.getBoundMethodHandle(ProgrammableInvoker.java:46)
	at jdk.incubator.foreign/jdk.internal.foreign.abi.x64.sysv.CallArranger.arrangeDowncall(CallArranger.java:134)
	at jdk.incubator.foreign/jdk.internal.foreign.abi.x64.sysv.SysVx64Linker.downcallHandle(SysVx64Linker.java:97)
	at org.openj9.test.jep389.downcall.StructTests2.test_add2IntStructs_returnStruct_2(StructTests2.java:1951)
...
and more

@pshipton
Copy link
Member Author

https://openj9-jenkins.osuosl.org/job/Test_openjdk19_j9_sanity.openjdk_x86-64_linux_Nightly/73
jdk_foreign_1
java/foreign/TestDowncallScope.java

23:38:34  Output overflow:
...
23:38:34  test TestDowncallScope.testDowncall(11356, "f18_S_SPF_DP", NON_VOID, [STRUCT, POINTER, FLOAT], [DOUBLE, POINTER]): failure
23:38:34  java.lang.NoSuchMethodError: java/lang/invoke/MethodHandle.invokeBasic(Ljava/lang/Object;Ljava/lang/Object;Ljava/lang/Object;Ljava/lang/Object;Ljava/lang/Object;Ljava/lang/Object;Ljava/lang/Object;Ljava/lang/Object;Ljava/lang/Object;)Ljava/lang/Object; (loaded from jrt:/java.base by <Bootstrap Loader>) called from class java.lang.invoke.BoundMethodHandle$Species_LLLLLL (loaded from <Unknown> by <Bootstrap Loader>).
23:38:34  	at java.lang.invoke.BoundMethodHandle$Species_LLLLLL.copyWithExtendL(java/lang/invoke/BoundMethodHandle$Species_LLLLLL)
23:38:34  	at java.base/java.lang.invoke.MethodHandles.filterReturnValue(MethodHandles.java:5870)
23:38:34  	at java.base/openj9.internal.foreign.abi.InternalDowncallHandler.permuteMH(InternalDowncallHandler.java:421)
23:38:34  	at java.base/openj9.internal.foreign.abi.InternalDowncallHandler.getBoundMethodHandle(InternalDowncallHandler.java:396)
23:38:34  	at java.base/jdk.internal.foreign.abi.DowncallLinker.getBoundMethodHandle(DowncallLinker.java:45)
23:38:34  	at java.base/jdk.internal.foreign.abi.x64.sysv.CallArranger.arrangeDowncall(CallArranger.java:130)
23:38:34  	at java.base/jdk.internal.foreign.abi.x64.sysv.SysVx64Linker.arrangeDowncall(SysVx64Linker.java:54)
23:38:34  	at java.base/jdk.internal.foreign.abi.AbstractLinker.lambda$downcallHandle$0(AbstractLinker.java:62)
23:38:34  	at java.base/jdk.internal.foreign.abi.SoftReferenceCache$Node.get(SoftReferenceCache.java:52)
23:38:34  	at java.base/jdk.internal.foreign.abi.SoftReferenceCache.get(SoftReferenceCache.java:38)
23:38:34  	at java.base/jdk.internal.foreign.abi.AbstractLinker.downcallHandle(AbstractLinker.java:60)
23:38:34  	at java.base/java.lang.foreign.Linker.downcallHandle(Linker.java:221)
23:38:34  	at CallGeneratorHelper.downcallHandle(CallGeneratorHelper.java:463)
23:38:34  	at TestDowncallBase.doCall(TestDowncallBase.java:40)
23:38:34  	at TestDowncallScope.testDowncall(TestDowncallScope.java:79)

@pshipton
Copy link
Member Author

pshipton commented Jan 5, 2023

https://openj9-jenkins.osuosl.org/job/Test_openjdk17_j9_sanity.functional_x86-64_linux_Nightly_testList_1/367 (Dec. 30)
Jep389Tests_testClinkerFfi_DownCall_0

FAILED: test_addLongAndLongsFromNestedStruct_2
java.lang.NoSuchMethodError: java/lang/invoke/MethodHandle.invokeBasic(Ljava/lang/Object;Ljava/lang/Object;Ljava/lang/Object;Ljava/lang/Object;Ljava/lang/Object;Ljava/lang/Object;Ljava/lang/Object;)Ljava/lang/Object; (loaded from jrt:/java.base by <Bootstrap Loader>) called from class java.lang.invoke.BoundMethodHandle$Species_LLLL (loaded from <Unknown> by <Bootstrap Loader>).
	at java.lang.invoke.BoundMethodHandle$Species_LLLL.copyWithExtendL(java/lang/invoke/BoundMethodHandle$Species_LLLL)
	at java.base/java.lang.invoke.MethodHandles.filterReturnValue(MethodHandles.java:5851)
	at jdk.incubator.foreign/openj9.internal.foreign.abi.InternalDowncallHandler.permuteMH(InternalDowncallHandler.java:421)
	at jdk.incubator.foreign/openj9.internal.foreign.abi.InternalDowncallHandler.getBoundMethodHandle(InternalDowncallHandler.java:396)
	at jdk.incubator.foreign/jdk.internal.foreign.abi.ProgrammableInvoker.getBoundMethodHandle(ProgrammableInvoker.java:46)
	at jdk.incubator.foreign/jdk.internal.foreign.abi.x64.sysv.CallArranger.arrangeDowncall(CallArranger.java:134)
	at jdk.incubator.foreign/jdk.internal.foreign.abi.x64.sysv.SysVx64Linker.downcallHandle(SysVx64Linker.java:97)
	at org.openj9.test.jep389.downcall.StructTests2.test_addLongAndLongsFromNestedStruct_2(StructTests2.java:2172)

@ChengJin01
Copy link

ChengJin01 commented Jan 5, 2023

@nbhuiyan, the failing test test_addLongAndLongsFromNestedStruct_2 is in our own test suite at

public void test_addLongAndLongsFromNestedStruct_2() throws Throwable {

which might be easier for you to narrow down as compared to the jtreg test suite.

@nbhuiyan
Copy link
Member

nbhuiyan commented Jan 10, 2023

Since my last update, I have managed to obtain the AOT compilation logs and core dumps for a few failing runs (where copyWithExtendL was inlined).

The reason why JIT-compiling permuteMH would not run into this failure is because from JIT-ed code, invokeBasic is dispatched into using the j2iTransition helper, from which we end up in the bytecode loop via c_cInterpreter. However, in the AOT-compiled code the invokeBasic call is considered unresolved, so the helper used from the AOT-compiled code is icallVMprJavaSendNativeStatic, which then leads to trying to resolve it using jitResolveSpecialMethod in failing cases. I believe icallVMprJavaSendNativeStatic is the correct helper to be used for run-time resolving VM INL methods. It seems icallVMprJavaSendNativeStatic just jumps to j2iTransition and does not do anything else. Edit: the actual helper being called is actually an unresolved helper snippet.

Prior to calling javaLookupMethodImpl, from where the NoSuchMethodError originates, the invokeBasic signature will need to be modified by the helpers in resolvesupport.cpp. This is because VM INL methods related to OpenJDK MH are signature polymorphic, and so the nameAndSig being passed to javaLookupMethodImpl for MethodHandle INL methods is modified such that the signature is an empty string and the lookup options have J9_LOOK_PARTIAL_SIGNATURE flag set. However, it seems like resolveSpecialMethodRefInto, which is the helper that deals with the invokeBasic immediately before the failure happens, does not have a mechanism in place to create an appropriate nameAndSig for signature-polymorphic INL methods. This mechanism only exists for other helpers, such as resolveStaticMethodRefInto, and resolveVirtualMethodRefInto. Does that mean MH-related VM INL methods were never supposed to be resolved via resolveSpecialMethodRefInto? Perhaps @fengxue-IS can provide some insights into this?

From the same AOT-compiled code, we have both passing cases and failing cases based on which helper is used prior to javaLookupMethodImpl, and the failures only happen when we go through resolveSpecialMethodRefInto. We could not have a passing case going through resolveSpecialMethodRefInto, as there will be no signature matches in most if not all cases. It appears to me that which helper is used depends on the signature of invokeBasic, decided somewhere between entry into icallVMprJavaSendNativeStatic and reaching a helper in resolvesupport.cpp. Since the signature was not being set properly for invokebasic by resolveSpecialMethodRefInto, I tried implementing the mechanisms in other helpers into it. However, I am not sure I am doing this right as I run into a segfault in javaLookupMethodImpl when trying to get the length of the name in the newly created nameAndSig passed from resolveSpecialMethodRefInto.

@fengxue-IS
Copy link
Contributor

@nbhuiyan The MH INLs (invokeBasic/linkTo...) isn't suppose to be resolved via resolveSpecialMethodRefInto. But given that invokeBasic is defined as final I suppose it could also work here but it really should be fixed to use the proper helper to resolve the method ref.
Your changes looks fine to me, maybe try cleaning old build before recompiling.

@nbhuiyan
Copy link
Member

nbhuiyan commented Jan 10, 2023

@fengxue-IS I agree that the right approach is to ensure that the right helper is used for resolving the method ref. The question that remains now is why do we end up in the resolveSpecialMethodRefInto helper in the first place. What information does the resolve process rely on to decide which helper to use, and is the compiled code providing some incorrect info that's resulting in going into the incorrect resolve helper?

@pshipton
Copy link
Member Author

https://openj9-jenkins.osuosl.org/job/Test_openjdk17_j9_sanity.openjdk_x86-64_linux_Nightly/388
jdk_foreign_0
jdk_foreign_1
java/foreign/StdLibTest.java
java/foreign/TestIntrinsics.java
java/foreign/TestUpcall.java

One example:

23:08:41  test StdLibTest.test_printf([STRING, DOUBLE, CHAR, DOUBLE]): failure
23:08:41  java.lang.NoSuchMethodError: java/lang/invoke/MethodHandle.invokeBasic(Ljava/lang/Object;Ljava/lang/Object;Ljava/lang/Object;Ljava/lang/Object;Ljava/lang/Object;Ljava/lang/Object;Ljava/lang/Object;Ljava/lang/Object;Ljava/lang/Object;Ljava/lang/Object;)Ljava/lang/Object; (loaded from jrt:/java.base by <Bootstrap Loader>) called from class java.lang.invoke.BoundMethodHandle$Species_LLLLLLL (loaded from <Unknown> by <Bootstrap Loader>).
23:08:41  	at java.lang.invoke.BoundMethodHandle$Species_LLLLLLL.copyWithExtendL(java/lang/invoke/BoundMethodHandle$Species_LLLLLLL)
23:08:41  	at java.base/java.lang.invoke.MethodHandles.filterReturnValue(MethodHandles.java:5851)
23:08:41  	at jdk.incubator.foreign/openj9.internal.foreign.abi.InternalDowncallHandler.permuteMH(InternalDowncallHandler.java:421)
23:08:41  	at jdk.incubator.foreign/openj9.internal.foreign.abi.InternalDowncallHandler.getBoundMethodHandle(InternalDowncallHandler.java:396)
23:08:41  	at jdk.incubator.foreign/jdk.internal.foreign.abi.ProgrammableInvoker.getBoundMethodHandle(ProgrammableInvoker.java:46)
23:08:41  	at jdk.incubator.foreign/jdk.internal.foreign.abi.x64.sysv.CallArranger.arrangeDowncall(CallArranger.java:134)
23:08:41  	at jdk.incubator.foreign/jdk.internal.foreign.abi.x64.sysv.SysVx64Linker.downcallHandle(SysVx64Linker.java:97)
23:08:41  	at jdk.incubator.foreign/jdk.internal.foreign.AbstractCLinker.downcallHandle(AbstractCLinker.java:44)
23:08:41  	at StdLibTest$StdLibHelper.specializedPrintf(StdLibTest.java:350)
23:08:41  	at StdLibTest$StdLibHelper.printf(StdLibTest.java:329)
23:08:41  	at StdLibTest.test_printf(StdLibTest.java:144)

@fengxue-IS
Copy link
Contributor

@fengxue-IS I agree that the right approach is to ensure that the right helper is used for resolving the method ref. The question that remains now is why do we end up in the resolveSpecialMethodRefInto helper in the first place. What information does the resolve process rely on to decide which helper to use, and is the compiled code providing some incorrect info that's resulting in going into the incorrect resolve helper?

The resolution helper is selected based on the bytecode / cp ref type, invokeBasic should be tagged as J9CPTYPE_INSTANCE_METHOD which can be either invokeSpecial or invokeVirtual as it isn't private, that correct bytecode should be invokeVirtual where special handling is done for MH INLs.

@nbhuiyan can you generate a core file and check what bytecode instruction is used to do the invocation in failing path BoundMethodHandle$Species_LLLLLLL.copyWithExtendL

@nbhuiyan
Copy link
Member

nbhuiyan commented Jan 11, 2023

@fengxue-IS , here are the bytecodes of copyWithExtendL obtained from a core dump:

  Name: copyWithExtendL
  Signature: (Ljava/lang/invoke/MethodType;Ljava/lang/invoke/LambdaForm;Ljava/lang/Object;)Ljava/lang/invoke/BoundMethodHandle;
  Access Flags (30010): default final
  Internal Attribute Flags:
  Max Stack: 10
  Thrown Exceptions (1):
    java/lang/Throwable
  Argument Count: 4
  Temp Count: 0

    0 getstatic 4 java/lang/invoke/BoundMethodHandle$Species_LLLLLL.BMH_SPECIES Ljava/lang/invoke/BoundMethodHandle$SpeciesData;
    3 iconst0
    4 invokevirtual 14 java/lang/invoke/BoundMethodHandle$SpeciesData.transformHelper(I)Ljava/lang/invoke/MethodHandle;
    7 aload1
    8 aload2
    9 aload0getfield
   10 getfield 6 java/lang/invoke/BoundMethodHandle$Species_LLLLLL.argL0 Ljava/lang/Object;
   13 aload0getfield
   14 getfield 7 java/lang/invoke/BoundMethodHandle$Species_LLLLLL.argL1 Ljava/lang/Object;
   17 aload0getfield
   18 getfield 8 java/lang/invoke/BoundMethodHandle$Species_LLLLLL.argL2 Ljava/lang/Object;
   21 aload0getfield
   22 getfield 9 java/lang/invoke/BoundMethodHandle$Species_LLLLLL.argL3 Ljava/lang/Object;
   25 aload0getfield
   26 getfield 10 java/lang/invoke/BoundMethodHandle$Species_LLLLLL.argL4 Ljava/lang/Object;
   29 aload0getfield
   30 getfield 11 java/lang/invoke/BoundMethodHandle$Species_LLLLLL.argL5 Ljava/lang/Object;
   33 aload3
   34 invokevirtual 16 java/lang/invoke/MethodHandle.invokeBasic(Ljava/lang/Object;Ljava/lang/Object;Ljava/lang/Object;Ljava/lang/Object;Ljava/lang/Object;Ljava/lang/Object;Ljava/lang/Object;Ljava/lang/Object;Ljava/lang/Object;)Ljava/lang/Object;
   37 checkcast 2 java/lang/invoke/BoundMethodHandle
   40 return1

@fengxue-IS
Copy link
Contributor

Thanks, the bytecode is using invokeVirtual as expected, so problem here is how did the AOT code consider this as J9BCinvokeSpecial to trigger the incorrect resolve helper.

@JasonFengJ9
Copy link
Member

JasonFengJ9 commented Jan 11, 2023

JDK17 0.36.0 milestone 2 build(ub18x64rt1-3)

openjdk version "17.0.6" 2023-01-17
IBM Semeru Runtime Open Edition 17.0.6.0-m2 (build 17.0.6+9)
Eclipse OpenJ9 VM 17.0.6.0-m2 (build v0.36.0-release-c5da55ccc, JRE 17 Linux amd64-64-Bit Compressed References 20230117_376 (JIT enabled, AOT enabled)
OpenJ9   - c5da55ccc
OMR      - 2bb04132e
JCL      - 2842f5c454a based on jdk-17.0.6+9)

[2023-01-10T21:04:07.230Z] variation: Mode150
[2023-01-10T21:04:07.230Z] JVM_OPTIONS:  -XX:+UseCompressedOops 

[2023-01-10T21:06:12.082Z] TEST: java/foreign/TestIntrinsics.java

[2023-01-10T21:06:12.083Z] STDOUT:
[2023-01-10T21:06:12.083Z] test TestIntrinsics.testIntrinsics(): skip
[2023-01-10T21:06:12.083Z] java.lang.RuntimeException: java.lang.NoSuchMethodError: java/lang/invoke/MethodHandle.invokeBasic(Ljava/lang/Object;Ljava/lang/Object;Ljava/lang/Object;Ljava/lang/Object;Ljava/lang/Object;Ljava/lang/Object;Ljava/lang/Object;Ljava/lang/Object;Ljava/lang/Object;Ljava/lang/Object;)Ljava/lang/Object; (loaded from jrt:/java.base by <Bootstrap Loader>) called from class java.lang.invoke.BoundMethodHandle$Species_LLLLLLL (loaded from <Unknown> by <Bootstrap Loader>).
[2023-01-10T21:06:12.083Z] 	at org.testng.internal.MethodInvocationHelper.invokeMethodNoCheckedException(MethodInvocationHelper.java:49)
[2023-01-10T21:06:12.083Z] 	at org.testng.internal.MethodInvocationHelper.invokeDataProvider(MethodInvocationHelper.java:145)
[2023-01-10T21:06:12.083Z] 	at org.testng.internal.Parameters.handleParameters(Parameters.java:797)
[2023-01-10T21:06:12.083Z] 	at org.testng.internal.Parameters.handleParameters(Parameters.java:740)
[2023-01-10T21:06:12.083Z] 	at org.testng.internal.ParameterHandler.handleParameters(ParameterHandler.java:59)
[2023-01-10T21:06:12.083Z] 	at org.testng.internal.ParameterHandler.createParameters(ParameterHandler.java:38)
[2023-01-10T21:06:12.083Z] 	at org.testng.internal.TestInvoker$MethodInvocationAgent.invoke(TestInvoker.java:789)
[2023-01-10T21:06:12.083Z] 	at org.testng.internal.TestInvoker.invokeTestMethods(TestInvoker.java:147)
[2023-01-10T21:06:12.083Z] 	at org.testng.internal.TestMethodWorker.invokeTestMethods(TestMethodWorker.java:146)
[2023-01-10T21:06:12.083Z] 	at org.testng.internal.TestMethodWorker.run(TestMethodWorker.java:128)
[2023-01-10T21:06:12.083Z] 	at java.base/java.util.ArrayList.forEach(ArrayList.java:1511)
[2023-01-10T21:06:12.083Z] 	at org.testng.TestRunner.privateRun(TestRunner.java:764)
[2023-01-10T21:06:12.083Z] 	at org.testng.TestRunner.run(TestRunner.java:585)
[2023-01-10T21:06:12.083Z] 	at org.testng.SuiteRunner.runTest(SuiteRunner.java:384)
[2023-01-10T21:06:12.083Z] 	at org.testng.SuiteRunner.runSequentially(SuiteRunner.java:378)
[2023-01-10T21:06:12.083Z] 	at org.testng.SuiteRunner.privateRun(SuiteRunner.java:337)
[2023-01-10T21:06:12.083Z] 	at org.testng.SuiteRunner.run(SuiteRunner.java:286)
[2023-01-10T21:06:12.083Z] 	at org.testng.SuiteRunnerWorker.runSuite(SuiteRunnerWorker.java:53)
[2023-01-10T21:06:12.083Z] 	at org.testng.SuiteRunnerWorker.run(SuiteRunnerWorker.java:96)
[2023-01-10T21:06:12.083Z] 	at org.testng.TestNG.runSuitesSequentially(TestNG.java:1218)
[2023-01-10T21:06:12.083Z] 	at org.testng.TestNG.runSuitesLocally(TestNG.java:1140)
[2023-01-10T21:06:12.083Z] 	at org.testng.TestNG.runSuites(TestNG.java:1069)
[2023-01-10T21:06:12.083Z] 	at org.testng.TestNG.run(TestNG.java:1037)
[2023-01-10T21:06:12.083Z] 	at com.sun.javatest.regtest.agent.TestNGRunner.main(TestNGRunner.java:94)
[2023-01-10T21:06:12.083Z] 	at com.sun.javatest.regtest.agent.TestNGRunner.main(TestNGRunner.java:54)
[2023-01-10T21:06:12.083Z] 	at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
[2023-01-10T21:06:12.083Z] 	at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:77)
[2023-01-10T21:06:12.083Z] 	at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
[2023-01-10T21:06:12.083Z] 	at java.base/java.lang.reflect.Method.invoke(Method.java:568)
[2023-01-10T21:06:12.083Z] 	at com.sun.javatest.regtest.agent.MainWrapper$MainThread.run(MainWrapper.java:127)
[2023-01-10T21:06:12.083Z] 	at java.base/java.lang.Thread.run(Thread.java:857)
[2023-01-10T21:06:12.083Z] Caused by: java.lang.NoSuchMethodError: java/lang/invoke/MethodHandle.invokeBasic(Ljava/lang/Object;Ljava/lang/Object;Ljava/lang/Object;Ljava/lang/Object;Ljava/lang/Object;Ljava/lang/Object;Ljava/lang/Object;Ljava/lang/Object;Ljava/lang/Object;Ljava/lang/Object;)Ljava/lang/Object; (loaded from jrt:/java.base by <Bootstrap Loader>) called from class java.lang.invoke.BoundMethodHandle$Species_LLLLLLL (loaded from <Unknown> by <Bootstrap Loader>).
[2023-01-10T21:06:12.083Z] 	at java.lang.invoke.BoundMethodHandle$Species_LLLLLLL.copyWithExtendL(java/lang/invoke/BoundMethodHandle$Species_LLLLLLL)
[2023-01-10T21:06:12.083Z] 	at java.base/java.lang.invoke.MethodHandles.filterReturnValue(MethodHandles.java:5851)
[2023-01-10T21:06:12.083Z] 	at jdk.incubator.foreign/openj9.internal.foreign.abi.InternalDowncallHandler.permuteMH(InternalDowncallHandler.java:421)
[2023-01-10T21:06:12.083Z] 	at jdk.incubator.foreign/openj9.internal.foreign.abi.InternalDowncallHandler.getBoundMethodHandle(InternalDowncallHandler.java:396)
[2023-01-10T21:06:12.083Z] 	at jdk.incubator.foreign/jdk.internal.foreign.abi.ProgrammableInvoker.getBoundMethodHandle(ProgrammableInvoker.java:46)
[2023-01-10T21:06:12.083Z] 	at jdk.incubator.foreign/jdk.internal.foreign.abi.x64.sysv.CallArranger.arrangeDowncall(CallArranger.java:134)
[2023-01-10T21:06:12.083Z] 	at jdk.incubator.foreign/jdk.internal.foreign.abi.x64.sysv.SysVx64Linker.downcallHandle(SysVx64Linker.java:97)
[2023-01-10T21:06:12.083Z] 	at jdk.incubator.foreign/jdk.internal.foreign.AbstractCLinker.downcallHandle(AbstractCLinker.java:44)
[2023-01-10T21:06:12.083Z] 	at TestIntrinsics.tests(TestIntrinsics.java:128)
[2023-01-10T21:06:12.083Z] 	at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
[2023-01-10T21:06:12.083Z] 	at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:77)
[2023-01-10T21:06:12.083Z] 	at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
[2023-01-10T21:06:12.083Z] 	at java.base/java.lang.reflect.Method.invoke(Method.java:568)
[2023-01-10T21:06:12.083Z] 	at org.testng.internal.MethodInvocationHelper.invokeMethod(MethodInvocationHelper.java:132)
[2023-01-10T21:06:12.083Z] 	at org.testng.internal.MethodInvocationHelper.invokeMethod(MethodInvocationHelper.java:76)
[2023-01-10T21:06:12.083Z] 	at org.testng.internal.MethodInvocationHelper.invokeMethodNoCheckedException(MethodInvocationHelper.java:45)
[2023-01-10T21:06:12.083Z] 	... 30 more

[2023-01-10T21:06:12.083Z] STDERR:
[2023-01-10T21:06:12.083Z] WARNING: Using incubator modules: jdk.incubator.foreign
[2023-01-10T21:06:12.083Z] [Utils] [ERROR] [Error] java.lang.NoSuchMethodError: java/lang/invoke/MethodHandle.invokeBasic(Ljava/lang/Object;Ljava/lang/Object;Ljava/lang/Object;Ljava/lang/Object;Ljava/lang/Object;Ljava/lang/Object;Ljava/lang/Object;Ljava/lang/Object;Ljava/lang/Object;Ljava/lang/Object;)Ljava/lang/Object; (loaded from jrt:/java.base by &lt;Bootstrap Loader&gt;) called from class java.lang.invoke.BoundMethodHandle$Species_LLLLLLL (loaded from &lt;Unknown&gt; by &lt;Bootstrap Loader&gt;).
[2023-01-10T21:06:12.083Z] 	at java.lang.invoke.BoundMethodHandle$Species_LLLLLLL.copyWithExtendL(java/lang/invoke/BoundMethodHandle$Species_LLLLLLL)
[2023-01-10T21:06:12.083Z] 	at java.base/java.lang.invoke.MethodHandles.filterReturnValue(MethodHandles.java:5851)
[2023-01-10T21:06:12.083Z] 	at jdk.incubator.foreign/openj9.internal.foreign.abi.InternalDowncallHandler.permuteMH(InternalDowncallHandler.java:421)
[2023-01-10T21:06:12.083Z] 	at jdk.incubator.foreign/openj9.internal.foreign.abi.InternalDowncallHandler.getBoundMethodHandle(InternalDowncallHandler.java:396)
[2023-01-10T21:06:12.083Z] 	at jdk.incubator.foreign/jdk.internal.foreign.abi.ProgrammableInvoker.getBoundMethodHandle(ProgrammableInvoker.java:46)
[2023-01-10T21:06:12.083Z] 	at jdk.incubator.foreign/jdk.internal.foreign.abi.x64.sysv.CallArranger.arrangeDowncall(CallArranger.java:134)
[2023-01-10T21:06:12.083Z] 	at jdk.incubator.foreign/jdk.internal.foreign.abi.x64.sysv.SysVx64Linker.downcallHandle(SysVx64Linker.java:97)
[2023-01-10T21:06:12.083Z] 	at jdk.incubator.foreign/jdk.internal.foreign.AbstractCLinker.downcallHandle(AbstractCLinker.java:44)
[2023-01-10T21:06:12.083Z] 	at TestIntrinsics.tests(TestIntrinsics.java:128)
[2023-01-10T21:06:12.083Z] 	at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
[2023-01-10T21:06:12.083Z] 	at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:77)
[2023-01-10T21:06:12.083Z] 	at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
[2023-01-10T21:06:12.083Z] 	at java.base/java.lang.reflect.Method.invoke(Method.java:568)
[2023-01-10T21:06:12.083Z] 	at org.testng.internal.MethodInvocationHelper.invokeMethod(MethodInvocationHelper.java:132)
[2023-01-10T21:06:12.083Z] 	at org.testng.internal.MethodInvocationHelper.invokeMethod(MethodInvocationHelper.java:76)
[2023-01-10T21:06:12.083Z] 	at org.testng.internal.MethodInvocationHelper.invokeMethodNoCheckedException(MethodInvocationHelper.java:45)
[2023-01-10T21:06:12.083Z] 	at org.testng.internal.MethodInvocationHelper.invokeDataProvider(MethodInvocationHelper.java:145)
[2023-01-10T21:06:12.083Z] 	at org.testng.internal.Parameters.handleParameters(Parameters.java:797)
[2023-01-10T21:06:12.083Z] 	at org.testng.internal.Parameters.handleParameters(Parameters.java:740)
[2023-01-10T21:06:12.083Z] 	at org.testng.internal.ParameterHandler.handleParameters(ParameterHandler.java:59)
[2023-01-10T21:06:12.083Z] 	at org.testng.internal.ParameterHandler.createParameters(ParameterHandler.java:38)
[2023-01-10T21:06:12.083Z] 	at org.testng.internal.TestInvoker$MethodInvocationAgent.invoke(TestInvoker.java:789)
[2023-01-10T21:06:12.083Z] 	at org.testng.internal.TestInvoker.invokeTestMethods(TestInvoker.java:147)
[2023-01-10T21:06:12.083Z] 	at org.testng.internal.TestMethodWorker.invokeTestMethods(TestMethodWorker.java:146)
[2023-01-10T21:06:12.083Z] 	at org.testng.internal.TestMethodWorker.run(TestMethodWorker.java:128)
[2023-01-10T21:06:12.083Z] 	at java.base/java.util.ArrayList.forEach(ArrayList.java:1511)
[2023-01-10T21:06:12.083Z] 	at org.testng.TestRunner.privateRun(TestRunner.java:764)
[2023-01-10T21:06:12.083Z] 	at org.testng.TestRunner.run(TestRunner.java:585)
[2023-01-10T21:06:12.083Z] 	at org.testng.SuiteRunner.runTest(SuiteRunner.java:384)
[2023-01-10T21:06:12.083Z] 	at org.testng.SuiteRunner.runSequentially(SuiteRunner.java:378)
[2023-01-10T21:06:12.083Z] 	at org.testng.SuiteRunner.privateRun(SuiteRunner.java:337)
[2023-01-10T21:06:12.083Z] 	at org.testng.SuiteRunner.run(SuiteRunner.java:286)
[2023-01-10T21:06:12.083Z] 	at org.testng.SuiteRunnerWorker.runSuite(SuiteRunnerWorker.java:53)
[2023-01-10T21:06:12.083Z] 	at org.testng.SuiteRunnerWorker.run(SuiteRunnerWorker.java:96)
[2023-01-10T21:06:12.083Z] 	at org.testng.TestNG.runSuitesSequentially(TestNG.java:1218)
[2023-01-10T21:06:12.083Z] 	at org.testng.TestNG.runSuitesLocally(TestNG.java:1140)
[2023-01-10T21:06:12.083Z] 	at org.testng.TestNG.runSuites(TestNG.java:1069)
[2023-01-10T21:06:12.083Z] 	at org.testng.TestNG.run(TestNG.java:1037)
[2023-01-10T21:06:12.083Z] 	at com.sun.javatest.regtest.agent.TestNGRunner.main(TestNGRunner.java:94)
[2023-01-10T21:06:12.083Z] 	at com.sun.javatest.regtest.agent.TestNGRunner.main(TestNGRunner.java:54)
[2023-01-10T21:06:12.083Z] 	at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
[2023-01-10T21:06:12.083Z] 	at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:77)
[2023-01-10T21:06:12.083Z] 	at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
[2023-01-10T21:06:12.083Z] 	at java.base/java.lang.reflect.Method.invoke(Method.java:568)
[2023-01-10T21:06:12.083Z] 	at com.sun.javatest.regtest.agent.MainWrapper$MainThread.run(MainWrapper.java:127)
[2023-01-10T21:06:12.083Z] 	at java.base/java.lang.Thread.run(Thread.java:857)
[2023-01-10T21:06:12.083Z] 
[2023-01-10T21:06:12.083Z] java.lang.Exception: failures: 1
[2023-01-10T21:06:12.083Z] 	at com.sun.javatest.regtest.agent.TestNGRunner.main(TestNGRunner.java:96)
[2023-01-10T21:06:12.083Z] 	at com.sun.javatest.regtest.agent.TestNGRunner.main(TestNGRunner.java:54)
[2023-01-10T21:06:12.083Z] 	at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
[2023-01-10T21:06:12.083Z] 	at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:77)
[2023-01-10T21:06:12.083Z] 	at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
[2023-01-10T21:06:12.083Z] 	at java.base/java.lang.reflect.Method.invoke(Method.java:568)
[2023-01-10T21:06:12.083Z] 	at com.sun.javatest.regtest.agent.MainWrapper$MainThread.run(MainWrapper.java:127)
[2023-01-10T21:06:12.083Z] 	at java.base/java.lang.Thread.run(Thread.java:857)
[2023-01-10T21:06:12.083Z] 

[2023-01-10T21:06:41.483Z] TEST: java/foreign/TestUpcall.java

[2023-01-10T21:06:41.493Z] ===============================================
[2023-01-10T21:06:41.493Z] java/foreign/TestUpcall.java
[2023-01-10T21:06:41.493Z] Total tests run: 1424, Passes: 688, Failures: 736, Skips: 0
[2023-01-10T21:06:41.493Z] ===============================================
[2023-01-10T21:06:41.493Z] 
[2023-01-10T21:06:41.493Z] STDERR:
[2023-01-10T21:06:41.493Z] WARNING: Using incubator modules: jdk.incubator.foreign
[2023-01-10T21:06:41.493Z] java.lang.Exception: failures: 736
[2023-01-10T21:06:41.493Z] 	at com.sun.javatest.regtest.agent.TestNGRunner.main(TestNGRunner.java:96)
[2023-01-10T21:06:41.493Z] 	at com.sun.javatest.regtest.agent.TestNGRunner.main(TestNGRunner.java:54)
[2023-01-10T21:06:41.493Z] 	at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
[2023-01-10T21:06:41.493Z] 	at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:77)
[2023-01-10T21:06:41.493Z] 	at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
[2023-01-10T21:06:41.493Z] 	at java.base/java.lang.reflect.Method.invoke(Method.java:568)
[2023-01-10T21:06:41.493Z] 	at com.sun.javatest.regtest.agent.MainWrapper$MainThread.run(MainWrapper.java:127)
[2023-01-10T21:06:41.493Z] 	at java.base/java.lang.Thread.run(Thread.java:857)
[2023-01-10T21:06:41.493Z] 
[2023-01-10T21:06:41.493Z] JavaTest Message: Test threw exception: java.lang.Exception: failures: 736

50x grinder jdk_foreign_0 - 25/50 failed

@pshipton
Copy link
Member Author

https://openj9-jenkins.osuosl.org/job/Test_openjdk17_j9_sanity.openjdk_x86-64_linux_Nightly/390
jdk_foreign_1
java/foreign/StdLibTest.java.StdLibTest
java/foreign/TestDowncall.java.TestDowncall
java/foreign/TestUpcall.java.TestUpcall

@pshipton
Copy link
Member Author

https://openj9-jenkins.osuosl.org/job/Test_openjdk19_j9_sanity.openjdk_x86-64_linux_Nightly/90
jdk_foreign_0
java/foreign/TestDowncallStack.java.TestDowncallStack
java/foreign/TestUpcallAsync.java.TestUpcallAsync
java/foreign/TestUpcallScope.java.TestUpcallScope
java/foreign/TestUpcallStack.java.TestUpcallStack
java/foreign/TestVarArgs.java.TestVarArgs

@nbhuiyan
Copy link
Member

This problem happens because methods that are not yet AOT compilable (which is all of the java/lang/invoke/* methods), are considered compilable by the inliner, which then inlines non-AOT-compilable callees resulting in the strange invokeBasic dispatch attempt via the special method resolve helper. We either need AOT compilations to handle MH-related INL calls properly, or for the inliner to not inline callee methods that are not eligible for AOT compilations during AOT. The inliner decides this by using calleeMethod->isCompilable(), which did not have an override for AOT methods. This is fixed in #16556.

@fengxue-IS
Copy link
Contributor

Is the INLs the only methods non-AOT compilable? or do we need to exclude the entire package?

@pshipton
Copy link
Member Author

https://openj9-jenkins.osuosl.org/job/Test_openjdk19_j9_sanity.openjdk_x86-64_linux_Nightly/92
jdk_foreign_1
java/foreign/TestDowncallStack.java.TestDowncallStack
java/foreign/TestUpcallAsync.java.TestUpcallAsync

@nbhuiyan
Copy link
Member

@fengxue-IS

Is the INLs the only methods non-AOT compilable? or do we need to exclude the entire package?

The MH INLs such as invokebasic and linkTo* are never compiled even in JIT. For AOT, the entire java/lang/invoke package has to be excluded from compilation.

@pshipton
Copy link
Member Author

There was a failure in https://openj9-jenkins.osuosl.org/job/Test_openjdk17_j9_sanity.openjdk_x86-64_linux_Nightly/394 but it seems to be testing a JVM before the fix was merged.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
comp:jit jdk19 project:panama Used to track Project Panama related work test failure
Projects
None yet
Development

Successfully merging a pull request may close this issue.

6 participants