ONJava.com    
 Published on ONJava.com (http://www.onjava.com/)
 See this if you're having trouble printing code examples


Build Flexible Logs With log4j

by Vikram Goyal
08/07/2002

log4j is the open source logging tool developed under the Jakarta Apache project. It is a set of APIs that allows developers to write log statements in their code and configure them externally, using properties files. This article explains the main concepts of this tool, followed by some advanced concepts using a Web-based example application.

A Note on the Accompanying Application

The application that accompanies this article is a Web-based application, which has been developed and tested using JDK1.3.1, Tomcat 4.0.1, log4j 1.2.4 and Ant 1.4.1 on a Windows XP machine. You can download the log4jdemo.war application file that you can deploy in any servlet engine. You can also download the source code. This application has the following flows, which are found in most Web applications:

Keep in mind that the application itself is trivial and is just a path to the main goal in this article -- understanding log4j. I have opted for a Web application to explain log4j instead of a normal application because of the high number of Web applications using log4j as the preferred logging mechanism.

Setup

log4j can be downloaded from the Apache Web site. The download is available in two formats, tar.gz and zip. Both downloads contain the source code for the log4j API, documentation, examples, and distributable log4j executables in the form of .jar files. Extract the files to a location of your choice. The source code is supplied, in case you want to do a build for yourself. The build can be done with the help of Ant and the build.xml files that are provided; you can customize the build script if required. The build will produce the log4j-1.2.4.jar file in the dist/lib directory if built using the dist target. Note that for the build to be successful, you will need to have the Java Management Extensions (JMX) API in your classpath, as well.

To make the log4j classes available to your application, you need to have the log4j-1.2.4.jar file in the classpath of your application. This file, as described above, is in the dist/lib folder. For our example Web application, this means that this .jar file should be in the WEB-INF/lib directory of our application. This is all that is required to make sure that your application can access and use the log4j API. The rest of the effort needs to go into writing a configuration file that tells log4j what, where, and how to log, and into introducing actual log statements in your application.

What Is a Logger?

Before we start cutting some code, let's look at the basics of log4j. There are three aspects of log4j: logger, appender, and layout. A logger logs to an appender in a particular layout (style).

Related Reading

Java In a Nutshell
By David Flanagan

Think of a logger as the silent component within your application that will take your request for logging and log it. Each class in your application can have an individual logger or a common logger. log4j provides a root logger that all of your loggers will inherit from. This also means that if you don't have an individual logger for each class, you can always use the root logger by calling Logger.getRootLogger(), although this is not recommended.

To create a logger and use it for logging in your classes, you typically need to call a static method of the Logger class that will retrieve a logger for you by name. If the particular logger has not already been created it will be created for you, and there will always be one instance of this logger in your JVM.

Loggers need to know where to send your requests for logging. This is where the appenders come into picture. log4j supports writing to files (FileAppender), to console (ConsoleAppender), to databases (JDBCAppender), to NT event logs (NTEventLogAppender), to SMTP servers (SMTPAppender), to remote servers (SocketAppender), and others. An appender defines the properties of the logging target to log4j. So, for example, if we attach a JDBCAppender to one of our loggers, we are telling log4j that logging requests from our logger should go to a certain database (using a certain username, password, connection string, etc.). All of these are properties of an appender (a JDBCAppender in this case), which are used by log4j to target our logging requests.

Loggers and appenders are concerned with originating and targeting our log requests. What about the format of the output? This is where a layout comes into picture. A layout defines the style and content of the output log. Some built-in layouts are provided with log4j, and you can create your own layouts, if they are required. A layout will tell log4j whether or not to include the date and time in the output, whether to include information about the logger, whether to include the line number from which the log originated, etc.

Loggers follow a parent-child relationship pattern. As mentioned earlier, log4j provides a root logger by default. This implies that all of our loggers will ultimately inherit from this root logger. A parent-child relationship is followed by using a named pattern. To illustrate, let's say you have a class called MyClass in a package called com.foo.bar. In this class, let's instantiate a logger by the name of com.foo.bar.MyClass. In this case, com.foo.bar.MyClass logger will be a child of the logger com.foo.bar -- if it exists. If it does not exist, the only ancestor of the com.foo.bar.MyClass logger will be the root logger provided by log4j (in case there is no logger by the name of com.foo or com).

Each logger in log4j is assigned a level. If you don't assign a level to a logger yourself, log4j automatically assigns to your logger the level of the parent logger. Since there is a possibility that the user might not assign any level to the self-created logger(s), the root logger always has a default level assigned to it, which is DEBUG. Thus, all loggers are guaranteed to have a level.

There are five levels of logging in log4j:

The signs indicate the ordering of the logging that log4j follows.

How does each logger having a level affect our logging efforts? Because a log request made from within our application using a particular logger will be sent to a corresponding appender only if the level of the log request is greater than or equal to the level of the logger itself. This means that all log requests from within our application can be of these five types only. This is a very important rule, and really is at the core of log4j. Let's take our previous example of com.foo.bar.MyClass logger to explain this further.

Suppose within your class (which is called com.foo.bar.MyClass -- no surprise here; we named our logger based on the class where it is instantiated, a standard practice), you use the logger to log a message of type WARN. Now let's say your logger com.foo.bar.MyClass has the level set at ERROR through your configuration. What does this mean? This means that the log request of type WARN will not be sent to any appender.

Why? Because log4j recognizes that the level of the log request is lower than the level of the logger, and thus does not log this request. Had the log request been of type ERROR or FATAL, it would have been logged. Similarly, had the level of the logger been set at level WARN, the log request would have been logged. This leads to a very important concept about log4j. You can externally change the level of each and every logger without having to change your source code, recompile, and deploy.

log4j is mostly configured using an external configuration file. The API provides for configuring the log4j system through code as well. The next section will guide you through a simple example and show how the configuration can be done.

A Simple log4j Example

The application uses five servlets (SetupServlet (which runs when your servlet engine starts up), LogonServlet, GetCommentsServlet, ForgotPasswordServlet, RegisterServlet); four JSPs (forgotpassword, logon, register, welcome); and a file-based database for storing user information (userDB, which should be in the WEB-INF folder; make sure that the path to it is correct in the web.xml file).

To see the example in action, deploy the log4jdemo.war file in your servlet engine. Once deployed, modify the web.xml file to make sure that the SetupServlet's init parameter for the props file contains the location of config-simple.properties. This file is in the WEB-INF directory of the deployed application (and so are three other configuration files: config-JDBC, config-MDC, and config-NDC). Restart your server. On your server's console, some messages will appear. If the StartupServlet was able to find userDB, you'll probably see messages like this on the screen:

Using properties file: 
C:\jakarta-tomcat-4.0.1\webapps\Log4JDemo\WEB-INF\config-simple.properties
  Watch is set to: null
  DEBUG - Added line: JohnDoe,herbert,johndoe@john.com,John Doe

The first two statements appearing on the screen are simple System.out.println statements. The next one and the ones after that, if any, are through log4j. Let us see how this was done.

Open up config-simple.properties in a text editor. It contains three lines (besides comments). The first line, log4j.rootLogger=debug, R tells log4j that the level of the root logger is at DEBUG. This is the default and is not required. The value after the comma, R, is required. It tells log4j that the root logger has an appender attached to it and that the name of the appender is "R." The rest of the lines in this file tell log4j about the properties of this appender R.

The line log4j.appender.R=org.apache.log4j.ConsoleAppender tells that this particular appender R is of the type ConsoleAppender; in short, that it will write to the console. The line log4j.appender.R.layout=org.apache.log4j.SimpleLayout tells log4j to use the simple layout, which, as you will see on the screen, simply writes two things: the level of the log request and the actual log message.

Now that we have understood the configuration of our simple example, lets see how we are actually logging in our code. Open up SetupServlet.java in a text editor and look up line 81:

PropertyConfigurator.configure(props);

Ignore the other statements around it for the moment. This particular line tells log4j to look up a file referenced by the variable props and use it to configure log4j's settings. This is the same file we just looked at, config-simple.properties. This line needs to be called once in your whole application, typically at the start of your application. A startup servlet is ideally suited to do this configuration in a Web application, as it is run when the servlet engine starts.

Having configured our log4j settings, we are ready to start logging. The next step is to get hold of a logger and use it to write our log statements. We can do this either using the root logger by invoking the Logger.getRootLogger() method, or, as we have done, by getting a logger of the class we are in, SetupServlet. This gives us a logger by the name of demo.log4j.servlet.SetupServlet) by invoking the following line:

