Monday, March 16, 2009

AspectJ for Java logging: Serviceability without the clutter ("around" we go) - part 3

Whenever I reuse someone else's code at the source level, I often discover that it uses some different logging toolkit than what I am using.
Log4J seems to take the prize because a lot of developers used it before JSR-47 came out, and some **still** use Log4J in defiance of JSR-47's release.
JRAS, from older versions of WebSphere, also comes to mind.

At any rate, combining two different log toolkits produces some undesirable results, mostly (1) two different configuration steps and (2) two different file outputs. You can add a new handler to Log4J to redirect its calls to solve problem "2", but "1" is still there rearing its ugly head.

AspectJ allows one to replace calls to a given method with different calls. You got it, how about an Aspect that replaces all Log4J calls with JSR-47 calls?

The alternative? Ripping through every single method in the second code-base to replace Log4J calls with JSR-47 calls, but it is very likely that the original code owner will not support your forked code-base. Yes, I don't like it either, and that is why I wrote this other aspect for a recent project.

There are ways of applying this technique to an existing JAR file if you are reusing libraries instead of source code. Theme for the next posting.

----
package my.project;

import java.util.logging.Level;
import java.util.logging.Logger;

/**
* Aspect used to wrap Log4J to ensure consistent logging throughout the entire project.
*
* @author Denilson Nastacio
*/
public aspect Log4J {

private static final Logger trace = Logger.getLogger("trace.my.project");

/*
* Pointcuts
*/

/**
* Pointcut for all log4j calls within the target module
*/
pointcut log4jCalls():
target(org.apache.commons.logging.Log) &&
within(my.someone.else.code*.*);

/**
* Pointcuts for isInfoEnabled calls.
*/
pointcut log4jIsInfoEnabled():
log4jCalls() &&
call(boolean isInfoEnabled());

/**
* Pointcuts for isTraceEnabled calls.
*/
pointcut log4jIsTraceEnabled():
log4jCalls() &&
call(boolean isTraceEnabled());

/**
* Pointcuts for isDebugEnabled calls.
*/
pointcut log4jIsDebugEnabled():
log4jCalls() &&
call(boolean isDebugEnabled());

/**
* Pointcuts for isWarnEnabled calls.
*/
pointcut log4jIsWarnEnabled():
log4jCalls() &&
call(boolean isWarnEnabled());

/**
* Pointcuts for isErrorEnabled calls.
*/
pointcut log4jIsErrorEnabled():
log4jCalls() &&
call(boolean isErrorEnabled());

/**
* Pointcuts for isFatalEnabled calls.
*/
pointcut log4jIsFatalEnabled():
log4jCalls() &&
call(boolean isFatalEnabled());

/**
* Pointcuts for info calls.
*/
pointcut log4jInfo(Object o):
log4jCalls() &&
args(o) &&
call(void info(Object));
pointcut log4jInfoEx(Object o, Throwable ex):
log4jCalls() &&
args(o,ex) &&
call(void info(Object,Throwable));

/**
* Pointcuts for trace calls.
*/
pointcut log4jTrace(Object o):
log4jCalls() &&
args(o) &&
call(void trace(Object));
pointcut log4jTraceEx(Object o, Throwable ex):
log4jCalls() &&
args(o,ex) &&
call(void trace(Object,Throwable));

/**
* Pointcuts for debug calls.
*/
pointcut log4jDebug(Object o):
log4jCalls() &&
args(o) &&
call(void debug(Object));
pointcut log4jDebugEx(Object o, Throwable ex):
log4jCalls() &&
args(o,ex) &&
call(void debug(Object,Throwable));

/**
* Pointcuts for warn calls.
*/
pointcut log4jWarn(Object o):
log4jCalls() &&
args(o) &&
call(void warn(Object));
pointcut log4jWarnEx(Object o, Throwable ex):
log4jCalls() &&
args(o,ex) &&
call(void warn(Object,Throwable));

/**
* Pointcuts for error calls.
*/
pointcut log4jError(Object o):
log4jCalls() &&
args(o) &&
call(void error(Object));
pointcut log4jErrorEx(Object o, Throwable ex):
log4jCalls() &&
args(o,ex) &&
call(void error(Object,Throwable));

/**
* Pointcuts for fatal calls.
*/
pointcut log4jFatal(Object o):
log4jCalls() &&
args(o) &&
call(void fatal(Object));
pointcut log4jFatalEx(Object o, Throwable ex):
log4jCalls() &&
args(o,ex) &&
call(void fatal(Object,Throwable));

/*
* Join points
*/

/**
* Replace calls to Log.isInfoEnabled
*/
boolean around(): log4jIsInfoEnabled() {
if (trace.isLoggable(Level.INFO)) {
return true;
} else {
return false;
}
}

/**
* Replace calls to Log.isTraceEnabled
*/
boolean around(): log4jIsTraceEnabled() {
if (trace.isLoggable(Level.FINER)) {
return true;
} else {
return false;
}
}

/**
* Replace calls to Log.isDebugEnabled
*/
boolean around(): log4jIsDebugEnabled() {
if (trace.isLoggable(Level.FINEST)) {
return true;
} else {
return false;
}
}

/**
* Replace calls to Log.isWarnEnabled
*/
boolean around(): log4jIsWarnEnabled() {
if (trace.isLoggable(Level.WARNING)) {
return true;
} else {
return false;
}
}

/**
* Replace calls to Log.isErrorEnabled
*/
boolean around(): log4jIsErrorEnabled() || log4jIsFatalEnabled() {
if (trace.isLoggable(Level.SEVERE)) {
return true;
} else {
return false;
}
}

/**
* Replace calls to Log.info
*/
void around(Object o): log4jInfo(o) {
if ("".equals(o) == false) {
trace.logp(Level.INFO,
thisJoinPointStaticPart.getSourceLocation().getWithinType().getName(),
thisJoinPointStaticPart.getSourceLocation().toString(),
o.toString());
}
}
void around(Object o, Throwable ex): log4jInfoEx(o, ex) {
trace.logp(Level.INFO,
thisJoinPointStaticPart.getSourceLocation().getWithinType().getName(),
thisJoinPointStaticPart.getSourceLocation().toString(),
o.toString(), ex);
}

/**
* Replace calls to Log.trace
*/
void around(Object o): log4jTrace(o) {
trace.logp(Level.FINER,
thisJoinPointStaticPart.getSourceLocation().getWithinType().getName(),
thisJoinPointStaticPart.getSourceLocation().toString(),
o.toString());
}
void around(Object o, Throwable ex): log4jTraceEx(o, ex) {
trace.logp(Level.FINER,
thisJoinPointStaticPart.getSourceLocation().getWithinType().getName(),
thisJoinPointStaticPart.getSourceLocation().toString(),
o.toString(), ex);
}

/**
* Replace calls to Log.debug
*/
void around(Object o): log4jDebug(o) {
trace.logp(Level.FINEST,
thisJoinPointStaticPart.getSourceLocation().getWithinType().getName(),
thisJoinPointStaticPart.getSourceLocation().toString(),
o.toString());
}
void around(Object o, Throwable ex): log4jDebugEx(o, ex) {
trace.logp(Level.FINEST,
thisJoinPointStaticPart.getSourceLocation().getWithinType().getName(),
thisJoinPointStaticPart.getSourceLocation().toString(),
o.toString(), ex);
}

/**
* Replace calls to Log.warn
*/
void around(Object o): log4jWarn(o) {
trace.logp(Level.WARNING,
thisJoinPointStaticPart.getSourceLocation().getWithinType().getName(),
thisJoinPointStaticPart.getSourceLocation().toString(),
o.toString());
}
void around(Object o, Throwable ex): log4jWarnEx(o, ex) {
trace.logp(Level.WARNING,
thisJoinPointStaticPart.getSourceLocation().getWithinType().getName(),
thisJoinPointStaticPart.getSourceLocation().toString(),
o.toString(), ex);
}

/**
* Replace calls to Log.error and Log.fatal
*/
void around(Object o): log4jError(o) ||
log4jFatal (o) {
trace.logp(Level.SEVERE,
thisJoinPointStaticPart.getSourceLocation().getWithinType().getName(),
thisJoinPointStaticPart.getSourceLocation().toString(),
o.toString());
}
void around(Object o, Throwable ex): log4jErrorEx(o, ex) ||
log4jFatalEx(o,ex) {
trace.logp(Level.SEVERE,
thisJoinPointStaticPart.getSourceLocation().getWithinType().getName(),
thisJoinPointStaticPart.getSourceLocation().toString(),
o.toString(), ex);
}

}

No comments:

Post a Comment