Focusing on open APIs for enterprise applications

Open Web Magazine

Subscribe to Open Web Magazine: eMailAlertsEmail Alerts newslettersWeekly Newsletters
Get Open Web Magazine: homepageHomepage mobileMobile rssRSS facebookFacebook twitterTwitter linkedinLinkedIn

Open Web Authors: Jnan Dash, Jayaram Krishnaswamy, Bob Gourley, Kevin Benedict, Pat Romanski

Related Topics: Open Web Magazine

Open Web: Article

LOGGING - Third Party Logging API

LOGGING - Third Party Logging API

During our last project we needed a logger but didn't want to develop our own, so we looked for third-party logging APIs. We found a few and experimented; one of them, log4j, far outshone the others. It helped us so much in tracing and debugging our problems that we recommended it for other projects, where it also got rave reviews.

This API was developed by IBM at their Zurich research lab ( Initially, IBM posted it on its alphaWorks Web site (, but has since moved it to an open source organization, Source Forge ( It can also be accessed at

The Need for Tracing and Logging
Two methods are widely used for debugging: you can either step through the code in a debug environment or you can add debug statements in your code, run the code, and analyze the log generated. The problem with the first method is that it can take a lot of time to step through the code, which can be done only as part of the development phase. In addition, it's difficult to get an overall view of the program execution as you only have the current state of the program at any given time. To get an overall view you have to record the values of the data as you step through the code, which is equivalent to adding debug and trace statements. The advantage of adding debug statements is that this mechanism is persistent. You can see the log anytime you wish (even after the system has been put into production), instead of stepping through the program every time.

Developers often use System.out.println statements to get desired values. Though this provides some quick help to developers, it's not a good solution in the long term. These statements aren't flexible (i.e., time, thread information is generally not logged, and the information to be logged is hard-coded).

If you want to change the format, you have to edit the entire code, and it can't be used in environments where console output isn't available (e.g., server-side components, EJBs, servlets, jsps). If performance is an issue, these statements have to be removed (or commented out) before the system goes into production. If there's a problem in production, the debug statements need to be inserted again, code needs to be compiled, and the application needs to be restarted. This obviously has its drawbacks.

Using a logging API solves these problems. Often these APIs are custom-made (leading to increased project costs), less flexible, unoptimized, and sometimes even unstable. I've used two such APIs and haven't been happy with them.

The Basic Stuff
The log4j API allows you to log text messages as well as exceptions. (It logs the passed message and then exception stack trace.) You can put logging statements in catch blocks, and the log generated can be very helpful in debugging.

Let's start with the concept of priorities (severities). Each logging message has to be put with a priority. Generally used priorities are DEBUG, INFO, WARN, and ERROR (four more priorities - NOTICE, CRIT, ALERT, EMERG - exist but they're discouraged as they get confusing and aren't really required). You can configure the log4j package so it only logs messages above a given priority.

Suppose you've configured the package with WARN priority. All messages with priority WARN and ERROR will be logged, and all messages with priority INFO and DEBUG will be ignored. During development you can configure it to log DEBUG messages, and during production all you have to do is configure it to log all messages with priority INFO or higher. These debug messages won't be logged. This obviously gives cleaner and less verbose logs and saves time in production.

Three functions are available to add debug messages:

  • debug(String message)
  • debug(Object message)
  • debug(String message, Throwable t)
These functions will log a message with debug priority. Similar convenience functions exist for INFO, WARN, and ERROR priorities. For other priorities (which are used less often) such functions don't exist. You can always use the following general functions to log a message:

log(Priority priority, String message)
log(Priority priority, String message, Throwable t)

Now that we're done with the simple concepts, let's talk about slightly more complex things like categories. The logging API supports multiple logs at the same time. This means you can log different messages into separate files, each with its own format, at the same time. Defining categories does this. Before any log statement you have to get the Category object. This is done by specifying the category you want to log to (e.g., employee, finance). I'll illustrate the usage with an example:

Get the Category object as follows:

Category cat = Category.getInstance(getClass().getName())

This returns a Category object that has all the methods used to log the messages.

The recommended use is to organize your code according to different modules and put them in separate packages (I guess most of us do this anyway). For instance, your employee-related classes would go in a package called com.mycompany.employee while your finance-related classes would go into package. Now all the log statements in the code in employee packages will log into the category com.mycompany.employee, and similarly, all code in the finance package will log using category

Though you can configure the categories using various configuration functions in the API, a better option is to use a configuration file. Your settings can be specified in a property file and log4j can load it to configure the categories (see Listing 1). The first three lines show three categories: com.mycompany.employee,, and ROOT. If you try to get a Category object for a nonexistent category (such as com.mycompany or, it will be created and returned. This new category will inherit its properties from the hierarchy.

The Hierarchy Story
Does this mean you have to configure a different category for each package? No. A very powerful feature of the log4j is category hierarchy (much like a class hierarchy). Just define a category - com.mycompany - and all the logging messages logged with category names - com.mycompany.employee, - will be logged to category com.mycompany. Now suppose you find some bug in the employee package. All you need to do is define another category, com.mycompany.employee, that logs to a different file with severity as DEBUG. All the debug output would go to a different file, which can be deleted after debugging.

The logging categories are hierarchical just like packages in the Java language. This means that if you have a category named com.mycompany and another one, com.mycompany.employee, the category com.mycompany.employee will inherit the properties of com.mycompany (including appenders), unless it's specifically configured to override inherited properties.

Does this mean that all the messages you log under com.mycompany.employee will also be logged under com.mycompany? Three rules determine this. They're well documented, with examples, in the Log4j documentation. I can't reproduce all of it here, but here are the rules:

  1. The chained priority for a given category C is equal to the first nonnull priority in the category hierarchy, starting at C.
  2. A log statement of priority p in a category with chained priority q will be printed if p >= q.
  3. The output of a log statement of category C will go to all the appenders in C and its parents. However, if a parent category of C has the additivity flag set to false, then appenders of that parent aren't used.
If you don't want to log com.mycompany.employee messages to com.mycompany category, use the additivity setting. Setting additivity to false for any category will cause it to stop sending its messages to its parent category. Look at line 4 of Listing 1; this tells us that for the category, you shouldn't send the log messages to the ROOT category. But as nothing is mentioned for the category com.mycompany.employee, the messages from this category will be logged in the ROOT category as well. Listing 2 contains a sample code that uses Listing 1 to configure categories. You might need to experiment with it to get more comfortable with the package.

For each category you can specify an appender - an object that will finally send messages to the required destination. There's a FileAppender, which will write the logs to a file, and the RollingFileAppender, which will roll over files beyond the specified size. It will rename the old file and start again in a fresh file. A SocketAppender, which will dump the logs to a socket, can be useful if you're building a distributed logger. An NTEventLogAppender will write the logs to the NT Event Log System. Note that NTEventLogAppender works only on Windows NT. Similarly, there's a SyslogAppender to log messages to a remote syslog daemon in unix environments. It also has a TextPaneAppender, which will add the log messages to a JTextPane.

As you can see in Listing 1, each appender comes with a list of appender-specific settings (for instance, the RollingFileAppender needs to know the file path and name, the maximum size of file, number of backup files, etc., and the SocketAppender needs to know the remote host, port number, etc.).

Now that the problem of where to log is solved, the appender also needs to know the layout in which it should log. Hence all appenders have a layout setting. There are different types of layouts, such as SimpleLayout, TTCCLayout (deprecated), and PatternLayout (the most flexible one). PatternLayout can log time (in various formats), thread name, priority, category, time elapsed from 1970 to creation of logging event, and message. This appender can also log the class name, filename, location (method + class name + line number), line number, and method name, but these should be used only during development as they're very slow.

This completes the discussion about the log4j features. Let's talk a bit about performance. Look at this code:

cat.debug("The account number is " + accountNumber);

isDebugEnabled will return true only if this category's debug messages will actually be logged. If not, it doesn't enter the if block, thus avoiding the cost of argument building. According to the documentation, on a 233 MHz ThinkPad running JDK 1.1.7B, it takes about 46 nanoseconds to determine if that statement should be logged or not. Actual logging is also fast, ranging from 79 microseconds using the SimpleLayout, to 164 ms using the TTCCLayout, and about a millisecond when printing exceptions. The performance of the PatternLayout is almost as good as the dedicated patterns, but with added flexibility.

How We Used It
We added a few of our own ideas to make it more effective. We derived our own exception class from RuntimeException to represent various exceptions in the system. The main feature of this class was that we put a log statement in the constructor to log the exception, the stack trace, and any nested exception. This logged every exception thrown in the system at any place, at any time with stack trace, and proved to be a very powerful tool.

Additionally, though PatternLayout provides facilities to log the class name and method name, it's supposed to be slow, so we mention these details in the message itself. For example:

Category cat = Category.getInstance(getClass().getName());
cat.log("Account.getBalance: Total balance in account is " + accountBalance);

Here, when the message will be logged, we know that the class is and the method is getBalance.

Another helpful thing for database-specific applications is to create a wrapper around java.sql.Statement and log all the SQL statements fired. This is handy when the SQL statements are being dynamically generated.

We also had a unique requirement. In our system the same code was running for different companies. Think of it as if the accounting is being done for 10 companies. We wanted to be able to separate the log files when desired. But with the category named, we couldn't do it. So we did a little modification and prepended the company name to the package name to get the category name. Our log statements looked like:

Category category = Category.getInstance(company + "");
category.log("Account.getBalance: Total balance in account is " + accountBalance);

Now we not only know the company name for which this log statement is being executed, but we also have the ability to separate the log files by company name.

(A similar functionality can be achieved using Nested Diagnostic Contexts. The log4j provides a class called NDC for this purpose.)

One important and helpful thing we found was excellent support. Not only have bugs been fixed within hours of the first report, but suggestions have been received with an open mind. (By the time you read this article, however, the log4j package will be owned and maintained by Ceki GŸlcŸ, the author of log4j package.)

There are a few shortcomings, but they're not limiting factors. One is that you can't remove a category once it's created. This was done to keep the API simple to use. Also, the appenders don't support JMS, XML, Database, or others. In the near future, more appenders like JMSAppender, XMLAppender, IRCAppender, JDBCAppender, and JtableAppender are planned.

Though other loggers are out there, we preferred log4j because it's powerful yet simple. However, this isn't a solution for everyone. You might want to check out other loggers such as Chris Barlock's Jlog (formerly called JRAS; it offers more in terms of filtering capability but at the cost of much higher complexity) and GraceLog by Chris Bladon (it enables you to inspect objects and log their contents).

I'd like to thank Ceki Gülcü, the author of log4j, for his invaluable input, and my friend Sumit Garg for helping me put this article together. I'd also like to thank Impetus Computing Systems and Info-One, whose resources I used to research and write this article.

More Stories By Vinay Aggarwal

Vinay Aggarwal, an integration consultant at Trilogy in Austin, Texas, has extensive experience in Java and Web tecnologies. He received his degree in mechanical engineering from PEC in Chandigrha, India.

Comments (0)

Share your thoughts on this story.

Add your comment
You must be signed in to add a comment. Sign-in | Register

In accordance with our Comment Policy, we encourage comments that are on topic, relevant and to-the-point. We will remove comments that include profanity, personal attacks, racial slurs, threats of violence, or other inappropriate material that violates our Terms and Conditions, and will block users who make repeated violations. We ask all readers to expect diversity of opinion and to treat one another with dignity and respect.