Convert logger.debug("message: " + text) to logger.debug(message: {}", text)

Question

I am trying to find the best way to address the issue of redundant string concatenation caused by using code of the following form:

logger.debug("Entering loop, arg is: " + arg) // @1

In most cases the logger.level is higher than debug and the arg.toString() and the string concatenation are a waste that user up cpu cycles and briefly use up memory.

Before the introduction of varargs the recommended approach was to test the logger level first:

if (logger.isDebugEnabled())    
  logger.debug("Entering loop, arg is: " + arg);  // @2

But now the preferred form is

  logger.debug("Entering loop, arg is: {}", arg); // @3

It is not very difficult to prefix each logger.debug with if (logger.isDebugEnabled()) (and its equivalent for the other methods) in a script, but I am trying to find the best way to convert the first form to the third.

Any suggestions? The challenge is to insert the correct number brace pairs {} in the format string. I wish logback would append the remaining arguments not covered by the placeholder at the end but I cannot find a reference that it does that.

As an alternative, I am thinking to write a class Concatenator as pasted at end and convert the first form to

logger.debug(new Concatenator("Entering loop, arg is: ", arg)); // @4

The Concatenator class delays the call to arg.toString() and string concatenation until the logger calls toString(), thereby avoiding both if the logger is at a higher filter level. It does add the overhead of creating an Object[] and a Concatenator but that should be cheaper than the alternative.

Questions:

• I think this conversion (@1->@4 -- replace + with , and enclose in new Contatenator(...)) is much easier. Is there something I am missing?
• Am I correct that @4 is much better than @1?

public class Concatenator {
    final Object[] input;
    String output;
    public Concatenator(Object... input) {
        this.input = input;
    }
    public String toString() {
        if (output == null) {
            StringBuffer b = new StringBuffer();
            for (Object s : input) b.append(s.toString());
            output = b.toString();
        }
        return output;
    }
    public static void main(String args[]) {
        new Concatenator("a", "b", new X());
        System.out.println(new Concatenator("c", "d", new X()));
    }
}
class X {
    public String toString() {
        System.out.println("X.toString");
        return super.toString();
    }
}

Answer 1

Unfortunately your approach isn't going to change anything. In fact, it introduces an additional object instantiation/allocation (your Concatenator). You're also using StringBuffer which introduces synchronization overhead you don't need.

The problem is the method signature for SLF4J's Logger.debug() calls. The first argument is always a String. This means you're going to have to call:

logger.debug(new Concatenator("Entering loop, arg is: ", arg).toString());

which means ... you're doing exactly the same thing as Java is going to do, but with more overhead.

The Java compiler handles the String concatenation operator (+) by creating a StringBuilder and doing exactly what you're doing in your Concatenator class on toString().

logger.debug("Entering loop, arg is: " + arg);

becomes:

logger.debug(new StringBuilder()
                 .append("Entering loop, arg is: ")
                 .append(arg).toString());

(If you use javap to look at the generated bytecode, you'll see that's the case.)

So, your current approach is going to be more expensive than what you have now.

Edit: So, the way you could make this work is by doing ...

logger.debug("{}", new Concatenator("Entering loop, arg is: ", arg));

This way your Concatenator is passed as an Object and its toString() not called unless the logger needs to. Also, replace the StringBuffer in your class with StringBuilder.

And if I didn't answer your question directly ... is this better than the original? Probably; The string concatenation isn't occurring unless it needs to. You are, however, introducing an object instantiation/allocation. The only real way to see the differences would be to profile it / write a benchmark.