Java Top

Get started with Spring 5 and Spring Boot 2, through the Learn Spring course:

>> CHECK OUT THE COURSE

1. Overview

In this tutorial, we'll use AspectJ to write trace logging output when calling methods of configured classes. By using an AOP advice to write trace logging output, we encapsulate the logic into a single compilation unit.

Our example expands upon the information presented in Intro to AspectJ.

2. Trace Logging Annotation

We'll use an annotation to configure classes so their method calls can be traced. Using an annotation gives us an easy mechanism for adding the trace logging output to new code without having to add logging statements directly.

Let's create the annotation:

@Retention(RetentionPolicy.RUNTIME)
@Target(ElementType.TYPE)
public @interface Trace {
}

3. Creating Our Aspect

We'll create an aspect to define our pointcut to match the join points we care about and the around advice containing the logic to execute.

Our aspect will look similar to this:

public aspect TracingAspect {
    private static final Log LOG = LogFactory.getLog(TracingAspect.class);

    pointcut traceAnnotatedClasses(): within(@Trace *) && execution(* *(..));

    Object around() : traceAnnotatedClasses() {
        String signature = thisJoinPoint.getSignature().toShortString();
        LOG.trace("Entering " + signature);
        try {
            return proceed();
        } finally {
            LOG.trace("Exiting " + signature);
        }
    }
}

In our aspect, we define a pointcut named traceAnnotatedClasses to match the execution of methods within classes annotated with our Trace annotation. By defining and naming a pointcut, we can reuse it as we would a method in a class. We'll use this named pointcut to configure ours around advice.

Our around advice will execute in place of any join point matched by our pointcut and will return an Object. By having an Object return type, we can account for advised methods having any return type, even void.

We retrieve the signature of the matched join point to create a short String representation of the signature to add context to our tracing messages. As a result, our logging output will have the name of the class and the method executed, which gives us some needed context.

In between our trace output calls, we've called a method named proceed. This method is available for around advice in order to continue the execution of the matched join point. The return type will be Object since we have no way to know the return type at compile time. We will send this value back to the caller after sending the final trace output to the log.

We wrap the proceed() call in a try/finally block to ensure the exit message is written. If we wanted to trace the thrown exception, we could add after() advice to write a log message when an exception is thrown:

after() throwing (Exception e) : traceAnnotatedClasses() {
    LOG.trace("Exception thrown from " + thisJoinPoint.getSignature().toShortString(), e);
}

4. Annotating Our Code

Now we need to enable our trace. Let's create a simple class and activate the trace logging with our custom annotation:

@Trace
@Component
public class MyTracedService {

    public void performSomeLogic() {
        ...
    }

    public void performSomeAdditionalLogic() {
        ...
    }
}

With the Trace annotation in place, the methods in our class will match the pointcut we've defined. When these methods execute, the tracing messages will be written to the log.

After running our code calling these methods, our log output should include content similar to:

22:37:58.867 [main] TRACE c.b.a.c.TracingAspect - Entering MyTracedService.performSomeAdditionalLogic()
22:37:58.868 [main] INFO  c.b.a.c.MyTracedService - Inside performSomeAdditionalLogic...
22:37:58.868 [main] TRACE c.b.a.c.TracingAspect - Exiting MyTracedService.performSomeAdditionalLogic()
22:37:58.869 [main] TRACE c.b.a.c.TracingAspect - Entering MyTracedService.performSomeLogic()
22:37:58.869 [main] INFO  c.b.a.c.MyTracedService - Inside performSomeLogic...
22:37:58.869 [main] TRACE c.b.a.c.TracingAspect - Exiting MyTracedService.performSomeLogic()

5. Conclusion

In this article, we used AspectJ to intercept all of a class's methods with a single annotation on the class. Doing so allows us to quickly add our trace logging functionality to new code.

We also consolidated our trace logging output logic to a single compilation unit to improve our ability to modify our trace logging output as our application evolves.

As always, the full source code of the article is available over on GitHub.

Java bottom

Get started with Spring 5 and Spring Boot 2, through the Learn Spring course:

>> CHECK OUT THE COURSE
guest
0 Comments
Inline Feedbacks
View all comments