diff --git a/README.md b/README.md index 3118db4..243cb86 100644 --- a/README.md +++ b/README.md @@ -8,6 +8,7 @@ article; each module's own README has that article's version table, quickstart, | [`jmm`](jmm/) | The Java Memory Model Explained: volatile, happens-before, and Why Your Double-Checked Lock Failed | | [`locks`](locks/) | synchronized vs ReentrantLock vs StampedLock: Benchmarks and a Decision Table | | [`atomics`](atomics/) | Java Atomics and VarHandle: CAS, LongAdder, and When Atomics Beat Locks | +| [`vt-pinning`](vt-pinning/) | Diagnosing Virtual Thread Pinning in Production: JFR Events, jcmd, and Real Fixes | ## License diff --git a/pom.xml b/pom.xml index f4273b0..0f00dba 100644 --- a/pom.xml +++ b/pom.xml @@ -16,6 +16,7 @@ jmm locks atomics + vt-pinning diff --git a/vt-pinning/README.md b/vt-pinning/README.md new file mode 100644 index 0000000..4a10543 --- /dev/null +++ b/vt-pinning/README.md @@ -0,0 +1,90 @@ +# vt-pinning + +Companion code for the ankurm.com post *"Diagnosing Virtual Thread Pinning in Production: JFR +Events, jcmd, and Real Fixes."* Fourth module in `java-core-examples`, the Java-core / +concurrency series. + +[JEP 491](https://openjdk.org/jeps/491) (GA in JDK 24) fixed the pinning caused by `synchronized`. +It did not touch the pinning caused by native code - a virtual thread executing a JNI native +method (or an FFM downcall) whose native frame calls back into blocking Java code still pins its +carrier, on every JDK version, because a continuation cannot be frozen across a native stack +frame. This module reproduces that with a real, tiny JNI library (not asserted from documentation) +and works through the diagnostics that still catch it once the old `-Djdk.tracePinnedThreads` flag +stops reporting anything at all. + +## Versions this was built and tested against + +| Component | Version | Notes | +|---|---|---| +| JDK (primary) | 25.0.4.1+1 (Temurin, LTS) | Has JEP 491; native pinning still reproduces. | +| JDK (comparison) | 21.0.10 (OpenJDK) | Pre-JEP-491, for the before/after. | +| gcc | system default | Builds the JNI native library; not committed, built by `scripts/build-native.sh`. | +| Maven | 3.9.11 | Compiles the Java classes only - no JMH in this module. | +| Hardware | 2 vCPU x86-64 VM | Same sandbox as the rest of this series. | + +## Quickstart + +```bash +export JDK25_HOME=/path/to/jdk-25 +export JDK21_HOME=/path/to/jdk-21 +export JAVA_HOME=$JDK21_HOME # any JDK's jni.h works for the native build +./scripts/build-native.sh +$JDK25_HOME/bin/javac --release 25 -d target/classes $(find src/main/java -name "*.java") +$JDK25_HOME/bin/java --enable-native-access=ALL-UNNAMED -Djava.library.path=target/native \ + -cp target/classes com.ankurm.vtpinning.NativePinningDemo +``` + +`scripts/run-all.sh` regenerates every file in `output/` (needs both `JDK25_HOME` and +`JDK21_HOME` set, plus `gcc` on `PATH`). + +## What's in here + +| File | What it shows | +|---|---| +| `src/main/c/vtpinning.c` | One JNI native function, shared by every demo class: calls back into a static Java method on the same native stack frame, so the callback's blocking happens with native frames still present. | +| `.../MonitorPinningDemo.java` | `synchronized` + `Thread.sleep` on a virtual thread - the case JEP 491 fixed. | +| `.../NativePinningDemo.java` | The case JEP 491 did not fix: a JNI native method whose callback blocks. | +| `.../ThreadDumpPinnedDemo.java` | One pinned and one unpinned virtual thread running concurrently, for a `jcmd Thread.dump_to_file` capture. | +| `.../PinningThroughputDemo.java` | The wall-time cost of native pinning vs. plain blocking, on a capped carrier pool. | +| `.../BoundedNativeCallDemo.java` | The fix: routing a pinning native call through a small dedicated executor instead of calling it directly from the shared carrier pool. | +| `output/01` | `MonitorPinningDemo` on JDK 21 vs JDK 25, with `-Djdk.tracePinnedThreads=full`. | +| `output/02` | `NativePinningDemo` on JDK 21 vs JDK 25, same flag - still fires on 21, silent on 25. | +| `output/03` | The `jdk.VirtualThreadPinned` JFR event, captured and printed with `jfr print`, for the same native pin on JDK 25. | +| `output/04` | A `jcmd Thread.dump_to_file -format=json` snapshot taken mid-pin, pinned and unpinned virtual thread entries side by side. | +| `output/05` | `PinningThroughputDemo`: 4 virtual threads / 2 carriers, native vs plain. | +| `output/06` | `BoundedNativeCallDemo`: direct vs bounded-executor routing, effect on unrelated work. | + +## Reading the numbers honestly (2-vCPU sandbox) + +**The old diagnostic flag doesn't just go quiet for the case JEP 491 fixed - it's silent for the +case JEP 491 left alone too** (`output/02`). `-Djdk.tracePinnedThreads=full` reports +`reason:NATIVE` on JDK 21 for the exact same native call that still measurably pins on JDK 25 +(confirmed independently via the JFR event in `output/03`, and via the throughput cost in +`output/05`). A team that kept the flag in their JVM args through an upgrade to JDK 24+ gets no +signal from it for either kind of pinning going forward - not just the kind that stopped +mattering. + +**A `jcmd` thread dump distinguishes pinned from unmounted with one field** (`output/04`): a +pinned virtual thread's JSON entry carries a `"carrier"` field naming the platform thread's `tid`, +and its stack includes `VirtualThread.parkOnCarrierThread`. An unmounted (not pinned) blocked +virtual thread has neither - no `carrier` field at all, and a plain `parkNanos` in its stack. This +needs no JFR recording running and works against a single dump taken after the fact. + +**Native pinning genuinely serializes work on a capped carrier pool** (`output/05`): 4 virtual +threads each blocking ~1000ms on 2 carriers finish in ~2015ms through the native path (two +carrier-bound batches) versus ~1022ms through plain `Thread.sleep` (all four unmount and share the +2 carriers freely). This isn't a benchmark artifact - it's the same mechanism JEP 491 fixed for +monitors, just for a case it didn't touch. + +**Routing the pinning call through a small dedicated executor protects everything else** +(`output/06`): with 2 carriers, 2 concurrent native-pinning calls, and 6 unrelated +100ms-sleep virtual threads competing for the same pool, calling the native code directly starves +the unrelated work until ~924ms - both carriers are pinned the whole time. Routing the same native +calls through a 2-thread dedicated executor (via `Future.get()`, which parks normally with no +native frame on *that* thread's own stack) lets the unrelated work finish in ~126ms while the +native calls run to completion in the background. The pinning cost doesn't go away, but it stops +being everyone else's problem. + +## License + +MIT - see the [repo-wide LICENSE](../LICENSE). diff --git a/vt-pinning/output/01-monitor-pinning-jdk21-vs-jdk25.txt b/vt-pinning/output/01-monitor-pinning-jdk21-vs-jdk25.txt new file mode 100644 index 0000000..f7d616f --- /dev/null +++ b/vt-pinning/output/01-monitor-pinning-jdk21-vs-jdk25.txt @@ -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 diff --git a/vt-pinning/output/02-native-pinning-jdk21-vs-jdk25.txt b/vt-pinning/output/02-native-pinning-jdk21-vs-jdk25.txt new file mode 100644 index 0000000..bffc4f9 --- /dev/null +++ b/vt-pinning/output/02-native-pinning-jdk21-vs-jdk25.txt @@ -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 diff --git a/vt-pinning/output/03-jfr-virtualthreadpinned-event.txt b/vt-pinning/output/03-jfr-virtualthreadpinned-event.txt new file mode 100644 index 0000000..c78e733 --- /dev/null +++ b/vt-pinning/output/03-jfr-virtualthreadpinned-event.txt @@ -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) + ] +} + diff --git a/vt-pinning/output/04-jcmd-thread-dump-pinned-vs-unpinned.txt b/vt-pinning/output/04-jcmd-thread-dump-pinned-vs-unpinned.txt new file mode 100644 index 0000000..c6d9de8 --- /dev/null +++ b/vt-pinning/output/04-jcmd-thread-dump-pinned-vs-unpinned.txt @@ -0,0 +1,45 @@ +$ java ThreadDumpPinnedDemo & +pid=7126 +done + +$ jcmd 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)" + ] +} + diff --git a/vt-pinning/output/05-pinning-throughput-cost.txt b/vt-pinning/output/05-pinning-throughput-cost.txt new file mode 100644 index 0000000..2c7bb2c --- /dev/null +++ b/vt-pinning/output/05-pinning-throughput-cost.txt @@ -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 diff --git a/vt-pinning/output/06-bounded-executor-fix.txt b/vt-pinning/output/06-bounded-executor-fix.txt new file mode 100644 index 0000000..18197d7 --- /dev/null +++ b/vt-pinning/output/06-bounded-executor-fix.txt @@ -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 diff --git a/vt-pinning/pom.xml b/vt-pinning/pom.xml new file mode 100644 index 0000000..a715850 --- /dev/null +++ b/vt-pinning/pom.xml @@ -0,0 +1,29 @@ + + + 4.0.0 + + + com.ankurm + java-core-examples + 1.0 + + + vt-pinning + vt-pinning + Diagnosing virtual thread pinning in production: reproducing the native-code pinning JEP 491 didn't fix, reading the jdk.VirtualThreadPinned JFR event, and finding a pinned carrier in a jcmd thread dump. + + + + + org.apache.maven.plugins + maven-compiler-plugin + 3.13.0 + + 25 + + + + + diff --git a/vt-pinning/scripts/build-native.sh b/vt-pinning/scripts/build-native.sh new file mode 100755 index 0000000..26d2df8 --- /dev/null +++ b/vt-pinning/scripts/build-native.sh @@ -0,0 +1,18 @@ +#!/usr/bin/env bash +# Compiles src/main/c/vtpinning.c into libvtpinning.so, linked against the JNI headers of +# whichever JDK is on JAVA_HOME (any JDK's jni.h works - the JNI ABI is stable across versions; +# this repo built it once against JDK 21's headers and loads it fine under JDK 21 and JDK 25). +# The .so is NOT committed to the repo; run this before the other scripts. +set -euo pipefail +cd "$(dirname "$0")/.." + +: "${JAVA_HOME:?Set JAVA_HOME to a JDK install (its include/ dir must have jni.h)}" + +mkdir -p target/native +gcc -shared -fPIC \ + -I"$JAVA_HOME/include" \ + -I"$JAVA_HOME/include/linux" \ + -o target/native/libvtpinning.so \ + src/main/c/vtpinning.c + +echo "Built target/native/libvtpinning.so" diff --git a/vt-pinning/scripts/run-all.sh b/vt-pinning/scripts/run-all.sh new file mode 100755 index 0000000..6f752e5 --- /dev/null +++ b/vt-pinning/scripts/run-all.sh @@ -0,0 +1,112 @@ +#!/usr/bin/env bash +# Regenerates every file in output/. Requires: +# - JDK25_HOME pointing at a JDK 24+ install (this repo used Temurin 25.0.4.1+1) +# - JDK21_HOME pointing at a pre-JDK-24 install (this repo used OpenJDK 21.0.10), for the +# before/after comparisons against JEP 491 +# - gcc on PATH (builds the JNI native library) +set -euo pipefail +cd "$(dirname "$0")/.." + +: "${JDK25_HOME:?Set JDK25_HOME to a JDK 24+ install}" +: "${JDK21_HOME:?Set JDK21_HOME to a pre-JDK-24 install}" + +JAVA_HOME="$JDK21_HOME" ./scripts/build-native.sh + +mkdir -p target/classes target/classes-21 +"$JDK25_HOME/bin/javac" --release 25 -d target/classes $(find src/main/java -name "*.java") +"$JDK21_HOME/bin/javac" --release 21 -d target/classes-21 $(find src/main/java -name "*.java") + +NATLIB=target/native + +echo "--- 01: monitor pinning, JDK21 vs JDK25 (JEP 491) ---" +{ + echo '$ java -Djdk.tracePinnedThreads=full MonitorPinningDemo (pre-JDK-24 runtime)' + echo "" + "$JDK21_HOME/bin/java" -Djdk.tracePinnedThreads=full -cp target/classes-21 \ + com.ankurm.vtpinning.MonitorPinningDemo 2>&1 | grep -v "Picked up" + echo "" + echo '$ java -Djdk.tracePinnedThreads=full MonitorPinningDemo (JDK 24+ runtime)' + echo "" + "$JDK25_HOME/bin/java" -Djdk.tracePinnedThreads=full -cp target/classes \ + com.ankurm.vtpinning.MonitorPinningDemo 2>&1 | grep -v "Picked up" +} > output/01-monitor-pinning-jdk21-vs-jdk25.txt + +echo "--- 02: native pinning, JDK21 vs JDK25 (still real on both) ---" +{ + echo '$ java -Djdk.tracePinnedThreads=full NativePinningDemo (pre-JDK-24 runtime)' + echo "" + "$JDK21_HOME/bin/java" -Djdk.tracePinnedThreads=full -Djava.library.path=$NATLIB -cp target/classes-21 \ + com.ankurm.vtpinning.NativePinningDemo 2>&1 | grep -v "Picked up" + echo "" + echo '$ java -Djdk.tracePinnedThreads=full NativePinningDemo (JDK 24+ runtime - flag is inert)' + echo "" + "$JDK25_HOME/bin/java" --enable-native-access=ALL-UNNAMED -Djdk.tracePinnedThreads=full -Djava.library.path=$NATLIB -cp target/classes \ + com.ankurm.vtpinning.NativePinningDemo 2>&1 | grep -v "Picked up\|WARNING" +} > output/02-native-pinning-jdk21-vs-jdk25.txt + +echo "--- 03: jdk.VirtualThreadPinned JFR event on JDK25 ---" +rm -f target/native-pin.jfr +{ + echo '$ java -XX:StartFlightRecording=...,jdk.VirtualThreadPinned#enabled=true,threshold=0ms NativePinningDemo' + echo "" + "$JDK25_HOME/bin/java" --enable-native-access=ALL-UNNAMED \ + "-XX:StartFlightRecording=filename=target/native-pin.jfr,settings=profile,jdk.VirtualThreadPinned#enabled=true,jdk.VirtualThreadPinned#threshold=0ms,jdk.VirtualThreadPinned#stackTrace=true" \ + -Djava.library.path=$NATLIB -cp target/classes com.ankurm.vtpinning.NativePinningDemo 2>&1 \ + | grep -v "Picked up\|WARNING\|jfr,startup\|^\[" + echo "" + echo '$ jfr print --events jdk.VirtualThreadPinned --stack-depth 10 target/native-pin.jfr' + echo "" + "$JDK25_HOME/bin/jfr" print --events jdk.VirtualThreadPinned --stack-depth 10 target/native-pin.jfr 2>&1 | grep -v "Picked up" +} > output/03-jfr-virtualthreadpinned-event.txt + +echo "--- 04: jcmd Thread.dump_to_file, pinned vs unpinned virtual thread ---" +rm -f target/threaddump.json target/threaddump_out.txt +"$JDK25_HOME/bin/java" --enable-native-access=ALL-UNNAMED -Djava.library.path=$NATLIB -cp target/classes \ + com.ankurm.vtpinning.ThreadDumpPinnedDemo > target/threaddump_out.txt 2>&1 & +PID=$! +sleep 1.5 +"$JDK25_HOME/bin/jcmd" "$PID" Thread.dump_to_file -format=json target/threaddump.json > target/jcmd_out.txt 2>&1 +wait $PID +{ + echo '$ java ThreadDumpPinnedDemo &' + grep -v "Picked up" target/threaddump_out.txt + echo "" + echo '$ jcmd Thread.dump_to_file -format=json threaddump.json (taken mid-flight)' + grep -v "Picked up" target/jcmd_out.txt + echo "" + echo '--- the two virtual thread entries from that dump ---' + python3 - <<'PYEOF' +import json +with open('target/threaddump.json') as f: + data = json.load(f) +for c in data['threadDump']['threadContainers']: + for t in c.get('threads', []): + if t.get('virtual'): + print(json.dumps(t, indent=2)) + print() +PYEOF +} > output/04-jcmd-thread-dump-pinned-vs-unpinned.txt + +echo "--- 05: throughput cost of native pinning vs plain blocking (capped carriers) ---" +{ + echo '$ java -Djdk.virtualThreadScheduler.parallelism=2 PinningThroughputDemo native 4 1000' + "$JDK25_HOME/bin/java" --enable-native-access=ALL-UNNAMED -Djdk.virtualThreadScheduler.parallelism=2 -Djava.library.path=$NATLIB -cp target/classes \ + com.ankurm.vtpinning.PinningThroughputDemo native 4 1000 2>&1 | grep -v "Picked up\|WARNING" + echo "" + echo '$ java -Djdk.virtualThreadScheduler.parallelism=2 PinningThroughputDemo plain 4 1000' + "$JDK25_HOME/bin/java" -Djdk.virtualThreadScheduler.parallelism=2 -Djava.library.path=$NATLIB -cp target/classes \ + com.ankurm.vtpinning.PinningThroughputDemo plain 4 1000 2>&1 | grep -v "Picked up\|WARNING" +} > output/05-pinning-throughput-cost.txt + +echo "--- 06: bounding the blast radius with a dedicated executor ---" +{ + echo '$ java -Djdk.virtualThreadScheduler.parallelism=2 BoundedNativeCallDemo direct' + "$JDK25_HOME/bin/java" --enable-native-access=ALL-UNNAMED -Djdk.virtualThreadScheduler.parallelism=2 -Djava.library.path=$NATLIB -cp target/classes \ + com.ankurm.vtpinning.BoundedNativeCallDemo direct 2>&1 | grep -v "Picked up\|WARNING" + echo "" + echo '$ java -Djdk.virtualThreadScheduler.parallelism=2 BoundedNativeCallDemo bounded' + "$JDK25_HOME/bin/java" --enable-native-access=ALL-UNNAMED -Djdk.virtualThreadScheduler.parallelism=2 -Djava.library.path=$NATLIB -cp target/classes \ + com.ankurm.vtpinning.BoundedNativeCallDemo bounded 2>&1 | grep -v "Picked up\|WARNING" +} > output/06-bounded-executor-fix.txt + +echo "Done. See output/." diff --git a/vt-pinning/src/main/c/vtpinning.c b/vt-pinning/src/main/c/vtpinning.c new file mode 100644 index 0000000..05317a1 --- /dev/null +++ b/vt-pinning/src/main/c/vtpinning.c @@ -0,0 +1,47 @@ +/* + * A minimal JNI native method used by every demo in this module. It does exactly one thing: + * call back into the Java class that invoked it, on the same native stack frame, so that + * whatever the callback does (in every demo here, a Thread.sleep) executes while native frames + * are still on the virtual thread's stack - which is precisely what a continuation cannot freeze + * across, and therefore what still pins a virtual thread's carrier on every JDK version, + * including JDK 24+ after JEP 491 fixed monitor pinning. + * + * Every demo class in this module declares the same native method name + * (blockingNativeCall) and static callback name (sleepCallback), just in different classes, so + * one shared native function - looked up by class name at call time - covers all of them. + */ +#include +#include + +/* JNI_OnLoad isn't required here; each demo class binds via System.loadLibrary + a matching + * Java__blockingNativeCall symbol would normally be needed per class. Instead we export + * one symbol per demo class below, all doing the identical call-back, to avoid duplicating this + * file four times for four otherwise-identical native methods. */ + +static void callSleepCallback(JNIEnv *env, jclass cls) { + jmethodID mid = (*env)->GetStaticMethodID(env, cls, "sleepCallback", "()V"); + if (mid == NULL) { + return; /* let the pending exception propagate back into Java */ + } + (*env)->CallStaticVoidMethod(env, cls, mid); +} + +JNIEXPORT void JNICALL Java_com_ankurm_vtpinning_NativePinningDemo_blockingNativeCall + (JNIEnv *env, jclass cls) { + callSleepCallback(env, cls); +} + +JNIEXPORT void JNICALL Java_com_ankurm_vtpinning_ThreadDumpPinnedDemo_blockingNativeCall + (JNIEnv *env, jclass cls) { + callSleepCallback(env, cls); +} + +JNIEXPORT void JNICALL Java_com_ankurm_vtpinning_PinningThroughputDemo_blockingNativeCall + (JNIEnv *env, jclass cls) { + callSleepCallback(env, cls); +} + +JNIEXPORT void JNICALL Java_com_ankurm_vtpinning_BoundedNativeCallDemo_blockingNativeCall + (JNIEnv *env, jclass cls) { + callSleepCallback(env, cls); +} diff --git a/vt-pinning/src/main/java/com/ankurm/vtpinning/BoundedNativeCallDemo.java b/vt-pinning/src/main/java/com/ankurm/vtpinning/BoundedNativeCallDemo.java new file mode 100644 index 0000000..5747a10 --- /dev/null +++ b/vt-pinning/src/main/java/com/ankurm/vtpinning/BoundedNativeCallDemo.java @@ -0,0 +1,103 @@ +package com.ankurm.vtpinning; + +import java.util.concurrent.CountDownLatch; +import java.util.concurrent.ExecutorService; +import java.util.concurrent.Executors; +import java.util.concurrent.Future; + +/** + * The fix for native-code pinning isn't eliminating it - it's architectural, and no JDK flag + * removes it. The fix is containing its blast radius: never let a native call that pins run + * directly on the same carrier pool everything else in the process shares. Route it through a + * small, explicitly-sized platform-thread executor instead, and call that executor from the + * virtual thread via a plain {@code Future.get()} - which parks normally (no native frame on + * *this* thread's stack) and unmounts, leaving the shared carrier pool free for unrelated work. + * + *

