Runtime / Method Logger

**ManuelBreu** · Jun 3rd, 2008, 09:54 AM

Hi there!
I just tried to set up a runtime logger and a method logger.
This is my code:

Code:

package com.psylock.passwordreset.log;

import org.apache.commons.logging.Log;
import org.apache.commons.logging.LogFactory;
import org.aspectj.lang.ProceedingJoinPoint;
import org.springframework.util.StopWatch;

// works only when debug modus is enable in log4j.properties (e.g. log4j.rootLogger=info, logfile)

public class RuntimeLog {

  private static final Log LOG = LogFactory.getLog( RuntimeLog.class );

  // this method is the around advice
  public Object logRuntime( final ProceedingJoinPoint call ) throws Throwable {
    Object returnValue;
    if( LOG.isDebugEnabled() ) {
      final String targetClassName = call.getTarget().getClass().getName();
      final String targetMethodName = call.getSignature().getName();
      final Log targetLog = LogFactory.getLog( targetClassName );
      if( targetLog.isDebugEnabled() ) {
        final StopWatch clock = new StopWatch( getClass().getName() );
        try {
          clock.start( call.toShortString() );
          returnValue = call.proceed();
        }
        finally {
          clock.stop();
          final StringBuffer sb = new StringBuffer( "Runtime " );
          sb.append( targetMethodName ).append( ":"  ); 
          sb.append( clock.getTotalTimeSeconds()   );
          targetLog.debug( sb.toString() );
        }
      }
      else {
        returnValue = call.proceed();
      }
    }
    else {
      returnValue = call.proceed();
    }
    return returnValue;
  }
}

Code:

