Log4j : Debugging Concepts - Part-3

What we already have and what we do not?

In the previous tutorial we introduced you to the central concepts of log4j. Although, with just that amount of information we presented in the previous tutorial, you are able to use some log4j aspects, you are still in need to grasp some more advanced points to reveal the full power of log4j. An interesting feature of log4j is that you can make use of it with just a little amount of knowledge about it and in the same time a developer who is keen to utilize it's full power can acquire at least a linear (or should we say exponential?) effort / benefit curve.

By now, you should be familiar with what is logging and for what purposes should we use it. You should have the skill of deciding when to use (or not to use) logging. The major central concepts (e.g., loggers, appenders, and layouts) of log4j should be present in your mind as well.

We are going in this tutorial to reveal more about these central concepts, to present new concepts to your attention, to give you more skills in using log4j, and most importantly, we are going to give you some real world examples for using log4j.

Levels; The complete story

We mentioned in the first tutorial that every log request has it's own level of importance (which we called simply a level). We mentioned as well that log requests issued using the info() method have higher importance level than log requests issued using the debug() method. The concept of levels allowed us to use the nice feature of blocking log requests that have a level of importance less than a specified amount. For example, we were able to block log requests issued using the debug() method and in the same time maintain all log requests issued using the info() method. This is just a part of the story and we are going to tell you here the complete story.

It's not about the two importance levels of the methods info(), and debug(). It's about a full featured set of methods by which you can issue log requests each of them has it's own level of importance. Here we present you the full list of these methods along it's associated importance level. While reading inside this table do not forget that all these methods are essentially identical with regard to that they all simply issue loge requests. What makes you prefer one of them in a particular line of your code is that you want to give your log request this specific level of importance which will, in turn, allow you to filter (in, or out) this specific log request in the future.

Method	Importance Level	Usage
debug()	Level.DEBUG - Least Importance Level	Issues log requests that are relevant while debugging the application.
info()	Level.INFO	Issues log requests that informs the user of the application about something (e.g., informs him about application progress)
warn()	Level.WARN	When you need to alert about harmful situations, issue a log request using this method.
error()	Level.ERROR	When an error is encountered (but you application can still run) issue a log request using this method.
fatal()	Level.ERROR	In case of very sever errors after which your application cannot continue any more, issue a log request using this method.

When we first started using log4j long time ago, we attempted to strictly follow the guidelines mentioned in the 'usage' column in the table above. We never been able to fix the usage of these methods! What seems to be a warning (i.e., warn()) for one team member seems to be an error (i.e., error()) from the point of view of another member. So, never care about the usage of these methods, care only about that they are from distinct importance levels. On the other hand, our experience shows that the ambiguity about the usage of these methods can be easily resolved when our team has it's own strict and jointly agreed log requests classification policy, beyond this specified by us in the above table. Your team can do the same as well.

Loggers; Round #2

As for now you should understand that the logger class is of central importance in log4j and that using it you issue most (if not all) of your log requests. We should emphasize here that the logger class can be used, as well, in customizing the logger (which will essentially affect the log requests issued by this particular logger).

For the purpose of the following decision, recall the important feature of log4j loggers that they are typically organized into hierarchical structures. This hierarchical structure is achieved by naming them using the Grandparent.Parent.Child naming convention we described before. We mentioned in the previous tutorial how greatly this naming convention gives unlimited flexibility for customizing these loggers (e.g., doing an action on logger x will automatically affect loggers x.y1 and x.y2 as well). You will see all of this in real action shortly!

Loggers vs. Levels; Can they cooperate for your advantage?

As for now, we defined the level of a log request to be how important this log request. We are presenting here another definition (or more specifically another use) of the term level. Be careful not to confuse this new use with the first one.

Let's first stress on that the only scheme we presented up to now for issuing a log request of a specified level is to use debug(), info(), warn(), error(), or fatal() (respectively) to indicate how important the log request.

Here's the good news: A logger can be assigned a level! So what? What benefits you will get from assigning a level for your logger? Curious? OK, read the following example then:

Example 1: A logger can be assigned a level

The purpose of this example is to show you how assigning a level to your logger can add much more flexibility to your logging experience.

To keep this example to the point we will not stick to the recommendation of naming loggers with the same name of the class inside which they are first created.

Compile and run the following code:

