Benchmarking Java Logging Frameworks

 

Java Logging Frameworks Blog Header

Button_ShareOnTwitter

One of the most common arguments against logging is its impact on your application’s performance. There’s no doubt logging can cost you some speed; the question is how much. When you’re armed with some real numbers, it’s much easier to find the right amount to log. In this article, we’ll compare the performance and reliability of four popular Java logging frameworks.

The Contenders

For this test, we investigated four of the most commonly used Java logging frameworks:

  1. Log4j 1.2.17
  2. Log4j 2.3
  3. Logback 1.1.3 using SLF4J 1.7.7
  4. JUL (java.util.logging)

We tested each framework using three types of appenders: file, syslog, and socket. For syslog and socket appenders, we sent log data to a local server over both TCP and UDP. We also tested asynchronous logging using each framework’s respective AsyncAppender. Note that this test doesn’t include asynchronous loggers, which promise even faster logging for Log4j 2.3.

Setup and Configuration

Our goal was to measure the amount of time needed to log a number of events. Our application logged 100,000 DEBUG events (INFO events for JUL) over 10 iterations (we actually did 11 iterations, but the first was discarded due to large startup times to warm the JIT). To simulate a workload, we generated prime numbers in the background. We repeated this test three times and averaged the results. This stress test also drives the logging frameworks harder than they would in a typical workload because we wanted to push them to their limit. For example, in a typical workload, you won’t see as many dropped events, because events will be more spread out over time, allowing the system to catch up.

We performed all testing on an Intel Core i7-4500U CPU with 8 GB of RAM and Java SE 7.

In the interest of fairness, we chose to keep each framework as close to its default configuration as possible. You might experience a boost in performance or reliability by tweaking your framework to suit your application.

Appender Configuration

We configured our file appenders to append entries to a single file using a PatternLayout of %d{HH:mm:ss.SSS} %-5level - %msg%n. Our socket appenders sent log data to a local socket server, which then wrote the entries to a file (see this link for an example using Log4j 1.2.17). Our syslog appenders sent log data to a local rsyslog server, which then forwarded the entries to Loggly.

The AsyncAppender was used with the default configuration, which has a buffer size of 128 events (256 events for Logback) and does not block when the buffer is full.

Test Results

File Appender

Logback came ahead in synchronous file logging, performing 9% faster than Log4j 2.3 and 11% faster than Log4j 1.2.17. All three frameworks significantly outperformed JUL, which took over four times as long as Logback.

Using asynchronous appenders, run times decreased noticeably. Logback once again showed the highest performance but dropped most of its log events in order to do so—76%! None of the other frameworks dropped any events running synchronously or asynchronously. This is due to the behavior of Logback’s AsyncAppender, which drops events below WARNING level if the queue becomes 80% full. Log4j 1.2.17 saw improved run times while managing to successfully record each event. Log4j 2.3 saw an increase in performance over the synchronous appender, but came third after Log4j 1.2.17.

01 Test Results for File Logging

Framework Time (ms) Drop Rate
Synchronous Log4j 1.2.17 501 0%
Log4j 2.3 490 0%
Logback 1.1.3 447 0%
JUL 1824 0%
Asynchronous Log4j 1.2.17 342 0%
Log4j 2.3 363 0%
Logback 1.1.3 215 76%

Syslog Appender

UDP

Using UDP, each framework experienced a similar rate of dropped messages due to packet loss. While Log4j 1.2.17 was the fastest, it also experienced the highest drop rate. Compared with Log4j 1.2.17, Log4j 2.3 saw a 1% improvement in dropped messages with a 9% drop in performance. SLF4J provided a somewhat more reliable experience for a substantial drop in performance.

Using an asynchronous appender resulted in a much shorter run time but also a much higher drop in reliability. The most striking difference came for Logback, which ran nearly 10 times faster but had eight times the number of dropped events.

02 Syslog Appender All Frameworks UDP

TCP

As expected, TCP with Log4j 2.3 proved to be a much more reliable transmission method. We saw a small number of dropped messages, but it was negligible when compared with UDP. The cost of this higher reliability is a run time that’s nearly twice as long.

With an asynchronous appender, we saw a decent boost in performance with no drop in throughput.

03 Syslog Appender Log4j

Framework Time (ms)—UDP Drop Rate—UDP Time (ms)—TCP Drop Rate—TCP
Synchronous Log4j 1.2.17 908 16%
Log4j 2.3 991 15% 1950 < 1%
Logback 1.1.3 3446 12%
Asynchronous Log4j 1.2.17 701 89%
Log4j 2.3 913 86% 1153 < 1%
Logback 1.1.3 353 97%

