Uploaded image for project: 'JDK'
  1. JDK
  2. JDK-8329140

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

    XMLWordPrintable

Details

    • x86_64
    • windows_10

    Description

      ADDITIONAL SYSTEM INFORMATION :
      Windows 11
      java -version
      openjdk version "21.0.2" 2024-01-16
      OpenJDK Runtime Environment (build 21.0.2+13-58)
      OpenJDK 64-Bit Server VM (build 21.0.2+13-58, mixed mode, sharing)

      A DESCRIPTION OF THE PROBLEM :
      Also posted at https://stackoverflow.com/questions/77779953/spring-boot-virtual-threads-djdk-tracepinnedthreads-full-causes-tasks-to-hang

      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);
              }
          }
      }

      Run with mvn clean test -Dtest=VirtualSpringApplicationTests -Djdk.tracePinnedThreads=full and it fails

      STEPS TO FOLLOW TO REPRODUCE THE PROBLEM :
      mvn clean test -Dtest=VirtualSpringApplicationTests -Djdk.tracePinnedThreads=full

      EXPECTED VERSUS ACTUAL BEHAVIOR :
      EXPECTED -
      expect same result as when you run it successfully with
      mvn clean test -Dtest=VirtualSpringApplicationTests
      ACTUAL -
      Hangs jhsdb jstack relevant parts shown below
      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)

      ---------- BEGIN SOURCE ----------
      includes in description
      ---------- END SOURCE ----------

      FREQUENCY : always


      Attachments

        Issue Links

          Activity

            People

              sspitsyn Serguei Spitsyn
              webbuggrp Webbug Group
              Votes:
              0 Vote for this issue
              Watchers:
              6 Start watching this issue

              Dates

                Created:
                Updated:
                Resolved: