[
Date Prev][
Date Next][
Thread Prev][
Thread Next][
Date Index][
Thread Index]
[
List Home]
[aspectj-users] Logger guard with aspectj
|
Hi!
In my project, there are nearly 5000+ log.* calls, and they have lots
of string concatenations in they argument.
As you know, these arguments are processed, no mather, the current log
level is applicable for a specific log call, or not.
For Example:
_log.info("This " + "is " + "an " + "info " + "level" + " log" + " call");
The arguments are processed by java at ERROR log level.
Based on profiler info, i found out, that this is a major performance
issue, so i need a solution.
You probably know, that log4j has a solution to that, what is called
"logger guard".
You applicate logger guard to performance critical log statements like this:
if(_log.isInfoEnabled())
_log.info("This " + "is " + "an " + "info " + "level" + " log"
+ " call");
To insert these statements 5000+ places is no option for me, so i
wrote an aspectj aspect, to weave these into the code at compile time:
@Aspect
public class LoggerGuardAspect {
public static String TRACE = "trace";
public static String DEBUG = "debug";
public static String INFO = "info";
public static String WARN = "warn";
public static String ERROR = "error";
public static String FATAL = "fatal";
private static Log _log = LogFactory.getLog(LoggerGuardAspect.class);
@Pointcut("call(* org.apache.commons.logging.Log.*(..)) &&
!within(org.aspect.LoggerGuardAspect)")
void loggerCall() {
}
@Around("loggerCall()")
public Object guardLogger(ProceedingJoinPoint thisJoinPoint) {
String methodName = thisJoinPoint.getSignature().getName();
if (methodName.equals(TRACE))
return guardLogger(thisJoinPoint, _log.isTraceEnabled());
else if (methodName.equals(DEBUG))
return guardLogger(thisJoinPoint, _log.isDebugEnabled());
else if (methodName.equals(INFO))
return guardLogger(thisJoinPoint, _log.isInfoEnabled());
else if (methodName.equals(WARN))
return guardLogger(thisJoinPoint, _log.isWarnEnabled());
else if (methodName.equals(ERROR))
return guardLogger(thisJoinPoint, _log.isErrorEnabled());
else if (methodName.equals(FATAL))
return guardLogger(thisJoinPoint, _log.isFatalEnabled());
return null;
}
private Object guardLogger(ProceedingJoinPoint thisJoinPoint, boolean
isLevelEnabled) {
try {
if (isLevelEnabled) {
return thisJoinPoint.proceed();
}
} catch (Throwable e) {
// never happen
}
return null;
}
}
I haven't experienced any performance boost with that aspect, so i
decompiled the weaven class to figure out what stuff aspectj exactly
inserted:
This is the original Test.java, before weave:
public class Test {
private static Log _log = LogFactory.getLog(Main.class);
public void loggedCall() {
_log.info("hello");
}
public static void main(String[] args) {
Main main = new Main();
main.loggedCall();
}
}
And this is the decompiled weaven version:
public class Main
{
public Main()
{
}
public void loggedCall()
{
String s = "hello";
Log log = _log;
JoinPoint joinpoint = Factory.makeJP(ajc$tjp_0, this, log, s);
Object aobj[] = new Object[4];
aobj[0] = this;
aobj[1] = log;
aobj[2] = s;
aobj[3] = joinpoint;
LoggerGuardAspect.aspectOf().guardLogger((new
AjcClosure1(aobj)).linkClosureAndJoinPoint(4112));
}
public static void main(String args[])
{
Main main = new Main();
main.loggedCall();
}
static final void info_aroundBody0(Main main1, Log log, Object
obj, JoinPoint joinpoint)
{
log.info(obj);
}
private static Log _log = LogFactory.getLog(org/test/Main);
private static final org.aspectj.lang.JoinPoint.StaticPart
ajc$tjp_0; /* synthetic field */
static
{
Factory factory = new Factory("Main.java",
Class.forName("org.test.Main"));
ajc$tjp_0 = factory.makeSJP("method-call",
factory.makeMethodSig("601", "info", "org.apache.commons.logging.Log",
"java.lang.Object:", "arg0:", "", "void"), 11);
}
private class AjcClosure1 extends AroundClosure
{
public Object run(Object aobj[])
{
Object aobj1[] = super.state;
Main.info_aroundBody0((Main)aobj1[0], (Log)aobj1[1],
aobj1[2], (JoinPoint)aobj1[3]);
return null;
}
public AjcClosure1(Object aobj[])
{
super(aobj);
}
}
}
Its not suprising that this code is not as fast as i expected. I can
see aspectj runtime calles, and other tricks.
Is there a way to get rid of these, or aspectj is simply not the
perfect solution to my problem?
Thanks