Socket Appender

UDP

Log4j 2.3’s socket appender was the slowest combination we tested. It was also one of the most error prone, dropping 44% of the events sent to it.

Using an asynchronous appender provided an almost 30% improvement in performance but with a 6% decrease in reliability.

04 Socket Appender Log4j

TCP

Log4j 1.2.17 showed a nearly 3-second improvement over Log4j 2.3 when using TCP. However, the star of the show is Logback, which managed to perform in less than one-fifth the time of Log4j 2.3.

When the application is logging asynchronously, Log4j 2.3 showed a marked improvement. Log4j 1.2.17 maintained its run time, but showed a small increase in the number of dropped events. Logback maintained its performance lead, but in doing so dropped over 90% of events.

05 Socket Appender All Frameworks TCP

Framework Time (ms)—UDP Drop Rate—UDP Time (ms)—TCP Drop Rate—TCP
Synchronous Log4j 1.2.17 1681 0%
Log4j 2.3 4810 44% 4306 0%
Logback 1.1.3 774 0%
Asynchronous Log4j 1.2.17 1687 < 1%
Log4j 2.3 3410 50% 2480 0%
Logback 1.1.3 243 93%

Conclusion

The combination that we found to offer the best performance and reliability is Log4j 1.2.17’s FileAppender using an AsyncAppender. This setup consistently completed in the fastest time with no dropped events. For raw performance, the clear winner was Logback’s FileAppender using an AsyncAppender.

There’s often a trade-off between fast and reliable logging. Logback in particular maximized performance by dropping a larger number of events, especially when we used an asynchronous appender. Log4j 1.2.17 and 2.3 tended to be more conservative but couldn’t provide nearly the same performance gains.

Button_ShareOnTwitter


Other Resources:

Button_ShareOnTwitter


10 comments

  • S

    4 months ago

    Without asynchronous loggers, you haven’t test Log4j 2.x, since that was the most important improvement. If you wanted to say that you prefer Logback over Log4j you can just say so, you do not need fake numbers.

    • Linda Somme

      3 months ago

      Here’s an update from Andre:
      The goal of the benchmark was to remove any bias by running each logger through essentially the same tests. I do make it clear in the post that asynchronous loggers can improve performance, I just don’t have concrete numbers on how significant the improvement is.

  • Vic

    5 months ago

    Hello,
    Is it possible to publish the performance tests as well?

    Cheers

    • Linda Somme

      3 months ago

      Vic,
      Unfortunately we can’t publish them at this time. But good suggestion!

  • Nitin Singh

    10 months ago

    How did you measure drop rate in different scenarios ?

    • Linda Somme

      3 months ago

      A response from Andre:
      Each log event was sent to an endpoint which then stored the event to a file. In the case of syslog and file appenders, I was able to read from an output file directly. For TCP, UDP, and HTTP appenders, I sent logs to a lightweight client that then forwarded each event to a file (there’s an example here that’s referenced in the post). I then counted the total number of entries related to that test (each event had a unique identifier) and compared it to the expected number.

  • Ralph Goers

    1 year ago

    Andre,

    Can you provide the details of how you performed these tests or provide the source for the test suite? For example, what layout were you using in your Appender tests? Log4j has had some optimizations in the PatternLayout in the 2.4 release so it would be good to know if those are applicable. I don’t believe Logback allows a Layout on the SocketAppender while Log4j does, but Logback does not include the caller information by default while Log4j might be, so it would be good to know if the equivalent functionality was being tested.

    • Linda Somme

      1 year ago

      Hi Ralph,
      Here are some additional details.

      The test uses a function that loops through a Logger call 100,000 times. This function is called 11 times, although the first run is strictly to let the JVM to warm up. While the test is running, I used a separate thread to repeatedly generate prime numbers to simulate load. I ran the test three times and averaged the results to get the final score.

      For layouts, I tried to stick as close to the defaults as possible. For PatternLayouts, I used %d{HH:mm:ss.SSS} %-5level – %msg%n. Log4j 2 2.4 does make substantial improvements to PatternLayout performance for general logging and for logging timestamps, so it would be worth testing those to see how it impacts your logging performance (see LOG4J2-930 and LOG4J2-1097)

      Log4j 2 does allow Layouts in SocketAppenders, but I used the default SerializedLayout. Logback’s SocketAppender does exclude caller information while Log4j doesn’t, but again this is due to staying close to the default config for each framework

  • Supsup

    1 year ago

    Please include “lower is better” or “higher is better” in graphics like this.

Share Your Thoughts

Top