Logging is generally one of those real-world complexities that isn't taught in school. Instead, it's learned as a best practice that's passed down from a coding guru to future coding gurus. Most applications of significant size, whether they are written in Java or not, tend to evolve logging frameworks. I say "evolve" because, unfortunately, it has been my experience that logging is usually put into a system long after the initial development. In fact, in many cases, it is usually developed in response to some heinous system problem that can't be tracked down through traditional techniques, such as walking the code with a debugger.

Typically, there are three cases when using a debugger is ineffective. The first case is when you are dealing with threading issues. Threading issues are often difficult to debug because of what is referred to as the Heisenberg Uncertainty Principle (HUP), which simply states that some phenomenon cannot be observed directly because the physical act of observation may interfere with the results. In the case of threading issues, which are often the result of race conditions, the act of attaching a debugger almost always skews the results. The second case where debugging is ineffective is on distributed systems. Although it is now easier than ever to attach and debug into a server, things can get dicey when you have multiple distributed servers. Also, as with threading problems, you may run into the HUP. In fact, you can almost think of distributed systems as being a generalization of the threading problem, where each server is analogous to a thread. The third--and often overlooked--difficult situation to debug occurs when you have the "random" bug. We have all run into these little beasts before. This type of bug is difficult to reproduce or seems to happen only when all the planets are in a certain alignment. Walking code in search of a bug like this can be extremely time-consuming and often yields nothing but frustration.

What are the Criteria for a Good Logging Framework?

So we know that we need logging frameworks, but what criteria do we have for them? Like all frameworks, logging frameworks need to be reliable, fast, flexible, and easy to use. Let's explore each of these attributes in detail.

Reliable

First and foremost, any kind of logging system must be reliable. Here is a counter-example. One of the first projects that I worked on right out of school (during the ancient days of two-tiered client/server architecture) had a requirement for all "serious" errors to be logged. Not knowing how valuable logging could be to development, the task was one of the final pieces of the system to be worked on. Since the term "serious" was never well-defined in the specification, the programmer implementing the logger decided to log everything from invalid user input to disk write failures. The logs were all being appended to a single file on the server, which of course led to an enormous amount of contention between transactions for the services of that file. In a last ditch effort to alleviate the situation, it was decided that all the errors should instead be logged to a relational database. The problem was that the first time the logging database was bounced, two separate errors about the database being unavailable were recorded. Each "serious" error in turn spun up two "serious" errors each and so on and so on in geometric progression until a second or two later when everything came to a grinding halt. Did I mention this was all during a customer acceptance test? Anyway, lesson learned: Logging frameworks must be extremely reliable and must not lead to recursive logging.

Fast

Although we may want to put a logging framework into a client-side application, speed is probably not going to be much of an issue. However logging on a server, especially if it is going to be extensive, needs to be fast. According to Apache, it has been their experience that approximately 4% of a typical code base is logging.

Flexible

Logging frameworks should be flexible in both where and what they log. For example, you should be able to log a single entry to multiple locations. Since you have to be careful about recursive logging, sending log entries to multiple monitored locations is a good protection against a failure scenario in which the resource being logged to is down. In addition, what is being logged should be configurable. Generally, there are times when you want more or less detail in your logs or you want information on all failures or just catastrophic ones. The more flexibility you have in this area, the easier it is going to be to track down the information you want.

Easy to Use

I don't care how good your logging framework is, it needs to be easy to use and easy to understand. If it's too complicated or difficult, developers are going to revert to using System.out.println(). So either they are going to clutter up system out with a bunch of garbage that can't be turned off or they are going to put in and remove each println() by hand when they need it. I know most people are really against it, but sometimes I do wish Java had a preprocessor like C/C++.

Log4j

So once again it's the open-source gurus at Apache Jakarta Project to the rescue. Let's see how their Log4j logger framework stacks up against our criteria.

Our first attribute is reliability, and in Apache's own words, "log4j is not reliable. It is a best-effort and fail-stop logging system." Although this statement implies that Log4j fails our criteria, it really doesn't. What they mean is that it can't be guaranteed to log every error. However, they have gone to extraordinary lengths to make sure that it will not throw any uncaught exceptions that would crash the application it is being run in.

Our next criteria is that it's fast, and yes, it is very fast. Although it does require a minimal amount of processing for provisioning each call and determining if a particular logging level has been enabled or not, the impact on your system will be negligible. They even have a few tricks you can use for those of you with servers in which every cycle counts, but like most optimizations, I don't recommend using these unless you absolutely have to.

Flexibility is where Log4j really shines. You can log to multiple locations in multiple formats as well as set different levels of logging and change them on the fly.

As for ease of use, that is up to you to decide after looking at the following examples. For these examples, you will need the binary distribution of Log4j from the Apache Jakarta Project Log4j Project. As of the writing of this article, the current version is 1.2.8. Download the package and add the src directory to your classpath.

Example 1: Basic Logging

For our first example, we will start with the following class:

In our example above, we are using two classes from the Log4j API: Logger and BasicConfigurator. Logger is the central class to the API; everything within the API exists as support for either using or configuring a Logger. Our second class is BasicConfigurator, which we will normally want to replace at some point down the road, but for now, it sets up a lot of defaults for us. Note that almost everything done with the Log4J API uses static classes and methods. This is done so that we don't have to continually pass around references to our Logger(s).

