Spring boot virtual threads -Djdk.tracePinnedThreads=full causes tasks to hang

349 views Asked by At

Not sure if this is a spring or java problem. If I run the test with the below setup including -Djdk.tracePinnedThreads=full the test hangs. Without it it runs fine. Any ideas why this might happen. Is there any additional configuration for spring I may need

pom.xml

<?xml version="1.0" encoding="UTF-8"?>
<project xmlns="http://maven.apache.org/POM/4.0.0" xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
    xsi:schemaLocation="http://maven.apache.org/POM/4.0.0 https://maven.apache.org/xsd/maven-4.0.0.xsd">
    <modelVersion>4.0.0</modelVersion>
    <parent>
        <groupId>org.springframework.boot</groupId>
        <artifactId>spring-boot-starter-parent</artifactId>
        <version>3.2.0</version>
        <relativePath/> <!-- lookup parent from repository -->
    </parent>
    <groupId>org.test</groupId>
    <artifactId>virtual-spring</artifactId>
    <version>0.0.1-SNAPSHOT</version>
    <name>VirtualSpring</name>
    <description>Virtual Spring Boot</description>
    <properties>
        <java.version>21</java.version>
    </properties>
    <dependencies>

        <dependency>
            <groupId>org.springframework.boot</groupId>
            <artifactId>spring-boot-starter</artifactId>
        </dependency>
           
        <!--Testing-->
        <dependency>
            <groupId>org.springframework.boot</groupId>
            <artifactId>spring-boot-starter-test</artifactId>
            <scope>test</scope>
        </dependency>
    </dependencies>

    <build>
        <plugins>
            <plugin>
                <groupId>org.springframework.boot</groupId>
                <artifactId>spring-boot-maven-plugin</artifactId>
            </plugin>
        </plugins>
    </build>

</project>

application.properties

spring.main.keep-alive=true
spring.threads.virtual.enabled=true

application class

package org.test;

import org.springframework.boot.SpringApplication;
import org.springframework.boot.autoconfigure.SpringBootApplication;

@SpringBootApplication
public class VirtualSpringApplication {

    public static void main(String[] args) {
        SpringApplication.run(VirtualSpringApplication.class, args);
    }

}

and test class

package org.test;

import org.junit.jupiter.api.Test;
import org.springframework.boot.test.context.SpringBootTest;

@SpringBootTest
class VirtualSpringApplicationTests {

    @Test
    public void pinned() throws InterruptedException {

        final Thread thread0 = Thread.startVirtualThread(() -> testForPin(0));
        final Thread thread1 = Thread.startVirtualThread(() -> testForPin(1));
        final Thread thread2 = Thread.startVirtualThread(() -> testForPin(2));
        System.out.println("THREADS STARTED\n");

        thread0.join();
        thread1.join();
        thread2.join();

    }

    synchronized public void testForPin(final int i) {

        System.out.println("Thread: " + Thread.currentThread().toString() + ", virtual=" + Thread.currentThread().isVirtual() + " i=" + i);
        try {
            Thread.sleep(1000);
            System.out.println("Thread Finished: " + Thread.currentThread().toString() + ", virtual=" + Thread.currentThread().isVirtual() + " i=" + i);
        } catch (final InterruptedException e) {
            throw new RuntimeException(e);
        }
    }
}

Update 1:jhsdb showing blocked threads (only relevant output shown due to size)

jhsdb jstack --pid 16244
Attaching to process ID 16244, please wait...
Debugger attached successfully.
Server compiler detected.
JVM version is 21.0.2+13-58
Deadlock Detection:

No deadlocks found.

