vt-pinning: diagnosing virtual thread pinning companion code

Reproduces the pinning JEP 491 did not fix (native JNI frames) with a real native library, alongside the monitor case it did fix. Covers the jdk.VirtualThreadPinned JFR event, reading pinned vs unmounted virtual threads from a jcmd Thread.dump_to_file, the measured throughput cost on a capped carrier pool, and a bounded-executor pattern to contain the blast radius. Co-Authored-By: Claude Sonnet 5 <[email protected]> Claude-Session: https://claude.ai/code/session_01FhzLY5p6okFva3qsnsRyvM
2026-09-30 06:35:35 +00:00
parent ff183da163
commit 0819993c51
18 changed files with 725 additions and 0 deletions
@@ -0,0 +1,19 @@
+$ java -Djdk.tracePinnedThreads=full MonitorPinningDemo   (pre-JDK-24 runtime)
+
+java.version=21.0.10
+jdk.tracePinnedThreads=full
+VirtualThread[#18]/runnable@ForkJoinPool-1-worker-1 reason:MONITOR
+    java.base/java.lang.VirtualThread$VThreadContinuation.onPinned(VirtualThread.java:199)
+    java.base/jdk.internal.vm.Continuation.onPinned0(Continuation.java:393)
+    java.base/java.lang.VirtualThread.parkNanos(VirtualThread.java:635)
+    java.base/java.lang.VirtualThread.sleepNanos(VirtualThread.java:807)
+    java.base/java.lang.Thread.sleep(Thread.java:507)
+    com.ankurm.vtpinning.MonitorPinningDemo.lambda$main$0(MonitorPinningDemo.java:27) <== monitors:1
+    java.base/java.lang.VirtualThread.run(VirtualThread.java:329)
+done
+
+$ java -Djdk.tracePinnedThreads=full MonitorPinningDemo   (JDK 24+ runtime)
+
+java.version=25.0.4.1
+jdk.tracePinnedThreads=full
+done
@@ -0,0 +1,22 @@
+$ java -Djdk.tracePinnedThreads=full NativePinningDemo   (pre-JDK-24 runtime)
+
+java.version=21.0.10
+jdk.tracePinnedThreads=full
+sleepMillis=200
+VirtualThread[#18]/runnable@ForkJoinPool-1-worker-1 reason:NATIVE
+    java.base/java.lang.VirtualThread$VThreadContinuation.onPinned(VirtualThread.java:199)
+    java.base/jdk.internal.vm.Continuation.onPinned0(Continuation.java:393)
+    java.base/java.lang.VirtualThread.parkNanos(VirtualThread.java:635)
+    java.base/java.lang.VirtualThread.sleepNanos(VirtualThread.java:807)
+    java.base/java.lang.Thread.sleep(Thread.java:507)
+    com.ankurm.vtpinning.NativePinningDemo.sleepCallback(NativePinningDemo.java:30)
+    com.ankurm.vtpinning.NativePinningDemo.blockingNativeCall(Native Method)
+    java.base/java.lang.VirtualThread.run(VirtualThread.java:329)
+done
+
+$ java -Djdk.tracePinnedThreads=full NativePinningDemo   (JDK 24+ runtime - flag is inert)
+
+java.version=25.0.4.1
+jdk.tracePinnedThreads=full
+sleepMillis=200
+done
@@ -0,0 +1,29 @@
+$ java -XX:StartFlightRecording=...,jdk.VirtualThreadPinned#enabled=true,threshold=0ms NativePinningDemo
+
+java.version=25.0.4.1
+jdk.tracePinnedThreads=null
+sleepMillis=200
+done
+
+$ jfr print --events jdk.VirtualThreadPinned --stack-depth 10 target/native-pin.jfr
+
+jdk.VirtualThreadPinned {
+  startTime = 12:02:49.269 (2026-09-30)
+  duration = 200 ms
+  blockingOperation = "LockSupport.park"
+  pinnedReason = "Native or VM frame on stack"
+  carrierThread = "ForkJoinPool-1-worker-1" (javaThreadId = 28)
+  eventThread = "" (javaThreadId = 27, virtual)
+  stackTrace = [
+    java.lang.VirtualThread.parkOnCarrierThread(boolean, long) line: 833
+    java.lang.VirtualThread.parkNanos(long) line: 801
+    java.lang.VirtualThread.sleepNanos(long) line: 983
+    java.lang.Thread.sleepNanos(long) line: 507
+    java.lang.Thread.sleep(long) line: 540
+    com.ankurm.vtpinning.NativePinningDemo.sleepCallback() line: 30
+    com.ankurm.vtpinning.NativePinningDemo.blockingNativeCall()
+    java.lang.VirtualThread.run(Runnable) line: 460
+    jdk.internal.vm.Continuation.enterSpecial(Continuation, boolean, boolean)
+  ]
+}
+
@@ -0,0 +1,45 @@
+$ java ThreadDumpPinnedDemo &
+pid=7126
+done
+
+$ jcmd <pid> Thread.dump_to_file -format=json threaddump.json    (taken mid-flight)
+7126:
+Created /home/claude/java-core-examples/vt-pinning/target/threaddump.json
+
+--- the two virtual thread entries from that dump ---
+{
+  "tid": "22",
+  "time": "2026-09-30T06:32:51.489994627Z",
+  "virtual": true,
+  "name": "",
+  "state": "TIMED_WAITING",
+  "stack": [
+    "java.base/jdk.internal.misc.Unsafe.park(Native Method)",
+    "java.base/java.lang.VirtualThread.parkOnCarrierThread(VirtualThread.java:822)",
+    "java.base/java.lang.VirtualThread.parkNanos(VirtualThread.java:801)",
+    "java.base/java.lang.VirtualThread.sleepNanos(VirtualThread.java:983)",
+    "java.base/java.lang.Thread.sleepNanos(Thread.java:507)",
+    "java.base/java.lang.Thread.sleep(Thread.java:540)",
+    "com.ankurm.vtpinning.ThreadDumpPinnedDemo.sleepCallback(ThreadDumpPinnedDemo.java:22)",
+    "com.ankurm.vtpinning.ThreadDumpPinnedDemo.blockingNativeCall(Native Method)",
+    "java.base/java.lang.VirtualThread.run(VirtualThread.java:460)"
+  ],
+  "carrier": "23"
+}
+
+{
+  "tid": "24",
+  "time": "2026-09-30T06:32:51.490322496Z",
+  "virtual": true,
+  "name": "",
+  "state": "TIMED_WAITING",
+  "stack": [
+    "java.base/java.lang.VirtualThread.parkNanos(VirtualThread.java:787)",
+    "java.base/java.lang.VirtualThread.sleepNanos(VirtualThread.java:983)",
+    "java.base/java.lang.Thread.sleepNanos(Thread.java:507)",
+    "java.base/java.lang.Thread.sleep(Thread.java:540)",
+    "com.ankurm.vtpinning.ThreadDumpPinnedDemo.lambda$main$0(ThreadDumpPinnedDemo.java:34)",
+    "java.base/java.lang.VirtualThread.run(VirtualThread.java:460)"
+  ]
+}
+
@@ -0,0 +1,6 @@
+$ java -Djdk.virtualThreadScheduler.parallelism=2 PinningThroughputDemo native 4 1000
+mode=native threadCount=4 blockMillis=1000 parallelism=2 elapsedMs=2015
+
+$ java -Djdk.virtualThreadScheduler.parallelism=2 PinningThroughputDemo plain 4 1000
+
+mode=plain threadCount=4 blockMillis=1000 parallelism=2 elapsedMs=1022
@@ -0,0 +1,5 @@
+$ java -Djdk.virtualThreadScheduler.parallelism=2 BoundedNativeCallDemo direct
+mode=direct parallelism=2 pinningCount=2 unrelatedCount=6 unrelatedWorkDoneAtMs=924 totalElapsedMs=924
+
+$ java -Djdk.virtualThreadScheduler.parallelism=2 BoundedNativeCallDemo bounded
+mode=bounded parallelism=2 pinningCount=2 unrelatedCount=6 unrelatedWorkDoneAtMs=126 totalElapsedMs=826