After the import statements and the declaration of the class, we create a static reference to a logger class using the static method Logger.getLogger(Log4jTest.class). Loggers are all named by the string passed in to the getLogger() method. So in this case, we have created a Logger called Log4jTest. Since only one logger with a given name can exist at a time, if one with this exact name had already existed, instead of creating a new Logger, we would have been given a reference to the existing one. Note the similarities between this and the singleton design pattern.

Next, we declare main() followed by a static call to BasicConfigurator.configure(). This method, as the name implies, will set up a number of basic configurations for us automatically. Most notably, it sets up the Logger to send its output to the console. It will set a standard format for the logging as well as a standard logging level. We will go into more details on each of these configurations later.

Now, we make two calls to logger.debug(), each of which will be logged to the console, based on the configuration provided by BasicConfigurator. The resulting output looks like this:

Example 2: Sharing a Logger

For our next example, we will show how two classes can share a logger. First, we will modify our example above to create a new instance of a class called SampleApplication. The modified source code looks like this:

Our new SampleApplication class looks like this:

In our new SampleApplication class, we also request a static reference to the Log4jTest logger, and since one already exists, we will just give a reference to it. It has already been configured, so we don't need to include BasicConfigurator. Note in our source the addition of a call to logger.debug() in SampleApplication's constructor. The console output for our application is now as follows:

Loggers, Appenders, and Layouts

Log4j has three basic concepts: loggers, appenders and layouts. As we have seen in our above two examples, loggers are the sources of information. When we get to a particular situation that we think is noteworthy, we call a method on the logger. Appenders are the natural reciprocal of loggers: They are the destinations for what is to be logged, and one of the key features of Log4j is that we can have multiple appenders for a single logger. Our final concept is that of a layout, which is simply a template for "pretty printing" of your appender. Another nice feature is that each appender can have its own layout.

Example 3: Multiple Appenders

For our next example, we will modify our previous example to have an additional appender that sends its results to a file. Changes only need to be made to Log4jTest.java:

In this example, we have added two new classes: PatternLayout and FileAppender. We simply instantiate a new PatternLayout and then provision it with a pattern. Each of the characters preceded by a percentage mark (%) will be replaced with a certain value. (For a table of all possible values, see the Log4j documentation, as the list is rather extensive.)
For our example, we have preserved the default pattern used in our previous example with the exception of prepending it with a date/time stamp represented by the "%d". Next, we create a FileAppender and provision it with our new pattern layout and a file name. Our last change is to then add this FileAppender to our basic configuration. Now, if we run the application again, we will see that the console output is identical to that of Example 2:

These are the contents of our newly created Log4jTest.log file:

Remember that your log files are appenders and that the application will keep adding entries to the end of the file each time you run it. This is one of the reasons I always add the date/time stamps to the front of each entry.

Example 4: Levels of Logging

Log4j in its standard configuration provides five levels of logging, each considered to be successively more important: debug, info, warn, error, and fatal. You can adjust your logger to any of the five levels, and it will log messages from that level or that of any higher level. In other words, if we set the logging level to warn, we would get messages for warn, error, and fatal but not for debug or info. You set a log messages level by calling the method corresponding to the name of the level.

Here, we have added a logging level for each message. The corresponding output looks like this:

To set the level of logging you desire, just call the setLevel method on your logger. The call would look like this to change the level to debug:

Note that it is also possible to create your own developer-assigned logging levels, but it is not encouraged by the authors of Log4j.

Best Practices

Configure your loggers at application initialization and use configuration files. Log4j has direct support for property files and XML files. In fact, you can even set up listeners so that if you swap out the configuration files, your application will pick up the changes at runtime. Also, don't forget about our debugger nemesis--the Heisenberg Uncertainty Principle, which can come into play when changing logging levels. Although not as intrusive as a debugger, loggers have been known to cause anomalies. And be careful what you log. Most applications have data that they need to keep secret, so be cautious when handling sensitive data such as passwords, encryption keys, social security numbers, or credit card numbers. There's no point in keeping your database secure if you log out all the data that goes into it. And finally, don't forget that Log4j is open-source, so if you want to integrate it into your platform or tool, feel free to do so. Just remember to submit changes back to the community.

Other Related Tools

Chainsaw--This is a great graphical tool for viewing and filtering logs and is now included in the standard Log4j distribution.

log4Unit--Log4j and junit are being used in conjunction with one another to not only prove that a test passes but to record what happened behind the scenes to make the test pass.

log4j400--This includes MessageQueues and DataQueues appenders for your iSeries.

Log4j has also been ported to just about every major computer language. You can get a current list of supported languages from the Apache Jakarta Project.

Conclusion

Use a logging framework from the beginning of a project. You are going to wind up adding one at some point anyway, so put it in when it can help speed up your development by assisting you in finding errors. In addition, a logging framework that is part of your overall configuration from the start is far more likely to fit in with your overall application architecture. Log4j meets all four of our criteria for a good logging framework. It is reliable, fast, and flexible and, after analyzing the examples above, I'm sure you will agree that it is easy to use. The best feature of Log4j is its flexibility--from formatting your results the way you want them to setting up multiple redundant logging targets, it can all be done with Log4j. Still not enough to entice you? In addition to what I have shown here, you can set up a named hierarchy of Loggers or experiment with contexts that give you detailed information about the state of the system at the time you call a log entry. And if you still crave more, try out Chainsaw, log4Unit, log4j400, or any of the other dozen or so Java Log4j extensions.

Michael J. Floyd is an extreme programmer and the Software Engineering Manager for DivXNetworks. He is also a consultant for San Diego State University and can be reached at This email address is being protected from spambots. You need JavaScript enabled to view it..