Logger log = Logger.getLogger(SetupServlet.class);

These methods return to you an object of the type Logger that we call our logging requests on. So, for example, on line 112 we have invoked the DEBUG method of this logger: log.debug("Added line: " + data);. And this is what we see on our console. Note that since in our configuration file we had set the level of our root logger at DEBUG, and we had not set any level for the demo.log4j.servlet.SetupServlet logger, our demo.log4j.servlet.SetupServlet logger also inherits this level. So when we say log.debug("Added line: " + data); from within our class, this log request is sent to our appender (ConsoleAppender). Try changing the level of the root logger to ERROR. The earlier line(s) will disappear, as the level of the logger has become higher than the actual log request. Note that to change the level of the root logger, you only need to modify the configuration file and restart your servlet engine (although it is not necessary if you are using configureAndWatch -- I will cover this in the "Tips and Tricks" section).

This completes our simple example. Let us recap what needs to be done in order to start using log4j in a simple example.

  1. Write a configuration file. In this file:
  2. In your code, get hold of a logger by class or name. Typically, this should be the logger associated with the class that you are currently in.
  3. Start logging using any of the methods of the logger you acquired in step 2 (log.debug(), log.info(), log.warn(), log.error(), log.fatal()).

Management Requirements

Although we have completed a fairly simple example and seen the power of log4j, our simple example will fall short in the real world. Let me point out the shortcomings in our simple example, as I am sure your boss would if he saw it!

