The ultimate way to gettting Log4J loggers

Author: Kasper B. Graversen, 26/05/08
Keywords: Log4J, Logging
Abstract: The standard way to acquire Log4j loggers do not ensure consistency between logger name and class using the logger. Such inconsistency leads to inconsistencies in the log files, rendering any information in the log file difficult to use. This article shows how to ensure between logger name and class using the logger through usage of the Spiffy Framework.
subscribe to my RSS feed


Bookmark and Share


The ultimate way to gettting Log4J loggers

There is a problem with the way Log4J loggers are acquired. The following code is pretty much the standard approach and as it will be shown, unfortunately, is far from best practice. 
private static final Logger log = Logger.getLogger( name );
The name can be any string. This is the core of the problem highlighted here. When there are no rules in effect, it leaves it up to the programmer to invent all sorts of crazy solutions. And even if the programmer is trying to abide any sane approach to naming of loggers, the approach is open to unintentional mistakes.

Conceptually, the freedom of the name enables naming loggers according to some conceptual partitioning of the application, for example horizontal or vertical slices; A horizontal slicing corresponds to using a specific logger in each layer of an application (e.g. the view layer, the controller layer and the persistence layer). The vertical slicing corresponds to using specific logger names within more or less arbitrary functional partitions of the application, e.g. all layers associated with implementing the booking functionality, the financial reports etc.

I've had the dubious pleasure of working on large applications employing the vertical slicing approach. At first the approach sounds interesting, maybe even a bit exotic. Using such approach in practice on a big system, however, quickly becomes an everlasting and futile exercise in trying to predict in which log destination/log file the next piece of information is to be found. The vertical slicing suffers from the problem, that it is often not possible to fully partition an application like that. Often there is a shared core of code in the application, and over time, one partition may draw upon the services of another partition. And so started the scattering of the logging information...

The horizontal slicing is equally bad. When an error has occured and you draw upon the information in the log files to detect what went wrong, you typically try to construct what happened in terms of vertical slices, i.e. what happened on the front-end, in the controllers and in the dao's. Having to jump around in several log files is not helpful.

In summary, the only sensible thing to do is 
import org.apache.log4j.Logger;

class Foo {
    private static final Logger log = Logger.getLogger( Foo.class );
}
This approach, unfortunately, does also have its share of problems. My main objection to the strategy is that the compiler does not ensure or enforce consistency between the class definition, and the class reference used in the getLogger() call.. The naming can become out of sync when refactoring or when some mindless twat on your project copy-paste inherits some code not realizing the need to ammend the class reference (yes, this occurs in real-life scenarios!).

At the cost of only using loggers in instance methods and with an overhead on object creations, loggers can be defined as 
import org.apache.log4j.Logger;

class Foo {
    private final Logger log = Logger.getLogger( this.getClass() );
}
All our problems would disappear were we able to say something like log = Logger.getLogger( thisclass );. Unfortunately, Java does not have a thisclass construct. What a pitty... If you have any idea why this is so, please let me know so I can update this space.

Consistent logging with the Spiffy Framework

By now we've established that we really want consistency between the class and the logger instance acquired. It's unfortunate, that the Log4J does not offer this support, and its unfortunate, that Java language isn't of much help either (no thisclass-like construct). Fortunately a so called LoggerHelper class in the Spiffy Framework exist. All you need to do is 
import org.apache.log4j.Logger;
import spiffy.log4j.LoggerHelper;

class Bar {
    private static final Logger log = LoggerHelper.getLogger();
}
Notice that the logger does not mention the class Bar it is defined within. Yet the logger acquired will be for that very class! The underlying functionality is quite simple. All the LoggerHelper does is to look on the call stack for the class invoking it and using this information to invoke the original log4j.Logger.getLogger().

If you are using Eclipse you'll benefit from configuring it to always insert the above logger statement when creating new class files. Just follow the instructions on this figure Figure showing how to configure Eclipse to automatically insert the proper log4j logger initialization.
Figure showing how to configure Eclipse to automatically insert the proper log4j logger initialization.

What if I don't want yet another .jar file in my project

You can just copy-paste inherit the code from the repository at http://spiffyframework.svn.sourceforge.net/viewvc/spiffyframework/tags/v0.05/src/spiffy/log4j/LoggerHelper.java?view=markup. The code is under the Apache 2.0 license so feel free.

Java 1.4 compatibility

Yes the implementation is JDK 1.4 compatible although the binaries in the Spiffy framework distribution are compiled with Java 5.
Download Spiffy framework at http://sourceforge.net/project/showfiles.php?group_id=209074

Is this slow??

I've heard this criticism before. However, loggers are only acquired once pr. class and at class load time so it is a much faster approach than using the this.getClass() trick as it encumbers each object instantiation. If you are still really worried, you should stop worrying and start profiling your code...

Enjoy!



Comments

If you have any comments to this article, please drop me a mail at firstclassthoughts at gmail dot com please indicate if I can't publish whole or parts of your comment on the site.


If you like this site consider subscribing to my RSS feed or how about subscribing by Email.


Help spread the word

Share this post on your favorite social bookmarking sites:
If you enjoyed this article, found it thought provoking, educative or otherwise good, please link to this page from your page or social bookmarking page. If you have any texts you think are worth publishing on First Class Thoughts, don't hesitate to send me a mail! Quality always welcome.


Bookmark and Share


The most recent contributions
28/07/09 Magic in mathematics II Fun with the number cyclic numbers, and specifically with 142857 as it is the smallest of such numbers.
13/07/09 My top 8 time-saving Firefox shortcuts This article presents my favorite top 8 time-saving shortcuts in Firefox 3.0 and Firefox 3.5. Get to know these and you'll be saving a lot of time. They have been ordered by "the element of most surprise"
20/05/09 Board Game Jungle speed / Arriba Review of the cool game "Jungle Speed" aka. "Arriba".
16/05/09 Danish Twin words "Twin words" are words that not only have multiple meanings, they must be composed next to each other in meaningful sentences. This article explores the concept of twin words.
Nothing of interest? Try browsing the entire article archive...