Java : Simplify Exception Logging with AspectJ
This page last changed on Mar 17, 2006 by Kees de Kooter
Introduction
Some snippets from http://www.developer.com/java/other/print.php/3109831
What's wrong with conventional logging
Now that you have seen logging using conventional and AspectJ-based techniques, let's look at the shortcomings of conventional solutions. Figure 1 illustrates the overall schematic of current logging solutions. Every place that needs to log an event needs to explicitly invoke a call to the log() method of an appropriate logger. As you can see, the logging calls will be all over the core modules. When a new module is added to the system, all of its methods that need logging must be instrumented. Such instrumentation is invasive, causing the tangling of the core concerns with the logging concern. Further, if you ever happen to change the logging toolkit to a different API, you need to revisit every logging statement and modify it.
The most fundamental difference between conventional logging and AspectJ-based logging is modularization of the logging concern. Instead of writing modules that implement core concepts in addition to invoking logging operations, with AspectJ you write a few aspects that advise the execution of the operations in the core modules to perform the logging. That way, the core modules do not carry any logging-related code. By modularizing, you separate the logging concern from the core concerns.
Exception logging Since exception throwing is an important event in the system, logging the thrown exception is important. AspectJ-based solution offers a way to introduce such a functionality wihtout changing even a single line of code in the core part of the system. Similar to method tracing, you can switch the underlying logging implementation just by changing the aspect.
Next
Unfortunately the article ends right there, stating that exception logging is important, that you can use aspects to achieve it but not how. So I started experimenting.
I mainly use loggers for logging exceptions, I hardly use DEBUG statements an only once in a while an INFO statement. Copy-pasting some variant of the following line over and over again just does not feel right in an OO environment or any other programming environment for that matter.
private Log log = LogFactory.getLog(this.getClass());
I started off reading the AspectJ Programming Guide: http://www.eclipse.org/aspectj/doc/released/progguide/index.html
Putting it together in Eclipse
Next I installed the Eclipse AspectJ plugin using the Eclipse update manager (the update site is http://download.eclipse.org/technology/ajdt/31/update) and created a small test project.
I wrote a test class that throws exceptions and one that triggers them:
public class ExceptionThrower {
public void throwException() throws Exception {
throw new Exception("Duh - an exception");
}
}
public class Main {
public static void main(String[] args) {
Main instance = new Main();
instance.test();
}
public void test() {
ExceptionThrower dummyException = new ExceptionThrower();
try {
dummyException.throwException();
} catch (Exception e) {
System.err.println("Caught by handler: " + e.toString());
}
}
}
I then wrote the aspect:
public aspect ExceptionLoggingAspect {
before (Exception e): handler(Exception+) && args(e) {
System.err.println("Caught by aspect: " + e.toString());
e.printStackTrace();
}
}And although the eclipse compiler complains Only before advice is supported on handler join points (compiler limitation) the code works 
. No more LogFactories polluting my code!
Caught by aspect: java.lang.Exception: Duh - an exception
java.lang.Exception: Duh - an exception
at nl.boplicity.ExceptionThrower.throwException(ExceptionThrower.java:16)
at nl.boplicity.Main.test(Main.java:26)
at nl.boplicity.Main.main(Main.java:17)
Caught by handler: java.lang.Exception: Duh - an exceptionFurther reading: Using AspectJ with Maven
The real thing
It is time to implement the aspect in a real application. Log4j is picking up the wrong class information - it displays the name of the aspect - so we have to collect the source information ourselves
public aspect ExceptionLoggingAspect {
private Log log = LogFactory.getLog(this.getClass());
private Map loggedThrowables = new WeakHashMap();
public pointcut scope(): within(nl.boplicity..*);
after() throwing(Throwable t): scope() {
logThrowable(t, thisJoinPointStaticPart,
thisEnclosingJoinPointStaticPart);
}
before (Throwable t): handler(Exception+) && args(t) && scope() {
logThrowable(t, thisJoinPointStaticPart,
thisEnclosingJoinPointStaticPart);
}
protected synchronized void logThrowable(Throwable t, StaticPart location,
StaticPart enclosing) {
if (!loggedThrowables.containsKey(t)) {
loggedThrowables.put(t, null);
Signature signature = location.getSignature();
String source = signature.getDeclaringTypeName() + ":" +
(enclosing.getSourceLocation().getLine());
log.error("(a) " + source + " - " + t.toString(), t);
}
}
}I congured log4j as follows, leaving out the %c:%L part which we assemble in the aspect now:
<appender
name="aspect-appender"
class="org.apache.log4j.ConsoleAppender">
<param
name="Target"
value="System.out" />
<layout class="org.apache.log4j.PatternLayout">
<param
name="ConversionPattern"
value="%d{ABSOLUTE} %5p %m%n" />
</layout>
</appender>
<category
name="nl.boplicity.aspects"
additivity="false">
<priority value="info"/>
<appender-ref ref="aspect-appender"/>
</category>
Posted by at Sep 11, 2006 16:01