import org.apache.log4j.Level; import org.apache.log4j.Logger; import org.apache.log4j.BasicConfigurator; public class Class1 {   //----------   static Logger lgr1 = Logger.getLogger("Class1");   static Logger lgr2 = Logger.getLogger("Class1.x");   static Logger lgr3 = Logger.getLogger("Class1.y");   static Logger lgr4 = Logger.getLogger("Class1.x.a1");   static Logger lgr5 = Logger.getLogger("Class1.x.a2");   static Logger lgr6 = Logger.getLogger("Class1.x.a3");   static Logger lgr7 = Logger.getLogger("Class1.y.b1");   static Logger lgr8 = Logger.getLogger("Class1.y.b2");   //----------   static public void main(String[] ars)   {      BasicConfigurator.configure();     //----------     lgr1.debug("This is from logger lgr1");     lgr2.debug("This is from logger lgr2");     lgr3.debug("This is from logger lgr3");     lgr4.debug("This is from logger lgr4");     lgr5.debug("This is from logger lgr5");     lgr6.debug("This is from logger lgr6");     lgr7.debug("This is from logger lgr7");     lgr8.debug("This is from logger lgr8");     //----------   }  }

You will simply, and certainly, get the following output:

Figure 1

What a simple example! We just wanted to show a simple fact that will change soon, all loggers are able to show the least important log request issued using the debug() method.

Now change your code as indicated below and compile it:

import org.apache.log4j.Level; import org.apache.log4j.Logger; import org.apache.log4j.BasicConfigurator; public class Class1 {   //----------   static Logger lgr1 = Logger.getLogger("Class1");   static Logger lgr2 = Logger.getLogger("Class1.x");   static Logger lgr3 = Logger.getLogger("Class1.y");   static Logger lgr4 = Logger.getLogger("Class1.x.a1");   static Logger lgr5 = Logger.getLogger("Class1.x.a2");   static Logger lgr6 = Logger.getLogger("Class1.x.a3");   static Logger lgr7 = Logger.getLogger("Class1.y.b1");   static Logger lgr8 = Logger.getLogger("Class1.y.b2");   //----------   static public void main(String[] ars)   {      BasicConfigurator.configure();     //---------- /*A*/    lgr2.setLevel(Level.INFO);     lgr1.debug("This is from logger lgr1");     lgr2.debug("This is from logger lgr2");     lgr3.debug("This is from logger lgr3");     lgr4.debug("This is from logger lgr4");     lgr5.debug("This is from logger lgr5");     lgr6.debug("This is from logger lgr6");     lgr7.debug("This is from logger lgr7");     lgr8.debug("This is from logger lgr8");     //----------   }  }

Run it and you will see the following output:

Figure 2

As you can see not all loggers are able to show their log requests now! How come?

Recall that the only change we did is the addition of line A. What is the meaning of this line? Simple, it means that you are asking log4j to block all log requests that are issued by logger lgr2 (Class1.x) if they are of importance level less than Level.INFO

This way you can justify why that logger lgr2 was unable to show its log request and hence we are unable to see its log request in the figure above.

But, wait a moment, line A affects lgr2, right? Then how come that the log requests from lgr4, lgr5, and lgr6 (Class1.x.a1, Class1.x.a2, and Class1.x.a3 respectively) are affected as well? They are not referenced in line A at all!

A careful reader to the previous tutorial can simply answer this question. We mentioned before that the hierarchal structure of loggers that comes as a result to the Grandparent.Parent.Child naming convention gives us the flexibility of affecting children by simply altering their parent. Since logger lgr2 (Class1.x) is the parent of loggers lgr4, lgr5, and lgr6 (Class1.x.a1, Class1.x.a2, and Class1.x.a3 respectively) then any customization that affects lgr2 will certainly affect its children as well.

One may ask, but what if we explicitly specified a level for a logger that is different from the level explicitly specified for its parent? The answer is that the level specified for the child will take precedence over the level specified for its parent. Think about it like this:

The logger asks itself whether a level was explicitly specified for it? if so it uses this level and ignores any levels specified to it's ancestors.

If not, it asks whether its immediate ancestor has an explicitly specified level? if so, it uses the level specified for it's ancestor and if not the process continues up to the highest possible level in the loggers hierarchy.

But what if none of all of them has its level specified? This is essentially the case mentioned before in which all loggers are able to show their log requests: There is no filtering at all in this case given that there is not reason for filtering other than the subject of this example: Levels assigned to loggers.

Why this example is useful? 

This example attempts to delivers a set of important ideas:

A logger can be assigned a level such that it will not be able to issue log requests less than a certain level of importance. Like any thing else, this exact level will be applied to all of the children of the logger unless some of them were selectively configured otherwise.

Yet another magic touch by log4j: This way you can have a complete tree of loggers (say 100 logger) and with only one line of code you can filter 50 of them out and keep the rest (of course given that these 50 to be filtered out are all children of the same logger). For example, assume you have a huge application; you can design its logger’s hierarchy such that all of the loggers that belong to a given module of your application are all children of a single parent logger. This way you can simply filter in / out the logging requests coming from complete parts of this huge application.

Can I have them all?

Although you have the flexibility of setting the level of every individual logger in your application as well setting the level of a set of loggers in a complete branch in your loggers hierarchy (by setting the level of their parent) you may sometimes opt to do some filtering on all of your loggers in your entire application in the same time.

This can be simply achieved by setting the level of your entire hierarchy using the repository.setThreshold() (You will have to import org.apache.log4j.spi.LoggerRepository). For example:

repository.setThreshold(Level.WARN);

The above example causes any log requests coming from any logger that have a level of importance less than Laval.WARN to be blocked.

In the following table you will be presented to some interesting uses of the repository.setThreshold() method:

Syntax	Effect
repository.setThreshold(Level.ALL);	No hierarchy wide filtering is performed. Any log request will not be blocked given that its level is higher than or equal the level assigned to the logger issuing this log request.
repository.setThreshold(Level.X);	Partial hierarchy wide filtering is performed. If you are issuing a log request that has an importance level of X or higher it will not be filtered out. Of course you have to make sure that this log request is allowed by the level of the logger issuing it as well.
repository.setThreshold(Level.OFF);	Full hierarchy wide filtering is performed. No logger whatever its level will be able to issue any log requests. All log requests are completely disabled.

Be careful here, we said: "Doing some filtering on all log requests coming from all of your loggers" not "Changing the level of all of your loggers". You have to be careful enough to grasp that we are not setting the level of all of our loggers, and that they remain with their levels even after using the repository.setThreshold() method. All what happens is that a filter is applied on the entire log4j loggers’ hierarchy to filter out any log requests you do not need. When this hierarchy wide filter is removed later, none of your loggers has it's level changed at all.