Log4j delivers control over logging

The open source log4j API for Java offers fast, efficient log services

Almost every large application includes its own logging or tracing API. Experience indicates that logging represents an important component of the development cycle. As such, logging offers several advantages. First, it can provide precise context about a run of the application. Once inserted into the code, the generation of logging output requires no human intervention. Second, log output can be saved in a persistent medium to be studied at a later time. Finally, in addition to its use in the development cycle, a sufficiently rich logging package can also be employed as an audit tool.

In conformance with that rule, in early 1996 the EU SEMPER (Secure Electronic Marketplace for Europe) project decided to write its own tracing API. After countless enhancements, several incarnations, and much work, that API has evolved into log4j, a popular logging package for Java. The package is distributed under the IBM Public License, certified by the open source initiative.

Logging does have its drawbacks. It can slow down an application. If too verbose, it can cause scrolling blindness. To alleviate those concerns, log4j is designed to be fast and flexible. Since logging is rarely the main focus of an application, log4j API strives to be simple to understand and use.

This article starts by describing the main components of the log4j architecture. It proceeds with a simple example depicting basic usage and configuration. It wraps up by touching on performance issues and the upcoming logging API from Sun.

Categories, appenders, and layouts

Log4j has three main components:

  • Categories
  • Appenders
  • Layouts

The three components work together to enable developers to log messages according to message type and priority, and to control at runtime how these messages are formatted and where they are reported. Let's look at each in turn.

Category hierarchy

The first and foremost advantage of any logging API over plain System.out.println resides in its ability to disable certain log statements while allowing others to print unhindered. That capability assumes that the logging space, that is, the space of all possible logging statements, is categorized according to some developer-chosen criteria.

In conformance with that observation, the org.log4j.Category class figures at the core of the package. Categories are named entities. In a naming scheme familiar to Java developers, a category is said to be a parent of another category if its name, followed by a dot, is a prefix of the child category name. For example, the category named com.foo is a parent of the category named com.foo.Bar. Similarly, java is a parent of java.util and an ancestor of java.util.Vector.

The root category, residing at the top of the category hierarchy, is exceptional in two ways:

  1. It always exists
  2. It cannot be retrieved by name

In the Category class, invoking the static getRoot() method retrieves the root category. The static getInstance() method instantiates all other categories. getInstance() takes the name of the desired category as a parameter. Some of the basic methods in the Category class are listed below:

package org.log4j;
public Category class {
   // Creation & retrieval methods:
   public static Category getRoot();
   public static Category getInstance(String name);
   // printing methods:
   public void debug(String message);
   public void info(String message);
   public void warn(String message);
   public void error(String message);
   // generic printing method:
   public void log(Priority p, String message);
}

Categories may be assigned priorities from the set defined by the org.log4j.Priority class. Although the priority set matches that of the Unix Syslog system, log4j encourages the use of only four priorities: ERROR, WARN, INFO and DEBUG, listed in decreasing order of priority. The rationale behind that seemingly restricted set is to promote a more flexible category hierarchy rather than a static (even if large) set of priorities. You may, however, define your own priorities by subclassing the Priority class. If a given category does not have an assigned priority, it inherits one from its closest ancestor with an assigned priority. As such, to ensure that all categories can eventually inherit a priority, the root category always has an assigned priority.

To make logging requests, invoke one of the printing methods of a category instance. Those printing methods are:

  • error()
  • warn()
  • info()
  • debug()
  • log()

By definition, the printing method determines the priority of a logging request. For example, if c is a category instance, then the statement c.info("..") is a logging request of priority INFO.

A logging request is said to be enabled if its priority is higher than or equal to the priority of its category. Otherwise, the request is said to be disabled.. A category without an assigned priority will inherit one from the hierarchy.

Below, you'll find an example of that rule:

// get a category instance named "com.foo"
Category  cat = Category.getInstance("com.foo");
// Now set its priority.
cat.setPriority(Priority.INFO);
Category barcat = Category.getInstance("com.foo.Bar");
// This request is enabled, because WARN >= INFO.
cat.warn("Low fuel level.");
// This request is disabled, because DEBUG < INFO.
cat.debug("Starting search for nearest gas station.");
// The category instance barcat, named "com.foo.Bar",
// will inherit its priority from the category named
// "com.foo" Thus, the following request is enabled
// because INFO >= INFO.
barcat.info("Located nearest gas station.");
// This request is disabled, because DEBUG < INFO.
barcat.debug("Exiting gas station search");

Calling the getInstance() method with the same name will always return a reference to the exact same category object. Thus, it is possible to configure a category and then retrieve the same instance somewhere else in the code without passing around references. Categories can be created and configured in any order. In particular, a parent category will find and link to its children even if it is instantiated after them. The log4j environment typically configures at application initialization, preferably by reading a configuration file, an approach we'll discuss shortly.

Log4j makes it easy to name categories by software component. That can be accomplished by statically instantiating a category in each class, with the category name equal to the fully qualified name of the class -- a useful and straightforward method of defining categories. As the log output bears the name of the generating category, such a naming strategy facilitiates identifying a log message's origin. However, that is only one possible, albeit common, strategy for naming categories. Log4j does not restrict the possible set of categories. Indeed, the developer is free to name the categories as desired.

Appenders and layouts

The ability to selectively enable or disable logging requests based on their category is only part of the picture. Log4j also allows logging requests to print to multiple output destinations called appenders in log4j speak. Currently, appenders exist for the console, files, GUI components, remote socket servers, NT Event Loggers, and remote UNIX Syslog daemons.

