In the last post, I wrote about how to log an exception, and said:
The correct place to put this would be a custom converter, but I don't feel like getting into it now, and the tricky bit would be populating the mapping, which is domain specific. Still, I think this points out where exception logging could be made more useful.
Let's start off with the example and then work our way back.
Assume you have an exception MyCustomException:
and you log an error, containing the domain specific exception:
Using the ExceptionMessageWithMappingsConverter converter, you will get the following exception for a single line:
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")]
Note that BatchUpdateException also contains properties, like updateCounts, errorCode, and SQLState. This is one of the fun bits of exception mapping: you can declare properties on the base type, and then build it up on the child types. This means in the BatchUpdateException case, the errorCode and SQLState properties are inherited from SQLException, so we only need to define it there.
This means that we can specify message itself as a property on java.lang.Throwable, and we can cover lots of ground with just the base cases. Poking around with the JDK gives us some candidates. Here's an incomplete list:
The base unit of operation is an ExceptionMapping, which is a function from Throwable to List<ExceptionProperty>. The vast majority involve JavaBean properties, but there's some chrome in there for handling exceptions with exposed fields as well:
This takes care of rendering exceptions, but it still doesn't map through to structured logging directly. To do that, we need to set up a custom JSON provider in logstash-logback-encoder:
and then this generates:
And now you have actual structured information that you can analyze and correlate with lnav or angle-grinder. Compare this with the text stacktrace, which does not break out the message or timestamp, and has the exception class name awkwardly wrapped: