The Logging Olympics – A Race Between Today’s Top 5 Java Logging Frameworks

By Tal Weiss —  December 18, 2013 — 7 Comments

Developers: Takipi tells you when new code breaks in production –  Learn more

blog running

Log4J vs SLF4J simple vs Logback vs Java Util Logging vs LOG4J2

Logging is an age-old and intrinsic part of virtually every server-side application. It’s the primary method by which applications output live state in a persistent and readable manner. Some applications may only log a few megabytes a day, while others may log gigabytes of data or more in a matter of hours.

As logging usually involves IO to write data to disk (either blocking or async) – it comes at a cost. When logging large amounts of data over short periods of time, that cost can ramp up quickly. We decided to take a deeper look at the speed of some of today’s leading logging engines.

 Most developers log data for three main reasons -

1. Monitoring – to see how code behaves in terms of throughput, scale, security, etc..

2. Debugging – to get access to the state that caused code to fail (variables, stack traces…). Takipi helps developers debug staging and production servers, and understand why code crashes and threads freeze.

3. Analytics – leverage live data from the app in order to derive conclusions about the way it’s being used.

Behind the facade. Most libraries today have logging built-in at key points in the code to provide visibility into their operations. To streamline this process and prevent different libraries from employing multiple logging methods in the same JVM, logging facades, which decouple code from the underlying engine, have come into the forefront. When we analyzed the top 100 software libraries for Java, SLF4J came up as the leading logging facade used by developers today.

The Competition

We decided to pick five of today’s most prominent logging engines, and see how they perform in a number of races. Now, before you take out the torches and pitchforks, I wanted to clarify that the point is not to say which is better, but to give a sense of the differences in throughput between the engines across a number of common logging tasks.

The Contestants

1. Log4J

2. Log4J2

3. Logback

4. SLF4J Simple Logging (SLF4J SL)

5. Java Util Logging (JUL)

The Race

We wanted to see how the engines compare across a set of standard logging activities. Each logging operation includes a timestamp and a thread ID as its context.

These are the races:

1. Logging a string constant

2. Logging the .toString() value of a POJO

3. Logging a throwable object

4. Logging a string constant without time/tid context

 

The Track

We decided to hold five heats for each race to determine the best score, measuring the number of logging operations completed. In each test we gave the logging engines a task to perform across 10 threads in the space of a minute (the tests ran separately). We then took out the 2 heats with biggest deviation and averaged the results of the remaining three.

Between each individual logging operation we gave the CPU some work to do to put some space between the logging operations (checking whether a small random number is prime). The engines are all running behind SLF4J using their default configuration. The benchmarks were run on an Amazon m1.large EC2 instance.

Update: during our initial test Log4J2 was configured with a %C qualified class layout which increased its overhead. At the advice of @RemkoPopma we updated the configuration to %c (logger name) to conform with the other configuration, which gave Log4J2 a considerable performance boost, as you’ll see below. It’s definitely something worth paying attention to, and really highlights the cost of logging context data.

 

The Results

Pre conf change (%C):

Log olympics results

Post conf Change (%c):

blog_running5

To see the full dataset – Click here.

Race #1 – String constants

In this race the engines are logging a string constant along with thread and timestamp context. Log4J comes out the clear winner here, being able to write almost 270% more lines than JUL, 12.5% more than logback, 52% more than SLF4J SL. It was interesting to note that before we changed Log4J2′s configuration it was able to write 4X(!) less lines, with the switch boosting it up #3 with only 30% less lines written than logback.

Race #2 - .toString()

In this race the engines are logging a POJO (via its .toString) along with thread and timestamp context. The results here were much closer with Log4J2 coming in at #1 with a 25% advantage (post change) over SLF4J SL coming in at #2. Log4J and Logback are neck and neck for the #3 spot with JUL taking silver with 88% throughput of SLF4J SL.

Race #3 – Throwable

In this race the engines are logging an exception object and a description string along with thread and timestamp context. It’s in this race the Log4J2 is on fire, coming in at #1 logging more than 3X (!) times the rows when compared SLF4J SL at #5.

Log4J and Logback are also left in the dust, logging less than half the lines of our esteemed winner. JUL comes in at a solid #2, logging 82% of the lines compared to our winner – not too bad.

Race #4 (running barefoot) – .toString() minus context

When dealing with server logs, each entry’s context (e.g. thread ID, class context, time-stamp, etc…) is almost as important as the content of the entry itself. For the previous races we used two of the most common context elements you’ll find in most server log entries – thread ID and timestamp. We thought it’d be interesting to analyze the overhead of those by running a .toString() race without using any of the engines’ context appenders.

Log4J2 is the winner here (post conf change, getting a 180% boost) with a clear 25% lead over by both Logback and JUL. SLF4J SL are trailing behind. It was puzzling to see that across the five different heats, SLF4J SL did better with the appenders than without (would love to hear your thoughts on it in the comments).

