JDK-8284028 : [LOOM] JVMTI is confused about current thread when JNI FindClass intercept is called
  • Type: Bug
  • Component: hotspot
  • Sub-Component: jvmti
  • Affected Version: repo-loom
  • Priority: P3
  • Status: Resolved
  • Resolution: Cannot Reproduce
  • Submitted: 2022-03-30
  • Updated: 2022-06-25
  • Resolved: 2022-04-30
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 19
19Resolved
Related Reports
Blocks :  
Relates :  
Description
JVMTI provides a mechanism for intercepting JNI calls. For example, to intercept FindClass calls, you can do the following:

jvmti->GetJNIFunctionTable(&redir_jni_functions);
redir_jni_functions->FindClass = MyFindClass;
jvmti->SetJNIFunctionTable(redir_jni_functions);

I noticed in a couple of JVMTI tests, there is some confusion over the current thread when the intercept call is made. If the current thread is a virtual thread, for some reason GetThreadInfo(NULL) returns the name of the carrier thread, even though GetStackTrace(NULL) properly returns the stack trace of the virtual thread. This can be observed in the FindClass callback in the following test:

   vmTestbase/nsk/jvmti/scenarios/jni_interception/JI01/ji01t001/

If you add the following to the MyFindClass method:

    nsk_printf("MyFindClass(%s)\n",classname);

    jvmtiThreadInfo threadinfo;
    NSK_JVMTI_VERIFY(jvmti->GetThreadInfo(NULL, &threadinfo));
    nsk_printf("thread name: %s\n", threadinfo.name);

    jvmtiError err;
    jvmtiFrameInfo f[30];
    jclass callerClass;
    char *sigClass, *name, *sig, *generic;
    jint i, count;
    err = jvmti->GetStackTrace(NULL, 0, 30, f, &count);
    for (i = 0; i < count; i++) {
        jvmti->GetMethodDeclaringClass(f[i].method, &callerClass);
        jvmti->GetClassSignature(callerClass, &sigClass, &generic);
        jvmti->GetMethodName(f[i].method, &name, &sig, &generic);
        nsk_printf(">>> frame %d: %s %s%s\n", i, sigClass, name, sig);
    }

And run with:

make test TEST=open/test/hotspot/jtreg/vmTestbase/nsk/jvmti/scenarios/jni_interception/JI01/ji01t001/ JTREG_MAIN_WRAPPER=Virtual

You will see the following in the output:

MyFindClass(Lnsk/jvmti/scenarios/jni_interception/JI01/ji01t001;)
thread name: ForkJoinPool-1-worker-1
>>> frame 0: Ljava/lang/Shutdown; halt0(I)V
>>> frame 1: Ljava/lang/Shutdown; halt(I)V
>>> frame 2: Ljava/lang/Shutdown; exit(I)V
>>> frame 3: Ljava/lang/Runtime; exit(I)V
>>> frame 4: Ljava/lang/System; exit(I)V
>>> frame 5: Lnsk/jvmti/scenarios/jni_interception/JI01/ji01t001; main([Ljava/lang/String;)V
>>> frame 6: Ljava/lang/invoke/LambdaForm$DMH.0x0000000801003c00; invokeStatic(Ljava/lang/Object;Ljava/lang/Object;)V
>>> frame 7: Ljava/lang/invoke/LambdaForm$MH.0x0000000801004c00; invoke(Ljava/lang/Object;Ljava/lang/Object;Ljava/lang/Object;)Ljava/lang/Object;
>>> frame 8: Ljava/lang/invoke/Invokers$Holder; invokeExact_MT(Ljava/lang/Object;Ljava/lang/Object;Ljava/lang/Object;Ljava/lang/Object;)Ljava/lang/Object;
>>> frame 9: Ljdk/internal/reflect/DirectMethodHandleAccessor; invokeImpl(Ljava/lang/Object;[Ljava/lang/Object;)Ljava/lang/Object;
>>> frame 10: Ljdk/internal/reflect/DirectMethodHandleAccessor; invoke(Ljava/lang/Object;[Ljava/lang/Object;)Ljava/lang/Object;
>>> frame 11: Ljava/lang/reflect/Method; invoke(Ljava/lang/Object;[Ljava/lang/Object;)Ljava/lang/Object;
>>> frame 12: Lcom/sun/javatest/regtest/agent/MainWrapper$MainTask; run()V
>>> frame 13: Ljava/lang/VirtualThread; run(Ljava/lang/Runnable;)V
>>> frame 14: Ljava/lang/VirtualThread$VThreadContinuation; lambda$new$0(Ljava/lang/VirtualThread;Ljava/lang/Runnable;)V
>>> frame 15: Ljava/lang/VirtualThread$VThreadContinuation$$Lambda$6.0x000000080104b170; run()V
>>> frame 16: Ljdk/internal/vm/Continuation; enter0()V
>>> frame 17: Ljdk/internal/vm/Continuation; enter(Ljdk/internal/vm/Continuation;Z)V

Notice the following:
- classname is for a class the test is trying to load
- the thread name is for a carrier thread
- the thread stack trace is for a virtual thread
- we are in the middle of a VM shutdown.
Comments
Thank you for checking this, Chris! Now, I'm closing this bug. We can re-open it if this problem is noticed again. I guess, you can fix this one now: JDK-8284027
30-04-2022

I have tested with your patch/fix for JDK-8284027 (allthr001) and all mach5 results above are with this patch.
29-04-2022

I remember now what that led me down the path to this test. I was originally working on a fix for JDK-8284027 (allthr001). That required a change to isExpectedThread() to filter out carrier threads. That fix ended up breaking this test, because isExpectedThread() was called on the current thread, which was (correctly) a virtual thread, but threadinfo.name said it was a carrier thread, so it got filtered out by isExpectedThread() and the test failed. Unless you have my patch for isExpectedThread(), you are not going to see this test fail when it thinks the thread is a carrier thread. I recall that with the isExpectedThread() patch, it was failing every time, but maybe I am remember that part wrong. I'll do more testing now that I have the isExpectedThread() patch in place and see if I can get it to reproduce.
29-04-2022

Looks like the above warning is related to JDK-8279358.
29-04-2022

I'm not seeing the issue anymore either. There may be something else involved that I'm missing, but unfortunately I no longer have our discussion notes that led me down this path. All I have is a couple of old test results with the following failure: The following fake exception stacktrace is for failure analysis. nsk.share.Fake_Exception_for_RULE_Creation: (ji01t001.cpp:215) WARNING: the number of occured calls (2) exceeds the expected number of calls (1). at nsk_lvcomplain(nsk_tools.cpp:172) # ERROR: ji01t001.cpp, 215: WARNING: the number of occured calls (2) exceeds the expected number of calls (1). # ERROR: ji01t001.cpp, 223: TEST FAILED: VMDeath: the tested JNI function FindClass() has not been redirected during JVMTI_PHASE_LIVE phase 0 intercepted call(s) instead of 1 as expected Ignore the WARNING. That seems to be normal.
29-04-2022

A bit of an explanation of the above stack trace. It is the stack trace when the JNI FindClass intercept callback is made. This at first seems a bit odd given that the top frame is for halt0(). The call to halt0 ends up in JVM_Halt(), which calls before_exit(), which generates a VM_DEATH event. In the test, the VMDeath event callback does a FindClass of "ji01t001", so this is why we end up in the test's JNI FindClass intercept method, and see the FindClass being done on the test itself.
28-04-2022