AspectJ keep context around async method calls

Question

I'm new to AspectJ and I'm trying to figure out, how too keep / track a context of multiple async method calls. Imagine the following code:

@TimerStart
public void doSomething() throws InterruptedException {
    Thread.sleep(1000);
    MyCallable callable = new MyCallable();
    Future future = executorService.submit(callable );
}

private class MyCallable implements Callable {
    @Override
    public Object call() throws Exception {
        someOtherMethod();
        return null;
    }

    @TimerEnd
    private void someOtherMethod() throws InterruptedException {
        Thread.sleep(1000);
    }
}

I'd like to measure the time passed between @TimerStart and @TimerEnd. I'm struggling with two problems right now:

• How do I keep an object between to aspects. Fields in an aspect seem to be all static so what about concurrency issues...?
• How do I get two advices, one executed before @TimerStart and one after @TimerEnd.

Currently I have something along the lines of this:

public aspect TimerAspect {

    pointcut timerStart(Object object, TimerStart timed):
        execution(@TimerStart * *(..)) && this(object) && @annotation(timed);

    pointcut timerStop(Object object, TimerEnd timed):
        cflow(execution(@TimerEnd * *(..)) && this(object) && @annotation(timed) && !within(FlowTimerAspect));


    before(Object object, TimerStart timed): timerStart(object, timed)  {
        System.out.println("##### Flow timer START");
    }

    after(Object object, TimerEnd timed): timerStop(object, timed)  {
        System.out.println("##### Flow timer STOP");
    }

However the only thing I get right now is a StackOverflowException (yeah I know - that's why I'm asking here).

EDIT: I stumbled upon percflow which seems to do the trick BUT only when the @TimerStart and @TimerEnd appear in the same thread. Suggestions are highly appreciated!!

public aspect TimerAspect percflow(timerStart(Object, TimerStart)) {

    private long context;

    pointcut timerStart(Object object, TimerStart timed):
            execution(@TimerStart * *(..)) && this(object) && @annotation(timed);

    pointcut timerStop(Object object, TimerEnd timed):
            execution(@TimerEnd * *(..)) && this(object) && @annotation(timed);


    before(Object object, TimerStart timed): timerStart(object, timed)  {
        context = System.currentTimeMillis();
    }

    after(Object object, TimerEnd timed): timerStop(object, timed)  {
        long passed = System.currentTimeMillis() - context;
        System.out.println("passed time: " + passed);
    }
}

Answer 1

Since you're planning to switch threads while measuring, the percflow instantiation method is not going to help you. You'll have to stick with the default singleton aspect and keep the timing values for the object of interest in a WeakHashMap. That way, you keep timings as long as the objects/threads associated with the timing are alive. We'll need another annotation to mark the event of associating a new object (a Callable in this example) with your timing. Let's call this @TimerJoin. The @TimerJoin annotation would be analogous to your existing @TimerStart and @TimerEnd annotations. Your measuring aspect will look like this.

import java.util.Map;
import java.util.WeakHashMap;

public aspect TimerAspect {

    private final Map<Object, Timer> objectTiming = new WeakHashMap<>();
    private final ThreadLocal<Timer> currentThreadTimer = new ThreadLocal<>();

    pointcut timerStart(Object object):
            execution(@TimerStart * *(..)) && this(object);

    pointcut timerStop(Object object):
            execution(@TimerEnd * *(..)) && this(object);

    pointcut timerJoin(Object object):
        (execution(@TimerJoin * *(..)) || execution(@TimerJoin *.new(..)) ) 
        && this(object);

    before(Object object): timerStart(object) {
        Timer timer = new Timer();
        timer.start();
        objectTiming.put(object, timer);
        currentThreadTimer.set(timer);
        System.out.println("##### Flow timer START");
    }

    before(Object object): timerJoin(object) {
        Timer timing = currentThreadTimer.get();
        objectTiming.put(object, timing);
        System.out.println("##### Flow timer JOIN");
    }

    after(Object object): timerStop(object) {
        Timer timing = objectTiming.get(object);
        timing.stop();
        System.out.println("##### Flow timer STOP");
        System.out.println("Elapsed: " + timing.getElapsed());
    }

}

And the simple Timer.java class:

public class Timer {

    private long start;
    private long stop;

    public long getStart() {
        return start;
    }

    public long getStop() {
        return stop;
    }

    public void start() {
        start = System.currentTimeMillis();
    }

    public void stop() {
        stop = System.currentTimeMillis();
    }

    public long getElapsed() {
        return stop-start;
    }
}

Modify your callable to mark it to join the timer on the current thread:

private class MyCallable implements Callable {

    @TimerJoin
    public MyCallable() {
    }

    @Override
    public Object call() throws Exception {
        someOtherMethod();
        return null;
    }

    @TimerEnd
    private void someOtherMethod() throws InterruptedException {
        Thread.sleep(1000);
    }
}

The rest of your code will be the same.

You may notice that the aspect is using a ThreadLocal as a means of storage for the current timer to be able to associate it with new objects. You may choose another kind of storage for this, but for the sake of the example, I tried to keep it simple. Also, again for the sake of simplicity, I left out any safety checks for nulls in the aspect. You'll need to handle the corner cases yourself.