"ForkJoinPool-1-worker-1" #61 daemon prio=5 tid=0x0000025b552abba0 nid=13468 waiting on condition [0x000000e1986fe000]
   java.lang.Thread.State: RUNNABLE
   JavaThread state: _thread_blocked
 - java.lang.VirtualThread$VThreadContinuation.onPinned(jdk.internal.vm.Continuation$Pinned) @bci=23, line=183 (Interpreted frame)
 - jdk.internal.vm.Continuation.onPinned0(int) @bci=5, line=393 (Interpreted frame)
 - jdk.internal.vm.Continuation.yield0(jdk.internal.vm.ContinuationScope, jdk.internal.vm.Continuation) @bci=325, line=385 (Interpreted frame)
 - jdk.internal.vm.Continuation.yield(jdk.internal.vm.ContinuationScope) @bci=69, line=351 (Interpreted frame)
 - java.lang.VirtualThread.yieldContinuation() @bci=12, line=431 (Interpreted frame)
 - java.lang.VirtualThread.parkNanos(long) @bci=69, line=621 (Interpreted frame)
 - java.lang.VirtualThread.sleepNanos(long) @bci=70, line=791 (Interpreted frame)
 - java.lang.Thread.sleep(long) @bci=53, line=507 (Interpreted frame)
 - org.test.VirtualSpringApplicationTests.testForPin(int) @bci=27, line=27 (Interpreted frame)
        - locked <0x0000000621801bb8> (a org.test.VirtualSpringApplicationTests)
 - org.test.VirtualSpringApplicationTests.lambda$pinned$0() @bci=2, line=12 (Interpreted frame)
 - org.test.VirtualSpringApplicationTests$$Lambda+0x0000025b58449680.run() @bci=4 (Interpreted frame)
 - java.lang.Thread.runWith(java.lang.Object, java.lang.Runnable) @bci=5, line=1596 (Interpreted frame)
 - java.lang.VirtualThread.run(java.lang.Runnable) @bci=63, line=309 (Interpreted frame)
 - java.lang.VirtualThread$VThreadContinuation$1.run() @bci=8, line=190 (Interpreted frame)
 - jdk.internal.vm.Continuation.enter0() @bci=4, line=320 (Interpreted frame)
 - jdk.internal.vm.Continuation.enter(jdk.internal.vm.Continuation, boolean) @bci=1, line=312 (Interpreted frame)
 - jdk.internal.vm.Continuation.enterSpecial(jdk.internal.vm.Continuation, boolean, boolean) @bci=0 (Compiled frame)
 - jdk.internal.vm.Continuation.run() @bci=122, line=248 (Interpreted frame)
 - java.lang.VirtualThread.runContinuation() @bci=71, line=221 (Interpreted frame)
 - java.lang.VirtualThread$$Lambda+0x0000025b5838ac20.run() @bci=4 (Interpreted frame)
 - java.util.concurrent.ForkJoinTask$RunnableExecuteAction.exec() @bci=4, line=1423 (Interpreted frame)
 - java.util.concurrent.ForkJoinTask.doExec() @bci=10, line=387 (Interpreted frame)
 - java.util.concurrent.ForkJoinPool$WorkQueue.topLevelExec(java.util.concurrent.ForkJoinTask, java.util.concurrent.ForkJoinPool$WorkQueue) @bci=19, line=1312 (Interpreted frame)
 - java.util.concurrent.ForkJoinPool.scan(java.util.concurrent.ForkJoinPool$WorkQueue, int, int) @bci=211, line=1843 (Interpreted frame)
 - java.util.concurrent.ForkJoinPool.runWorker(java.util.concurrent.ForkJoinPool$WorkQueue) @bci=35, line=1808 (Interpreted frame)
 - java.util.concurrent.ForkJoinWorkerThread.run() @bci=31, line=188 (Interpreted frame)


