[Spring 3.1] Method execution time logging using Spring AOP

Step 1. configure 'applicationContext.xml'



<?xml version="1.0" encoding="UTF-8" ?>
<beans xmlns="http://www.springframework.org/schema/beans"
xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance" xmlns:context="http://www.springframework.org/schema/context"
xmlns:aop="http://www.springframework.org/schema/aop" xmlns:p="http://www.springframework.org/schema/p"
xmlns:tx="http://www.springframework.org/schema/tx" xmlns:util="http://www.springframework.org/schema/util"
xsi:schemaLocation="http://www.springframework.org/schema/beans
           http://www.springframework.org/schema/beans/spring-beans-3.1.xsd
           http://www.springframework.org/schema/context
           http://www.springframework.org/schema/context/spring-context-3.1.xsd
           http://www.springframework.org/schema/tx
           http://www.springframework.org/schema/tx/spring-tx-3.1.xsd
           http://www.springframework.org/schema/aop
           http://www.springframework.org/schema/aop/spring-aop-3.1.xsd
           http://www.springframework.org/schema/util
           http://www.springframework.org/schema/util/spring-util-3.1.xsd"
default-autowire="no">


<aop:aspectj-autoproxy />


<context:component-scan base-package="com.core" />


<bean id="businessProfiler" class="com.core.common.MethodLogger" />


</beans>


Step2: Provide Spring Dependency.




<dependency>
<groupId>org.springframework</groupId>
<artifactId>spring-aop</artifactId>
<version>3.1.1.RELEASE</version>
</dependency>
<dependency>
<groupId>cglib</groupId>
<artifactId>cglib</artifactId>
<version>2.2.2</version>
</dependency>

Step3 : Create MethodLogger.java



package com.core.common;


import org.apache.log4j.Logger;
import org.aspectj.lang.ProceedingJoinPoint;
import org.aspectj.lang.annotation.Around;
import org.aspectj.lang.annotation.Aspect;
import org.aspectj.lang.annotation.Pointcut;
import org.springframework.stereotype.Component;


@Component
@Aspect
public class MethodLogger
{


private static final Logger log = Logger.getLogger("app." + MethodLogger.class.getName());


@Pointcut("execution(* com..*.*(..))")
public void businessMethods()
{
}


@Around("businessMethods()")
public Object timeMethod(ProceedingJoinPoint joinPoint) throws Throwable
{
long startTime = System.currentTimeMillis();
// stopWatch.start();


Object retVal = joinPoint.proceed();
long endTime = System.currentTimeMillis();


// stopWatch.stop();


// TODO: Optimize this junk code
StringBuffer logMessage = new StringBuffer();
logMessage.append(joinPoint.getTarget().getClass().getName());
logMessage.append(".");
logMessage.append(joinPoint.getSignature().getName());
logMessage.append("(");
// append args
Object[] args = joinPoint.getArgs();
for(int i = 0; i < args.length; i++)
{
logMessage.append(args[i]).append(",");
}
if(args.length > 0)
{
logMessage.deleteCharAt(logMessage.length() - 1);
}


logMessage.append(") execution time: " + (endTime - startTime) + " ms");
log.info(logMessage.toString());
return retVal;
}


/*
* @AfterReturning(pointcut = "execution(* com.core.common..*.*(..))",
* returning = "retVal") public void logAfterMethod(JoinPoint joinPoint,
* Object retVal) { }
*/
}