Java Aspect-Oriented Programming with Annotations

Let’s imagine you want to log the time taken by some annoted methods using a @LogExecTime annotation.

I first create an annotation LogExecTime:

@Retention(RetentionPolicy.RUNTIME)
@Target(ElementType.METHOD)
public @interface LogExecTime {

}

Then I define an aspect:

@Component  // For Spring AOP
@Aspect
public class LogTimeAspect {
    @Around(value = "@annotation(annotation)")
    public Object LogExecutionTime(final ProceedingJoinPoint joinPoint, final LogExecTime annotation) throws Throwable {
        final long startMillis = System.currentTimeMillis();
        try {
            System.out.println("Starting timed operation");
            final Object retVal = joinPoint.proceed();
            return retVal;
        } finally {
            final long duration = System.currentTimeMillis() - startMillis;
            System.out.println("Call to " + joinPoint.getSignature() + " took " + duration + " ms");
        }

    }
}

I create a class annoted with LogExecTime:

@Component
public class Operator {

    @LogExecTime
    public void operate() throws InterruptedException {
        System.out.println("Performing operation");
        Thread.sleep(1000);
    }
}

And a main using Spring AOP:

public class SpringMain {

    public static void main(String[] args) throws InterruptedException {
        ApplicationContext context = new GenericXmlApplicationContext("applicationContext.xml");
        final Operator bean = context.getBean(Operator.class);
        bean.operate();
    }
}

If I run this class I’m getting the following output on stdout:

Starting timed operation
Performing operation
Call to void testaop.Operator.Operate() took 1044 ms

Now with the magic. As I did use Spring AOP rather than AspectJ weaver, the magic is occurring at run time using proxy-ish mechanisms. So the .class files are left untouched. For instance if I debug this program and put a breakpoint in operate you’ll see how Spring has performed the magic:

As Spring AOP implementation is non-intrusive and uses the Spring mechanisms you need to add the @Component annotation and create the object using Spring context rather than plain new.

AspectJ on the other side will change the .class files. I tried this project with AspectJ and decompiled the Operator class with jad. Which lead to:

public void operate()
    throws InterruptedException
{
    JoinPoint joinpoint = Factory.makeJP(ajc$tjp_0, this, this);
    operate_aroundBody1$advice(this, joinpoint, LogTimeAspect.aspectOf(), (ProceedingJoinPoint)joinpoint, (LogExecTime)(ajc$anno$0 == null && (ajc$anno$0 = testaop/Operator.getDeclaredMethod("operate", new Class[0]).getAnnotation(testaop/LogExecTime)) == null ? ajc$anno$0 : ajc$anno$0));
}

private static final void operate_aroundBody0(Operator ajc$this, JoinPoint joinpoint)
{
    System.out.println("Performing operation");
    Thread.sleep(1000L);
}

private static final Object operate_aroundBody1$advice(Operator ajc$this, JoinPoint thisJoinPoint, LogTimeAspect ajc$aspectInstance, ProceedingJoinPoint joinPoint, LogExecTime annotation)
{
    long startMillis = System.currentTimeMillis();
    Object obj;
    System.out.println("Starting timed operation");
    ProceedingJoinPoint proceedingjoinpoint = joinPoint;
    operate_aroundBody0(ajc$this, proceedingjoinpoint);
    Object retVal = null;
    obj = retVal;
    long duration = System.currentTimeMillis() - startMillis;
    System.out.println((new StringBuilder("Call to ")).append(joinPoint.getSignature()).append(" took ").append(duration).append(" ms").toString());
    return obj;
    Exception exception;
    exception;
    long duration = System.currentTimeMillis() - startMillis;
    System.out.println((new StringBuilder("Call to ")).append(joinPoint.getSignature()).append(" took ").append(duration).append(" ms").toString());
    throw exception;
}

private static void ajc$preClinit()
{
    Factory factory = new Factory("Operator.java", testaop/Operator);
    ajc$tjp_0 = factory.makeSJP("method-execution", factory.makeMethodSig("1", "operate", "testaop.Operator", "", "", "java.lang.InterruptedException", "void"), 5);
}

private static final org.aspectj.lang.JoinPoint.StaticPart ajc$tjp_0; /* synthetic field */
private static Annotation ajc$anno$0; /* synthetic field */

static 
{
    ajc$preClinit();
}