2015-08-19

Log4j: A Debugging Perspective (Part1)

Who are you?

If you or your client once discovered a bug in your application and never being able to reproduce it again.
If you once felt that your too late discovered application bug let you down by reducing your reputation in front of your client.
If you are not completely satisfied with the traditional debugger you are using or even have no access to a debugger at all.
If you ever set in front of your running application wondering what it's doing now and what exact parts of it are currently being executed.
You are already familiar with Java, know how to compile your code, and how to use JDK.
If you are any one of the those people then please read on ... logging is for you!
Introduction

Every time we attend a meeting or a conference that is some how related to debugging, we frequently hear the famous statement: 'Fixing bugs is not easy!'. Our experience shows that fixing bugs is rather easy. What makes people think like that is they topically mix discovering the location of a bug inside their code and actually fixing it. If you are to discover where your bug is, then fixing it is no more than doing some changes in a line or two of code. Very rare bugs that can cause dramatic / architectural changes to you application. Logging is concerned (among few other concerns) with the process of discovering bugs and can be a great aid for this purpose.

What is logging?

Logging is one of the low level technologies that can be used for debugging your code. Like a debugger watch which enables you to view variables values, logging can be an aid for you to print out your variables current values for example. Logging in it's simplest form involves placing overhead statements in your code that prints out a value of a variable or indicates the occurrence of an event of particular interest to you.

 
When to use logging?

Logging is not a replacement for the well established and the standardized testing activities that are well known in software engineering. If you already implemented your test plan that was successful enough that aided you in the discovery of most of the bugs in your application, then logging is exactly for you. After all this extensive testing you cannot be absolutely sure that your application is 100% bug free and will never fail. This is where the use of logging can provide you with continues monitoring for your application so that you are always sure about what is happening inside your application.

Egyptians say: "You can sometimes hit two or more birds with only one bullet". If you want to add auditing or profiling to your application then logging can be used to achieve this while in the same time aids you in testing and debugging your application.

Ever wondered why should you use log4j; Why logging is useful?

Logging is typically confused with the use of tradition debuggers. Here we present a set of important facts that are vital to your understanding of why logging is important in some cases. Although logging can be considered as one of the techniques that can be used for the purpose of debugging a particular application, it has several significantly distinct features if compared to the use of a traditional debugger. In the following table we list some of these significantly unique features to give you the skill judging which of them is appropriate in which scenario:

Aspect Logging Using a traditional debugger
Attendance Can be performed by your application while it's unattended. In other words, you can safely leave you application running and later analyze it's output log files for whatever information you need. Must be attended. Some professional must be setting all the time monitoring the debugging sessions and judging the behavior of the application being debugged.
Information display The display of the debugging data can be as sophisticated, detailed, and formatted as you like. Do not consider it a strange case to have graphs for example as an output for your application logs. You are limited to the display options that are available inside your debugger. For most cases these options are rather limited if compared to the unlimited flexibility of information display in customized logging.
Ability of further information analysis Can allow exporting logging data to many third party tools outside the application being debugged for proper display and analysis. For example you can export data from your application logs into spreadsheets and relational database management systems, hence benefiting from their rich analysis tools. This can be particularly useful when you need to analyze huge amounts of data that cannot be analyzed by a human in front of a screen as in the debugger case. The data you are seeing on the screen while in a debugging session is highly volatile and has the life only of the debugging session. The maximum you can do is to sometimes copy data from your debugger to another analysis application which is incomparable to the data transfer capabilities of the logging case.
Platform dependence You can simply, seamlessly, and transparently analyze your logging data on a machine that is totally different from the machine on which you run your application (difference can be in hardware, operating system, ... etc). This is particularly useful when the machine on which you have to run your application is not equipped with the analysis tools you need to analyze your logs. With reference to this feature, logging can be considered to be 100% platform independent. A debugger designed for a particular platform cannot be used on a different one. With the exception of some limited remote debugging cases, the debugger must be running on the same machine on which your application is running. This assumes this particular machine has a debugger suitable for it; some platforms have no debuggers at all.
Alteration of the useful code This is one of the disadvantages involved when using logging. You have to alter your useful code with extra overhead lines of code to implement a proper logging mechanism. If a debugger is available, you can immediately debug your application without altering a single line in it's code.
Availability Always available. If you can write an application and run it on a particular platform, then you are essentially able to implement logging for your application on this platform. Platform is not an issue at all in logging. Sometimes logging is used for a single reason: There is no debugger available for this platform. There must be a debugger that is designed specifically to run on the particular platform under which the application being debugged is run.
Mobility You can send your logging data to anywhere for later unattended analysis. A professional must be setting in person in the front of the debugger while in the debugging session. While you can overcome this using remote desktop tools or a remote debugger, it's apparent it's a reduced flexibility if compared to the logging case.
Debugging special applications In certain cases the use of debuggers is not feasible even if debuggers are available. Take for example the debugging of a graphical application in which the switching from the graphics display adapter mode in which the application is running to the mode in which the debugger can be run is not practically possible. Take as another example the debugging of real time system applications in which data acquisition is performed very fast that tracking it using a debugger is not practical at all. In the first case, the silent behavior of logging to files is very desirable. In the later case the ability of very quickly logging the data being collected to log files is highly desirable as well. Several similar examples exist like distributed applications and multithreaded applications. Even if available for a particular platform, its use can be impossible at all or at least impractical for applications of special behavior.
Performance The application performance can be affected by adding the overhead logging lines to your code. By careful design and the use of the proper logging technology, you can reduce this performance degradation to forgivable amounts. With exception to the specially built debugging version of an application, debuggers can be considered to place a little change in application performance.
Code lines granularity and control You can have clues about which part of your application is being executed now but of course not to the same fine level as in the traditional debugger case. You cannot have a control over the code being run other than the control that is built by the developer of the application being debugged. You can execute your code while monitoring what code is being run to any granularity, line by line or even instruction by instruction. You have finer control and can for example bypass certain code lines, repeat other, and even you can stop your application at any time.
Although we did not list every possible aspect of this comparison you can take the flavor of when logging is more applicable than the use of traditional debuggers. When it's a about a machine working by its own generating massive amounts of data for later analysis then we are talking about logging. When it's about an interactive session that is attended all the time and a human is exist to monitor the session's humanly readable data then we simply use traditional debuggers. An important last distinction between the two scenarios is that you can opt for your application to continue forever with the logging built inside it but on the other hand you will not be able to run your production application version under a debugger every time forever.

