MattHicks.com

Programming on the Edge

Showing posts with label scribe. Show all posts
Showing posts with label scribe. Show all posts

Scribe 2.0: Fastest JVM Logger in the World!

Published by Matt Hicks under , , , , , , , , , , on Tuesday, February 06, 2018
An intentionally provocative heading, but one I stand behind until someone can prove otherwise (and I welcome just that).  Scribe 1.x was pretty fast (http://www.matthicks.com/2017/01/logging-performance.html), but was not written with performance in mind.  When I came back around and realized just how fast log4j2 is, I could see no reason why a Scala logging solution shouldn't be able to run circles around it.

Note: the benchmarks below are tested using simple file logging to represent the most common production logging scenario.

Log4J Comparison

Now, for people like me that often want to skip all the blustering, explanations, and bravado, I'll cut straight to the result graph of the performance comparison between log4j 2.10.0 and Scribe 2.0.0:

Like I said, log4j2 is fast, but Scribe 2 is just shy of a 50% performance boost on that.  If we look at the over-time graph it provides additional insights:

You can see that log4j does well, but operations increase in cost partway through, while Scribe is smooth and steady for the entire run.

Method and Line Numbers

This is all compelling but practically speaking, 99% of applications won't even notice the difference between 1,500 nanoseconds and 800 nanoseconds per record logging.  Thus far I've been comparing Apples to Oranges though.  In Scribe, the method and line numbers are integrated into the log records by default.  If we add that to the logging (which any reasonable logging framework should have) we see a different story:

Shocking, right?  If you know Java, you'll probably realize why this is.  In Java, the only way to get access to method and line numbers in your logging is by walking the stack trace.  This is a very expensive operation to be doing and slows the logging to a crawl.  This is why it's not on by default, and why you don't see this talked about much in Java logging frameworks.  However, Scala Macros come to the rescue!  In Scribe, we get all of that for free.  The method and line number information are extracted at compile-time so you can see that Scribe is just as fast whether method and line number logging is enabled or not.

Typesafe Scala Logging

In 1.x my focus was the comparison with Scala Logging.  As you can see below, we're not even in the same ballpark:


It's a pretty pathetic comparison.  In Scribe, 1.x Scribe was noticeably faster, but this shows just how inefficient Scala Logging is.

All Loggers

If you'd like to see the side-by-side comparisons of all the competitors:


Though the log4jTrace and scalaLogging results dwarf the performance distinction between log4j and Scribe, if you've seen all the results here, Scribe is the clear performance winner here.  I'll make another post to show why it's also more powerful, but I'll save that for another day.

Sources

I'm not a master with log4j or Scala Logging, so it's possible I'm not giving ideal running circumstances for these loggers to "show their stuff".  The original source code is posted in the repository: https://github.com/outr/scribe/blob/master/benchmarks/src/main/scala/scribe/benchmark/LoggingSpeedBenchmark.scala

The JMH benchmark results were also saved to a JSON file if you want the raw results to make sure I'm not trying to pull a fast one: https://github.com/outr/scribe/blob/master/work/benchmark/2018.01.31.benchmarks.json

Getting Started

To learn more about Scribe and start using it, check it out here: https://github.com/outr/scribe

Please feel free to email me if you find any mistakes in anything I've said to set me straight, or you can publicly shame me by writing a comment on this post.  I welcome criticism and praise, but criticism gives me something to learn from, so it is more appreciated.

Logging Performance

Published by Matt Hicks under , , , , , , , , , , on Thursday, January 12, 2017
I've never been a fan of the setup of logging frameworks as far back as when I was a Java developer.  The hassle and complexity of configuring and managing the logging framework was always a big hassle and would often create serious problems in the application if not done right.  Even today in Scala it doesn't feel much better.  Certainly we have Macros that give some additional compile-time optimizations, but it's amazing how little has changed.

A while back I created a Scala logging framework called Scribe.  Honestly, the primary reason had more to do with giving greater flexibility to control configuration in code over performance or anything else.  However, by not building on top of log4j, logback, slf4j, or JUL, I found that the system was not only far more simplistic and configurable, but it was also faster.

I recently did a comparison between Lightbend's Scala Logging framework to see how it performs.  Without any additional optimizations the results were pretty impressive.  I configured both Scribe and Scala Logging to avoid writing to standard out as that would be the primary bottleneck of performance and simply wrote a custom Writer / Appender that would simply count the log entries:


Over sixty seconds I recorded how many records could be logged.  Scala Logging was able to log 474k records and Scribe was able to log 610k.  Now, obviously this is far more logging than any reasonable application should be doing, but the point was to prove that not only can Scribe keep up with the most popular Scala logging framework (Scala Logging) on top of the most popular Java logging framework (Logback), but it quite a bit faster.

The second thing I measured was memory consumption over the run.  Memory usage is a very important factor with regard to logging as it should have a very small footprint to give maximum allocation to the application itself.  Again, my finding were pretty strongly in favor of Scribe:

While Scala Logging utilized 704kb of memory Scribe utilized on 596kb.  Again, not a substantial difference when we're discussing hundreds of thousands of records being logged, but this is meant to prove that Scribe is the better performer.

Very often I hear that a developer won't use a framework because there aren't enough developers using it.  Obviously this creates a chicken / egg situation as you can't get developers using it because not enough developers use it.

Hopefully this short post will give some additionally credibility to the value of Scribe that people will start comparing features and see just how much it has to offer.  If there's something missing that your existing logging framework has, just create a ticket.