Easily time your methods with Spring AOP

What is AOP?

Aspect-Oriented Programming (AOP) complements Object-Oriented Programming (OOP) by providing another way of thinking about program structure. The key unit of modularity in OOP is the class, whereas in AOP the unit of modularity is the aspect. Aspects enable the modularization of concerns such as transaction management that cut across multiple types and objects.

AOP Key Concepts

• Aspect - a modularization of a concern that cuts across multiple classes. In Spring AOP, aspects are implemented using regular classes annotated with the @Aspect annotation.
• Join-Point -  a point during the execution of a program
  such as method execution or handling of an exception.
• Pointcut - a predicate that matches join points. In simpler words, you can think of a point cut like a pointer which points to methods/classes that matches the pointcut criteria.
• Advice - action taken by an aspect at a particular join point.

Set up maven dependencies

In your pom.xml file include this dependency in order to use Spring AOP.

<dependency>
    <groupId>org.springframework.boot</groupId>
    <artifactId>spring-boot-starter-aop</artifactId>
</dependency>

Aspect Classes:

Lets create all the necessary AOP classes.
in this example, I created a separate package and called it aspect to keep everything organized.

TrackTime.java

@Target(ElementType.METHOD)
@Retention(RetentionPolicy.RUNTIME)
public @interface TrackTime {

}

Notice, @Target(ElementType.METHOD) means this annotation will be used to annotate methods and @Retention(RetentionPolicy.RUNTIME) means it will be available in runtime. Read more about @Target and @Retention here.

CommonJoinPointConfig.java

Lets set our first pointcut to use the TrackTime annotation.
Obviously we could define the @Pointcut on each Aspect function we use, but it is best-practice to keep all the @Pointcuts in one place. This approach is aligned with the Single-responsibility-principle  and it will prevent code duplication in cases we need to use a @Pointcut more than one time.

public class CommonJoinPointConfig {

	@Pointcut("@annotation(com.aspectDemo.aspect.TrackTime)")
	public void trackTimeAnnotation(){}
}

BasicAspectAccess.Java

Finally, add the Advice that will be executed when the pointcut is triggered.
@Around annotation let us use a ProceedingJoinPoint which means we can execute code before and after the method is triggered.

@Aspect
@Configuration
public class BasicAspectAccess {
	@Around("com.aspectDemo.aspect.CommonJoinPointConfig.trackTimeAnnotation()")
	public Object around(ProceedingJoinPoint joinPoint) throws Throwable {
		long startTime = System.currentTimeMillis();

		Object o  = joinPoint.proceed();

		long timeTaken = System.currentTimeMillis() - startTime;
		logger.info("Time Taken by {} is {}ms", joinPoint, timeTaken);
		return o;
	}
}

Spring Application

Now, we can create a simple SpringBootApplication to demonstrate the AOP functionality.

Dao.Java
This @Repository class simulates data fetch from the database.

@Repository
public class Dao {
	public String retrieveSomethingFromDB() {
		return "Data from DB";
	}
}

BusinessLogic.Java
This @Service class executes business logic a retrieved db data.
Lets say we would like to time the function 'executeBusinessLogic()', so we will add @TrackTime annotation to it.

@Service
public class BusinessLogic {

	private Logger logger = LoggerFactory.getLogger(this.getClass());

	private final Dao dao;

	// using Spring constructor injection
	public BusinessLogic(Dao dao) {
		this.dao = dao;
	}

	@TrackTime
	public String executeBusinessLogic() {
		String data = dao.retrieveSomethingFromDB();
		logger.info("In BusinessLogic - {}", data);
		return data;
	}
}

Application.Java
Finally, lets create an Application class to run the code.

@SpringBootApplication
public class Application implements CommandLineRunner{

	private final Logger logger = LoggerFactory.getLogger(this.getClass());
	private final BusinessLogic businessLogic;

	// using spring constructor injection
	public Application(BusinessLogic businessLogic) {
		this.businessLogic = businessLogic;
	}

	public static void main(String[] args) {
		SpringApplication.run(Application.class, args);
	}

	@Override
	public void run(String... args) throws Exception {
		logger.info(businessLogic.executeBusinessLogic());
	}
}

Run the Application

After running the app, lets take a look at the logs :

  .   ____          _            __ _ _
 /\\ / ___'_ __ _ _(_)_ __  __ _ \ \ \ \
( ( )\___ | '_ | '_| | '_ \/ _` | \ \ \ \
 \\/  ___)| |_)| | | | | || (_| |  ) ) ) )
  '  |____| .__|_| |_|_| |_\__, | / / / /
 =========|_|==============|___/=/_/_/_/
 :: Spring Boot ::                (v2.5.6)

2022-08-22 16:35:27.162  INFO 92717 --- [main] 
	ctAccess$$EnhancerBySpringCGLIB$$20ef027 :
	Time Taken by execution(String 		
	com.aspectDemo.business.BusinessLogic.executeBusinessLogic()) is 8ms

You can see that the function 'executeBusinessLogic()' indeed measured and the time it took it to run is 8ms.

All the code from this post can be found in this Github repo.