[
Date Prev][
Date Next][
Thread Prev][
Thread Next][
Date Index][
Thread Index]
[
List Home]
|
Re: [aspectj-users] Logger guard with aspectj
|
No, I'm afraid you cannot use AspectJ in that way to hide the cost of
building the arguments.
They need to be built into the thisJoinPoint object for you to use
them later. If the trace aspect was inserting the calls themselves,
then they could be correctly guarded.
We have an if() pointcut which can sometimes be implemented in an
optimized fashion to avoid building the thisJoinPoint object for some
condition (eg. your pointcut can say "&& if(traceOn)" where traceOn is
some static boolean). But it is not supported for Around advice.
cheers,
Andy.
2008/6/16 Béres Gábor <beres.gabor@xxxxxxxxx>:
> 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
> _______________________________________________
> aspectj-users mailing list
> aspectj-users@xxxxxxxxxxx
> https://dev.eclipse.org/mailman/listinfo/aspectj-users
>
