views:

1441

answers:

8

I decided to use Log4J logging framework for a new Java project. I am wondering what strategy should I use for creating/managing Logger instances and why?

  • one instance of Logger per class e.g.

    class Foo { private static final Logger log = Logger.getLogger( Foo.class ); }

  • one instance of Logger per thread

  • one instance of Logger per application
  • horizontal slicing : one instance of Logger in each layer of an application (e.g. the view layer, the controller layer and the persistence layer)
  • vertical slicing : one instance of Logger within functional partitions of the application

Note: This issue is already considered to some extent in these articles:

The ultimate way to gettting [sic] Log4J loggers

Whats the overhead of creating a Log4j Logger

+6  A: 

Typically, you'd have loggers setup per class because that's a nice logical component. Threads are already part of the log messages (if your filter displays them) so slicing loggers that way is probably redundant.

Regarding application or layer based loggers, the problem is that you have to find a place to stick that Logger object. Not a really big deal. The bigger issue is that some classes may be used at multiple levels of from multiple applications... it could be difficult to get your logger right. Or at least tricky.

...and the last thing you want is bad assumptions in your logging setup.

If you care about applications and layers and have easy separation points, the NDC is the way to go. The code can be a little excessive sometimes but I don't know how many times I've been saved by an accurate context stack showing me that Foo.bar() was called from application X in layer Y.

PSpeed
+10  A: 

The strategy that is most used is to create a logger per class. If you create new threads give them a usefull name, so their logging is easily distinguishable.

Creating loggers per class has the benefit of being able to switch on/off logging in the package structure of your classes:

log4j.logger.org.apache = INFO
log4j.logger.com.example = DEBUG
log4j.logger.com.example.verbose = ERROR

The above would set all apache library code to INFO level, switch logging from your own code to DEBUG level with the exception of the verbose package.

rsp
I see the benefit if you want to control logging level by package structure. Is there a better way to achieve this than copying `private static Logger logger = Logger.getLogger(MyClass.class);` to each class?
Marcus
Given that you need some way to provide a logger instance both your package- and classname, I don't see an alternative to creating one per class. If you would create logger per package, you still would need to retrieve a reference to the logger instance in order to use it.
rsp
Which `Logger` constructor do you use do create a `Logger` for a package? Is it `getLogger(String name)` where name is just a String specifying the package (ie: "a.b.c")? If you do that can you configure the logging level as you mention a la `log4j.logger.a.b.c = INFO`?
Marcus
Yes, I think you would use the String variant as in `private static Logger logger = Logger.getLogger(MyClass.class.getPackage());` The logger hierarchy also works if you create loggers with names "a.b", "a.b.c", etc. See the manual at http://logging.apache.org/log4j/1.2/manual.html
rsp
A: 

Common convention is "a logger pr class and use the class name as its name". This is good advice.

My personal experience is that this logger variable should NOT be declared static but an instance variable which is retrieved for each new. This allows the logging framework to treat two calls differently depending on where they come from. A static variable is the same for ALL instances of that class (in that class loader).

Also you should learn all the possibilities with your logging backend of choice. You may have possibilities you did not expect possible.

Thorbjørn Ravn Andersen
Just a note, for log4j at least, if you are using the class name as the look up then it will be the same logger instance every time. No reason to grab it again and again for each class instance. You might as well keep it statically.
PSpeed
There are pros and cons for having static loggers. They can be problematic in managed containers and they shouldn't be used at all in code intended to run inside OSGi. See SLF4J's pros and cons: http://www.slf4j.org/faq.html#declared_static
hbunny
+2  A: 

As has been said by others, I would create a Logger per class:

private final static Logger LOGGER = Logger.getLogger(Foo.class);

However, I have found it useful in the past to have other information in the logger. For instance, if you have a web site, you could include the user ID in every log message. That way,, you can trace everything a user is doing (very useful for debugging problems etc).

The easiest way to do this is to use an MDC, but you can use a Logger created for each instance of the class with the name including the user ID.

Another advantage of using an MDC is if you use SL4J, you can change the settings depending upon the values in your MDC. So if you wish to log all activity for a particular user at DEBUG level, and leave all of the other users at ERROR, you can. You can also redirect different output to different places depending upon your MDC.

Some useful links:

http://logging.apache.org/log4j/1.2/apidocs/org/apache/log4j/MDC.html

http://www.slf4j.org/api/index.html?org/slf4j/MDC.html

MatthieuF
+1 For mentioning SLF4J
Tim
+1  A: 
  • Create one logger per class.
  • If you have dependencies that require Commons Logging (quite likely) use slf4j's bridge for Commons Logging. Instantiate your loggers (per class) using the Commons Logging interface: private static final Log log = LogFactory.getLog(MyClass.class);
  • Manifest this pattern in your IDE using shortcuts. I use IDEA's live templates for this purpose.
  • Provide contextual information to threads using an NDC (thread local stack of strings) or an MDC (thread local map of String → ?).

Examples for templates:

private static final Log log = LogFactory.getLog($class$.class); // live template 'log'

if (log.isDebugEnabled())
    log.debug(String.format("$string$", $vars$)); // live template 'ld', 'lw', 'le' ...
yawn
A: 

When deploying multiple EARs / WARs, it may be better to package the log4j.jar higher up in the classloader hierarchy.
i.e. not in WAR or EAR, but in the System-classloader of your container, otherwise multiple Log4J instances will write to the same file concurrently leading to strange behaviour.

Bas
+2  A: 

I'm certain this isn't a best practice, but I've sacked some startup time on applications before to save lines of code. Specifically, when pasting in:

Logger logger = Logger.getLogger(MyClass.class);

...developers often forget to change "MyClass" to the current class name, and several loggers always wind up pointing at the wrong place. This Is Bad.

I've occasionally written:

static Logger logger = LogUtil.getInstance();

And:

class LogUtil {
   public Logger getInstance() {
      String callingClassName = Thread.currentThread().getStackTrace()[2];
      return Logger.getLogger(callingClassName);
   }
}

The "2" in that code might be wrong, but the gist is there; take a performance hit to (on class load, as a static variable) find the class name, so that a developer doesn't really have a way to mistype this or introduce any error.

I'm generally not thrilled with losing performance to prevent developer error at runtime, but if it happens as a singleton, once? Often sounds like a good trade to me.

Dean J
+1  A: 
javaloper