A category may refer to multiple appenders. Each enabled logging request for a given category will be forwarded to all the appenders in that category as well as the appenders higher in the hierarchy. In other words, appenders are inherited additively from the category hierarchy. For example, if you add a console appender to the root category, all enabled logging requests will at least print on the console. If, in addition, a file appender is added to a category, say C, then enabled logging requests for C and C's children will print on a file and on the console. Be aware that you can override that default behavior so that appender accumulation is no longer additive.

More often than not, users want to customize not only the output destination but also the output format, a feat accomplished by associating a layout with an appender. The layout formats the logging request according to the user's wishes, whereas an appender takes care of sending the formatted output to its destination. The PatternLayout, part of the standard log4j distribution, lets the user specify the output format according to conversion patterns similar to the C language printf function.

For example, the PatternLayout with the conversion pattern %r [%t]%-5p %c - %m%n will output something akin to:

176 [main] INFO  org.foo.Bar - Located nearest gas station.

In the output above:

  • The first field equals the number of milliseconds elapsed since the start of the program
  • The second field indicates the thread making the log request
  • The third field represents the priority of the log statement
  • The fourth field equals the name of the category associated with the log request

The text after the - indicates the statement's message.

Configuration

Inserting log requests into the application code requires a fair amount of planning and effort. Observation shows that code dedicated to logging represents approximately four percent of the application's total. Consequently, even moderately sized applications will have thousands of logging statements embedded within their code. Given their number, it becomes imperative to manage those log statements without the need to modify them manually.

The log4j environment can be fully configured programmatically. However, it is far more flexible to configure log4j by using configuration files. Currently, configuration files can be written in XML or in Java properties (key=value) format.

Let us give a taste of how that is done with the help of an imaginary application -- MyApp -- that uses log4j:

 import com.foo.Bar;
 // Import log4j classes.
 import org.log4j.Category;
 import org.log4j.BasicConfigurator;
 public class MyApp {
   // Define a static category variable so that it references the
   // Category instance named "MyApp".
   static Category cat = Category.getInstance(MyApp.class.getName());
   public static void main(String[] args) {
     // Set up a simple configuration that logs on the console.
     BasicConfigurator.configure();
     cat.info("Entering application.");
     Bar bar = new Bar();
     bar.doIt();
     cat.info("Exiting application.");
   }
 }

As seen in the code above, MyApp begins by importing log4j related classes. It then defines a static category variable with the name MyApp, which happens to be the class' fully qualified name.

MyApp uses the Bar class defined in the package com.foo:

 package com.foo;
 import org.log4j.Category;
 public class Bar {
   static Category cat = Category.getInstance(Bar.class.getName());
   public void doIt() {
     cat.debug("Did it again!");
   }
 }

In MyApp, the invocation of the BasicConfigurator.configure() method creates a rather simple log4j setup. That method is hardwired to add to the root category a FileAppender printing on the console. The output will be formatted by using a PatternLayout set to the pattern %-4r [%t] %-5p %c %x - %m%n.

Note that by default, the root category is assigned to Priority.DEBUG.

The output of MyApp is:

0    [main] INFO  MyApp  - Entering application.
36   [main] DEBUG com.foo.Bar  - Did it again!
51   [main] INFO  MyApp  - Exiting application.

Figure 1 depicts MyApp's object diagram immediately after it calls the BasicConfigurator.configure() method.

Figure 1. MyApp's object diagram after calling the BasicConfigurator.configure() method

The MyApp class configures log4j by invoking BasicConfigurator.configure() method. Other classes need only import the org.log4j.Category class, retrieve the categories they want to use and log away.

The previous example always outputs the same log information. Fortunately, it is easy to modify MyApp so that the log output can be controlled at runtime. Below, you'll see a slightly modified version:

 import com.foo.Bar;
 import org.log4j.Category;
 import org.log4j.PropertyConfigurator;
 public class MyApp {
   static Category cat = Category.getInstance(MyApp.class.getName());
   public static void main(String[] args) {
     // BasicConfigurator replaced with PropertyConfigurator.
     PropertyConfigurator.configure(args[0]);
     cat.info("Entering application.");
     Bar bar = new Bar();
     bar.doIt();
     cat.info("Exiting application.");
   }
 }

This version of MyApp instructs PropertyConfigurator to parse a configuration file and set up logging accordingly.

Let's look at a sample configuration file that results in exactly the same output as the previous BasicConfigurator-based example:

# Set root category priority to DEBUG and its only appender to A1.
log4j.rootCategory=DEBUG, A1
# A1 is set to be a FileAppender which outputs to System.out.
log4j.appender.A1=org.log4j.FileAppender
log4j.appender.A1.File=System.out
# A1 uses PatternLayout.
log4j.appender.A1.layout=org.log4j.PatternLayout
log4j.appender.A1.layout.ConversionPattern=%-4r [%t] %-5p %c %x - %m%n

Suppose we no longer wish to see the output of any component belonging to the com.foo package. The following configuration file shows one possible way of achieving that:

log4j.rootCategory=DEBUG, A1
log4j.appender.A1=org.log4j.FileAppender
log4j.appender.A1.File=System.out
log4j.appender.A1.layout=org.log4j.PatternLayout
# Print the date in ISO 8601 format
log4j.appender.A1.layout.ConversionPattern=%d [%t] %-5p %c - %m%n
# Print only messages of priority WARN or above in the package com.foo.
log4j.category.com.foo=WARN
1 2 Page
Recommended
Join the discussion
Be the first to comment on this article. Our Commenting Policies
See more