oracle / visualvm

VisualVM is an All-in-One Java Troubleshooting Tool
https://visualvm.github.io/
Other
2.79k stars 297 forks source link

Profiled program crashes when profiling virtual thread using jdk21 #549

Open andrebreves opened 5 months ago

andrebreves commented 5 months ago

Describe the bug

Whenever I try to Profile the CPU for a program with virtual threads it fails with the following error:

Profiler Agent Error: GetCurrentThreadCpuTime failed with 73
Assertion failed: (res == JVMTI_ERROR_NONE), function Java_org_graalvm_visualvm_lib_jfluid_server_system_Timers_getThreadCPUTimeInNanos, file ../src-jdk15/Timers.c, line 108.
Abort trap: 6

The error code 73 corresponds to JVMTI_ERROR_UNSUPPORTED_OPERATION.

The error seems to be triggered in Timers.c:

/*
 * Class:     org_graalvm_visualvm_lib_jfluid_server_system_Timers
 * Method:    getThreadCPUTimeInNanos
 * Signature: ()J
 */
JNIEXPORT jlong JNICALL Java_org_graalvm_visualvm_lib_jfluid_server_system_Timers_getThreadCPUTimeInNanos
  (JNIEnv *env, jclass clz)
{
    jlong threadTime;
    jvmtiError res;

    res = (*_jvmti)->GetCurrentThreadCpuTime(_jvmti,&threadTime);
    if (res != JVMTI_ERROR_NONE) fprintf(stderr, "Profiler Agent Error: GetCurrentThreadCpuTime failed with %d\n",res);
    assert(res == JVMTI_ERROR_NONE);
    return threadTime;
}

Looking into the source code of jdk21 it seems that the function GetCurrentThreadCpuTime doesn't support virtual threads:

// nanos_ptr - pre-checked for null
jvmtiError
JvmtiEnv::GetCurrentThreadCpuTime(jlong* nanos_ptr) {
  Thread* thread = Thread::current();

  // Surprisingly the GetCurrentThreadCpuTime is used by non-JavaThread's.
  if (thread->is_Java_thread()) {
    if (JavaThread::cast(thread)->is_vthread_mounted()) {
      // No support for a VirtualThread (yet).
      return JVMTI_ERROR_UNSUPPORTED_OPERATION;
    }
  }
  *nanos_ptr = os::current_thread_cpu_time();
  return JVMTI_ERROR_NONE;
} /* end GetCurrentThreadCpuTime */

To Reproduce

  1. Create the following program TriggerVisualVMProfileCrash.java:
class TriggerVisualVMProfileCrash {
    public static void main(String... args) throws Exception {
        System.out.println("Activate profiling and press key...");
        System.in.read();
        Thread.ofVirtual().start(() -> print());
    }

    public static void print() {
        System.out.println("print() called");
    }
}
  1. Run the program in the console:
java -XX:+EnableDynamicAgentLoading -Xverify:none TriggerVisualVMProfileCrash.java
  1. Activate de CPU Profiler for the class TriggerVisualVMProfileCrash: image

  2. Press enter in the console so the program continues execution.

  3. The program will crash

Desktop (please complete the following information):

voidmain commented 4 months ago

I just hit this same issue. Here's my full output:

Profiler Agent: JNI OnLoad Initializing...
Profiler Agent: JNI OnLoad Initialized successfully
Profiler Agent: Waiting for connection on port 5140 (Protocol version: 20)
Profiler Agent: Established connection with the tool
*** Profiler engine warning: Cannot use ClassLoader.findLoadedClass() and/or ClassLoader.findBootstrapClass() in ClassLoaderManager
Profiler Agent: Local accelerated session
Profiler Agent Error: GetCurrentThreadCpuTime failed with 73
Assertion failed: (res == JVMTI_ERROR_NONE), function Java_org_graalvm_visualvm_lib_jfluid_server_system_Timers_getThreadCPUTimeInNanos, file ../src-jdk15/Timers.c, line 108.
./start.sh: line 36: 40735 Abort trap: 6           ~/dev/java/current21/bin/java ${suspend} -Djdk.instrument.traceUsage -XX:+EnableDynamicAgentLoading -Xverify:none -Xshare:off -cp "${CLASSPATH}" io.fusionauth.http.load.Main

This is simple to reproduce in the https://github.com/FusionAuth/java-http project using the branch bpontarelli/virtual-threads. Happy to provide build and run instructions if needed.