String concatenation performance in Log4j

Question

I have often heard people saying that its one of the best practices to avoid String Concatenation and use {} instead while logging.

I was looking into the Log4j code to see how they have handled this and figured that they are doing something similar.

Here is a snippet of format() method which takes the pattern and arguments and returns the message to be logged.

/**
 * Formats arguments using SLF4J-like formatter.
 * @param pattern pattern, may be malformed.
 * @param arguments arguments.
 * @return Message string
 */
private static String format(final String pattern,
                             final Object[] arguments) {
    if (pattern != null) {
        String retval = "";
        int count = 0;
        int prev = 0;
        int pos = pattern.indexOf("{");
        while(pos >= 0) {
            if (pos == 0 || pattern.charAt(pos-1) != '\\') {
                retval += pattern.substring(prev, pos);
                if (pos + 1 < pattern.length() && pattern.charAt(pos+1) == '}') {
                    if(arguments != null && count < arguments.length) {
                        retval += arguments[count++];
                    } else {
                        retval += "{}";
                    }
                    prev = pos + 2;
                } else {
                    retval += "{";
                    prev = pos + 1;
                }
            } else {
                retval += pattern.substring(prev, pos - 1) + "{";
                prev = pos + 1;
            }
            pos = pattern.indexOf("{", prev);
        }
        return retval + pattern.substring(prev);
    }
    return null;
}

I'm not able to understand how this implementation is better than using concatenation. Any insights into this will be really helpful.

Answer 1

The benefit of format strings in logging systems is, that the logging system can decide if the string concatenation must happen or not.

Let's use these lines as example:

log.debug("Count: " + list.size());
log.debug("Count: {}", list.size());

As long as the level for this logger is debug or below, there is no difference in performance, but if the log level is higher than debug the second line won't perform the concatenation at all.

Answer 2

Some of the answers to this question explain:

• Logger slf4j advantages of formatting with {} instead of string concatenation

The short version is that format-based usage faster because in

   Logger.debug("my name is {}", name);

the expensive string bashing only occurs after log4j decides that the event needs to be logged; e.g. after the filtering based on the logging level, etcetera.

By contrast, with the string concatenation version

   Logger.debug("my name is " + name);

the string bashing happens while evaluating the arguments. Thus, it happens even in the cases where no event is actually logged. You can partially avoid that by adding "guards" in your code (see below), but doing that makes your applications logging calls verbose.

---

But take a look at this example:

   log.debug("Count: " + list.size());
   log.debug("Count: {}", list.size());

The format version will be faster, but both versions always evaluate the list.size() expression. If that is an expensive operation, then you may need to resort to using a guard; e.g.

   if (log.isDebugEnabled()) {
       log.debug("Count: " + list.size());
   }

Answer 3

Alternative to not execute list.size() :

// Instead of
if (log.isDebugEnabled()) {
   log.debug("Count: " + list.size());
}

// Use if >= Java 8
log.debug("Count: {}", () -> list.size());

This will evaluate list.size() only when needed.

Credit : https://garygregory.wordpress.com/2015/09/16/a-gentle-introduction-to-the-log4j-api-and-lambda-basics/