How to intercept proceed() in another AspectJ aspect?

Question

I have a situation as follows: I have a LoggingAspect with several pointcuts matching specific method executions in my main application. The corresponding advice bodies basically all look similar, causing a lot of code duplication:

void around() : download() {
    String message = "Downloading, verifying (MD5) and unpacking";
    SimpleLogger.verbose(message, IndentMode.INDENT_AFTER);
    proceed();
    SimpleLogger.verbose(message + " - done", IndentMode.DEDENT_BEFORE);
}

There is some variation, though. Sometimes the pointcut & advice have an arg or this parameter which is also printed to the log. Sometimes the "done" message is not printed if it s just a minor call not wrapping a lot of other calls, like this:

void around(BasicFilter filter) : fixFaultyLinkTargets()  && this(filter) {
    String message = "TOC file: checking for faulty link targets";
    SimpleLogger.verbose(message, IndentMode.INDENT_AFTER);
    proceed(filter);
    SimpleLogger.dedent();
}

The constant thing is that I manually tell the logger

• to increase the indent level after the first message is printed, i.e. directly before proceed() is called, and
• to decrease the indent level before the final message is printed (if any is printed), i.e. directly after proceed() has returned.

My idea is that I would like to write a meta aspect (or call it a helper aspect) with a pointcut which intercepts the proceed() calls in LoggingAspect so as to automatically adjust the indentation level accordingly. But there seems to be no pointcut matching proceed(). I have tried call(SomeMethodInMyMainApp), even a pointcut matching everything in the logging aspect, but the pointcut matches anything I do not need, but never ever the proceed.

If anybody knows how I can do this, I would appreciate a hint or a code snippet.

An indirect way of doing this might be to intercept not the advice themselves, but the method calls (or executions) advised by those advice by creating an extra pointcut like this:

// ATTENTION: each new pointcut must also be added here
pointcut catchAll() : download() || fixFaultyLinkTargets() || ...;

void around() : catchAll() {
    SimpleLogger.indent();
    proceed();
    SimpleLogger.dedent();
}

I would prefer another way though, without me having to remember to update the extra catchAll() pointcut everytime I change something in the logging aspect.

Answer 1

