Log And Throw
Log And Throw
26. Mai 2016 1 Kommentar zu Log And ThrowjQAssistant can be used to find antipatterns very efficiently in existing code bases. One nice example is „log and throw“:
try {
...
} catch (AnyException e) {
LOGGER.error("Something very suspicious happened.", e);
throw new OtherException(e);
}
The snippet catches an execption, logs it (including the stack trace) and creates a new exception which then is thrown.
The problem with this approach is that the exception will be caught somewhere else and logged again – so the full information ends up in the log files at least as many times as this pattern is repeated within the call hierarchy.
In other words: log files become bloated with redundant information which makes them very hard to analyze.
Logging At Boundaries
Therefore the recommended way to go is to „either log or throw“, thus an exception will always be logged exactly once.
In general it’s a good idea to let exceptions which cannot be handled „bubble up“ through the call hierarchy and implement handling mechanisms on the „boundaries“ of the system. Here everything gets caught, logged and furthermore specific actions are executed which correspond to the technical nature of the boundary, e.g.
– a UI may present an error message to the user
– a REST service should return an appropriate status code to the client
Frameworks (e.g. JAX-RS) often provide generic handlers for these purposes.
Finding The Antipattern
Coming back to „log and throw“ the question arises how this anti-pattern can be detected using jQAssistant. First we need to find points in the application where exceptions are thrown. Sadly this information is not directly available in the data model but we have a simple workaround: we can look for invocations on constructors of exception types. The second step is to identify invocations of logger methods which take „Throwable“ as (last) parameter and which are co-located to the before-mentioned pattern within a defined range of line numbers, e.g. „4“:
// 1. Identify all methods that invoke a constructor on an exception type MATCH (exceptionType)-[:DECLARES]->(constructor:Constructor), (method:Method)-[newException:INVOKES]->(constructor) WHERE exceptionType.fqn =~ ".*Exception" WITH method, newException // 2. Find all log invocations with a Throwable parameter that are co-located to creating Exception instances within a distance of max. 4 lines MATCH (logger:Type)-[:DECLARES]->(logMethod:Method)<-[log:INVOKES]-(method) WHERE logger.fqn = "java.util.logging.Logger" // Java Util Logging (JUL), replace with your logging framework and logMethod.signature =~ ".*,java.lang.Throwable\\)" and abs(log.lineNumber - newException.lineNumber) <= 4 WITH method, log // 3. Find the declaring type for each detected suspicious method and return the result MATCH (type:Type)-[:DECLARES]->(method) RETURN type.fqn as DeclaringType, log.lineNumber as LineNumber ORDER BY DeclaringType, LineNumber
At a first distant glance the query is quite complex. After taking a closer look we see that it actually consists of the described two parts and an additional third one. The latter just prepares information for the result to be returned (i.e. the Java type and line number).
Let’s try it on the Java Runtime Enviroment:
jqassistant.cmd scan -f <path to JRE>/lib/rt.jar jqassistant.cmd server
After opening the browser (http://localhost:7474) and executing the query we see the following result:
The first entry is „com.sun.jmx.mbeanserver.JmxMBeanServer“, let’s have a look at this class within the IDE:
Got ya!
Leave a comment
Case Study
Download our Case Study "Standardization and Automation at E-Post Development": EN (PDF, 1 MB) DEU (PDF, 1 MB)
1 Comment
[…] Log And Throw […]