Log4j : Debugging Concepts - Part-2

What is log4j? Log4j is a popular library of ready Java classes that enable you to easily implement logging for your Java applications. Being used as a logging tool for huge reputable applications (like IBM's NetView), log4j is known for it's efficiency and flexibility. Log4j is the result of the countless efforts made by the E. U. SEMPER project in 1996 and is currently being distributed under the Apache Software License; or more simply an open source license. What is our working environment / platform? Any Java developer with average experience can easily adapt the use of log4j for his own working environment. For reference purposes, we are documenting here what environment we used in this tutorial:

• Operating system: Microsoft Windows XP Professional SP2
• JDK: J2SE Development Kit 5.0 Update 6
• Log4j: Version 1.2.13

How to install log4j?

The installation of log4j is rather simple. First of all download it from link [5] below. It comes in form of a compressed archive.

1. Extract the archive you downloaded to any folder.
2. For you to be able to compile and run code based on log4j you have to add the log4j classes archive to your 'classpath' environment variable. Here's how to locate the log4j classes archive:
   • View the contents of the folder 'H\dist\lib\' where 'H' is the name of the folder inside which you extracted your log4j download.
   • Inside the 'H\dist\lib\' folder you should find a file named 'log4j-V.jar' where 'V' is the log4j version ('V' is 1.2.13 for our particular tutorial)
   • 'log4j-V.jar' is the name of the log4j classes archive you need to add to your 'classpath' environment variable.

How to use log4j: A simple first example (Example 1)

Here we will present an example for how to use log4j in it's simplest form. For you to have a bird view over what we are going to do in this example, we are informing you that we are going to initialize log4j and print a simple logging statement.

Create a '.java' source file and type the following code inside it:

/*1*/ import org.apache.log4j.Logger;  /*2*/ import org.apache.log4j.BasicConfigurator; /*3*/ public class MyClass  /*4*/ { /*5*/     static Logger lgr = Logger.getLogger("MyClass"); /*6*/     static public void main(String[] ars) /*7*/     {  /*8*/       BasicConfigurator.configure(); /*9*/       lgr.debug("This is a logging message!");  /*10*/   }  /*11*/  }

Save, compile, and run the example. You will see the following output as a result:

Figure 1

Let's analyze the output before explaining the code so that our explanation of code is more meaningful. As you can see, our example output includes several parts. Here's the explanation for what every part stands for:

• 0: This is the time at which the log message was printed. This is not absolute time. It's a relative time (in milliseconds) measured approximately from the time at which your application started to run.
• [main]: Indicate the name of the thread which requested the printing of this particular logging message.
• DEBUG: This is the level of the request. For the time being consider it as an indicator to that this particular logging message belongs to the debugging category of log messages. More about this later.
• MyClass: This is the name of the logger that was used to print this logging message. More about this later.
• This is a logging message!: The is the actual logging message that we wanted to print out in this example.

Being able to figure out the components of a log4j log messages, you are now ready to understand the code of our example. We are not going to go deep inside log4j while explaining the code as this is a simple example, but things will become much clearer as we proceed.

• Line 1 and 2 reference the classes we need to use in our example.
• Line 5 retrieves a logger. For now you can consider a logger to be simply an object responsible for printing log message. If you have a class and you need to perform logging inside it, then you have to retrieve a logger inside this particular class. When you retrieve a logger you have to provide a name for this logger ("MyClass" in our case). In the typical case, the name should be the same as the name of the class inside which the logger is being retrieved. More about this later.
• Line 8 initializes / configures log4j. This is crucial for any use of log4j inside your application. Please do not attempt to initialize / configure the log4j library more than once even if you are going to do logging in several classes. Doing so is not an efficient method for using log4j.
• Line 9 is the line that prints the log message shown in the output above.

In summary, to use log4j you typically proceed in the following scenario:

1. Initialize / configure log4j first (using the BasicConfigurator.configure() method)
2. Retrieve a logger (using the Logger.getLogger() method)
3. Use the logging methods of the logger you retrieved (For example: .debug()) to display log messages.

A bird view of log4j

People sometimes think that when a new technology is being approached, then they have to comprehend its terms one by one in a sequential order. On the other hand and throughout our use of log4j for long time now, experience indicates that it's better to have a general overview of what log4j is composed of before actually sequentially digging deep inside it. To aid you in having a general overview of what is what, we are presenting here some of the major and the most essential concepts in log4j. Please read these concepts carefully and be sure to understand them thoroughly before going further.

• Log request: This is simply a request that is made by your application to do logging. Typically this is a line inside your code which is placed with the aim to output a message signifying the occurrence of a certain event or to show useful information about the current state of your running application.
• Logger: A logger can simply considered as the object in charge for doing logging. Although the logging process itself is of course the result of coordination of several other objects, the logger object remain the major (and sometimes the only) object you need to use when issuing a log request. Because loggers is (we think) a major central concept in log4j, we are going to provide you with more details about them below.
• Appender: While issuing log requests one may opt to direct the message that appear as a result of this log request to a specific destination. For example your log messages can appear on the console (the screen), can be stored inside a disk file, or can be totally transmitted to another disparate machine via network. Several other destinations do exist as well. Any of these possible destinations that can receive log requests is simply called an appender. The use of appenders can be considered to be thread safe.
• Layout: As you can see in example 1, the log request we issued in line 9 caused the output to appear in specific format as you can see in figure 1. This format is not fixed and can be flexibly customized so that the output of your log request is exactly as you prefer. This will cause several formats of the output of the log request to exist. Any of these formats is simply called a layout.

Loggers: The core of log4j

Understanding the role played by loggers in log4j is not essential only because they are the object type you will use extensively but also because their understanding is crucial to the skills you need to acquire to effectively use the rest of log4j classes. 

A logger, as we described it above, is the class you use to issue log requests. So, in general, to be able to issue log requests you have first to retrieve a logger.

Every logger has its own unique name. When we attempt to retrieve a logger we do that using it's name as parameter to the Logger.getLogger() method (as we did in line 5 of example 1). Two possible alternatives can arise in this case:

• If this is the first time you use this name, then you are simply requesting the creation of a new logger.
• If you already used this logger name before, then you are simply requesting the retrieval of the same logger you created / configured else where.

This pattern suggests a nice feature of log4j loggers: You need not to pass references to loggers from where they were created to where they will be used. In other words you can create a logger any time by simply using it's name for the first time and then later retrieve exactly the same logger elsewhere by simply passing the same logger name to the Logger.getLogger() function. Please note that logger names are case sensitive. 

Although you can name your logger with whatever pattern or names you like, experience suggests two recommendations in this regard:

• The name of the logger should be the same as the name of the class inside which this logger is first created. This way you will not only be able to easily display the name of the class requesting logging, but also your loggers will have the same exact hierarchy as the hierarchy of the classes of your application which in turn will significantly simplicities the management of these loggers. For how this will make your loggers hierarchy identical to your classes hierarchy please read the next recommendation. 

• Loggers names should follow the convention of parent.child. For example, when you name 3 of your loggers as "x", "x.y1", and "x.y2" then you can greatly simplify their management. When you want to, for example, do a given task on all of these loggers you need not to perform this task on all of them individually. Instead you can perform it only on the logger with the name 'x' and the loggers "x.y1", and "x.y2" will simply follow their parent (i.e., "x"). This rule can be extended to deeper levels and in the same time to many children. For example you can have loggers with the names: "x.y1.z1", "x.y1.z2", "x.y1.z1.a", "x.y1.z1.b", ... etc. With reference to the first recommendation above, it's expected that you have a parent class and two child classes that are mapped to the loggers "x", "x.y1", and "x.y2" respectively.

Using a logger, you typically issue a log request inside your code using one of the following methods: debug(), error(), fatal(), info(), log(), warn(). All of these methods are essentially identical with regard to that they issue a log request (e.g., they all print a log message to your screen). The only meaningful difference between them is they are of different levels. For now, consider a level of a log request to be some thing that by which we define how much this loge request is important. For example, log requests performed using the fatal() method are considered to be more important than those performed using the info() method. One may ask, why associate a level with each log request? The answer to this question is the same as the answer to another question: "Ok, We are convinced now why logging is important; but why on the earth we do not simply do logging simply using System.out.println() and forget all about log4j?". To know the answer for all of these questions please read on! 

One of the most useful features of log4j is that you can assign levels of importance to the log requests you perform. This way you can later request that all log requests that are less than a certain level of importance not to be issued at all although they are still exist in your code. Take for example the famous case when one wants his application to display some log requests while he is debugging it and that these set of debugging related log requests are totally eliminated in the final product (of course without he wasting time actually deleting them from his code). For the sake of demonstration, let's assume that in this example he wants some informative log requests to persist not only in the debug version of the application but in the final product as well. To achieve this specific logging behavior, one could simply log his debugging only log requests using the debug() method, and in the same time issue his informative log requests using the info() method. Since log requests performed using the debug() method are less important to those performed using the info() method then one can simply enable all log requests from the level of debug() and up in his debug version and then in the final product he should only enable log requests from the level of info() and above. Confused? Let's illustrate all of this by a real example. 

Log requests in action; An example (Example 2)

In this example we are going to demonstrate how to use the fact that log requests in log4j are grouped in levels to filter log requests. We are going to enable the logging of some log requests and then we are going to disable them without removing them from the code.

This is how we will write the debug version of our application:

/*1*/  import org.apache.log4j.Level; /*2*/  import org.apache.log4j.Logger; /*3*/  import org.apache.log4j.BasicConfigurator; /*4*/  public class MyClass2 /*5*/  { /*6*/    static Logger lgr = Logger.getLogger("MyClass2"); /*7*/    static public void main(String[] ars) /*8*/    {  /*9*/      BasicConfigurator.configure(); /*10*/      lgr.debug( /*11*/        "This is a log request issued by the" /*12*/        +" debug() method!" /*13*/        );  /*14*/      lgr.info( /*15*/        "This is a log request issued by the" /*16*/        +" info() method!" /*17*/        );  /*18*/    }  /*19*/}

Run the code above and it will produce the following output:

Figure 2

You can easily figure out that all our log requests (the one issued by the debug() method in line 10 and the one issued by the info() method in line 14) are visible. This is how the debug version of our application behaves: All log requests are displayed.

Now consider that we are going to ship our application to our client and consider for the purpose of making things real that we do not have only 2 log requests as in our example but instead we have hundreds of log request. How could we eliminate all of log requests issued using the debug() method and maintain only those issued using the info() method? Traversing our code and manually deleting code lines that uses the debug() method is simply unrealistic. Now be prepared for the magic of log4j: Just add line 9.1 (from the code written below) to your code and you are done!

/*1*/   import org.apache.log4j.Level; /*2*/   import org.apache.log4j.Logger; /*3*/   import org.apache.log4j.BasicConfigurator; /*4*/   public class MyClass2 /*5*/   { /*6*/    static Logger lgr = Logger.getLogger("MyClass2"); /*7*/    static public void main(String[] ars) /*8*/    {  /*9*/      BasicConfigurator.configure(); /*9.1*/    lgr.setLevel(Level.INFO); /*10*/      lgr.debug( /*11*/        "This is a log request issued by the" /*12*/        +" debug() method!" /*13*/        );  /*14*/      lgr.info( /*15*/        "This is a log request issued by the" /*16*/        +" info() method!" /*17*/        );  /*18*/    }  /*19*/   }

Before we explain this magic, run our production version (figure 5) and it will produce the following output:

Figure 3

As you can see in the above output the log request(s) issued using the debug() method were eliminated and it remains only the log request(s) issued using the info() method. How we achieved this? Please read on ... 

The line we added commands log4j not to display any log requests with a level of importance lower than the level of importance of the log requests issued by the info() method. This is specifically what the parameter Level.INFO says. To be more precise, using this line we are performing a setting task on our logger object (lgr in this case) and telling him: "Dear logger lgr, Please do not actually display any log requests with an importance level less than Level.INFO even if we asked you to do so. You are a really clever logger, thank you very much." 

And; What is next?

It's obvious that this is a tutorial for the sole purpose to introduce log4j and to convince you why logging in general is useful and why log4j in particular should be used for this purpose. Please refer to the links section below for complete details about log4j.

Log4j Versions:

This tutorial is based on version (1.2.13) which is the latest available release version.

A later version (1.3) is now under beta testing and is expected to be released in Jun 2006. This version will include many new features and you may need to do some changes in your code to make it fully compatible with this version. For more about this refer to link [1] below.

Log4j Replacements and Alternatives

In JDK 1.4, you will find the API of java.util.logging. Although you will find it much similar to log4j with regard to it's architecture, log4j is still considered to be more rich with regard to it's functionality. 

NLOG4J is a production-quality replacement of log4j. For more about NLOG4J please refer to link [6]

Relevant Links and References

1. Preparing for log4j version 1.3
2. Log4j official website
3. Log4j documentation
4. To buy 'The complete log4j manual'
5. To download log4j
6. For more about NLOG4J