Suggestion wrap the proceed() in an anonymous class. And the write an aspect which adress this execution (but don't forget potential exceptions of proceed()).

My suggestion:

// AspectProceedCaller.java
public abstract class AspectProceedCaller { 
    public abstract Object doProceed(); 
};

// aspect ProceedCallerAspect.aj
aspect ProceedCallerAspect {
     pointcut execProceedCaller() : execution( * AspectProceedCaller+.doProceed() );

     Object around() : execProceedCaller() {
         try {
              SimpleLogger.indent();
              return proceed();
         }
         finally {
              SimpleLogger.dedent();
         }
     }
};


// Your application aspect 
aspect AnyAspect {
    pointcut anyPointcut() : ...;

    Object around() : anyPointcut() {
        AspectProceedCaller apc=new AspectProceedCaller() {
            public Object doProceed() {
                return proceed();
            }
        };  

        // DO Stuff before ....

        Object retval = apc.doProceed();

        // ... and after calling proceed.

        return retval;
    }
};

Best regards Marko

Answer 2

Please note: I am going to answer my own question here, adding more information and the additional feature of parametrisation to the solution suggested by loddar2012. Because his answer led me to the right direction, I am going to accept it even though this answer here really addresses all my needs from the original question, such as (quoting myself):

There is some variation, though. Sometimes the pointcut & advice have an arg or this parameter which is also printed to the log. Sometimes the "done" message is not printed if it s just a minor call not wrapping a lot of other calls

The basic thing we are dealing with here is what Ramnivas Laddad calls the worker object pattern in his book AspectJ in Action. His (and loddar2012's) idea is, in plain prose

• to wrap a call into an instance of an anonymous class (the worker object) where
  • the base class or implemented interface provides a method intended to do the work,
  • the worker object provides a concrete implementation of the worker method and specifically calls proceed() therein,
  • the worker method can be called right after object creation (as we will do here) or later, maybe even in its own thread,
  • the worker object may be passed around or added to a scheduling queue (none of which we will need here).

An elegant solution if you need to execute your proceed() calls asynchronously would be to create instances of anonymous Runnable classes. We will use our own abstract base class LogHelper, though, because we want some more sugar in our tea, specifically the option to pass a log message and some other parameters influencing log output to each worker. So this is what I did (package names and imports not shown in the sample code):

Abstract worker base class:

abstract class LogHelper {
    // Object state needed for logging
    String message;
    boolean logDone;
    boolean indent;
    LogType type;

    // Main constructor
    LogHelper(String message, boolean logDone, boolean indent, LogType type) {
        this.message = message;
        this.logDone = logDone;
        this.indent = indent;
        this.type = type;
    }
    // Convenience constructors for frequent use cases
    LogHelper(String message, boolean logDone) {
        this(message, logDone, true, LogType.VERBOSE);
    }
    LogHelper(String message) {
        this(message, true);
    }

    // Worker method to be overridden by each anonymous subclass
    abstract void log();
}

Logging advice capturing execution of worker objects:

aspect LoggingAspect
{
    void around(LogHelper logHelper) :
        execution(* LogHelper.log()) && this(logHelper)
    {
        try {
            SimpleLogger.log(logHelper.type, logHelper.message);
            if (logHelper.indent)
                SimpleLogger.indent();
            proceed(logHelper);
        } finally {
            if (logHelper.indent)
                SimpleLogger.dedent();
            if (logHelper.logDone)
                SimpleLogger.log(logHelper.type, logHelper.message + " - done");
        }
    }
    // (...)
}

As you can see, the logging advice does some things before calling proceed(logHelper) (i.e. executing the worker object's log() method) and some things afterwards, using the state information stored inside the worker object, such as

• message to be logged,
• log level (here called "type"),
• flag specifying if indentation level should be raised before proceeding,
• flag specifying if "done" message should be printed after worker execution.

Because in my use case all logged methods return void, there is no need to implement return value passing, but this would be easily possible, if necessary. The advice's return value would then just be Object and we would pass the result of proceed() back to our caller, no big deal.

Some advice capturing joinpoints to be logged and utilising parametrised worker objects to get the work done:

aspect LoggingAspect
{
    // (...)

    pointcut processBook()     : execution(* OpenbookCleaner.downloadAndCleanBook(Book));
    pointcut download()        : execution(* Downloader.download());
    pointcut cleanBook()       : execution(* OpenbookCleaner.cleanBook(Book));
    pointcut cleanChapter()    : execution(* OpenbookCleaner.cleanChapter(Book, File));
    pointcut initialiseTitle() : execution(* *Filter.initialiseTitle(boolean));

    void around(final Book book) : processBook() && args(book) {
        new LogHelper("Book: " + book.unpackDirectory) {
            void log() { proceed(book); } }.log();
    }
    void around() : download() {
        new LogHelper("Downloading, verifying (MD5) and unpacking") {
            void log() { proceed(); } }.log();
    }
    void around() : cleanBook() {
        new LogHelper("Filtering") {
            void log() { proceed(); } }.log();
    }
    void around(final File origFile) : cleanChapter() && args(*, origFile) {
        new LogHelper("Chapter: " + origFile.getName()) {
            void log() { proceed(origFile); } }.log();
    }
    void around() : initialiseTitle() {
        new LogHelper("Initialising page title", false) {
            void log() { proceed(); } }.log();
    }
}

The examples show how you can

• instantiate an anonymous LogHelper as a worker object with one or more constructor parameters, setting its state
• implement the log() method, optionally using joinpoint state bound via this() or args(),
• call/run the worker object (the call will be intercepted by the logging advice's pointcut and the real logging business be done there).