Logback: Logging revisited

Partha BhattacharjeeJuly 24th, 2012Last Updated: October 22nd, 2012

0 91 5 minutes read

Hi, I am back again with my rant about logging as an inherent part of any application design and development. I am a big fan of strong basics, and in my humble opinion logging is one of those often overlooked but basic critical element of any enterprise grade application.

I have written about this before here. This is not really mandatory to read in order to make sense of the current article, but it might help to give it a cursory look, to set the context for this article.

In the first article, I introduced logging as a high benefit, low cost alternative to the omnipresent System.out.println(), that all java folks love so much. I had used log4j in that article. Log4j is a solid framework and delivers on it’s promise. In all the years that I have used it, it has never let me down. I can whole heartedly recommend it. However, having said that, there are few alternatives also, which have been around in the market for a while and I am happy to say that at least one of them seem to be challenging log4j in it’s own turf. I am talking about Logback.

It is certainly not new kid in the block – and that is one of the reasons I am suggesting you consider this for enterprise grade applications to start with. A quick look at Maven Central suggests that the first version was published way back in 2006. Between 2006 and 8-June2012 – which is when the latest version was pushed to Maven Central, there have been 46 versions. Compare this with log4j. The first version was pushed in Maven Central in 2005 and the last on 26 May 2012, and between these there have been a total of 14 different versions. I do not mean to use this data to compare these two frameworks. The only intent is to assure the reader that Logback have been around long enough and is current enough to be taken seriously.

Being around is one thing and making your mark is different. As far as ambition and intent goes, Logback makes it pretty clear that it intends to be successor of log4j – and says that in clear words at it’s homepage. Of courser there is an exhaustive list of features / benefits that Logback claims over Log4j. You can read about them at this link. That’s it really. The point of this article is that I am suggesting that while designing and developing a enterprise grade java based applications, look at logging a bit more carefully and also consider using Logback.

A few of the audience at this point, I am hoping, will like to roll up their sleeves, fire up their favorite editor and take Logback out for a spin. If you are one of them, then you and I have something in common. You might want to read on.

The very first thing that Logback promises is faster implementation (at this link). Really? I would like to check that claim.

I start by creating a vanilla java application using Maven.

File: MavenCommands.bat

call mvn archetype:create ^
 -DarchetypeGroupId=org.apache.maven.archetypes ^
 -DgroupId=org.academy ^
 -DartifactId=logger

This unfortunately is preloaded with JUnit 3. I set up JUnit 4 and also add Contiperf, so that I could run the tests multiple times – something that would come in handy if I were to check performance.

File: /logger/pom.xml

[...]
 
                      UTF-8
                      
                      4.10
                               
                      2.2.0
                      
 [...]                           
 
[...]
                          
                      junit
                                 
                      junit
                           
                      ${junit.version}
                      
                      test
                                      
                      org.databene
                               
                      contiperf
                            
                      ${contiperf.version}
                       
                      test

Also, I like to explicitly control the java version that is being used to compile and execute my code.

File: /logger/pom.xml

[...]
 
                     2.0.2
                     
                     1.7
                                                         
[...]
 
                      org.apache.maven.plugins
                                       
                      maven-compiler-plugin
                                    
                      ${maven-compiler-plugin.version}
                               
                      ${java.version}                        
   
                       ${java.version}

Last of configurations – for the time being. Slap on surefire to run unit tests.

File: /logger/pom.xml

[...]
 
                     2.12
                                                     
[...]
 
                      org.apache.maven.plugins
                                       
                      maven-surefire-plugin
                                    
                      ${maven-surefire-plugin.version}
                               
                        org.apache.maven.surefire
                                
                        surefire-junit47
                                   
                        ${maven-surefire-plugin.version}
                         
                       -XX:-UseSplitVerifier

Please note, I have taken the pains of adding all these dependencies to this article with their versions, just to ensure that should you try this yourself, you know exactly what was the software configuration of my test.

Now, let us finally add the unit tests.

File: /logger/src/test/java/org/academy/AppTest.java

public class AppTest {                                 
 private final static Logger logger = LoggerFactory 
   .getLogger(AppTest.class);                 
                                                        
 @Rule                                             
 public ContiPerfRule i = new ContiPerfRule();      
                                                        
 @Test                                             
 @PerfTest(invocations = 10, threads = 1)           
 @Required(max = 1200, average = 1000)              
 public void test() {                         
  for(int i = 0; i<10000 ; i++){          
   logger.debug("Hello {}", "world.");        
  }                                              
 }                                                  
}  

So, we have used the logger in my unit test but have not added an implementation of logger. What I intend to do is to add log4j (with slf4j) and logback (with inherent support of slf4j) one by one and run this simple test multiple times to compare performance.

To add log4j I used this setting.

File: /logger/pom.xml

org.slf4j
            
slf4j-api
      
${slf4j.version}
     
org.slf4j
            
jcl-over-slf4j
 
${slf4j.version}
     
runtime
                  
org.slf4j
            
slf4j-log4j12
  
${slf4j.version}
     
runtime

and for logback I used this setting.

File: /logger/pom.xml

ch.qos.logback
       
logback-classic
 
${logback.version}

with the following versions.

File: /logger/pom.xml

6.1
    
0.6

For either of these logger framework to actually log anything you will have to add a file telling loggers what to log and where.

File: src/main/resources/log4j.properties

# Set root logger level to DEBUG and its only appender to A1.
log4j.rootLogger=DEBUG, A1
 
# configure A1 to spit out data in console
log4j.appender.A1=org.apache.log4j.ConsoleAppender
log4j.appender.A1.layout=org.apache.log4j.PatternLayout 
log4j.appender.A1.layout.ConversionPattern=%d [%t] %-5p %c - %m%n

Finally, for the moment of truth. I ran the tests thrice with each framework i.e. logback and log4j. Essentially I log.debug() a string 1000,000 times in each test and timed them. And this is how the final figures came out.

Framework	1st run	2nd run	3rd run
Logback	0.375 seconds	0.375 seconds	0.406 seconds
Log4j	0.454 seconds	0.453 seconds	0.454 seconds

As far as this little experiment goes, Logback clearly performs faster than Log4j. Of course this is overly simplistic experiment and many valid scenarios have not been considered. For example, we have not really used vanilla log4j. We have used log4j in conjunction with the slf4j API, which is not quite the same thing. Also, being faster is not the only consideration. Log4j works asynchronously (read here and here) whereas as far as I know Logback does not. Logback has quite a few nifty features that Log4j does not.

So, in isolation this little code does not really prove anything. If at all, it brings me back to the first point that I made – Logback is a serious potential and worth a good look if you are designing / coding an enterprise grade java based application.

That is all for this article. Happy coding.

Want to read on? May I suggest …

The first article of this series. 10 tips for application logging. How to exclude commons logging easily

A nice tip on boosting performance of NOT logging.

Reference: Logging revisited from our JCG partner Partho at the Tech for Enterprise blog.

Do you want to know how to develop your skillset to become a Java Rockstar?

Subscribe to our newsletter to start Rocking right now!

To get you started we give you our best selling eBooks for FREE!

1. JPA Mini Book

2. JVM Troubleshooting Guide

3. JUnit Tutorial for Unit Testing

4. Java Annotations Tutorial