[package com.psylock.passwordreset.log;

import org.apache.commons.logging.Log;
import org.apache.commons.logging.LogFactory;
import org.aspectj.lang.JoinPoint;


public class MethodLog {
  //Works only if INFO or DEBUG-modus is enabled in log4j.properties	
  
	private static final Log LOG = LogFactory.getLog( MethodLog.class );

  public void logMethodEntry( final JoinPoint joinPoint ) {
    if( LOG.isDebugEnabled() || LOG.isInfoEnabled() ) {
      final Object[] args = joinPoint.getArgs();
      final String name = joinPoint.getSignature().toLongString();
      final StringBuffer sb = new StringBuffer( name + "called with: [" );
      for( int i = 0; i < args.length; i++ ){
          final Object o = args[ i ];
          sb.append( o );
          sb.append( ( i == args.length - 1 ) ? "]" : ", " );
        }
        if(LOG.isDebugEnabled())
        	LOG.debug( sb );
        else if(LOG.isInfoEnabled())
        	LOG.info( sb );
    }
  }
  
  public void logMethodExit( final JoinPoint joinPoint, final Object result ) {
    if( LOG.isDebugEnabled() ) {
      final String name = joinPoint.getSignature().toLongString();
      if( LOG.isDebugEnabled() ) 
  		LOG.debug( name + " returning: [" + result + "]" );
      else if(LOG.isInfoEnabled())
  	  	LOG.info(  name + " returning: [" + result + "]" ); 
    }
  }
}

my application-servlet is configured that way:

Code:

[<beans xmlns="http://www.springframework.org/schema/beans" xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
        xmlns:p="http://www.springframework.org/schema/p" xmlns:context="http://www.springframework.org/schema/context"
        xsi:schemaLocation="
	        http://www.springframework.org/schema/beans 
	        http://www.springframework.org/schema/beans/spring-beans-2.5.xsd
	        http://www.springframework.org/schema/context 
	        http://www.springframework.org/schema/context/spring-context-2.5.xsd
            
           http://www.springframework.org/schema/tx 
           http://www.springframework.org/schema/tx/spring-tx-2.0.xsd                       
           http://www.springframework.org/schema/aop    
           http://www.springframework.org/schema/aop/spring-aop-2.0.xsd"
      xmlns:aop="http://www.springframework.org/schema/aop" 
      xmlns:tx="http://www.springframework.org/schema/tx" >
         
[....]

  <bean id="runtimeLog" class="com.testapp.test.log.RuntimeLog" />
  <bean id="methodLog"  class="com.testapp.test.log.MethodLog" />
  

   <aop:config>  
    <aop:pointcut id="serviceMethods" 
      expression="execution(com.testapp.test.service.*(..))" />
    

    <aop:aspect id="profilingAspect" ref="runtimeLog">
      <aop:around method="logRuntime" 
        pointcut-ref="serviceMethods" />
    </aop:aspect>
    

    <aop:aspect id="loggingAspect" ref="methodLog">
      <aop:before method="logMethodEntry" 
        pointcut-ref="serviceMethods" />
      <aop:after-returning method="logMethodExit" 
        returning="result" pointcut-ref="serviceMethods" />
    </aop:aspect>   
  </aop:config>

However, I'm getting the following exception:

Code:

03.06.2008 16:49:12 org.apache.catalina.core.ApplicationContext log
INFO: Initializing Spring FrameworkServlet 'PasswordReset'
03.06.2008 16:49:12 org.apache.catalina.core.ApplicationContext log
SCHWERWIEGEND: StandardWrapper.Throwable
org.springframework.beans.factory.BeanDefinitionStoreException: Unexpected exception parsing XML document from ServletContext resource [/WEB-INF/PasswordReset-servlet.xml]; nested exception is java.lang.NoClassDefFoundError: org/aspectj/weaver/reflect/ReflectionWorld$ReflectionWorldException
	at org.springframework.beans.factory.xml.XmlBeanDefinitionReader.doLoadBeanDefinitions(XmlBeanDefinitionReader.java:420)
	at org.springframework.beans.factory.xml.XmlBeanDefinitionReader.loadBeanDefinitions(XmlBeanDefinitionReader.java:342)
	at org.springframework.beans.factory.xml.XmlBeanDefinitionReader.loadBeanDefinitions(XmlBeanDefinitionReader.java:310)
	at org.springframework.beans.factory.support.AbstractBeanDefinitionReader.loadBeanDefinitions(AbstractBeanDefinitionReader.java:143)
	at org.springframework.beans.factory.support.AbstractBeanDefinitionReader.loadBeanDefinitions(AbstractBeanDefinitionReader.java:178)
	at org.springframework.beans.factory.support.AbstractBeanDefinitionReader.loadBeanDefinitions(AbstractBeanDefinitionReader.java:149)
	at org.springframework.web.context.support.XmlWebApplicationContext.loadBeanDefinitions(XmlWebApplicationContext.java:124)
	at org.springframework.web.context.support.XmlWebApplicationContext.loadBeanDefinitions(XmlWebApplicationContext.java:92)
	at org.springframework.context.support.AbstractRefreshableApplicationContext.refreshBeanFactory(AbstractRefreshableApplicationContext.java:123)
	at org.springframework.context.support.AbstractApplicationContext.obtainFreshBeanFactory(AbstractApplicationContext.java:423)
	at org.springframework.context.support.AbstractApplicationContext.refresh(AbstractApplicationContext.java:353)
	at org.springframework.web.servlet.FrameworkServlet.createWebApplicationContext(FrameworkServlet.java:354)
	at org.springframework.web.servlet.FrameworkServlet.initWebApplicationContext(FrameworkServlet.java:292)
	at org.springframework.web.servlet.FrameworkServlet.initServletBean(FrameworkServlet.java:262)
	at org.springframework.web.servlet.HttpServletBean.init(HttpServletBean.java:126)
	at javax.servlet.GenericServlet.init(GenericServlet.java:212)
	at org.apache.catalina.core.StandardWrapper.loadServlet(StandardWrapper.java:1161)
	at org.apache.catalina.core.StandardWrapper.allocate(StandardWrapper.java:806)
	at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:129)
	at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:175)
	at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:128)
	at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:102)
	at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:109)
	at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:286)
	at org.apache.coyote.http11.Http11AprProcessor.process(Http11AprProcessor.java:856)
	at org.apache.coyote.http11.Http11AprProtocol$Http11ConnectionHandler.process(Http11AprProtocol.java:565)
	at org.apache.tomcat.util.net.AprEndpoint$Worker.run(AprEndpoint.java:1509)
	at java.lang.Thread.run(Unknown Source)