Let us see how we can cover these problems with log4j. I will not elaborate much on the second point, as it is a simple matter of replacing the SimpleLayout with the PatternLayout and specifying a conversion pattern for it. Let me point you to the Javadoc of the PatternLayout for all of the available conversion patterns.

Add Those Enhancements

JDBCAppender

We will start with logging to a place other than the screen or the console. Since database logging is quite popular, let us look at how we can modify our simple example to log to a database. The example application was tested on a MySQL server, but it will work with any database, provided you have the right JDBC drivers. A note of warning, though, about using the JDBCAppender in the current version of log4j: the documentation says that it is going to be completely replaced in the future with a revamped version. Although the inner working of this appender might change, the way one goes about using it is unlikely to change.

Let us start by opening the config-JDBC.properties file from our example application. The first statement should not come as a surprise. As with the simple example, we have set the root logger and its level to DEBUG, and attached an appender, R, to it. The next few lines define R to be of the type JDBCAppender and declare its properties.

log4j.appender.R=org.apache.log4j.jdbc.JDBCAppender
log4j.appender.R.URL=jdbc:mysql://localhost/LOG4JDemo
log4j.appender.R.user=default
log4j.appender.R.password=default
log4j.appender.R.sql=INSERT INTO JDBCTEST (Message) VALUES ('%d - %c - %p - %m')

The first line tells log4j that R is of the type JDBCAppender. The second line declares the URL to the database to which we want to log. The third and the fourth lines are the user name and password to use to log to this database. The last line is the SQL query that will be executed. We will talk more about this soon.

Developers who have used JDBC will instantly recognize the similarity between declaring these values and using JDBC in general. These are the values that you need to specifiy to any JDBC-compliant application. You will, of course, need to change these values to reflect your own. For example, if you are logging to Oracle, the URL in the above case will become jdbc:oracle:thin:@yourhostSID. Another thing to note: these drivers should be available to your application, which in turn means that log4j gets access to them.

Let us now talk more about that last statement. The SQL that you use to log into the database can be varied and changed according to your requirements. The statement that I have used logs the following to a table called JDBCTEST: the date(%d), the category/logger(%c), the priority(%p); the actual message(%m) is logged to a column called Message. log4j picks up this statement and passes it through a formatter, which applies the layout specified for this appender, which in turn replaces the pattern matches with the actual values. log4j, then, simply executes this formatted SQL.

You can, if required, log different things in different columns. For example, another valid statement could be:

INSERT INTO JDBCTEST (Date, Logger, Priority, Message) VALUES ('%d', '%c', '%p', '%m')

This means that in our database, we have defined our JDBCTEST with corresponding columns of Date, Logger, Priority, and Message. You can test the application with JDBC by specifying the path to the config-JDBC.properties as the parameter in the StartupServlet.

So what code changes are needed to start logging to the database now? None! That is where the enormous power of log4j really manifests itself. To start logging to the database, we don't need to make any code changes. We just start using a different configuration file with the right parameters, and the log statements that were coming on the console will now be directed to the JDBCTEST table in your database.

