Exception Mapping¶
Exception Mapping is done to show the important details of an exception, including the root cause in a summary format. This is especially useful in line oriented formats, because rendering a stacktrace can take up screen real estate without providing much value.
An example will help. Given the following program:
public class Thrower {
private static final Logger logger = LoggerFactory.getLogger(Thrower.class);
public static void main(String[] progArgs) {
try {
doSomethingExceptional();
} catch (RuntimeException e) {
logger.error("domain specific message", e);
}
}
static void doSomethingExceptional() {
Throwable cause = new BatchUpdateException();
throw new MyCustomException("This is my message", "one is one", "two is more than one", "three is more than two and one", cause);
}
}
public class MyCustomException extends RuntimeException {
public MyCustomException(String message, String one, String two, String three, Throwable cause) {
// ...
}
public String getOne() { return one; }
public String getTwo() { return two; }
public String getThree() { return three; }
}
and the Logback file:
<configuration>
<newRule pattern="*/exceptionMappings"
actionClass="com.tersesystems.logback.exceptionmapping.ExceptionMappingRegistryAction"/>
<newRule pattern="*/exceptionMappings/mapping"
actionClass="com.tersesystems.logback.exceptionmapping.ExceptionMappingAction"/>
<conversionRule conversionWord="richex" converterClass="com.tersesystems.logback.exceptionmapping.ExceptionMessageWithMappingsConverter" />
<exceptionMappings>
<!-- comes with default mappings for JDK exceptions, but you can add your own -->
<mapping name="com.tersesystems.logback.exceptionmapping.MyCustomException" properties="one,two,three"/>
</exceptionMappings>
<appender name="CONSOLE" class="ch.qos.logback.core.ConsoleAppender">
<encoder>
<pattern>%-5relative %-5level %logger{35} - %msg%richex{1, 10, exception=[}%n</pattern>
</encoder>
</appender>
<root level="TRACE">
<appender-ref ref="CONSOLE"/>
</root>
</configuration>
Then this renders the following:
184 ERROR c.t.l.exceptionmapping.Thrower - domain specific message exception=[com.tersesystems.logback.exceptionmapping.MyCustomException(one="one is one" two="two is more than one" three="three is more than two and one" message="This is my message") > java.sql.BatchUpdateException(updateCounts="null" errorCode="0" SQLState="null" message="null")]
You can integrate exception mapping with Typesafe Config and logstash-logback-encoder
by adding extra mappings.
For example, you can map a whole bunch of exceptions at once in HOCON, and not have to do it line by line in XML:
<configuration>
<newRule pattern="*/exceptionMappings/configMappings"
actionClass="com.tersesystems.logback.exceptionmapping.config.TypesafeConfigMappingsAction"/>
<exceptionMappings>
<!-- Or point to HOCON path -->
<configMappings path="exceptionmappings"/>
</exceptionMappings>
</configuration>
and
exceptionmappings {
example.MySpecialException: ["timestamp"]
}
and configure it in JSON using ExceptionArgumentsProvider
:
<encoder class="net.logstash.logback.encoder.LoggingEventCompositeJsonEncoder">
<providers>
<provider class="com.tersesystems.logback.exceptionmapping.json.ExceptionArgumentsProvider">
<fieldName>exception</fieldName>
</provider>
</providers>
</encoder>
and get the following exception
that contains an array of exceptions and the associated properties, in this case timestamp
:
{
"id" : "Fa6x8H0EqomdHaINzdiAAA",
"sequence" : 3,
"@timestamp" : "2019-07-06T03:52:48.730+00:00",
"@version" : "1",
"message" : "I am an error",
"logger_name" : "example.Main$Runner",
"thread_name" : "pool-1-thread-1",
"level" : "ERROR",
"stack_hash" : "233f3cf1",
"exception" : [ {
"name" : "example.MySpecialException",
"properties" : {
"message" : "Level 1",
"timestamp" : "2019-07-06T03:52:48.728Z"
}
}, {
"name" : "example.MySpecialException",
"properties" : {
"message" : "Level 2",
"timestamp" : "2019-07-06T03:52:48.728Z"
}
}, {
"name" : "example.MySpecialException",
"properties" : {
"message" : "Level 3",
"timestamp" : "2019-07-06T03:52:48.728Z"
}
}, {
"name" : "example.MySpecialException",
"properties" : {
"message" : "Level 4",
"timestamp" : "2019-07-06T03:52:48.728Z"
}
}, {
"name" : "example.MySpecialException",
"properties" : {
"message" : "Level 5",
"timestamp" : "2019-07-06T03:52:48.728Z"
}
}, {
"name" : "example.MySpecialException",
"properties" : {
"message" : "Level 6",
"timestamp" : "2019-07-06T03:52:48.728Z"
}
}, {
"name" : "example.MySpecialException",
"properties" : {
"message" : "Level 7",
"timestamp" : "2019-07-06T03:52:48.728Z"
}
}, {
"name" : "example.MySpecialException",
"properties" : {
"message" : "Level 8",
"timestamp" : "2019-07-06T03:52:48.728Z"
}
}, {
"name" : "example.MySpecialException",
"properties" : {
"message" : "Level 9",
"timestamp" : "2019-07-06T03:52:48.728Z"
}
} ],
"stack_trace" : "<#1165e3b1> example.MySpecialException: Level 9\n\tat example.Main$Runner.nestException(Main.java:56)\n\t... 9 common frames omitted\nWrapped by: <#eb336a2d> example.MySpecialException: Level 8\n\tat example.Main$Runner.nestException(Main.java:56)\n\t... 10 common frames omitted\nWrapped by: <#cc1fb404> example.MySpecialException: Level 7\n\tat example.Main$Runner.nestException(Main.java:56)\n\t... 11 common frames omitted\nWrapped by: <#2af187a0> example.MySpecialException: Level 6\n\tat example.Main$Runner.nestException(Main.java:56)\n\t... 12 common frames omitted\nWrapped by: <#7dac62d1> example.MySpecialException: Level 5\n\tat example.Main$Runner.nestException(Main.java:56)\n\t... 13 common frames omitted\nWrapped by: <#2ea4460d> example.MySpecialException: Level 4\n\tat example.Main$Runner.nestException(Main.java:56)\n\t... 14 common frames omitted\nWrapped by: <#261bed64> example.MySpecialException: Level 3\n\tat example.Main$Runner.nestException(Main.java:56)\n\t... 15 common frames omitted\nWrapped by: <#e660d440> example.MySpecialException: Level 2\n\tat example.Main$Runner.nestException(Main.java:56)\n\t... 16 common frames omitted\nWrapped by: <#233f3cf1> example.MySpecialException: Level 1\n\tat example.Main$Runner.nestException(Main.java:56)\n\tat example.Main$Runner.nestException(Main.java:57)\n\tat example.Main$Runner.nestException(Main.java:57)\n\tat example.Main$Runner.nestException(Main.java:57)\n\tat example.Main$Runner.nestException(Main.java:57)\n\tat example.Main$Runner.nestException(Main.java:57)\n\tat example.Main$Runner.nestException(Main.java:57)\n\tat example.Main$Runner.nestException(Main.java:57)\n\tat example.Main$Runner.nestException(Main.java:57)\n\tat example.Main$Runner.generateException(Main.java:51)\n\tat example.Main$Runner.doError(Main.java:44)\n\tat java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)\n\tat java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308)\n\tat java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180)\n\tat java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294)\n\tat java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)\n\tat java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)\n\tat java.lang.Thread.run(Thread.java:748)\n"
}
This is a lot easier for structured logging parsers to grok than the associated stacktrace.
See How to Log an Exception and How to Log an Exception, Part 2 for more details.