JarCastingCDI logging-interceptor 
CDI interceptor for logging to slf4j.
Logging is the standard example for writing interceptors. Yet, I didn't find a good one, so I wrote my own (and it was a lot of fun :)
There are two main use-cases for logging interceptors:
- Log calls to existing methods: instead of repeating the method name and arguments within the method, simply annotate it. Often called tracing (see example). Note that interceptors are not triggered when you do local calls, so you may need to resort to the other, more classical logging use-case:
- Instead of using the generic logging api, you can define a pojo that does nothing but log (with the same annotation as above). Makes mocking your unit tests very easy, in case you want to make sure about what logs are written. (see example)
News
Version 3.x
We use semantic versioning. tl;dr: versions consist of three parts with a semantic: The Bad (major = breaking changes), the Good (minor = new features), and the Ugly (micro/patch = bugfixes).
So going to 3.0.0 was Bad, as it may break existing applications. But sometimes Bad things are necessary. Here we need it to get to Java 8 and replace esp. Joda-Date (BTW: big kudos to Stephen for that project and for making it obsolete by moving it to Java 8).
Features
- Logs to slf4j (and you can go to any logging framework from there).
- Annotate methods as
@Loggedto log the call and eventually return value or exceptions thrown (both including time). - Annotate a class to have all managed methods within logged (see examples).
- Annotate a CDI
@Stereotypeand have all managed methods logged. - Define the log level in the
@Loggedannotation; if you don't specify one, it's derived from the recursively containing type or package (i.e. you can annotate yourpackage-info.javaand inherit the log level from there; this doesn't work for the interception itself, as CDI doesn't support that) or finallyDEBUG. - The exception thrown is logged with a message like
failed with IllegalArgumentExceptionso the stack trace isn't repeated for every method the throw passes through. - If the last parameter is a
Throwable, it's passed to slf4j, so the stack trace is printed out; i.e. the logging-interceptor formats the message without theThrowablebefore it passes it on (that's an addition to the slf4j api). (see example) - The default logger is the top level class containing the method being logged; you can explicitly set it in the
@Loggedannotation. - The default log message is the name of the method, with camel case converted to spaces (e.g. "getNextCustomer" -> "get next customer") and parameters appended; you can explicitly set it in the
@Loggedannotation. - Define a
returnFormatto control what's being logged when the message returns. Defaults toreturn {returnValue} [time:{time}], or nothing for void methods. - And empty log message format or return format won't be logged at all, so you can have either or.
- In addition to the slf4j log message format placeholders, you can use positional indexes (e.g.
{0}) or parameter names (e.g.{firstName}; requires jdk8 parameter meta data or debug info). And you can use simple expressions, likeperson.address.zip. - Parameters annotated as
@DontLogare not logged; very useful for, e.g., passwords. - Parameters annotated as
@LogContextare added to the MDC (and cleaned up thereafter). Very handy to add, e.g., the main business reference key to all logs written below. - Define producers for
LogContextVariables for other MDC variables; a producer for theversionandappof the containing jar/ear/war is provided (requires the implementation or specification version in the manifest). As a convenience, you also can just annotate a field as@LogContext, so you don't have to package the field into aLogContextVariable. - Add a MDC variable
indentto your pattern to visualize the call hierarchy of logged statements. - Define converters, to e.g. extract the customer number from a customer object, by implementing
Converter(see example). Converters forjavax.ws.rs.core.UriInfoandjavax.ws.rs.core.Responseare provided. - Set
@Logged#jsonto have some information put into an MDC variablejson. It's a JSON map without the outer curlies; you'll have to add those to your pattern.EVENT: thetimestamp,event(the method name, not converted to spaces),logger, andlevel.PARAMETERS: the parameters of the method.CONTEXT: all MDC variables (like%X, but with colons instead of=between keys and values).ALL: for all of the above, so you can log using json with the log pattern{%X{json}}.
- Set
@Logged#repeatto limit the number of log repeats, e.g.ONCE_PER_DAYwill not repeat any calls until 24 hours have passed since the previous call. - Also works
@AroundTimeout, e.g. when a EJB@Schedulefires... although we can't test it automatically in our Weld container.
Examples
Basic Trace
@Path("/customers")
@Logged(level = INFO)
public class CustomersResource {
@GET
@Path("/{customer-id}")
public Customer getCustomer(@PathParam("customer-id") String customerId) {
return ...
}
}
would log calls to all methods in CustomersResource at INFO level, e.g.:
get customer 1234
return Customer(id=1234, firstName="Joe", ...)
Classic Logger
static class CustomersResourceLogger {
@Logged("found {} for id {}")
void foundCustomerForId(Customer customer, String customerId) {}
}
@Inject CustomersResourceLogger log;
...
log.foundCustomerForId(customer, "1234");
...
would log:
found Customer(id=1234, firstName="Joe", ...) for id 1234
Log Stack Trace
static class ExceptionLogger {
@Logged(level = ERROR)
void failed(String operation, RuntimeException e) {}
}
@Inject
ExceptionLogger exceptionLogger;
...
try {
...
} catch (RuntimeException e) {
exceptionLogger.failed("my operation", e);
}
...
would log the message failed my operation with the exception and stack trace.
Converter
public class ResponseLogConverter implements Converter {
public String convert(Response response) {
StatusType statusInfo = response.getStatusInfo();
return statusInfo.getStatusCode() + " " + statusInfo.getReasonPhrase() + entityInfo(response);
}
private String entityInfo(Response response) {
Object entity = response.getEntity();
if (entity == null)
return "";
return ": " + entity.getClass().getSimpleName();
}
}
Download
Add Bintray to your settings.xml (see the Set me up! button) and this Maven dependency to your pom.xml:
<dependency>
<groupId>com.github.t1</groupId>
<artifactId>logging-interceptor</artifactId>
<version>${logging-interceptor.version}</version>
</dependency>
Enable in Java EE 7
The interceptor is annotated with a @Priority (see the last paragraph in Java EE Tutorial). So it is automatically activated if you add it as a library to you application.
Enable in Java EE 6
Enabling interceptors from a library jar is a bit tricky in CDI 1.0. If you'd just add the logging-interceptor.jar to your war or ear, it was a separate CDI module, and the interceptor was not useable in your application. So you'll have to overlay the jar contents into your application by adding this to your pom.xml:
<build>
<plugins>
<plugin>
<groupId>org.apache.maven.plugins</groupId>
<artifactId>maven-war-plugin</artifactId>
<version>2.4</version>
<configuration>
<overlays>
<overlay>
<groupId>com.github.t1</groupId>
<artifactId>logging-interceptor</artifactId>
<type>jar</type>
<targetPath>WEB-INF/classes</targetPath>
</overlay>
</overlays>
</configuration>
</plugin>
</plugins>
</build>
<dependencies>
<dependency>
<groupId>com.github.t1</groupId>
<artifactId>logging-interceptor</artifactId>
<optional>true</optional>
</dependency>
</dependencies>
Then you can activate the interceptor in the application's beans.xml:
<beans xmlns="http://java.sun.com/xml/ns/javaee" xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
xsi:schemaLocation="http://java.sun.com/xml/ns/javaee http://java.sun.com/xml/ns/javaee/beans_1_0.xsd">
<interceptors>
<class>com.github.t1.log.LoggingInterceptor</class>
</interceptors>
</beans>
License
Licensed under Apache License 2.0