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.

I don't understand why slf4j uses its own format string syntax instead of the standard %s style. Annoying. — Keith Tyler, Jul 31 '19 at 17:36
@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. — user149408, Apr 28 '20 at 13:25

score 512 · Answer 1 · edited Jan 23 '20 at 04:49

512

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.

edited Jan 23 '20 at 04:49

Betlista

10,327
13
69
110

answered Jun 16 '11 at 15:12

Ceki

26,753
7
62
71

4

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. ) – Ceki Jun 20 '11 at 10:37
3

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. – rowe Jun 22 '11 at 13:19
8

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: http://www.slf4j.org/apidocs/org/slf4j/Logger.html – Adam Gent Apr 20 '13 at 20:43
2

I created [improvement request](https://jira.qos.ch/browse/SLF4J-482), you can vote for it if you like it. – Betlista Jan 23 '20 at 05:18
1

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()` – dfche Jul 07 '21 at 14:41

score 10 · Answer 2 · edited Jan 23 '20 at 04:50

10

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

edited Jan 23 '20 at 04:50

Betlista

10,327
13
69
110

answered Jan 28 '14 at 09:00

Yaniv

164
1
9

score 0 · Answer 3 · answered Oct 19 '21 at 16:45

The accepted answer is great. I'm just adding here my case that is now working thanks for the answer. This may help someone else.

I'm using SLF4J and logback with a JSON encoder. Furthermore, I use marker and arguments to enrich my output.

    logger.error(getMarker("errorEvent"),
                 "An error occurred",
                 entries(mapOf("someKey" to "someValue")),
                 new Exception())

The output:

  {
   "level": "ERROR",
   "event": "errorEvent",
   "eventData": {
      "someKey": "someValue"
   },
   "stacktrace": "...omitted...",
   "message": "An error occurred"
}

Of course there is a lot of configuration of logstash behind the scenes, but I just wanted to show that the arguments passed as entries are shown in the configured eventData tag.

How to log formatted message, object array, exception?

3 Answers3

Linked

Related