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

91 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
  20. Nice post. Thanks for sharing the valuable information. it’s really helpful. Who want to learn this blog most helpful. Keep sharing on updated posts…
    Devops online training
    Devops certification training
    Devops online course
    Devops training course

    ReplyDelete
  21. It is amazing and wonderful to visit your site.Thanks for sharing this information,this is useful to me...Your good knowledge and kindness in playing with all the pieces were very useful. I don’t know what I would have done if I had not encountered such a step like this.
    Selenium online training
    Selenium certification training
    Selenium online course
    Selenium training course

    ReplyDelete
  22. The most sacred place National War museum Delhi is inaugurated now in the nearby vicinity of India Gate . Here in the article we will help you out in solving our signature query how to reach National War memorial Delhi nearby India Gate . Along with that we will also sort out few other queries related to the National War memorial Delhi like nearest metro station, war memorial Delhi timing and also nearest metro stations to India Gate .

    ReplyDelete
  23. Good job! Fruitful article. I like this very much. It is very useful for my research. It shows your interest in this topic very well. I hope you will post some more information about the software. Please keep sharing!!
    SEO Training in Chennai
    SEO Training in Bangalore
    SEO Training in Coimbatore
    SEO Training in Madurai

    ReplyDelete

  24. Nuvigil smart drug is the trade name for Armodafinil smart drug and is the enantiopure compound of Modafinil. There are a number of health benefits that the use of Nuvigil smart drug has to offer to its users. So, you can buy Nuvigil online. The use of the smart drug is safe and has no health issues attached to its usage. In the year 2006, the FDA approved the use of generic Nuvigil smart drug to be used to treat a number of mental issues. Buy Nuvigil online as the use of Nuvigil smart drug has long effect when compared to other smart drugs. This is mainly because Armodafinil smart drug has a longer half-life than the other smart drugs. Therefore more and more people are depending on Nuvigil smart drug to carry on their daily routine smoothly.
    Buy Nuvigil online

    ReplyDelete
  25. Thanks for the informative article. This is one of the best resources I have found in quite some time. Nicely written and great info. I really cannot thank you enough for sharing.
    Salesforce online training
    Hadoop online training

    ReplyDelete
  26. Good Post, I am a big believer in posting comments on sites to let the blog writers know that they ve added something advantageous to the world wide web.

    Best Google cloud Online Certification

    ReplyDelete
  27. I just loved your article on the beginners guide to starting a blog.If somebody take this blog article seriously in their life, he/she can earn his living by doing blogging.thank you for thizs article. blockchain online training

    ReplyDelete
  28. I am very impressive to read this post thanks for sharing this very good information.
    Events Planner In Delhi
    Wedding Planner In Delhi

    ReplyDelete
  29. Thanks for Sharing This Article.It is very so much valuable content. I hope these Commenting lists will help to my website
    best workday studio online training

    ReplyDelete
  30. I just loved your article on the beginners guide to starting a blog.If somebody take this blog article seriously in their life, he/she can earn his living by doing blogging.thank you for thizs article. best devops online training

    ReplyDelete