8

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.

user2004685
  • 9,548
  • 5
  • 37
  • 54
  • What happens if you have a super long string that you need to split up with "+" for readability. But you still keep the "{}" placeholders. `logger.debug("Very very very very very very very very very very very very very" + " very very very very long {}", textName);` – Paul Erlenmeyer Mar 13 '22 at 00:38

3 Answers3

13

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.

larsgrefer
  • 2,735
  • 19
  • 36
  • What happens if you have a super long string that you need to split up with "+" for readability. But you still keep the "{}" placeholders. `logger.debug("Very very very very very very very very very very very very very" + " very very very very long {}", textName);` – Paul Erlenmeyer Mar 13 '22 at 00:36
  • @PaulErlenmeyer That's not a problem, This constant string concatenation will be performed ahead of time by the compiler. – larsgrefer Mar 14 '22 at 12:47
  • So only concatenation between method calls and strings matters? – Paul Erlenmeyer Mar 14 '22 at 18:22
  • 1
    Concatenations between String literals and/or String constants are fine, as they can be performed ahead of time by the compiler. It gets "bad" when non-constant expressions like method calls, local variables, or non-static fields are involved, where the concatenation has to be performed at runtime. – larsgrefer Mar 16 '22 at 02:51
  • Would there be performance difference if I use a StringBuilder vs this String formatting? – experiment unit 1998X Mar 27 '23 at 02:38
8

Some of the answers to this question explain:

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());
   }
Stephen C
  • 698,415
  • 94
  • 811
  • 1,216
0

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/

Mehmet Akbilgin
  • 1
  • 2