Problem performance Logging using Spring AOP

[rajneesh19]

Hi all,

I am trying to implement performance logging using Spring AOp in my application. But it creates only an empty log file:

Following are the configuration I am doing:
In application context:

<bean id="springMonitoringAspectInterceptor" class="org.springframework.aop.interceptor.PerformanceMonitorInterceptor">				
</bean>	
			
<aop:config>       		
	<aop:pointcut id="springMonitoringPointcut" expression="execution(* com.project14.service.common.AppService.execute(..))"/>                           	                            		
	<aop:advisor pointcut-ref="springMonitoringPointcut" advice-ref="springMonitoringAspectInterceptor"/>      	
</aop:config>

In log4j config xml:

  <appender name="perfLog" class="org.apache.log4j.DailyRollingFileAppender">
      <param name="Threshold" value="INFO" />
      <param name="File" value="${catalina.home}/logs/dashboard_pref.log"/>
      <param name="DatePattern" value="'-'yyyy-MM-dd'.log'"/>
      <layout class="org.apache.log4j.PatternLayout">
         <param name="ConversionPattern" value="[%d{ISO8601}] - %-5p- [%X{USER_ENCRYPT_ID}%x] - %C.%M(%F:%L) - %m %n" />
      </layout>
   </appender>

   <logger name="org.springframework.aop.interceptor.PerformanceMonitorInterceptor" additivity="false">
        <level value="TRACE"/>
        <appender-ref ref="perfLog"/>
    </logger>

aopalliance-1.0.jar
aspectjweaver-1.6.8.jar are in class path. There is no compilation error.

AppService is an interface all the service class implements it's execute method. I want to log execution time of excute method of each service.
I am using spring 3.0 libraries for this project.
Please help.

[ullgren]

I've not tested your example but if com.project14.service.common.AppService is an interface you should probably use the pointcut expresion

execution(* com.project14.service.common.AppService+.execute(..))

The + sign indicates that it should match any subtype of AppService.

[rajneesh19]

No its not working. Again black log file

[ullgren]

In the log4j config your appender has threshold INFO.
Since perflogging is on TRACE level you need to change that to TRACE for the appender.

As it is now the logging will be done on the logger but filtered out in the appender.

If the "execute" method is defined in the interface you do not need the plus sign in the expression.

[rajneesh19]

Thanks its working,
But the output message is not as per expectation.

[2011-12-12 16:25:04,038] - DEBUG- [03408929B88F770CDD3F1DB440D93E05-f5b5d3595709e3209bf74cb1b53618ec-Deepanssssss] - org.springframework.aop.interceptor.PerformanceMonitorInterceptor.invokeUnderTrace(PerformanceMonitorInterceptor.java:65) - StopWatch 'com.project14.service.common.AppService.execute': running time (millis) = 5391

Since all services implements AppService.execute and point cut is also defined on that, its printing interface name (AppService.execute) for all service classes, in steed of actual class name. So not able to identify which service is taking what time.

Any suggestion

[ullgren]

Set the LogTargetClassInvocation property of PerformanceMonitorInterceptor to true:

 
 <bean id="springMonitoringAspectInterceptor"
         class="org.springframework.aop.interceptor.PerformanceMonitorInterceptor">
       <property name="LogTargetClassInvocation" value="true" />
   </bean>

or force the use of CGLIB proxies by adding proxy-target-class="true" to aop:config.

 <aop:config proxy-target-class="true">