"ForkJoinPool-1-worker-2" #64 daemon prio=5 tid=0x0000025b552ac230 nid=1028 waiting for monitor entry [0x000000e1987fe000]
   java.lang.Thread.State: BLOCKED (on object monitor)
   JavaThread state: _thread_blocked
 - org.test.VirtualSpringApplicationTests.testForPin(int) @bci=0, line=25 (Interpreted frame)
        - waiting to lock <0x0000000621801bb8> (a org.test.VirtualSpringApplicationTests)
 - org.test.VirtualSpringApplicationTests.lambda$pinned$1() @bci=2, line=13 (Interpreted frame)
 - org.test.VirtualSpringApplicationTests$$Lambda+0x0000025b584498a0.run() @bci=4 (Interpreted frame)
 - java.lang.Thread.runWith(java.lang.Object, java.lang.Runnable) @bci=5, line=1596 (Interpreted frame)
 - java.lang.VirtualThread.run(java.lang.Runnable) @bci=63, line=309 (Interpreted frame)
 - java.lang.VirtualThread$VThreadContinuation$1.run() @bci=8, line=190 (Interpreted frame)
 - jdk.internal.vm.Continuation.enter0() @bci=4, line=320 (Interpreted frame)
 - jdk.internal.vm.Continuation.enter(jdk.internal.vm.Continuation, boolean) @bci=1, line=312 (Interpreted frame)
 - jdk.internal.vm.Continuation.enterSpecial(jdk.internal.vm.Continuation, boolean, boolean) @bci=0 (Compiled frame)
 - jdk.internal.vm.Continuation.run() @bci=122, line=248 (Interpreted frame)
 - java.lang.VirtualThread.runContinuation() @bci=71, line=221 (Interpreted frame)
 - java.lang.VirtualThread$$Lambda+0x0000025b5838ac20.run() @bci=4 (Interpreted frame)
 - java.util.concurrent.ForkJoinTask$RunnableExecuteAction.exec() @bci=4, line=1423 (Interpreted frame)
 - java.util.concurrent.ForkJoinTask.doExec() @bci=10, line=387 (Interpreted frame)
 - java.util.concurrent.ForkJoinPool$WorkQueue.topLevelExec(java.util.concurrent.ForkJoinTask, java.util.concurrent.ForkJoinPool$WorkQueue) @bci=19, line=1312 (Interpreted frame)
 - java.util.concurrent.ForkJoinPool.scan(java.util.concurrent.ForkJoinPool$WorkQueue, int, int) @bci=211, line=1843 (Interpreted frame)
 - java.util.concurrent.ForkJoinPool.runWorker(java.util.concurrent.ForkJoinPool$WorkQueue) @bci=35, line=1808 (Interpreted frame)
 - java.util.concurrent.ForkJoinWorkerThread.run() @bci=31, line=188 (Interpreted frame)


"ForkJoinPool-1-worker-3" #65 daemon prio=5 tid=0x0000025b552acf50 nid=11824 waiting for monitor entry [0x000000e1988fe000]
   java.lang.Thread.State: BLOCKED (on object monitor)
   JavaThread state: _thread_blocked
 - org.test.VirtualSpringApplicationTests.testForPin(int) @bci=0, line=25 (Interpreted frame)
        - waiting to lock <0x0000000621801bb8> (a org.test.VirtualSpringApplicationTests)
 - org.test.VirtualSpringApplicationTests.lambda$pinned$2() @bci=2, line=14 (Interpreted frame)
 - org.test.VirtualSpringApplicationTests$$Lambda+0x0000025b58449ac0.run() @bci=4 (Interpreted frame)
 - java.lang.Thread.runWith(java.lang.Object, java.lang.Runnable) @bci=5, line=1596 (Interpreted frame)
 - java.lang.VirtualThread.run(java.lang.Runnable) @bci=63, line=309 (Interpreted frame)
 - java.lang.VirtualThread$VThreadContinuation$1.run() @bci=8, line=190 (Interpreted frame)
 - jdk.internal.vm.Continuation.enter0() @bci=4, line=320 (Interpreted frame)
 - jdk.internal.vm.Continuation.enter(jdk.internal.vm.Continuation, boolean) @bci=1, line=312 (Interpreted frame)
 - jdk.internal.vm.Continuation.enterSpecial(jdk.internal.vm.Continuation, boolean, boolean) @bci=0 (Compiled frame)
 - jdk.internal.vm.Continuation.run() @bci=122, line=248 (Interpreted frame)
 - java.lang.VirtualThread.runContinuation() @bci=71, line=221 (Interpreted frame)
 - java.lang.VirtualThread$$Lambda+0x0000025b5838ac20.run() @bci=4 (Interpreted frame)
 - java.util.concurrent.ForkJoinTask$RunnableExecuteAction.exec() @bci=4, line=1423 (Interpreted frame)
 - java.util.concurrent.ForkJoinTask.doExec() @bci=10, line=387 (Interpreted frame)
 - java.util.concurrent.ForkJoinPool$WorkQueue.topLevelExec(java.util.concurrent.ForkJoinTask, java.util.concurrent.ForkJoinPool$WorkQueue) @bci=19, line=1312 (Interpreted frame)
 - java.util.concurrent.ForkJoinPool.scan(java.util.concurrent.ForkJoinPool$WorkQueue, int, int) @bci=211, line=1843 (Interpreted frame)
 - java.util.concurrent.ForkJoinPool.runWorker(java.util.concurrent.ForkJoinPool$WorkQueue) @bci=35, line=1808 (Interpreted frame)
 - java.util.concurrent.ForkJoinWorkerThread.run() @bci=31, line=188 (Interpreted frame)
0

There are 0 answers