6 Replies Latest reply on Sep 29, 2005 2:33 PM by Michael Frieß

    Intercepting some method deep down in log4j

    Michael Frieß Newbie

      Hey Folks :-)

      I'm currently wondering if it is possible to intercept a method in a library if the method is called within the library itself (meaning: the method is NOT called directly within your own sources).
      Here is some source code, to clarify my question.

      My jboss-aop.xml contains:

       <bind pointcut="call(void org.apache.log4j.ConsoleAppender->append(LoggingEvent))">
       <advice name="print" aspect="MyAspect"/>
       </bind>
      


      My own sources contain statements like:

       logger.log("hi");
       logger.debug("guys");
       logger.error("!!!");
      


      "logger" is a static log4j variable. So this would call several methods within the log4j library and may find its way to the org.apache.log4j.ConsoleAppender class and finally to System.out & err...

      I'm aware that it is possible to create a binding which would intercept all calls to logger.log(), logger.error(), etc... However, I would like to do the interception as deep as possible within the log4j library itself... At the root, you could say :-)

      Can't wait for your replies :-) Thanks in advance.


        • 1. Re: Intercepting some method deep down in log4j
          Bill Burke Master

          Sure, should work. Witha ll JBoss AOP programs you either use AOPC, our compiler (you'd have to unjar log4j and compile everything), or use runtime weaving. See our documentation for details.

          Let me know how it goes.

          • 2. Re: Intercepting some method deep down in log4j
            Michael Frieß Newbie

            Ok, I tried it over a few days now and it works partially.

            Unfortunately, it seems that you can not intercept a method-execution within a class "B" if the method is defined in "B"'s super-class "A", can you?

            I also tried expressions like:

            within(org.apache.log4j.ConsoleAppender) AND execution(* $instanceof{org.apache.log4j.WriterAppender}->subAppend(..))
            
            //subAppend is defined in WriterAppender but is inherited to ConsoleAppender -> protected void subAppend(LoggingEvent event)
            

            ...without success :-(

            The next thing I tried was to use a caller-pointcut. However I could not find out how to get (and change) the paramters for the actual method being called... (not that important, though - however it may be a nice feature to have)


            Thanks in advance,

            freezy

            • 3. Re: Intercepting some method deep down in log4j
              Michael Frieß Newbie

              Oh, to the "works partially"-part.
              I'm currently using the expression:

              <bind pointcut="execution(* org.apache.log4j.Category->debug(..))">
              


              This "hacks" into "org.apache.log4j.Category" which seems to be the outer most class within the log4j-delegating-process...

              Of course this is less than optimal, because I would simply like to "hack" directly into "ConsoleAppender" so that other Loggers are not affected...


              • 4. Re: Intercepting some method deep down in log4j
                Bill Burke Master

                Oh, you mean, you want to intercept subAppend, which is defined ina Superclass, but only with instances of B?

                No, we don't support that yet, but Kabir is fixing (fixed) this in 2.0. You would have to "prepare" the superclass though and the expression would be:

                execution(* org.apache.log4j.ConsoleAppender->subAppend(..))
                



                • 5. Re: Intercepting some method deep down in log4j
                  Michael Frieß Newbie

                  Hi again :-)

                  I'm currently trying to catch executions of WriterAppender->subAppend() (tried also append()). Unfortunately, I'm getting this exception:

                   [java] java.lang.ExceptionInInitializerError
                   [java] at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
                   [java] at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:39)
                   [java] at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:27)
                   [java] at java.lang.reflect.Constructor.newInstance(Constructor.java:274)
                   [java] at java.lang.Class.newInstance0(Class.java:308)
                   [java] at java.lang.Class.newInstance(Class.java:261)
                   [java] at org.apache.log4j.xml.DOMConfigurator.parseAppender(DOMConfigurator.java:174)
                   [java] at org.apache.log4j.xml.DOMConfigurator.findAppenderByName(DOMConfigurator.java:150)
                   [java] at org.apache.log4j.xml.DOMConfigurator.findAppenderByReference(DOMConfigurator.java:163)
                   [java] at org.apache.log4j.xml.DOMConfigurator.parseChildrenOfLoggerElement(DOMConfigurator.java:425)
                   [java] at org.apache.log4j.xml.DOMConfigurator.parseRoot(DOMConfigurator.java:394)
                   [java] at org.apache.log4j.xml.DOMConfigurator.parse(DOMConfigurator.java:829)
                   [java] at org.apache.log4j.xml.DOMConfigurator.doConfigure(DOMConfigurator.java:712)
                   [java] at org.apache.log4j.xml.DOMConfigurator.doConfigure(DOMConfigurator.java:618)
                   [java] at org.apache.log4j.helpers.OptionConverter.selectAndConfigure(OptionConverter.java:468)
                   [java] at org.apache.log4j.LogManager.<clinit>(LogManager.java:122)
                   [java] at org.apache.log4j.Logger.getLogger(Logger.java:117)
                   [java] at eshop.aop.SimpleProfilingInterceptor.<clinit>(SimpleProfilingInterceptor.java:42)
                   [java] at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
                   [java] at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:39)
                   [java] at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:27)
                   [java] at java.lang.reflect.Constructor.newInstance(Constructor.java:274)
                   [java] at java.lang.Class.newInstance0(Class.java:308)
                   [java] at java.lang.Class.newInstance(Class.java:261)
                   [java] at org.jboss.aop.advice.GenericAspectFactory.createPerVM(GenericAspectFactory.java:131)
                   [java] at org.jboss.aop.AspectManager.getPerVMAspect(AspectManager.java:1382)
                   [java] at org.jboss.aop.AspectManager.getPerVMAspect(AspectManager.java:1371)
                   [java] at org.jboss.aop.advice.ScopedInterceptorFactory.create(ScopedInterceptorFactory.java:46)
                   [java] at org.jboss.aop.Advisor.createInterceptorChain(Advisor.java:531)
                   [java] at org.jboss.aop.Advisor.resolveMethodPointcut(Advisor.java:572)
                   [java] at org.jboss.aop.ClassAdvisor.createInterceptorChains(ClassAdvisor.java:451)
                   [java] at org.jboss.aop.ClassAdvisor$1.run(ClassAdvisor.java:233)
                   [java] at java.security.AccessController.doPrivileged(Native Method)
                   [java] at org.jboss.aop.ClassAdvisor.attachClass(ClassAdvisor.java:205)
                   [java] at org.jboss.aop.AspectManager.getAdvisor(AspectManager.java:439)
                   [java] at eshop.test.ConsoleClient.<clinit>(ConsoleClient.java)
                   [java] Caused by: java.lang.ClassCastException
                   [java] at org.jboss.aop.advice.ScopedInterceptorFactory.create(ScopedInterceptorFactory.java:46)
                   [java] at org.jboss.aop.Advisor.createInterceptorChain(Advisor.java:531)
                   [java] at org.jboss.aop.Advisor.resolveMethodPointcut(Advisor.java:572)
                   [java] at org.jboss.aop.ClassAdvisor.createInterceptorChains(ClassAdvisor.java:451)
                   [java] at org.jboss.aop.ClassAdvisor$1.run(ClassAdvisor.java:233)
                   [java] at java.security.AccessController.doPrivileged(Native Method)
                   [java] at org.jboss.aop.ClassAdvisor.attachClass(ClassAdvisor.java:205)
                   [java] at org.jboss.aop.AspectManager.getAdvisor(AspectManager.java:439)
                   [java] at org.apache.log4j.WriterAppender.<clinit>(WriterAppender.java)
                   [java] ... 36 more
                  


                  My pointcut definition:
                   <bind pointcut="execution(* org.apache.log4j.WriterAppender->subAppend(org.apache.log4j.spi.LoggingEvent))">
                   <interceptor class="eshop.aop.TraceToConsoleInterceptor"/>
                   </bind>
                  


                  Interceptor code:
                   public java.lang.Object invoke(org.jboss.aop.joinpoint.Invocation invocation) throws java.lang.Throwable
                   {
                   try
                   {
                   System.out.println("entering");
                   return invocation.invokeNext();
                   }
                   finally
                   {
                   System.out.println("leaving");
                   }
                   }
                  


                  Log4j calling order:
                   consoleAppenderInstance.doAppend(); // defined in WriterAppender
                   this.append(); // defined in AppenderSkeleton
                   this.subAppend(); // defined in WriterAppender
                  


                  I'm using the AOP-Classloader and Jdk1.4.
                  Any ideas what this might cause? I don't get it, because as I understand JBossAOP it should work this way: if I use a pointcut definition for WriterAppender's method "subAppend" then the "subAppend" method gets aspected. So every call from a sub-class should call the aspected method, shouldn't it?

                  I hope it's not too difficult to understand my thoughts :-)

                  Thanks in advance,
                  freezy

                  • 6. Re: Intercepting some method deep down in log4j
                    Michael Frieß Newbie

                    Uhm, I found the error :-)
                    I forgot to have the Interceptor interface in the class definition...