How To Use Lazy Loading for Efficient Java Logging

It is always a good Java programming practice to prefix log statements with a check for "loggability" by testing Logger.isLoggable(Level) prior to logging. However, this practice presents Java developers with a dilemma: Failing to do so results in slower performance, but following it contributes to more total lines of code. Often, developers opt to just bypass it.

In this intermediate Java tip, Jason Weinstein offers a solution: lazy loading. By wrapping Java logging in your own class (as shown below), you can ensure the isLoggable() test is always made, while at the same time lazily binding the message creation so that it occurs only when the message is going to be logged.

Logger logger = Logger.getLogger("your class name");

Here's an example of bad logging practice:

logger.log(Level.FINE, "your message " + foo + " " + bar);

Note the string concatenation and toString() calls made regardless of whether the message is logged or not.

Here's an example of good logging practice:

if (logger.isLoggable(Level.FINE)) {
    logger.log(Level.FINE, "your message " + foo + " " + bar);
}

Here's an example of how lazy logging can simplify the good practice above:

LazyLogger logger = LazyLogger.getLogger("your class name");

// avoids string concatenation and toString() method calls

    logger.log(Level.FINE, "your message ", foo, " ", bar);

Here's a full example class:

public class LazyLogger {
    private final Logger logger;

    public LazyLogger(Logger logger) {
        if (logger == null) {
            throw new IllegalArgumentException("logger cannot be null");
        }
        this.logger = logger;
    }

    public static LazyLogger getLogger(String name) {
        Logger logger = Logger.getLogger(name);
        return new LazyLogger(logger);
    }

    public void finest(Object... params) {
        log(Level.FINEST, params);
    }

    public void finer(Object... params) {
        log(Level.FINER, params);
    }

    public void fine(Object... params) {
        log(Level.FINE, params);
    }

    public void config(Object... params) {
        log(Level.CONFIG, params);
    }

    public void info(Object... params) {
        log(Level.INFO, params);
    }

    public void warning(Object... params) {
        log(Level.WARNING, params);
    }

    public void severe(Object... params) {
        log(Level.SEVERE, params);
    }

    public void log(Level level, Object... params) {
        // Check logging level before continuing
        if (logger.isLoggable(level)) {
            String message;
            if (params != null) {
                if (params.length == 1) {
                    message = String.valueOf(params[0]);
                } else {
                    StringBuilder buf = new StringBuilder();
                    for (Object param : params) {
                        buf.append(param);
                    }
                    message = buf.toString();
                }
            } else {
                message = "null";
            }
            logger.log(level, message);
        }
    }

    public static void main(String[] args) {
        LazyLogger logger = LazyLogger.getLogger("main");
        logger.log(Level.FINE, "Hello", " ", "World");
    }

Some More Tips by Experts on above article:

1. Be aware that the variable parameter list do not perform like a fix variable list.String's operator in modern JVM is highly optimized. The problem is not the concatenation of strings, The problem lies in foo & bar: the cost to get them (maybe need a call to a database) and to hold them (very long string representation). But then, foo & bar should not be logged.

2. More specifically, the problem isn't cat-ing Strings, it's garbage-collecting strings. Fewer strings helps, so this solution makes things better. Constant strings won't be garbage-collected. In practice, you'll also want methods that take Throwable as an argument. What would that make the varg-based API look like?

As a side note, instead of just declaring that the best-practice is to use an if-check on the logging level, you should discuss the problems with that approach. I've run into a lot of merge issues, especially with ClearCase. Critical logic gets merged into the if block. Something is broken, but turning logging on magically fixes the problem. Much aggravation follows. For some projects, we decided the best practice was to avoid the if's until they've proven to be a problem.

3.If I have to log big and different messages (real-time DB error message, or dynamic xml information, etc..) then in lazy logging the independent strings irrespective of the logging category under which the message is logged have to be built.

Ex:- The method call:
logger.log(Level.INFO, "Message : " myObj.toString());

builds the myObj string even if the logger level is sent to ERROR or FATAL level.
In case of services built in Java, issue becomes more prevalent as we need to judicially build the strings when they are needed because of the Java heap limits.


Thanks to Jason