NDC/MDC

Nested Diagnostic Context (NDC) and Mapped Diagnostic Context (MDC) help in situations where one application is involved in simultaneously serving multiple clients, and you are interested in separating or distingushing log content from each of these multiple clients. A Web application is a really good example of such a situation.

So how do we separate or distinguish content from multiple clients? By marking each log statement with client-specific information. This, in a typical Web application, could include, among other things, the client's IP address, which is readily available to the servlet container. So, in NDC, you push this information on a stack when entering a context, and pop it when leaving that context. log4j uses this context-specific information when writing to the appender, if in your associated layout, you use the %x conversion pattern. To see how this is done, lets look at one configuration file (config-NDC.properties) and one source file (GetCommentsServlet.java).

There is a marked difference in the config-NDC file from the previous configuration files that we have seen. For the first time, we are looking at multiple loggers. The first few lines are similar to the config-simple file, and that is exactly what we want to do. For all of the loggers in our application, except the logger associated with our GetCommentsServlet, we want the output to come on console in a simple layout. For the demo.log4j.servlet.GetCommentsServlet logger, we have a separate appender (R1), which also logs to the screen using a console appender, but its conversion pattern includes the %x symbol.

    log4j.logger.demo.log4j.servlet.GetCommentsServlet=debug, R1
...
log4j.appender.R1.layout.ConversionPattern=%p - [%x] - %m%n

Note how we reference the logger for GetCommentsServlet. All loggers (except the rootLogger, which is referenced by log4j.rootLogger) can be referenced by log4j.logger.<name of logger>. This is true for most elements of log4j.

The source for GetCommentsServlet points to the way we would use NDC by pushing and popping client specific information to the NDC stack.

Notice lines 40 and 57. On line 40, we push the client-specific information on the stack. Now all enabled log statements will contain this specific information replacing the %x conversion pattern. On line 57, we pop this information off of the stack. So the log statements will not contain this client-specific information.

Having covered the basics of NDC, lets discuss Mapped Diagnostic Context (MDC). MDC is similar to NDC, except that instead of pushing and popping information on a stack, the client-specific information is maintained in a map (in a java.util.Map). This implies that there must be a unique key associated with each piece of client information. If you look at line 43 in GetCommentsServlet.java, you'll see we do exactly that.

MDC.put("RemoteHost", remHost);

The MDC class provides static methods to manipulate client-specific information in the map. Thus, with each log statement sent to an appender, this information about the RemoteHost will replace the corresponding conversion character for MDC, which is %X{key}. What is this key? This is the key that we associate with our remHost value while putting it in the map, RemoteHost. If, for example, we wanted to put the RemoteAddress in our output, we would do the following:

In the code:

MDC.put("RemoteAddress", 
req.getRemoteAddr());

In the configuration file, add the following:

%X{RemoteAddress}

An example of this configuration is in the config-MDC.properties file. Although it is similar to the config-NDC.properties file, it differs in two important things. First, we use MDC instead of NDC, and second, the appender for our second logger is a RollingFileAppender instead of the ConsoleAppender.

Tips And Tricks

The first tip, if you are a planning to be a regular user of log4j, is to go to the very source of tips -- the log4j user mailing list. An archive of all messages is maintained at the Mail Archive, and you can subscribe to the list by sending an email to the list.

Here are some more concrete tips:

Resources

At this point in time, the best resource for learning log4j remain the log4j Web site, the source code that comes with it, and the short manual that accompanies it. The log4j mailing list is also good.

Conclusion

log4j is a popular logging tool developed and distributed under the Apache Project. There are other logging tools available, including the log API bundled in JDK 1.4. log4j is superior to all of these APIs, as it provides unprecedented control over all aspects of logging and is hierarchical in nature. It provides runtime control over logging without having to touch the source code.

I hope this article has given you some direction on how to get started with log4j and to use some of its advanced features; however, the best way to learn log4j is to experiment with it. Use the accompanying example application as a starting guide. Modify the configuration files, add, remove appenders, play with the layouts, etc. This will give you confidence in using log4j in your own application and give you an understanding of how it works. Good Luck !

Vikram Goyal is the author of Pro Java ME MMAPI.


Return to ONJava.com.

Copyright © 2009 O'Reilly Media, Inc.