Tuesday, 24 October 2017

Allocation free logging with log4j2

Introduction

Recently I was working for a client trying to remove some GC pauses for a large well crafted Java system. After profiling I realised that most of the garbage was being produced by logging!! Was there a simple unobtrusive way to remove all that allocation?  Turns out there was :)

Which framework should I use for GC free logging?


Let's turn our attention back to the age old question of which logging framework to use.

The usual candidates are
  • log4j2
  • logback
  • java.util.logging
  • slf4j (simple)
and unless you are doing something super funky you might not think it makes a huge difference which one you choose.

There have been many studies done comparing performance and those of course this can be important if you are playing in the ultra low latency arena. (see Benchmarking Java logging frameworks)


But what I'm concerned about is allocation!!

See my earlier post on the evils of allocation The First Rule of Performance Optimisation.  

In a typical system 30%-50% of all allocation can be in logging!!

So even if most people don't mind if logging takes a couple of milliseconds longer in one framework than another they will almost certainly care about long GC pauses caused by the garbage created by the logging framework.

And all this logging allocation can be removed by simple configuration.

Log4J2 from 2.6 onwards is allocation free so really no excuse not to take advantage of it :) 

Let's see it in action

It's one thing making the allocation free claim but let's see if this holds true in practice.

Consider this simple logging code below: Note that I've used slf4j in the code and therefore only need change the configuration to run with the different logging frameworks.  It's a good idea to do this because although log4j2 might be the best framework at the moment who knows what tomorrow will bring...



Run with log4j2 - no allocation

If we configure the program to run with log4j2 using this maven configuration:

<dependency>
    <groupId>org.slf4j</groupId>
    <artifactId>slf4j-api</artifactId>
    <version>1.7.25</version>
</dependency>
<dependency>
    <groupId>org.apache.logging.log4j</groupId>
    <artifactId>log4j-api</artifactId>
    <version>2.9.1</version>
</dependency>
<dependency>
    <groupId>org.apache.logging.log4j</groupId>
    <artifactId>log4j-core</artifactId>
    <version>2.9.1</version>
</dependency>
<dependency>
    <groupId>org.apache.logging.log4j</groupId>
    <artifactId>log4j-slf4j-impl</artifactId>
    <version>2.9.1</version>
</dependency>

And we use this log4j2 configuration

xml version="1.0" encoding="UTF-8" ?><Configuration status="INFO">
    <Appenders>
        <Console name="Console" target="SYSTEM_OUT">
            <PatternLayout pattern="%d{HH:mm:ss:SSS} [%t] %-5level %logger[36] %msg%n"></PatternLayout>
        </Console>
        <File name="MyFile" fileName="all.log" immeadiateFlush="false" append="false">
            <PatternLayout pattern="%d{dd MMM yyyy HH:mm:ss,SSS} [%t] %-5level %logger[36] %msg%n"></PatternLayout>
        </File>
    </Appenders>
    <Loggers>
        <Root level="debug">
            
            <AppenderRef ref="MyFile"></AppenderRef>
        </Root>
    </Loggers>
</Configuration>

Then we get 0 allocation!

We can prove this by running Flight Recorder on the program (see below):