Caused by: java.lang.NoClassDefFoundError: org/aspectj/weaver/reflect/ReflectionWorld$ReflectionWorldException
	at java.lang.Class.forName0(Native Method)
	at java.lang.Class.forName(Unknown Source)
	at org.springframework.aop.config.ConfigBeanDefinitionParser.class$(ConfigBeanDefinitionParser.java:208)
	at org.springframework.aop.config.ConfigBeanDefinitionParser.createPointcutDefinition(ConfigBeanDefinitionParser.java:536)
	at org.springframework.aop.config.ConfigBeanDefinitionParser.parsePointcut(ConfigBeanDefinitionParser.java:473)
	at org.springframework.aop.config.ConfigBeanDefinitionParser.parse(ConfigBeanDefinitionParser.java:142)
	at org.springframework.beans.factory.xml.NamespaceHandlerSupport.parse(NamespaceHandlerSupport.java:69)
	at org.springframework.beans.factory.xml.BeanDefinitionParserDelegate.parseCustomElement(BeanDefinitionParserDelegate.java:1253)
	at org.springframework.beans.factory.xml.BeanDefinitionParserDelegate.parseCustomElement(BeanDefinitionParserDelegate.java:1243)
	at org.springframework.beans.factory.xml.DefaultBeanDefinitionDocumentReader.parseBeanDefinitions(DefaultBeanDefinitionDocumentReader.java:135)
	at org.springframework.beans.factory.xml.DefaultBeanDefinitionDocumentReader.registerBeanDefinitions(DefaultBeanDefinitionDocumentReader.java:92)
	at org.springframework.beans.factory.xml.XmlBeanDefinitionReader.registerBeanDefinitions(XmlBeanDefinitionReader.java:507)
	at org.springframework.beans.factory.xml.XmlBeanDefinitionReader.doLoadBeanDefinitions(XmlBeanDefinitionReader.java:398)
	... 27 more

I hope you can help me. I'm new to Spring AOP and don't know what is wrong here

Thanks!

Greetz
manu

**Marten Deinum** · Jun 3rd, 2008, 01:28 PM

Make sure you have the aspectj-weaver.jar on your classpath.

**ManuelBreu** · Jun 6th, 2008, 04:39 AM

Hi!
Aspectj-weaver.jar is added to the buildpath as well as the other aspectj jars (aspectj-1.6.0).
Is it possible that the reason for the error may be a wrong path:
"execution(com.testapp.test.service.*(..))"
(all methods in all classes, which are located in the package com.testapp.test.service).

greetz
manu

**Marten Deinum** · Jun 6th, 2008, 04:55 AM

The fact that it is at the BUILDTIME CLASSPATH doesn't mean it is at the RUNTIME CLASSPATH.... So check your server and generated war file.

**ManuelBreu** · Jun 6th, 2008, 12:09 PM

I'm using eclipse to deploy my projects, which includes all needed jars automatically if they are added to the buildpath.
So all needed jars are existent.

greetz,
manu

**Marten Deinum** · Jun 6th, 2008, 01:51 PM

Well there is something wrong with your classpath. So you might want to check your tomcat instance and check if there is maybe some different aspectj version/jar somewhere in its classpath.

**David Winterfeldt** · Jun 7th, 2008, 03:40 PM

If you're sure it's in your classpath, also double check that you have your J2EE modules set right for the Eclipse project in case the AspectJ jar wasn't included. If it isn't, it won't be deployed to Tomcat.

Project Properties/J2EE Module Depedencies

**Marten Deinum** · Jun 9th, 2008, 02:23 AM

Good point David!. I keep forgetting that you have to specify it there also, at least for referenced libraries.

**ManuelBreu** · Jun 9th, 2008, 05:27 AM

Hi, again..
How embarrising..

There was a problem in Eclipse and the jars hadn't been added..
Now I fixed the problem and the method works fine =)
However, another little problem:
If I want to log all method entries etc. at the package com.test.testapp.api.service, which pointcut-path is needed?
I tried "execution(* com.test.testapp.api.service.*(..))".
However, I'm getting an exception: "warning no match for this type name"

greetz
manu

**Marten Deinum** · Jun 9th, 2008, 05:42 AM

Your pointcut is wrong. You match the execution of any method on a class named 'service' in the 'com.test.testapp.api' package. You propaly forgot a .* to indicatie any class.

Code:

<aop:pointcut id="serviceMethod" expression="execution(* com.test.testapp.api.service.*.*(..))" />

Thread: Runtime / Method Logger

Thread Tools

Display

Runtime / Method Logger

Posting Permissions