Log4j Implicit String Formatting

Question

I am using log4j v1.2.14 for logging in my project and I am also using Java 7 String.format() to put variables in my output. Currently I am writing

LOGGER.info(String.format("Your var is [%s] and you are [%s]", myVar, myVar1));

Is this really the best way to output strings? I feel that log4j should have this implemented implicitly as below:

LOGGER.info("Your var is [%s] and you are [%s]", myVar, myVar1);

Have I missed something? Further, are there any Java logging frameworks that support this?

Look at slf4j, which I think implements this approach – Yosef Weiner Jun 22 '15 at 08:27 — Yosef Weiner, Jun 22 '15 at 08:27

score 74 · Accepted Answer · answered Jun 22 '15 at 09:53

74

slf4j's api provides "parameterized logging", which allows you to do exactly that, although with a slightly different syntax. The example there is:

logger.debug("Value {} was inserted between {} and {}.", newVal, below, above);

For an implementation, you can use Logback which implements slf4j natively, or the slf4j bindings to connect with log4j or other loggers. The User Manual explains that, along with a short example.

answered Jun 22 '15 at 09:53

Yosef Weiner

5,432
1
24
37

1

Just for additional information (maybe this has changed in the meantime): The plain log4j API supports this as well. The same code as you already wrote can be used. – Thomas Apr 29 '20 at 15:17

score 15 · Answer 2 · edited Oct 11 '22 at 22:54

15

Using String.format, +, or a string formatter other than the one provided by your logging system (log4j for example) is considered as a bad practice.

Usually, in the code there are lots of low level logs (debug, info) you don't want to see in production. If you use for example String.format to format the string to log, then you will allocate on the heap and format a new String, which can be very long and consume resources, even if at the end nothing will be logged (for example if the log4j min level is set to warning or error).

By using the logger formatter system (like the one from log4j), you allow your logger to avoid the generation of the formatted string if it doesn't need to be logged.

This may make a great difference in some cases.

edited Oct 11 '22 at 22:54

Victor Sergienko

13,115
3
57
91

answered Dec 07 '18 at 21:59

Mathieu

181
1
6

3

"is considered as a bad practice" ?? – Blessed Geek Feb 13 '19 at 03:37
Please elaborate on why that's bad practice. Also, a followup question (and I think the OP's actual question), what is the string formatter provided by log4j? Does one exist? – bobanahalf Aug 21 '19 at 14:55
This went a bit off-topic with what was asked but it is exactly what I was searching for (why the log4j parameters are better than using String.format). Thanks. Extra resource: http://www.slf4j.org/faq.html#logging_performance – Doug Nov 10 '20 at 07:45
I guess [calling varargs function](https://docs.oracle.com/javase/8/docs/technotes/guides/language/varargs.html) still implicitly allocates an `Array`. In this case, surrounding the log line with `log.isDebugEnabled()` should reduce the overhead even further. – Victor Sergienko Oct 11 '22 at 23:05

bobanahalf · Answer 3 · 2019-08-21T17:13:13.643

Log4j supports internal formatting. I haven't found it documented anywhere, but I saw an example of it here:

https://logging.apache.org/log4j/2.x/manual/markers.html

I tried it out and it works! I'm on log4j 2.11.2.

int i = 42;
String str1 = "the answer";
String str2 = "life, the universe, and everything";
console.info("{} is {} to {}", i, str1, str2);

Looking at the javadoc for Logger, I'd say it was introduced in Lo4j 2, and supports up to 10 parameters.

https://logging.apache.org/log4j/2.x/log4j-api/apidocs/org/apache/logging/log4j/Logger.html

score 1 · Answer 4 · answered Jun 22 '15 at 09:13

1

Btw, In this scenario there is not much difference between using + to add your variables to the string and String.format - unless you really want to reuse the "Your var is..." in all your logs.

slf4j lets you log as

log.info("Your var is {} and you are {}", myVar, myVar1);

Note the use of {} instead of print formatters. Also this requires Java >= 1.5

answered Jun 22 '15 at 09:13

ring bearer

20,383
7
59
72

1

Besides my personal preference, it is recommended best practice to use `String.format()`, usually because it is easier to read and modify: http://stackoverflow.com/questions/925423/is-it-better-practice-to-use-string-format-over-string-concatenation-in-java – Rossiar Jun 22 '15 at 09:14
`+` will allocate as many `String`s as there are `+` sings minus 1. `format()` will only allocate one `String` and one `Array`. – Victor Sergienko Oct 11 '22 at 23:31

Victor Sergienko · Answer 5 · 2022-10-11T23:36:18.377

I upvoted the "use logger.debug(format, varargs)" approach first, because it doesn't allocate extra String when it's not needed.

But then it occurred to me that logger.debug(String format, Object... varargs) still allocates an Array for the varargs.

Tried this on https://godbolt.org/noscript/java


class VarargTest {
    static boolean debugging = false;
    static void debug(String format, Object... args) {
       if (debugging) {
           System.out.println(String.format(format, args));
       }
    }

    static void logVarargs(int n) {
        debug("debug message {}", n);
    }

    static void logIf(int n) {
        if (VarargTest.debugging) {
            debug("debug message 2 " + n);
        }
    }
}

and indeed, the resulting debug() call allocates an Array.

So the fastest code should be

if (logger.isDebugEnabled()) {
    logger.debug("format {}", arg);
}

If it's not super performance critical, a more readable and reasonably fast code would be simply

    logger.debug("format {}", arg);

Log4j Implicit String Formatting

5 Answers5

Linked