jdk.VirtualThreadPinned event not caught

Question

Given this code, that tries to listen to the event jdk.VirtualThreadPinned when a virtual thread is pinned:

import static org.junit.Assert.assertTrue;

import java.util.concurrent.CountDownLatch;
import java.util.concurrent.TimeUnit;

import jdk.jfr.Event;
import jdk.jfr.Name;
import jdk.jfr.consumer.RecordingStream;
import org.junit.Test;

public class JFRTest {

    @Test
    public void pinnedVirtualThreads() throws InterruptedException {
        CountDownLatch stopListening = new CountDownLatch(1);
        CountDownLatch startListening = new CountDownLatch(1);
        try (RecordingStream recordingStream = new RecordingStream()) {
            // Create and start the recording stream
            startRecordingStream(recordingStream, startListening, stopListening);
    
            // Make sure JFR listener is running before continue
            while (true) {
                new StartEvent().commit();
                if (startListening.await(1, TimeUnit.SECONDS)) {
                    break;
                }
            }
    
            // Simulate blocking operation
            Thread vt = Thread.ofVirtual().start(() -> {
                synchronized (this) {
                    System.out.println("Virtual Thread is pinned");
                }
            });
            vt.join();
        }
        // Wait till the jdk.VirtualThreadPinned triggers
        assertTrue("jdk.VirtualThreadPinned was not sent", stopListening.await(5, TimeUnit.SECONDS));
    }
    
    private void startRecordingStream(RecordingStream recordingStream, CountDownLatch startListening, CountDownLatch stopListening) {
        // Enable the jdk.VirtualThreadPinned event
        recordingStream.enable("jdk.VirtualThreadPinned").withStackTrace();

        // Notify listener is running after receiving the StartEvent
        recordingStream.onEvent("StartEvent", event -> {
            System.out.println("Received " + event);
            startListening.countDown();
        });

        // Set an event handler
        recordingStream.onEvent("jdk.VirtualThreadPinned", event -> {
            System.out.println("VirtualThreadPinned event detected!");
            System.out.println("Timestamp: " + event);
            stopListening.countDown();
        });

        // Start the recording stream
        recordingStream.startAsync();
    }

    @Name("StartEvent")
    private static class StartEvent extends Event {
    }
}

This is the output:

[INFO] Running com.example.general.JFRTest
Received StartEvent {
  startTime = 10:37:46.830 (2024-06-12)
  eventThread = "main" (javaThreadId = 1)
  stackTrace = [
    com.example.general.JFRTest.pinnedVirtualThreads() line: 25
    jdk.internal.reflect.DirectMethodHandleAccessor.invoke(Object, Object[]) line: 103
    java.lang.reflect.Method.invoke(Object, Object[]) line: 580
    org.junit.runners.model.FrameworkMethod$1.runReflectiveCall() line: 59
    org.junit.internal.runners.model.ReflectiveCallable.run() line: 12
  ]
}


Virtual Thread is pinned
[ERROR] Tests run: 1, Failures: 1, Errors: 0, Skipped: 0, Time elapsed: 6.215 s <<< FAILURE! - in com.example.general.JFRTest
[ERROR] com.example.general.JFRTest.pinnedVirtualThreads  Time elapsed: 6.187 s  <<< FAILURE!
java.lang.AssertionError: jdk.VirtualThreadPinned was not sent

As you can see, this part should trigger the event jdk.VirtualThreadPinned, but it is not happening. On the other hand, the other event StartEvent is caught:

Thread vt = Thread.ofVirtual().start(() -> {
    synchronized (this) {
        System.out.println("Virtual Thread is pinned");
    }
});

I don't know why.

This is my JDK version is: 21.0.3+7-LTS-152

Answer 1

jdk.VirtualThreadPinned is only fired when the runtime tries to park a thread that is pinned. You can trigger this for instance by calling Thread.sleep with the virtual thread runnable:

Thread vt = Thread.ofVirtual().start(() -> {
    synchronized (lock) {
        System.out.println("Virtual Thread is pinned");
        try {
            Thread.sleep(1000);
        } catch (InterruptedException e) {
            throw new RuntimeException(e);
        }
    }
});

You also need to make sure the event stream is flushed, otherwise your callback for the jdk.VirtualThreadPinned event will never be called. You can do this by calling .stop() on the recording stream (close()-ing the stream stops the recording abruptly, and doesn't wait for all events to be consumed). For instance, right before the end of the try block:

    vt.join();
    recordingStream.stop();
} // end of try

With those 2 changes, I see the event being fired:

VirtualThreadPinned event detected!
Timestamp: jdk.VirtualThreadPinned {
  startTime = 10:28:32.075 (2024-06-12)
  duration = 998 ms
  eventThread = "" (javaThreadId = 37, virtual)
  stackTrace = [
    java.lang.VirtualThread.parkOnCarrierThread(boolean, long) line: 689
    java.lang.VirtualThread.parkNanos(long) line: 648
    java.lang.VirtualThread.sleepNanos(long) line: 812
    java.lang.Thread.sleepNanos(long) line: 489
    java.lang.Thread.sleep(long) line: 522
    ...
  ]
}