StopWatch with annotations to Profile methods using Spring Aspect Oriented Programming (AOP)

The following example is a way to measure the execution time for methods using Spring Aspect Oriented Programming (AOP).

First we need to create a new annotation:

import java.lang.annotation.*;


@Retention(RetentionPolicy.RUNTIME)
@Target(ElementType.METHOD)
@Inherited
@Documented
public @interface ProfileExecution 

{

}

Then we can create our aspect:

import org.aspectj.lang.ProceedingJoinPoint;
import org.aspectj.lang.Signature;
import org.aspectj.lang.annotation.Around;
import org.aspectj.lang.annotation.Aspect;
import org.aspectj.lang.annotation.Pointcut;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
import org.springframework.util.StopWatch; 


@Aspect
public class ProfileExecutionAspect {

 private static final Logger logger = LoggerFactory.getLogger(ProfileExecutionAspect.class);

 @Pointcut(value="execution(public * *(..))")
 public void anyPublicMethod() { }

 @Around("anyPublicMethod() && @annotation(ProfileExecution)")
 public void profileExecuteMethod(ProceedingJoinPoint jointPoint) throws Throwable {
 Signature signature = jointPoint.getSignature();
 String methodName = signature.toShortString();

 StopWatch stopWatch = new StopWatch(ProfileExecutionAspect.class.getName());
 stopWatch.start(methodName);

 jointPoint.proceed();

 stopWatch.stop();
 logger.info(stopWatch.prettyPrint());

 }
}

We also need to annotate our configuration file with @EnableAspectJAutoProxy and create a @Bean of our aspect type ProfileExecutionAspect.

import org.springframework.context.annotation.*;

@Configuration
@ComponentScan
@EnableAspectJAutoProxy
public class Application {
 @Bean
 public ProfileExecutionAspect profileExecutionAspect() {
 return new ProfileExecutionAspect();
 }

} 

I know that some people will argue that its better to use spring xml configuration with aop but personally i prefer to use annotations.

Now you can use the @ProfileExecution to annotate any public method on a bean managed by spring container to get profile information on logger:

21:15:39.811 [main] INFO test.ProfileExecutionAspect - StopWatch 'test.ProfileExecutionAspect': running time (millis) = 10
-----------------------------------------
ms     %     Task name
-----------------------------------------
00010  100%  TestClass.testMethod()

For this sample to run you can use the following dependencies on your maven pom.xml file:

 
 <dependencies>
 <dependency>
 <groupId>org.springframework</groupId>
 <artifactId>spring-context</artifactId>
 <version>4.1.6.RELEASE</version>
 <exclusions>
 <exclusion>
 <groupId>commons-logging</groupId>
 <artifactId>commons-logging</artifactId>
 </exclusion>
 </exclusions>
 </dependency>
 <dependency>
 <groupId>org.springframework</groupId>
 <artifactId>spring-aspects</artifactId>
 <version>4.1.6.RELEASE</version>
 </dependency>
 <dependency>
 <groupId>ch.qos.logback</groupId>
 <artifactId>logback-classic</artifactId>
 <version>1.1.3</version>
 </dependency>
 <dependency>
 <groupId>org.slf4j</groupId>
 <artifactId>jcl-over-slf4j</artifactId>
 <version>1.7.12</version>
 </dependency>
 </dependencies>