The only memory being allocated is due to Flight Recorder (by the way FR can be configured so that this doesn't happen).



Run using logback

Try exactly the same this using Logback.

Use this Maven configuration

<dependency>
    <groupId>ch.qos.logback</groupId>
    <artifactId>logback-classic</artifactId>
    <version>1.2.3</version>
</dependency>

Use this logback configuration:

<configuration>
    <appender name="FILE" class="ch.qos.logback.core.FileAppender">
        <file>myApp.log</file>
        <encoder>
            <pattern>%date %level [%thread] %logger{10} [%file:%line] %msg%n</pattern>
        </encoder>
    </appender>
    <appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">
        <encoder>
            <pattern>%msg%n</pattern>
        </encoder>
    </appender>
    <root level="debug">
        <appender-ref ref="FILE" />
        
    </root>
</configuration>

And when we run with Flight Recorder we see a hug amount allocation!


But a word of warning....

You need to use the log4j2 configuration exactly as specified in the documentation see supported layouts.  If you even change date format slightly allocation will again be rampant.

Summary

  • Use slf4j so that you can easily change your logging implementation
  • Use log4j2 to avoid allocation
  • Make sure you use the supported formats to support allocation free logging

51 comments:

  1. While working logging can cause a lot of errors. You have to be perfect so your program can be error less. Thank you for sharing. This was very helpful.

    ReplyDelete
  2. Today, we can’t simply ignore the importance of the video and movie streaming applications as we have been more dependent on our smartphones. And talking about the video streaming applications, SnapTube is by far the most famous and downloaded streaming application of the current time. So want more insight on the SnapTube app? Check out this website Download Snaptube Latest Apk

    ReplyDelete
  3. https://www.learndigital.co/ sign up to learn digital marketing.

    ReplyDelete
  4. Amazing Article ! I have bookmarked this article page as i received good information from this. All the best for the upcoming articles.

    Tekslate Online Training's

    ReplyDelete
  5. hi, this is Really a great post. Appreciate the effort in educating us. Thanks for it.
    DevOps Online Training

    ReplyDelete
  6. it is really explainable very well and i got more information from your blog.
    shareplex training
    sharepoint Training

    ReplyDelete
  7. This comment has been removed by the author.

    ReplyDelete
  8. Hey gays how are you.Please Download And enjoy the software Movavi Video Converter Activation Key

    ReplyDelete
  9. I see there are many dead trigger 2 mod apk 1.3.1 unlmiited money people who are into things hungry shark world unlimited gem that are pretty much jnc311 review not liked by others but people do visit it so much games download for android mobile touch screen

    ReplyDelete
  10. Interesting information and attractive.This blog is really rocking... Yes, the post is very interesting and I really like it.I never seen articles like this. I meant it's so knowledgeable, informative, and good looking site. I appreciate your hard work. Good job.
    Kindly visit us @
    Sathya Online Shopping
    Online AC Price | Air Conditioner Online | AC Offers Online | AC Online Shopping
    Inverter AC | Best Inverter AC | Inverter Split AC
    Buy Split AC Online | Best Split AC | Split AC Online
    LED TV Sale | Buy LED TV Online | Smart LED TV | LED TV Price
    Laptop Price | Laptops for Sale | Buy Laptop | Buy Laptop Online
    Full HD TV Price | LED HD TV Price
    Buy Ultra HD TV | Buy Ultra HD TV Online
    Buy Mobile Online | Buy Smartphone Online in India

    ReplyDelete
  11. This comment has been removed by the author.

    ReplyDelete
  12. The article is very interesting and very understood to be read, may be useful for the people. I wanted to thank you for this great read!! I definitely enjoyed every little bit of it. I have to bookmarked to check out new stuff on your post. Thanks for sharing the information keep updating, looking forward for more posts..
    Kindly visit us @
    Madurai Travels
    Best Travels in Madurai
    Cabs in Madurai
    Tours and Travels in Madurai

    ReplyDelete
  13. Excellent Blog. I really want to admire the quality of this post. I like the way of your presentation of ideas, views and valuable content. No doubt you are doing great work. I’ll be waiting for your next post. Thanks .Keep it up! Kindly visit us @ Christmas Gift Boxes | Wallet Box | Perfume Box Manufacturer
    Candle Packaging Boxes
    Luxury Leather Box
    Luxury Clothes Box
    Luxury Cosmetics Box
    Shoe Box Manufacturer
    Luxury Watch Box

    ReplyDelete
  14. An amazing web journal I visit this blog, it's unbelievably wonderful. Oddly, in this blog's content made without a doubt and reasonable. The substance of data is informative.
    Oracle Fusion Financials Online Training
    Oracle Fusion HCM Online Training
    Oracle Fusion SCM Online Training

    ReplyDelete
  15. Wow, what an awesome spot to spend hours and hours! It's beautiful and I'm also surprised that you had it all to yourselves! we are the one of the best HIV treatment hospital in India..Click here for more details Best HIV Treatment in India | Top HIV Hospital in India | HIV AIDS Treatment in Mumbai | HIV Specialist in Bangalore | HIV Positive Treatment in India | Medicine for AIDS in India

    ReplyDelete

  16. Sports big news provide is a all type sports contents. In This portal is a sports all type content, For ex. Cricket, cwc19, UEFA, football, Copa America 2019 etc.

    Cricket
    Cricket World Cup 2019
    Live Streaming
    World Cup 2019 Final
    IPL 2020 Live Streaming
    Copa America 2019 Venues
    Tennis
    Copa America 2019
    Cricket World Cup Live
    Football

    ReplyDelete
  17. hallo pecinta game android, ada game seru ini untuk kamu mainkan bersama teman-teman kamu. Yang pasti game yang berjudul dead trigger 2 ini tidak kalah serunya dari game yang lainnya. Kami telah menyediakan review tetang game ini dengan lengkap beserta link downloadnya. Kamu bisa download game dead trigger 2 ini secara gratis offline disini. Jika kamu penasaran tentang keseruan game dead trigger 2 andorid apk obb ini silahkan mampir ke blog android saya ya. Baca selengkapnya: dead trigger 2 hack apk. link: https://downloadgameofflineapkmod.blogspot.com/2019/07/dead-trigger-2-offline-version-apk-obb.html

    ReplyDelete
  18. Great Article… I love to read your articles because your writing style is too good, its is very very helpful for all of us and I never get bored while reading your article because, they are becomes a more and more interesting from the starting lines until the end.
    Blockchain online training

    ReplyDelete
  19. nice article
    Unicsol offers Best full stack developer course in hyderabadget trained by 10+years of experienced faculty and get placed as full stack developer.

    ReplyDelete