Stop using named (with counter) VT names due to https://bugs.openjdk.org/browse/JDK-8372410

[franz1981]

• Fixes RunOnVirtualThread has some unexpected cost due to the default VT builder #51201

[ozangunalp]

If we remove the counter we should remove the trailing dash in VirtualThreadsConfig#namePrefix default value. So the default thread name would be quarkus-virtual-thread.

Or we can remove the name call completely and let VTs have default thread names, until the JDK bug is resolved.

[franz1981]

@ozangunalp
I still see a value into having VT named to be recognized as "quarkus" ones.
that help troubleshooting deadlocks or other problems with jstack.

[ozangunalp]

I agree let's remove the trailing dash from VirtualThreadsConfig#namePrefix default value.

[franz1981]

I saw few failing tests before, let's see if I forgot anything.
@ozangunalp should I change the config doc to explain that's not using any counter anymore?
In theory people have the threadId for that

[gsmet]

What does it bring exactly? It makes so much of a difference that we can’t wait for the JDK fix?

[ozangunalp]

What does it bring exactly? It makes so much of a difference that we can’t wait for the JDK fix?

That's a good point. Setting the config VirtualThreadsConfig#namePrefix null should also have the same effect, as it won't name the VTs.

Edit:

Like this : https://quarkus.io/guides/virtual-threads#virtual-thread-names

[gastaldi]

Don't forget to also change the guide here:

quarkus/docs/src/main/asciidoc/virtual-threads.adoc

Line 437 in fe54e86

Quarkus managed virtual threads are named and prefixed with `quarkus-virtual-thread-`.

[franz1981]

What does it bring exactly? It makes so much of a difference that we can’t wait for the JDK fix?

Let me show you...

package red.hat.puzzles.loom;

import org.openjdk.jmh.annotations.*;

import java.util.concurrent.ThreadFactory;
import java.util.concurrent.TimeUnit;
import java.util.concurrent.atomic.AtomicLong;

@BenchmarkMode(Mode.AverageTime)
@OutputTimeUnit(TimeUnit.NANOSECONDS)
@Measurement(iterations = 10, time = 400, timeUnit = TimeUnit.MILLISECONDS)
@Warmup(iterations = 10, time = 1, timeUnit = TimeUnit.SECONDS)
@State(Scope.Thread)
@Fork(2)
public class VirtualThreadThreadCreate {

    ThreadFactory namingFactory;
    ThreadFactory delegatingFactory;
    ThreadFactory prefixOnlyFactory;

    private String prefix;

    @Setup
    public void init() {
        prefix = "quarkus-virtual-thread-";
        namingFactory = Thread.ofVirtual().name(prefix, 0).factory();
        var vtFactory = Thread.ofVirtual().factory();
        final AtomicLong counter = new AtomicLong();
        delegatingFactory = r -> {
            Thread t = vtFactory.newThread(r);
            t.setName(prefix + counter.getAndIncrement());
            return t;
        };
        prefixOnlyFactory = Thread.ofVirtual().name(prefix).factory();
    }

    @Benchmark
    public Thread createWithNamingFactory() {
        return namingFactory.newThread(() -> {
        });
    }

    @Benchmark
    public Thread createWithDelegatingFactory() {
        return delegatingFactory.newThread(() -> {
        });
    }

    @Benchmark
    public Thread createWithPrefixOnlyFactory() {
        return prefixOnlyFactory.newThread(() -> {
        });
    }
}

we got:

Benchmark                                                                 Mode  Cnt      Score     Error   Units
VirtualThreadThreadCreate.createWithDelegatingFactory                     avgt   20     29.179 ±   0.964   ns/op
VirtualThreadThreadCreate.createWithDelegatingFactory:gc.alloc.rate.norm  avgt   20    344.001 ±   0.001    B/op
VirtualThreadThreadCreate.createWithNamingFactory                         avgt   20     37.591 ±   0.411   ns/op
VirtualThreadThreadCreate.createWithNamingFactory:gc.alloc.rate.norm      avgt   20    432.001 ±   0.001    B/op
VirtualThreadThreadCreate.createWithPrefixOnlyFactory                     avgt   20     13.301 ±   0.203   ns/op
VirtualThreadThreadCreate.createWithPrefixOnlyFactory:gc.alloc.rate.norm  avgt   20    272.000 ±   0.001    B/op

which shows that the version without counter is not only faster but cheaper in term of allocations.
The other point is: "it really help users having another id if you already can read the thread-id which is unique as well?"
Having the name which state that such VT are quarkus related, is good, but providing another counter, not really, IMHO

[github-actions]

😭 Deploy PR Preview failed.

[Sanne]

@franz1981 I'm afraid there are several tests that will need to be adapted

[franz1981]

@Sanne

Thanks, looking into it

[franz1981]

@Sanne @ozangunalp

While waiting the status of the tests, I see these options here:

