Re: Naïve Tomcat experiment--does this indicate pinning?

[Cay Horstmann]

Il 01/05/2022 19:01, Alan Bateman ha scritto:
> On 01/05/2022 17:38, Cay Horstmann wrote:
>> Hi, I am running a simple experiment with Tomcat where one can easily 
>> replace the executor for what I presume are the threads for each 
>> servlet request. I use the following executor to which I submit all 
>> tasks:
>>
>>       ThreadFactory myfactory = Thread.ofVirtual()
>>          .name("myfactory-", 1)
>>          .factory();
>>       exec = Executors.newThreadPerTaskExecutor(myfactory);
>>
>> Now I run a servlet that sleeps for 100 ms and then returns 
>> Thread.currentThread().toString().
>>
>> When I fire lots of concurrent requests at the servlet, those returned 
>> strings look like this:
>>
>> VirtualThread[#13508,myfactory-13452]/runnable at ForkJoinPool-1-worker-16
>> VirtualThread[#13515,myfactory-13459]/runnable at ForkJoinPool-1-worker-16
>> VirtualThread[#13513,myfactory-13457]/runnable at ForkJoinPool-1-worker-11
>> VirtualThread[#13512,myfactory-13456]/runnable at ForkJoinPool-1-worker-15
>>
>> I was hoping that making 10000 requests would result in 10000 tasks 
>> that would all complete after roughly 100 ms. But it takes over 2 
>> minutes to complete.
>>
>> So, now I am wondering whether it is possible that those threads 
>> acquire an object lock or do something else that pins them. After all, 
>> if not, why would they execute on different worker threads? How would 
>> one go about debugging such a scenario?
> 
> Can you run with -Djdk.tracePinnedThreads=full and see if it prints 
> anything? Or if you can get JFR recording then you can use `jfr print 
> --events jdk.VirtualThreadPinned` to see if there are of these events. 
> Another option is to get a thread dump while it is running with `jcmd 
> <pid> Thread.dump_to_file -format=json <file>`. There's more on these 
> diagnostics in the JEP.
> 
> -Alan
> 

Thanks, those were good tips. I was able to see the virtual threads in 
the thread dump, and there were no messages about pinning.

For some reason, Tomcat is taking its sweet time launching the virtual 
threads. In my executor, I added the creation time as an ExtentLocal and 
fished it out in the servlet. I also add the query time as a query 
parameter. The difference between query time and thread creation time 
increases steadily, so there must be some other throttling going on 
inside Tomcat. Annoyingly, the virtual threads are quite a bit slower 
than the org.apache.catalina.core.StandardThreadExecutor. When I launch 
1000 requests simultaneously, the last request gets serviced by a newly 
created virtual thread two minutes later! With the standard Tomcat 
thread pool, 1000 requests are handled in 4 seconds.

I remember some report from way back when where someone added virtual 
threads to Tomcat with better success. I'd love a reference to that effort.

Cheers,

Cay




-- 

Cay S. Horstmann | http://horstmann.com | mailto:cay at horstmann.com