An absolute reason for which you will be convinced that logging (in certain cases) is far more suitable than the use of traditional debuggers is the answer of this question: "Who know more about your code? Your code itself or a traditional debugger?" When you are debugging by logging then your code is taking care of it and your code is of course more aware about itself than any possible traditional debugger --- Judge by yourself!

So, up to now we are recommending logging and exposing its advantages. The important question now is whether or not all of these advantages come for free? Of course you have to pay. The major inconveniencies involved in employing logging are the decreased application performance and (naturally) the extra effort of implementing logging inside your code. In a traditional debugger you simply plug your application into the debugger and you are done. In logging you certainly need more efforts. If logging is implemented carefully, then its effect on application performance can be made of minimum significance.

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.

Extract the archive you downloaded to any folder.
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
2
3
4
5
6
7
8
9
10
11
/*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:

Initialize / configure log4j first (using the BasicConfigurator.configure() method)
Retrieve a logger (using the Logger.getLogger() method)
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

Preparing for log4j version 1.3
Log4j official website
Log4j documentation
To buy 'The complete log4j manual'
To download log4j
For more about NLOG4J
About the Author:

ThinkAndCare was first established in 1989 as one of the very first pioneers in the IT industry in Egypt. Along its 17 years of age, ThinkAndCare played a major (if not an exclusive) rule in the production and delivery of several Software Development related titles to the Egyptian market. Being deeply involved in the field of Software Development and Software Engineering, ThinkAndCare was able to produce outstanding training products if compared to their competitors who are specialized solely in the training field.

Who are you?

If you or your client once discovered a bug in your application and never being able to reproduce it again.
If you once felt that your too late discovered application bug let you down by reducing your reputation in front of your client.
If you are not completely satisfied with the traditional debugger you are using or even have no access to a debugger at all.
If you ever set in front of your running application wondering what it's doing now and what exact parts of it are currently being executed.
You are already familiar with Java, know how to compile your code, and how to use JDK.
If you are any one of the those people then please read on ... logging is for you!
Introduction

Every time we attend a meeting or a conference that is some how related to debugging, we frequently hear the famous statement: 'Fixing bugs is not easy!'. Our experience shows that fixing bugs is rather easy. What makes people think like that is they topically mix discovering the location of a bug inside their code and actually fixing it. If you are to discover where your bug is, then fixing it is no more than doing some changes in a line or two of code. Very rare bugs that can cause dramatic / architectural changes to you application. Logging is concerned (among few other concerns) with the process of discovering bugs and can be a great aid for this purpose.

What is logging?

Logging is one of the low level technologies that can be used for debugging your code. Like a debugger watch which enables you to view variables values, logging can be an aid for you to print out your variables current values for example. Logging in it's simplest form involves placing overhead statements in your code that prints out a value of a variable or indicates the occurrence of an event of particular interest to you.

 
When to use logging?

Logging is not a replacement for the well established and the standardized testing activities that are well known in software engineering. If you already implemented your test plan that was successful enough that aided you in the discovery of most of the bugs in your application, then logging is exactly for you. After all this extensive testing you cannot be absolutely sure that your application is 100% bug free and will never fail. This is where the use of logging can provide you with continues monitoring for your application so that you are always sure about what is happening inside your application.

Egyptians say: "You can sometimes hit two or more birds with only one bullet". If you want to add auditing or profiling to your application then logging can be used to achieve this while in the same time aids you in testing and debugging your application.

Ever wondered why should you use log4j; Why logging is useful?

Logging is typically confused with the use of tradition debuggers. Here we present a set of important facts that are vital to your understanding of why logging is important in some cases. Although logging can be considered as one of the techniques that can be used for the purpose of debugging a particular application, it has several significantly distinct features if compared to the use of a traditional debugger. In the following table we list some of these significantly unique features to give you the skill judging which of them is appropriate in which scenario:

Aspect Logging Using a traditional debugger
Attendance Can be performed by your application while it's unattended. In other words, you can safely leave you application running and later analyze it's output log files for whatever information you need. Must be attended. Some professional must be setting all the time monitoring the debugging sessions and judging the behavior of the application being debugged.
Information display The display of the debugging data can be as sophisticated, detailed, and formatted as you like. Do not consider it a strange case to have graphs for example as an output for your application logs. You are limited to the display options that are available inside your debugger. For most cases these options are rather limited if compared to the unlimited flexibility of information display in customized logging.
Ability of further information analysis Can allow exporting logging data to many third party tools outside the application being debugged for proper display and analysis. For example you can export data from your application logs into spreadsheets and relational database management systems, hence benefiting from their rich analysis tools. This can be particularly useful when you need to analyze huge amounts of data that cannot be analyzed by a human in front of a screen as in the debugger case. The data you are seeing on the screen while in a debugging session is highly volatile and has the life only of the debugging session. The maximum you can do is to sometimes copy data from your debugger to another analysis application which is incomparable to the data transfer capabilities of the logging case.
Platform dependence You can simply, seamlessly, and transparently analyze your logging data on a machine that is totally different from the machine on which you run your application (difference can be in hardware, operating system, ... etc). This is particularly useful when the machine on which you have to run your application is not equipped with the analysis tools you need to analyze your logs. With reference to this feature, logging can be considered to be 100% platform independent. A debugger designed for a particular platform cannot be used on a different one. With the exception of some limited remote debugging cases, the debugger must be running on the same machine on which your application is running. This assumes this particular machine has a debugger suitable for it; some platforms have no debuggers at all.
Alteration of the useful code This is one of the disadvantages involved when using logging. You have to alter your useful code with extra overhead lines of code to implement a proper logging mechanism. If a debugger is available, you can immediately debug your application without altering a single line in it's code.
Availability Always available. If you can write an application and run it on a particular platform, then you are essentially able to implement logging for your application on this platform. Platform is not an issue at all in logging. Sometimes logging is used for a single reason: There is no debugger available for this platform. There must be a debugger that is designed specifically to run on the particular platform under which the application being debugged is run.
Mobility You can send your logging data to anywhere for later unattended analysis. A professional must be setting in person in the front of the debugger while in the debugging session. While you can overcome this using remote desktop tools or a remote debugger, it's apparent it's a reduced flexibility if compared to the logging case.
Debugging special applications In certain cases the use of debuggers is not feasible even if debuggers are available. Take for example the debugging of a graphical application in which the switching from the graphics display adapter mode in which the application is running to the mode in which the debugger can be run is not practically possible. Take as another example the debugging of real time system applications in which data acquisition is performed very fast that tracking it using a debugger is not practical at all. In the first case, the silent behavior of logging to files is very desirable. In the later case the ability of very quickly logging the data being collected to log files is highly desirable as well. Several similar examples exist like distributed applications and multithreaded applications. Even if available for a particular platform, its use can be impossible at all or at least impractical for applications of special behavior.
Performance The application performance can be affected by adding the overhead logging lines to your code. By careful design and the use of the proper logging technology, you can reduce this performance degradation to forgivable amounts. With exception to the specially built debugging version of an application, debuggers can be considered to place a little change in application performance.
Code lines granularity and control You can have clues about which part of your application is being executed now but of course not to the same fine level as in the traditional debugger case. You cannot have a control over the code being run other than the control that is built by the developer of the application being debugged. You can execute your code while monitoring what code is being run to any granularity, line by line or even instruction by instruction. You have finer control and can for example bypass certain code lines, repeat other, and even you can stop your application at any time.
Although we did not list every possible aspect of this comparison you can take the flavor of when logging is more applicable than the use of traditional debuggers. When it's a about a machine working by its own generating massive amounts of data for later analysis then we are talking about logging. When it's about an interactive session that is attended all the time and a human is exist to monitor the session's humanly readable data then we simply use traditional debuggers. An important last distinction between the two scenarios is that you can opt for your application to continue forever with the logging built inside it but on the other hand you will not be able to run your production application version under a debugger every time forever.

An absolute reason for which you will be convinced that logging (in certain cases) is far more suitable than the use of traditional debuggers is the answer of this question: "Who know more about your code? Your code itself or a traditional debugger?" When you are debugging by logging then your code is taking care of it and your code is of course more aware about itself than any possible traditional debugger --- Judge by yourself!

So, up to now we are recommending logging and exposing its advantages. The important question now is whether or not all of these advantages come for free? Of course you have to pay. The major inconveniencies involved in employing logging are the decreased application performance and (naturally) the extra effort of implementing logging inside your code. In a traditional debugger you simply plug your application into the debugger and you are done. In logging you certainly need more efforts. If logging is implemented carefully, then its effect on application performance can be made of minimum significance.

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.

Extract the archive you downloaded to any folder.
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:

Initialize / configure log4j first (using the BasicConfigurator.configure() method)
Retrieve a logger (using the Logger.getLogger() method)
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.

No comments:

Post a Comment