How to log formatted message, object array, exception?

Question

What is the correct approach to log both a populated message and a stack trace of the exception?

logger.error(
    "\ncontext info one two three: {} {} {}\n",
    new Object[] {"1", "2", "3"},
    new Exception("something went wrong"));

I'd like to produce an output similar to this:

context info one two three: 1 2 3
java.lang.Exception: something went wrong
stacktrace 0
stacktrace 1
stacktrace ...

My SLF4J version is 1.6.1.

Solution 1

As of SLF4J 1.6.0, in the presence of multiple parameters and if the last argument in a logging statement is an exception, then SLF4J will presume that the user wants the last argument to be treated as an exception and not a simple parameter. See also the relevant FAQ entry.

So, writing (in SLF4J version 1.7.x and later)

 logger.error("one two three: {} {} {}", "a", "b", 
              "c", new Exception("something went wrong"));

or writing (in SLF4J version 1.6.x)

 logger.error("one two three: {} {} {}", new Object[] {"a", "b", 
              "c", new Exception("something went wrong")});

will yield

one two three: a b c
java.lang.Exception: something went wrong
    at Example.main(Example.java:13)
    at java.lang.reflect.Method.invoke(Method.java:597)
    at ...

The exact output will depend on the underlying framework (e.g. logback, log4j, etc) as well on how the underlying framework is configured. However, if the last parameter is an exception it will be interpreted as such regardless of the underlying framework.

Solution 2

In addition to @Ceki 's answer, If you are using logback and setup a config file in your project (usually logback.xml), you can define the log to plot the stack trace as well using

<encoder>
    <pattern>%date |%-5level| [%thread] [%file:%line] - %msg%n%ex{full}</pattern> 
</encoder>

the %ex in pattern is what makes the difference

Comments

[Keith Tyler]

I don't understand why slf4j uses its own format string syntax instead of the standard %s style. Annoying.

[Betlista]

@KeithTyler I like {} more, the matter of taste...

[user149408]

@KeithTyler The toString() method of the arguments might be expensive. With this syntax, only a reference to each object is passed and the toString() method is only called if the particular message is actually getting logged. Objects referenced in an info() log call will not have their toString() method called if the log level is WARN or higher. The {} syntax is a reminder to users that this is not a String.format()-like operation, i.e. they should pass objects rather than string representations thereof.

[Ceki]

Which underlying logging framework are you using? As mentioned in my answer above, if the last parameter is an exception it will be interpreted as such regardless of the underlying framework. (Tested with logback, slf4j-log4j12, slf4j-jdk14 and slf4j-simple. )

[rowe]

Sorry, I did not recognize that in your example you used n=3 placeholders in the format string and n+1=4 elements in the object array. I had n placeholders in the format string and also n elements in the object array plus an exception as third parameter. My expectation was that the exception would be printed with stacktrace but this never happened. Does this work as designed? Also, if I have n placeholders and n elements in the object array with an exception being the last element I don't see any stacktrace. Maybe the n placeholders with n+1 objects in an array should be a bit more emphasized.

[Adam Gent]

I was going give @Ceki a hard time about it not being in the Javadocs but its at the top of the Logger javadoc class: slf4j.org/apidocs/org/slf4j/Logger.html

[Betlista]

I created improvement request, you can vote for it if you like it.

[dfche]

Do you know how to make Intellij IDEA 2020.2.3 not to complain about this? It gives me a warning The formatted log message expects N arguments, passed N-1 so I'm forced to use String.format()