Logging in Java and in general: Best Practices?

Question

Sometimes when I see my logging code I wonder if I am doing it right. There might be no definitive answer to that, but I have the following concerns:

Library Classes

I have several library classes which might log some INFO messages. Fatal Errors are reported as exceptions. Currently I have a static logger instance in my classes with the class name as the logging name. (Log4j's: Logger.getLogger(MyClass.class))

Is this the right way? Maybe the user of this library class doesn't want any messages from my implementation or wants to redirect them to an application specific log. Should I allow the user to set a logger from the "outside world"? How do you handle such cases?

General logs

In some applications my classes might want to write a log message to a specific log not identified by the class' name. (I.e.: HTTP Request log) What is the best way to do such a thing? A lookup service comes to mind...

Answer 1

The preferred option for the kind of log4j configuration you're describing is to use the log4j configuration file. This allows users of your implementation to do exactly what you're asking for, since they can override your configuration later on with something more suitable for their own implementation. See here for a very thorough primer.

Answer 2

Your conventions are pretty standard and quite fine (imho).

The one thing to watch is memory fragmentation from excessive unnedded debug calls so, with Log4J (and most other Java logging frameworks), you end up with something like this:

if (log.isDebugEnabled()) {
  log.debug("...");
}

because constructing that log message (that you probably aren't using) could be expensive, especially if done thousands or millions of times.

Your INFO level logging shouldn't be too "chatty" (and from what you say, it sounds like it isn't). INFO messages should be generally meaningful and significant, like the application being started and stopped. Things that you might want to know if you encounter a problem. Debug/fine level logging is more used for when you actually have a problem you're trying to diagnose. Debug/fine logging is typically only turned on when needed. Info is typically on all the time.

If someone doesn't want specific INFO messages from your classes, they are of course free to change your log4j configuration to not get them. Log4j is beautifully straightforward in this department (as opposed to Java 1.4 logging).

As for your HTTP thing, I've generally not found that to be an issue with Java logging because typically a single class is responsible for what you're interested in so you only need to put it in one place. In the (rare in my experience) when you want common log messages across seemingly unrelated classes, just put in some token that can easily be grepped for.

Answer 3

In @cletus' answer, he wrote of the problem of

if (log.isDebugEnabled()) {
  log.debug("val is " + value);
}

which might be overcome by using SL4J. It provides a formatting help

log.debug("val is {}", value);

where the message is only constructed if the level is debug.

So, nowaday, using SL4J and its companion logger, Logback, is advised for performance and stability reasons.

Answer 4

With respect to instantiating loggers, I have had some success using an Eclipse Java Template for setting up my loggers:

private static Logger log = Logger.getLogger(${enclosing_type}.class);

This avoids the problem of a JVM mucking about with your stack trace, and reduces (trivially, perhaps) the overhead from creating the stack trace in the first place.

The great thing about using a template like this is that you can share it with your team if you want to set a consistent standard across the board for loggers.

It looks like IntelliJ supports the same concept for a template variable representing the name of the enclosing type. I don't see a way to do it easily in NetBeans.

Answer 5

I have probably stolen this from somewhere, but it's nice.

It reduces the risk of mixing up loggers when copying and pasti^h^h^h refactoring, and it's less to type.

In your code:

private final static Logger logger = LoggerFactory.make();

...and in LoggerFactory:

public static Logger make() {
    Throwable t = new Throwable();
    StackTraceElement directCaller = t.getStackTrace()[1];
    return Logger.getLogger(directCaller.getClassName());
}

(Note that the stackdump is done during initialisation. The stacktrace will probably not be optimized away by the JVM but there are actually no guarantees)

Answer 6

As an addition, I think it's important to mean Simple Logging Facade for Java (SLF4J) (http://www.slf4j.org/). Due to some issues of using different logging frameworks in diversified parts of a big project, SLF4J is the de facto standard to solve a problem to manage these parts successfully, isn't it?

The second one notion: it's seems that some old-school tasks can be substituted by Aspect-Oriented-Programming, Spring frmwrk has it's own implementation, AOP-approach for logging considered here at StackOverflow and here on Spring blog.