Replace synchronized blocks with locks for performance in virtual threads

[kelemen]

Log4j uses might be using synchronized blocks on certain hot paths, e.g., RollingFileManager. This might cause performance degradation when such code runs in a virtual thread, since synchronized blocks pin the carrier thread and undermine the whole non-blocking nature promised by virtual threads. To avoid this one can replace synchronized blocks with atomic components, locks, etc.

This ticket aims to find such synchronized usages and replace them with more virtual-thread-friendly constructs.

[vy]

This – replacing synchronized blocks with locks to comply with virtual threads proposed by JEP 425, in particular, at hot spots – is indeed a known limitation that is still yet to be worked out. There is also LOG4J2-3622 dealing with the disableThreadLocals kill-switch issue.

[kelemen]

There is no such "kill-switch" anymore (in 21). So, I guess that is one problem solved :)

[vy]

@kelemen, thanks for tip! I have updated LOG4J2-3622 with the information you shared, and closed it. It is good to keep this ticket around for the synchronized-to-lock effort. I have updated the description of this ticket accordingly too.

[jvz]

I've updated most of the usages (at least in API and Core). There's a little bit left to do to migrate the rest, but this is largely complete.

[agentgt]

Hey guys I have been working on my own SLF4J adapter that is for Java 21. I was benchmarking against log4j2 and logback noticed when I load up like 10,000 vthreads log4j2 crushes in these scenarios (about half the time) and appears because it pins the threads and thus a single writer scenario happens (which is fast).

I made sure this was the case as I disabled ThreadLocals and set garbage collection to epsilon etc (e.g. no gc).

However the benchmark is flawed because:

• I'm only testing System.out piped to a file
• The only IO that is happening is obviously logging

The code seems to be in OutputStreamManager which I'm sure @jvz is aware of:

        synchronized (this) {
          ByteBufferDestinationHelper.writeToUnsynchronized(data, this);
        }

As soon as I did similar my library performed similar to log4j2.

I'm just letting you know because there maybe some that actually want the above behavior (e.g. pinning the thread)!

I'm trying to decide how to construct a more realistic test of virtual threads hitting other IO like a database and then logging to how bad synchronized is for log4j2.

[jvz]

Yeah, you can see that updated in 9d102de#diff-734786443edbd8c3b84ca999ecbf69a160ce730ac68eaedbf5f593955242142b where synchronized is replaced with use of the ReentrantLock from its parent class in 9d102de#diff-a0c89b2147b519600e9faf94a28d0a9a9817b59ea98bb0b940b6d03191446d4a

Pinning a thread for log output is one of the exact use cases for using asynchronous loggers so that appenders get pinned to that async thread.