High CPU usage in async mode with Log4j2

[will-zdu]

Description

When using Log4j2 in asynchronous logging mode, the CPU usage is significantly higher than expected, even under low logging throughput. This issue persists regardless of the configured

Configuration

Version: [2.24.3]

Operating system: [linux 6.8]

JDK: [jdk 11]

Logs

no

Reproduction

[An isolated test reproducing the test.
JUnit tests similar to the ones in the code base are extremely appreciated.]
-Dlog4j2.contextSelector=org.apache.logging.log4j.core.async.AsyncLoggerContextSelector
-DAsyncLogger.WaitStrategy=Sleep

add these jvm options
and run ,we will found the high cpu usage on "Log4j2-TF" thread

[will-zdu]

com.lmax.disruptor.SleepingWaitStrategy#applyWaitMethod
the default sleepTimeNs to too low，cause the hign cpu usage

[ppkarwasz]

@will-zdu,

Depending on the Disruptor waiting strategy you choose a high CPU usage on the asynchronous thread is perfectly normal. See the documentation of the log4j2.asyncLoggerWaitStrategy configuration attribute and the LMAX documentation of alternative wait strategies for details.

You can finely tune the Sleep wait strategy using the log4j2.asyncLoggerRetries and log4j2.asyncLoggerSleepTimeNs configuration properties, e.g.:

-Dlog4j2.contextSelector=org.apache.logging.log4j.core.async.AsyncLoggerContextSelector
-Dlog4j2.asyncLoggerWaitStrategy=Sleep
-Dlog4j2.asyncLoggerRetries=200
-Dlog4j2.asyncLoggerSleepTimeNs=1000

Does this solve your problem?

[will-zdu]

I know this configuration can avoid this problem, but the question is whether there is a problem with this default configuration and whether it needs to be adjusted.

[ppkarwasz]

I know this configuration can avoid this problem, but the question is whether there is a problem with this default configuration and whether it needs to be adjusted.

I don't feel competent to answer to that. However, the value we use in Log4j Core are exactly the same values used by the LMAX Disruptor library:

    private static final int DEFAULT_RETRIES = 200;
    private static final long DEFAULT_SLEEP = 100;

I wouldn't feel comfortable modifying those values without extensive benchmarks and usage statistics. Values that are perfect for your use case might match the expectations of most Log4j Core or might be the exception. It is impossible to say. You can try proposing a change in the LMAX Disruptor library directly. If they change the defaults, we will follow their recommendations.