This demo runs {@code pinningCount} native-pinning calls alongside {@code unrelatedCount} + * ordinary virtual threads doing short, unrelated sleeps, on a carrier pool capped small enough + * that direct native calls would starve the unrelated work. {@code mode=direct} calls native code + * straight from the virtual thread (competes for the shared pool); {@code mode=bounded} routes it + * through a dedicated 2-thread executor instead. + * + *

Usage: {@code java -Djdk.virtualThreadScheduler.parallelism=2 BoundedNativeCallDemo + * direct|bounded} + */ +public final class BoundedNativeCallDemo { + + static { + System.loadLibrary("vtpinning"); + } + + private static native void blockingNativeCall(); + + @SuppressWarnings("unused") + private static void sleepCallback() { + try { + Thread.sleep(800); + } catch (InterruptedException e) { + Thread.currentThread().interrupt(); + } + } + + public static void main(String[] args) throws Exception { + String mode = args.length > 0 ? args[0] : "direct"; + int pinningCount = 2; + int unrelatedCount = 6; + + ExecutorService nativePool = Executors.newFixedThreadPool(2); + try { + long start = System.nanoTime(); + + CountDownLatch pinningLatch = new CountDownLatch(pinningCount); + for (int i = 0; i < pinningCount; i++) { + Thread.ofVirtual().start(() -> { + try { + if ("bounded".equals(mode)) { + Future f = nativePool.submit(BoundedNativeCallDemo::blockingNativeCall); + f.get(); + } else { + blockingNativeCall(); + } + } catch (Exception e) { + throw new RuntimeException(e); + } finally { + pinningLatch.countDown(); + } + }); + } + + CountDownLatch unrelatedLatch = new CountDownLatch(unrelatedCount); + long[] unrelatedFinishedAt = new long[unrelatedCount]; + for (int i = 0; i < unrelatedCount; i++) { + int idx = i; + Thread.ofVirtual().start(() -> { + try { + Thread.sleep(100); + } catch (InterruptedException e) { + Thread.currentThread().interrupt(); + } finally { + unrelatedFinishedAt[idx] = (System.nanoTime() - start) / 1_000_000; + unrelatedLatch.countDown(); + } + }); + } + + unrelatedLatch.await(); + long unrelatedDoneMs = 0; + for (long t : unrelatedFinishedAt) { + unrelatedDoneMs = Math.max(unrelatedDoneMs, t); + } + pinningLatch.await(); + long totalMs = (System.nanoTime() - start) / 1_000_000; + + System.out.println("mode=" + mode + + " parallelism=" + System.getProperty("jdk.virtualThreadScheduler.parallelism") + + " pinningCount=" + pinningCount + + " unrelatedCount=" + unrelatedCount + + " unrelatedWorkDoneAtMs=" + unrelatedDoneMs + + " totalElapsedMs=" + totalMs); + } finally { + nativePool.shutdown(); + } + } +} diff --git a/vt-pinning/src/main/java/com/ankurm/vtpinning/MonitorPinningDemo.java b/vt-pinning/src/main/java/com/ankurm/vtpinning/MonitorPinningDemo.java new file mode 100644 index 0000000..b927490 --- /dev/null +++ b/vt-pinning/src/main/java/com/ankurm/vtpinning/MonitorPinningDemo.java @@ -0,0 +1,36 @@ +package com.ankurm.vtpinning; + +/** + * A virtual thread that enters a {@code synchronized} block and then blocks inside it. + * + *

Before JEP 491 (pre-JDK 24), this pinned the carrier thread for the full duration of the + * block. JEP 491 shipped GA in JDK 24 and removed that pinning: the virtual thread can now + * acquire, hold, and release a monitor independently of its carrier, so a {@code Thread.sleep} + * (or any other blocking call) inside {@code synchronized} no longer pins. + * + *

Run this with {@code -Djdk.tracePinnedThreads=full} on a pre-JDK-24 runtime and it prints a + * {@code reason:MONITOR} stack trace. Run it the same way on JDK 24+ and nothing prints at all - + * not because the flag broke, but because there is nothing left to report for this specific case. + * See {@link NativePinningDemo} for the pinning that JEP 491 did not touch. + */ +public final class MonitorPinningDemo { + + private static final Object LOCK = new Object(); + + public static void main(String[] args) throws Exception { + System.out.println("java.version=" + System.getProperty("java.version")); + System.out.println("jdk.tracePinnedThreads=" + System.getProperty("jdk.tracePinnedThreads")); + + Thread t = Thread.ofVirtual().start(() -> { + synchronized (LOCK) { + try { + Thread.sleep(200); + } catch (InterruptedException e) { + Thread.currentThread().interrupt(); + } + } + }); + t.join(); + System.out.println("done"); + } +} diff --git a/vt-pinning/src/main/java/com/ankurm/vtpinning/NativePinningDemo.java b/vt-pinning/src/main/java/com/ankurm/vtpinning/NativePinningDemo.java new file mode 100644 index 0000000..06fc70f --- /dev/null +++ b/vt-pinning/src/main/java/com/ankurm/vtpinning/NativePinningDemo.java @@ -0,0 +1,50 @@ +package com.ankurm.vtpinning; + +/** + * Reproduces the pinning JEP 491 did NOT fix: a virtual thread executing native code (a JNI + * native method, or the Foreign Function & Memory API) whose native frame calls back into + * Java code that blocks. The continuation backing the virtual thread cannot be frozen across a + * native stack frame, so the carrier stays pinned for as long as the callback blocks - + * regardless of JDK version, because this is architectural, not a bug JEP 491 targeted. + * + *

Requires {@code libvtpinning.so} on {@code java.library.path} (built by + * {@code scripts/build-native.sh} from {@code src/main/c/vtpinning.c}). The native method calls + * straight back into {@link #sleepCallback()}, which is the only thing that actually blocks. + * + *

Usage: {@code java --enable-native-access=ALL-UNNAMED NativePinningDemo [sleepMillis]} + * (sleepMillis defaults to 200; pass a larger value to hold the pin open long enough to attach a + * jcmd thread dump to it - see {@link ThreadDumpPinnedDemo}). + */ +public final class NativePinningDemo { + + static { + System.loadLibrary("vtpinning"); + } + + private static native void blockingNativeCall(); + + // Called back FROM native code, while native frames are still on this thread's stack. + @SuppressWarnings("unused") + private static void sleepCallback() { + try { + Thread.sleep(SLEEP_MILLIS); + } catch (InterruptedException e) { + Thread.currentThread().interrupt(); + } + } + + private static volatile long SLEEP_MILLIS = 200; + + public static void main(String[] args) throws Exception { + if (args.length > 0) { + SLEEP_MILLIS = Long.parseLong(args[0]); + } + System.out.println("java.version=" + System.getProperty("java.version")); + System.out.println("jdk.tracePinnedThreads=" + System.getProperty("jdk.tracePinnedThreads")); + System.out.println("sleepMillis=" + SLEEP_MILLIS); + + Thread t = Thread.ofVirtual().start(NativePinningDemo::blockingNativeCall); + t.join(); + System.out.println("done"); + } +} diff --git a/vt-pinning/src/main/java/com/ankurm/vtpinning/PinningThroughputDemo.java b/vt-pinning/src/main/java/com/ankurm/vtpinning/PinningThroughputDemo.java new file mode 100644 index 0000000..164c9e5 --- /dev/null +++ b/vt-pinning/src/main/java/com/ankurm/vtpinning/PinningThroughputDemo.java @@ -0,0 +1,68 @@ +package com.ankurm.vtpinning; + +import java.util.concurrent.CountDownLatch; + +/** + * What native-code pinning actually costs in wall time, versus the same workload done in a way + * that unmounts normally. Runs {@code threadCount} virtual threads, each blocking for + * {@code blockMillis}, either through the native pinning path ({@code mode=native}) or through a + * plain {@code Thread.sleep} that unmounts ({@code mode=plain}). Run with + * {@code -Djdk.virtualThreadScheduler.parallelism=N} to cap the carrier pool and make the + * difference visible on a small thread count. + * + *

Usage: {@code java -Djdk.virtualThreadScheduler.parallelism=2 PinningThroughputDemo + * native|plain [threadCount] [blockMillis]} + */ +public final class PinningThroughputDemo { + + static { + System.loadLibrary("vtpinning"); + } + + private static native void blockingNativeCall(); + + private static volatile long BLOCK_MILLIS = 1000; + + @SuppressWarnings("unused") + private static void sleepCallback() { + try { + Thread.sleep(BLOCK_MILLIS); + } catch (InterruptedException e) { + Thread.currentThread().interrupt(); + } + } + + public static void main(String[] args) throws Exception { + String mode = args.length > 0 ? args[0] : "native"; + int threadCount = args.length > 1 ? Integer.parseInt(args[1]) : 4; + if (args.length > 2) { + BLOCK_MILLIS = Long.parseLong(args[2]); + } + + long start = System.nanoTime(); + CountDownLatch latch = new CountDownLatch(threadCount); + for (int i = 0; i < threadCount; i++) { + Thread.ofVirtual().start(() -> { + try { + if ("native".equals(mode)) { + blockingNativeCall(); + } else { + Thread.sleep(BLOCK_MILLIS); + } + } catch (InterruptedException e) { + Thread.currentThread().interrupt(); + } finally { + latch.countDown(); + } + }); + } + latch.await(); + long elapsedMs = (System.nanoTime() - start) / 1_000_000; + + System.out.println("mode=" + mode + + " threadCount=" + threadCount + + " blockMillis=" + BLOCK_MILLIS + + " parallelism=" + System.getProperty("jdk.virtualThreadScheduler.parallelism") + + " elapsedMs=" + elapsedMs); + } +} diff --git a/vt-pinning/src/main/java/com/ankurm/vtpinning/ThreadDumpPinnedDemo.java b/vt-pinning/src/main/java/com/ankurm/vtpinning/ThreadDumpPinnedDemo.java new file mode 100644 index 0000000..c8624f0 --- /dev/null +++ b/vt-pinning/src/main/java/com/ankurm/vtpinning/ThreadDumpPinnedDemo.java @@ -0,0 +1,44 @@ +package com.ankurm.vtpinning; + +/** + * Companion to {@code scripts/run-all.sh}'s jcmd capture: starts one virtual thread pinned via + * native code (see {@link NativePinningDemo}) and one virtual thread merely sleeping (unpinned, + * unmounted), both long enough that a {@code jcmd Thread.dump_to_file -format=json} taken + * a second later catches both mid-flight. Compare the two entries in the dump: the pinned one + * carries a {@code "carrier"} field naming the platform thread it is stuck to and its stack shows + * {@code VirtualThread.parkOnCarrierThread}; the unpinned one has neither. + */ +public final class ThreadDumpPinnedDemo { + + static { + System.loadLibrary("vtpinning"); + } + + private static native void blockingNativeCall(); + + @SuppressWarnings("unused") + private static void sleepCallback() { + try { + Thread.sleep(4000); + } catch (InterruptedException e) { + Thread.currentThread().interrupt(); + } + } + + public static void main(String[] args) throws Exception { + System.out.println("pid=" + ProcessHandle.current().pid()); + + Thread pinned = Thread.ofVirtual().start(ThreadDumpPinnedDemo::blockingNativeCall); + Thread unpinned = Thread.ofVirtual().start(() -> { + try { + Thread.sleep(4000); + } catch (InterruptedException e) { + Thread.currentThread().interrupt(); + } + }); + + pinned.join(); + unpinned.join(); + System.out.println("done"); + } +}