JMH Benchmark for different synchronous Java Logger implementations.

Idea of this benchmark is to put all loggers in the same conditions and measure how they all handle the most common scenarios. Compare their implementation in such scenarios, some loggers have more flexible configurations, different APIs, some have more features, different implementations.

At the end it's your choice, do you want flexibility some loggers provide and what are trade-offs of each implementation.

Benchmark features these loggers:

• io.goodforgod:slf4j-simple-logger:0.13.0
• org.slf4j:slf4j-simple:1.7.36
• ch.qos.logback:logback-classic:1.2.11
• org.apache.logging.log4j:log4j-core:2.17.2
• System.Logger (Java 17)

Benchmark consists of different common logging scenarios developers typically use in their applications, by the name of the test you can understand what this situation try to emulate, here is full list of tests:

• messageAndStacktrace
• messageWithoutArguments
• messageOneArgumentInTheEnd
• messageOneArgumentInTheMiddle
• messageOneArgumentInTheStart
• messageTwoArgumentInTheEnd
• messageTwoArgumentInTheMiddle
• messageTwoArgumentInTheStart
• messageThreeArgumentInTheEnd
• messageThreeArgumentInTheMiddle
• messageThreeArgumentInTheStart

Here are corresponding examples of resulted log messages (excluding messageAndStacktrace due to big stacktrace):

2022-03-22T15:33:48.723 [INFO] io.goodforgod.benchmark.LoggerBenchmark - Message is printed for this logger without arguments
2022-03-22T15:33:48.723 [INFO] io.goodforgod.benchmark.LoggerBenchmark - Message is printed for this logger and with the argument: FirstArgument
2022-03-22T15:33:48.723 [INFO] io.goodforgod.benchmark.LoggerBenchmark - Message is printed for FirstArgument argument for this logger
2022-03-22T15:33:48.723 [INFO] io.goodforgod.benchmark.LoggerBenchmark - FirstArgument argument and message is printed for this logger
2022-03-22T15:33:48.723 [INFO] io.goodforgod.benchmark.LoggerBenchmark - Message is printed for this logger and with arguments FirstArgument and SecondArgument
2022-03-22T15:33:48.723 [INFO] io.goodforgod.benchmark.LoggerBenchmark - Message is printed for FirstArgument and SecondArgument argument for this logger
2022-03-22T15:33:48.723 [INFO] io.goodforgod.benchmark.LoggerBenchmark - FirstArgument and SecondArgument arguments and message is printed for this logger
2022-03-22T15:33:48.723 [INFO] io.goodforgod.benchmark.LoggerBenchmark - Message is printed for this logger and with arguments FirstArgument and SecondArgument and ThirdArgument
2022-03-22T15:33:48.723 [INFO] io.goodforgod.benchmark.LoggerBenchmark - Message is printed for FirstArgument and SecondArgument and ThirdArgument argument for this logger
2022-03-22T15:33:48.723 [INFO] io.goodforgod.benchmark.LoggerBenchmark - FirstArgument and SecondArgument and ThirdArgument argument and message is printed for this logger

If you want to look at benchmark details, you can check it here.

All loggers participants are configured to the same layout, so the all participants will be in equal conditions.

Pseudo layout for all loggers:

{date} [{level}] {logger} - {message}{separator}{throwable with stacktrace}

Description of layout:

• date - uses formatter yyyy-MM-dd'T'HH:mm:ss.SSS
• level - logging level
• logger - logger full class name
• message - logging message
• separator - new line to separate logging messages
• stacktrace - exception stacktrace

All loggers use synchronous output, without any async appending mechanism.

All loggers are configured to output to STDERR.

Benchmark emulates real world usage of loggers, same way logger will be used in real running application. To achieve this, benchmark uses real IO output for loggers, but to mitigate IO of the specific machine and console output, all loggers output is redirected to /dev/null. This is done to benchmark how loggers are working in real environment including IO interactions and avoid benchmarking how machine prints data to STDOUT where benchmark is running at.

Loggers have different implementations and such huge performance gaps (as seen by results) occur mostly due to some loggers accessing IO more frequently than others. So measuring IO interactions is indented and critical to receive real world insights.

JMH precaution:

REMEMBER: The numbers below are just data. To gain reusable insights, you need to follow up on
why the numbers are the way they are. Use profilers (see -prof, -lprof), design factorial
experiments, perform baseline and negative tests that provide experimental control, make sure
the benchmarking environment is safe on JVM/OS/HW level, ask for reviews from the domain experts.
Do not assume the numbers tell you what you want them to tell.

This benchmark results are based on run inside GitHub CI and have forwarded stderr to /dev/null.

Benchmark setup configuration:

• OS: Ubuntu (Github CI)
• Processor: Unknown
• Java: JDK 17.0.2, OpenJDK 64-Bit Server VM, 17.0.2 8-LTS
• Execution: java -jar benchmark-name.jar 2>/dev/null

You can validate results yourself.

If we take goodforgod-simple-logger as baseline and compute other loggers performance based on numbers above:

If we shrink results even more and compute average for all messages with arguments as single result then:

This benchmark have forwarded stderr to NUL (/dev/null analog in windows)

Benchmark setup configuration:

• OS: Windows 10
• Processor: AMD Ryzen 2600X
• Java: OpenJDK 64-Bit Server VM (build 17 35-2724, mixed mode, sharing)
• Execution: java -jar benchmark-name.jar 2>NUL

If we take goodforgod-simple-logger as baseline and compute other loggers performance based on numbers above:

If we shrink results even more and compute average for all messages with arguments as single result then:

This benchmark have forwarded stderr to NUL (/dev/null analog in windows)

Benchmark setup configuration:

• OS: Windows 10
• Processor: Intel i5-6200U
• Java: OpenJDK 64-Bit Server VM (build 17.0.1 12-39, mixed mode, sharing)
• Execution: java -jar benchmark-name.jar 2>NUL

If we take goodforgod-simple-logger as baseline and compute other loggers performance based on numbers above:

If we shrink results even more and compute average for all messages with arguments as single result then:

In case you want to try benchmark yourself, then you should compile and package all benchmarks first:

./gradlew shadowJar

Then you can run each of them in their proper directory, for example to run goodforgod-simple-logger benchmark:

java -jar goodforgod-simple-logger/build/libs/*all.jar

If you want to suppress logger output to measure raw performance, you should redirect STRERR that logger produce to /dev/null.

java -jar goodforgod-simple-logger/build/libs/*all.jar 2>/dev/null

You can configure the number of warmup and iterations with command line arguments, the first argument corresponds to warmups and second is for iterations:

Example below will run 1 warmup and 2 iteration:

java -jar goodforgod-simple-logger/build/libs/*all.jar 1 2