Log4J saw the biggest bump with a 15% increase in throughput. JUL, while not performing as well as Log4J or Log4J2 in this race, deliver almost the exact same results with and without the context data.

I’d love to hear your comments and inputs. You can also check out the code on GitHub.

log monster

How to add links to your log files with variable values at the moment an error occurred – read more

blog_boat (1)

 

 The 7 Log Management Tools Java Developers Should Know – read more

CI

CI – Know when your code slowed down after deploying a new version – read more 

Tal Weiss

Posts Twitter

Tal is the CEO of Takipi. Tal has been designing scalable, real-time Java and C++ applications for the past 15 years. He still enjoys analyzing a good bug though, and instrumenting code. In his free time Tal plays Jazz drums.
  • BelSoft

    You should probably run these benchmark on your local machine.
    There are many things that can happen on Amazon instances that could modify the results.

  • http://www.fromdev.com/ Java Developer

    Wow, interesting benchmarks. Clearly no single winner. However its annoying that mix of these libraries create a lot of pain. Specially if you have a dependency that uses one of them.

    Thanks for sharing the results.

    I would also want to know if you could run this on a single machine/laptop and see results. Amazon is all VMs so results may vary, but they are still useful since we use a lot of amazon cloud.

  • Pablo Fernandez

    Just as a sidenote, on applications that log too much (either because there are too many log calls, too many requests or both) we found that most file appenders have a explicit lock that gets *heavily* contended, sometimes becoming the application bottleneck.

    For these scenarios most logging implementations provide an AsyncAppender that uses a nonblocking data structure and discards lower level (INFO, DEBUG, TRACE) log lines when full.

  • Remko Popma

    Dear Takipi, your test is unfairly biased against Log4j2.

    Specifically, the configuration pattern layout used in the test is %C (caller class) for Log4j2 only. All other logging frameworks are tested with pattern layout %c or %logger (logger name). This means that Log4j2 (and only Log4J2) is forced to walk the stack trace to collect location information on the caller. (This is 1.3-5 times slower than not including location information, as documented several times in the Log4J2 docs.)

    Can you correct this error and re-run the tests?

    A few more requests:

    Could you do some warmup before starting the measurements? The current code in com.takipi.benchmark.logging.BM includes the initialization time in the measurement. (Logging frameworks that take more time to read config files etc when they start up are presented as less performant.) Initialization time is probably not what you want to measure. May I suggest creating a separate BaseTest instance and letting this instance run for 15+ seconds (and delete its output so it doesn’t get counted) before starting the threadpool that does the measurements?

    Could you include a test that uses Log4j2′s RandomAccessFileAppender instead of the FileAppender? RandomAccessFileAppender is many times faster than FileAppender.

    Could you mention that the test only measures synchronous logging, and does not include asynchronous logging? This is important because asynchronous logging can give much, much better performance than synchronous logging. (See the graphs here: http://logging.apache.org/log4j/2.x/manual/async.html#Performance )

    • http://www.takipi.com/ Tal Weiss

      Hi Remko,

      We’ve gone ahead and updated the post to reflect the change in configuration. Thanks for the heads up!

      Re warmup. you’re right in that a warmup period can yield better results in terms of JVM / IO readiness, but as a race between the frameworks I thought it’d be interesting to see how they go from 0 to 100mph.

      Re sync vs. async, as most developers usually log synchronously in relation to their code I thought I’d focus on that. You’re totally right that in high scale situations diverting the logging operation to a background / dedicated thread can help yield better throughput.

      If you’re interested in taking the test, modifying it and running it again, I’d be happy to link and share your results.

      Thanks for the great input.

      • Remko Popma

        Hi Tal,

        Thanks for re-running the test and updating the article so quickly. And on Christmas eve! Much appreciated!

        Re warmup, I understand that your first priority was fixing the configuration and I appreciate the quick response, but I would like to ask you to reconsider. I think many of your readers are interested in this post because it may help them choose between logging frameworks. If the startup/initialization time skews the results then the article may not be as useful to your readers because it does not reflect how logging frameworks will perform in production.

        Please don’t take this the wrong way, I realize how much work you’ve put into this already.

        If it is useful I can make the code changes for the warmup and send you a pull request.

        By the way, just curious, according to the Log4j2 docs, RandomAccessFileAppender can be about twice as fast as FIleAppender (http://logging.apache.org/log4j/2.x/manual/async.html#RandomAccessFileAppenderPerformance ). I would be really interested to see if those numbers hold out in your test as well. Wouldn’t you want to use the fastest appender when doing a performance test? I would think that RandomAccessFileAppender would be a more natural choice for this test than FileAppender…

        • Dan Eloff

          Doh, back to Google, this benchmark may not have meaningful results, it can’t be used as the basis of a decision.