1. dropping the name-prefix config as a whole, and just replace it with name: Thread(s) can already be identified by their Thread::getId, on logging, whilst the name allow users to distinguish which one are related Quarkus and which not.
2. leave it as it is, with a workaround: see Stop using named (with counter) VT names due to https://bugs.openjdk.org/browse/JDK-8372410 #51223 (comment) createWithDelegatingFactory; low risk (no test changes), the performance impact is mitigated, although it's still allocating and costing more than the option 1.

I have to be honest that although I'm usually all in for low risk changes, Loom adoption is still at early stages, and I prefer to not maintaining features which imply a cost on our side and no improvement for the life of users.

[Sanne]

I like option 1

[ozangunalp]

+1. Let's go with option 1.

[wjglerum]

I actually liked the fact that virtual threads have a name with a unique number too. And I would showcase that with some demos in my presentations too 😄 This is quite useful when you are inspecting what is happening and to check where you code is executed.

Just build this branch locally and with this change everything that runs on a virtual threads shows as quarkus-virtual-thread for both normal logs and access logs. And I'm not able to identify if it's the same virtual thread or a different one. This is especially useful if you do work in parallel and want to see what happens. Also later if you use structured concurrency.

[franz1981]

And I'm not able to identify if it's the same virtual thread or a different one. 

This looks more a problem of logging instead, which shouldn't rely on thread names but on thread ids

FYI
https://github.com/openjdk/loom/blob/c2d6b72d0997615894ecca1ad8489027a7e61138/src/java.base/share/classes/java/lang/VirtualThread.java#L1376-L1380

Thread.toString is making use of both informations because the name alone, being just a String, is not expected/enforced to identify uniquely them, whilst the thread id has been implemented to do so

@ozangunalp any idea where it happens?

[wjglerum]

And I'm not able to identify if it's the same virtual thread or a different one.

This looks more a problem of logging instead, which shouldn't rely on thread names but on thread ids

FYI https://github.com/openjdk/loom/blob/c2d6b72d0997615894ecca1ad8489027a7e61138/src/java.base/share/classes/java/lang/VirtualThread.java#L1376-L1380

Thread.toString is making use of both informations because the name alone, being just a String, is not expected/enforced to identify uniquely them, whilst the thread id has been implemented to do so

@ozangunalp any idea where it happens?

If we somehow can make the logging output the thread id that would be good I think to be able to correctly identify them.

[ozangunalp]

The issue is most users already use the thread name in their logs to identify threads.

I think we accept that downside, and can add to the documentation that VTs can still be identified via thread ids.

[Sanne]

Just build this branch locally and with this change everything that runs on a virtual threads shows as quarkus-virtual-thread for both normal logs and access logs. And I'm not able to identify if it's the same virtual thread or a different one.

Thanks @wjglerum ! I think this is really important feedback - I naively assumed from @franz1981 's comments above about using threadId that loggers would already do it , my bad.

I agree this would be a substantial set back if existing log formats wouldn't be able to distinguish two different threads - in this case my preference changes, I don't think we can break that - error diagnostics needs to remain useable.

I see two options:

• adapt our logging system as part of this PR (and possibly logging formats), & document the need to adapt custom formats
• switch to the other alternative, at least for now

[franz1981]

Due to the better and correct usage of thread Ids I would vote for

adapt our logging system as part of this PR (and possibly logging formats), & document the need to adapt custom formats

No idea where loggings happen - any pointer?

[franz1981]

@ozangunalp @geoand waiting the CI, this was my leftover PR ^^

[franz1981]

PTAL @ozangunalp @geoand

Finalizing artifact upload
Error: Failed to FinalizeArtifact: Received non-retryable error: Failed request: (403) Forbidden: Error from intermediary with HTTP status code 403 "Forbidden"

the last error I see :"( but doesn't seem related my changes here no?

[quarkus-bot]

Status for workflow Quarkus Documentation CI

This is the status report for running Quarkus Documentation CI on commit a0df980.

✅ The latest workflow run for the pull request has completed successfully.

It should be safe to merge provided you have a look at the other checks in the summary.

Warning

There are other workflow runs running, you probably need to wait for their status before merging.

[quarkus-bot]

Status for workflow Quarkus CI

This is the status report for running Quarkus CI on commit a0df980.

✅ The latest workflow run for the pull request has completed successfully.

It should be safe to merge provided you have a look at the other checks in the summary.

You can consult the Develocity build scans.

[cescoffier]

Can you squash your commits?

[gastaldi]

Maybe explain what happens if it's an empty value?

[franz1981]

In theory it is the same for other properties; empty is considered as absent...but if it helps users I can do it for sure 🙏

[Sanne]

Do we really need yet-another-property? What's the value of allowing to configure this?

[franz1981]

It's not a new property; it's what some users asked for because they feel can improve their debugging sessions.
I have clarified at #51223 (comment) what means

[Sanne]

It's not a new property

hum ok then...