VirtualThreadCreation.java

import java.util.concurrent.CountDownLatch;
import java.util.concurrent.Executor;
import java.util.concurrent.Executors;

public class VThreadCreation {
    private static final int TASKS = 1024;

    public static void main(String[] args) throws InterruptedException {
        long rounds = Long.MAX_VALUE;
        if (args.length == 1) {
            rounds = Long.parseLong(args[0]);
        }
        try (var vExecutor = Executors.newVirtualThreadPerTaskExecutor()) {
            for (long i = 0; i < rounds; i++) {
                submitTasksAndWait(vExecutor, TASKS);
            }
        }
    }

    public static void submitTasksAndWait(Executor executor, int tasks) throws InterruptedException {
        var done = new CountDownLatch(tasks);
        for (int i = 0; i < tasks; i++) {
            executor.execute(done::countDown);
        }
        done.await();
    }

}

Environment:

$ java -version
java version "20.0.1" 2023-04-18
Java(TM) SE Runtime Environment (build 20.0.1+9-29)
Java HotSpot(TM) 64-Bit Server VM (build 20.0.1+9-29, mixed mode, sharing)

Running on a Ryzen [email protected] GHz and

Linux fedora.fritz.box 6.3.8-200.fc38.x86_64 #1 SMP PREEMPT_DYNAMIC Thu Jun 15 02:15:40 UTC 2023 x86_64 GNU/Linux

This is a reproducer for 2 types of issues:

1. scalability issue due to JVMTI with any attached agent
2. costy wrong_method_handle in the hot path (ie Continuation::enterVirtual)

1. JVMTI scalability issue

Run it with:

$ java --source 20 --enable-preview VThreadCreation.java &
$ pid=$!
$ timeout 30s sudo perf lock record -p $pid
[ perf record: Woken up 1 times to write data ]
[ perf record: Captured and wrote 8.014 MB perf.data (46532 samples) ]
# kill the process
$ kill -SIGTERM $pid

and report it with

$ sudo perf lock report -c -t -F acquired,contended,avg_wait
                Name   acquired  contended     avg wait 

     ForkJoinPool-1-        554        554      4.03 us 
     ForkJoinPool-1-        550        550      4.01 us 
     ForkJoinPool-1-        546        546      3.99 us 
     ForkJoinPool-1-        540        540      4.04 us 
     ForkJoinPool-1-        527        527      4.02 us 
     ForkJoinPool-1-        525        525      3.86 us 
     ForkJoinPool-1-        523        523      4.22 us 
     ForkJoinPool-1-        521        521      4.03 us 
     ForkJoinPool-1-        518        518      4.00 us 
     ForkJoinPool-1-        515        515      3.93 us 
     ForkJoinPool-1-        513        513      4.05 us 
     ForkJoinPool-1-        510        510      3.99 us 
     ForkJoinPool-1-        510        510      4.20 us 
     ForkJoinPool-1-        508        508      4.02 us 
     ForkJoinPool-1-        506        506      4.08 us 
     ForkJoinPool-1-        506        506      4.09 us 
     ForkJoinPool-1-        506        506      3.95 us 
     ForkJoinPool-1-        504        504      4.26 us 
     ForkJoinPool-1-        503        503      4.27 us 
     ForkJoinPool-1-        502        502      4.07 us 
     ForkJoinPool-1-        502        502      4.04 us 
     ForkJoinPool-1-        500        500      4.10 us 
     ForkJoinPool-1-        494        494      4.09 us 
     ForkJoinPool-1-        494        494      4.04 us 
     ForkJoinPool-1-        490        490      4.18 us 
     ForkJoinPool-1-        487        487      4.24 us 
     ForkJoinPool-1-        487        487      4.18 us 
     ForkJoinPool-1-        486        486      4.21 us 
     ForkJoinPool-1-        485        485      4.13 us 
     ForkJoinPool-1-        482        482      4.08 us 
     ForkJoinPool-1-        465        465      4.15 us 
     ForkJoinPool-1-        464        464      3.97 us 
# omitted for brevity

While if I run it with the debugging agent (or any agent attached really):

$ java --source 20 --enable-preview -agentlib:jdwp=transport=dt_socket,server=y,suspend=n,address=*:5005 VThreadCreation.java &
$ pid=$!
$ timeout 30s sudo perf lock record -p $pid
[ perf record: Woken up 4575 times to write data ]


Warning:
8 out of order events recorded.
[ perf record: Captured and wrote 10222.471 MB perf.data (60885492 samples) ]
# kill the process
$ kill -SIGTERM $pid

Which has reported a LOT more events this time:

$ sudo perf lock report -c -t -F acquired,contended,avg_wait
Warning:
8 out of order events recorded.
                Name   acquired  contended     avg wait 

     ForkJoinPool-1-     955388     955388     26.30 us 
     ForkJoinPool-1-     953578     953578     26.31 us 
     ForkJoinPool-1-     953179     953179     26.31 us 
     ForkJoinPool-1-     953174     953174     26.29 us 
     ForkJoinPool-1-     953168     953168     26.32 us 
     ForkJoinPool-1-     952933     952933     26.30 us 
     ForkJoinPool-1-     952555     952555     26.30 us 
     ForkJoinPool-1-     952345     952345     26.30 us 
     ForkJoinPool-1-     952256     952256     26.30 us 
     ForkJoinPool-1-     952046     952046     26.29 us 
     ForkJoinPool-1-     951798     951798     26.31 us 
     ForkJoinPool-1-     951680     951680     26.31 us 
     ForkJoinPool-1-     951627     951627     26.29 us 
     ForkJoinPool-1-     951540     951540     26.31 us 
     ForkJoinPool-1-     951295     951295     26.32 us 
     ForkJoinPool-1-     951267     951267     26.31 us 
     ForkJoinPool-1-     950976     950976     26.32 us 
     ForkJoinPool-1-     950669     950669     26.30 us 
     ForkJoinPool-1-     950610     950610     26.33 us 
     ForkJoinPool-1-     950531     950531     26.31 us 
     ForkJoinPool-1-     950461     950461     26.31 us 
     ForkJoinPool-1-     950261     950261     26.31 us 
     ForkJoinPool-1-     950257     950257     26.34 us 
     ForkJoinPool-1-     950034     950034     26.31 us 
     ForkJoinPool-1-     949997     949997     26.30 us 
     ForkJoinPool-1-     949907     949907     26.29 us 
     ForkJoinPool-1-     949883     949883     26.31 us 
     ForkJoinPool-1-     949418     949418     26.32 us 
     ForkJoinPool-1-     949290     949290     26.31 us 
     ForkJoinPool-1-     949288     949288     26.32 us 
     ForkJoinPool-1-     949271     949271     26.32 us 
     ForkJoinPool-1-     948603     948603     26.31 us 
# omitted for brevity

Running the same application with

-XX:+UnlockExperimentalVMOptions -XX:-DoJVMTIVirtualThreadTransitions

just fix the contention issue even with the agent attached.

2. Costy wrong_method_handle

Run it with

$ timeout 30s perf record -g -a java --source 20 --enable-preview VThreadCreation.java

and

$ perf report

would show