Friday, February 3

My Reusable Advice - part 1

Logging and tracing are separate concerns of an application (except for applications where this is an explicitly specified requirement). Thus, I was becoming increasingly annoyed with the


import org.apache.commons.logging.Log;
import org.apache.commons.logging.LogFactory;
...



and corresponding logging calls all over core modules, business classes, and even POJOs that required occasional debugging.

Furthermore, any changes to logging policies/strategies required multiple changes across multiple classes and a rebuild.

AOP is the technology for separating crosscutting concerns into single units called aspects. An aspect is a modular unit of crosscutting implementation that encapsulates behaviors that affect multiple classes into reusable modules.
AOP is thus the best way to log & trace entry & exit methods on demand. My earlier reluctance was due to the slightly harder way to debug control flow, as exemplified below:


...
if (condition){
log("Doing X")
do X
}else{
log("Doing Y")
do Y
}
...


The scenario above is still possible but not so straight forward to do with AOP. But really, the gains outshone the limitations. Consider the advice below, using the SpringFramework:


import org.aopalliance.intercept.MethodInterceptor;
import org.aopalliance.intercept.MethodInvocation;
import org.apache.commons.logging.Log;
import org.apache.commons.logging.LogFactory;

public class MethodExecutionTimeInterceptor implements MethodInterceptor {
private final Log logger = LogFactory.getLog(getClass());
public Object invoke(MethodInvocation methodInvocation) throws Throwable {
logger.info("intercepted method '" + methodInvocation.getMethod().getDeclaringClass() + "::" + methodInvocation.getMethod().getName() + "'");
long startTime = System.currentTimeMillis();
try {
Object retVal = methodInvocation.proceed();
return retVal;
} finally {
logger.info("method duration '" + (System.currentTimeMillis() - startTime) + "' msecs");
logger.info("resuming method '" + methodInvocation.getMethod().getDeclaringClass() + "::" + methodInvocation.getMethod().getName() + "'");
}
}
}


I can apply the logging unit above to any subset of classes in my application, or indeed to the whole application. The advice will automatically run whenever its pointcut matches a join point in my running program. Should logging requirements change or become redundant, I can remove the aspect without touching application code. The original code does not know of the logging aspect being applied to it.
This single aspect contributes to the implementation of a number of methods, modules, or objects, increasing both reusability and maintainability of the code.

For future reference, IBM DeveloperWorks as an extensive array of very useful articles on AOP.

A full logging example can be found here, many AOP resources can be found here, and a good introduction to AOP can be found here.

No comments: