Learn to create aspectj based interceptor in spring boot application to write performance logging based on time taken in method executions of aop intercepted methods.
1. Maven Dependency
To add AOP support, we must include spring-boot-starter-aop dependency in application.
<project xmlns="http://maven.apache.org/POM/4.0.0" xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance" xsi:schemaLocation="http://maven.apache.org/POM/4.0.0 http://maven.apache.org/xsd/maven-4.0.0.xsd"> <modelVersion>4.0.0</modelVersion> <groupId>com.company</groupId> <artifactId>SpringBootEhcache</artifactId> <version>0.0.1-SNAPSHOT</version> <packaging>jar</packaging> <name>SpringBootEhcache</name> <url>http://maven.apache.org</url> <parent> <groupId>org.springframework.boot</groupId> <artifactId>spring-boot-starter-parent</artifactId> <version>2.1.6.RELEASE</version> <relativePath /> </parent> <properties> <project.build.sourceEncoding>UTF-8</project.build.sourceEncoding> <project.reporting.outputEncoding>UTF-8</project.reporting.outputEncoding> <java.version>1.8</java.version> <skipTests>true</skipTests> </properties> <dependencies> <dependency> <groupId>org.springframework.boot</groupId> <artifactId>spring-boot-starter-web</artifactId> </dependency> <dependency> <groupId>org.springframework.boot</groupId> <artifactId>spring-boot-starter-aop</artifactId> </dependency> <dependency> <groupId>org.apache.commons</groupId> <artifactId>commons-lang3</artifactId> </dependency> </dependencies> <build> <plugins> <plugin> <groupId>org.springframework.boot</groupId> <artifactId>spring-boot-maven-plugin</artifactId> </plugin> </plugins> </build> </project>
If you are not using Spring boot, then add below dependencies.
<dependency> <groupId>org.springframework</groupId> <artifactId>spring-aop</artifactId> <version>5.0.1.RELEASE</version> </dependency> <dependency> <groupId>org.aspectj</groupId> <artifactId>aspectjweaver</artifactId> <version>1.8.12</version> </dependency>
2. Performance Logging Aspect
Create a spring bean and use annotation @Aspect on class to make it AOP aspect. It will have the methods which can intercept the methods and apply advice around those methods.
Make sure to use @EnableAspectJAutoProxy annotation along with
@Configuration
to enable aop support, if you are not using spring boot auto configuration.
In given class, we have used @Around advice around all methods present in classes in package com.company.service
.
We used StopWatch
class to capture start time of method and end time of method. By subtracting start time from end time, we get the total time taken for method execution.
The ProceedingJoinPoint class argument provides us the class name and method name which is going to be executed.
At last, we log everything in desired format in log files.
package com.company.aop; import org.apache.logging.log4j.LogManager; import org.apache.logging.log4j.Logger; import org.aspectj.lang.ProceedingJoinPoint; import org.aspectj.lang.annotation.Around; import org.aspectj.lang.annotation.Aspect; import org.aspectj.lang.reflect.MethodSignature; import org.springframework.stereotype.Component; import org.springframework.util.StopWatch; @Aspect @Component public class LoggingAspect { private static final Logger LOGGER = LogManager.getLogger(LoggingAspect.class); //AOP expression for which methods shall be intercepted @Around("execution(* com.company.service..*(..)))") public Object profileAllMethods(ProceedingJoinPoint proceedingJoinPoint) throws Throwable { MethodSignature methodSignature = (MethodSignature) proceedingJoinPoint.getSignature(); //Get intercepted method details String className = methodSignature.getDeclaringType().getSimpleName(); String methodName = methodSignature.getName(); final StopWatch stopWatch = new StopWatch(); //Measure method execution time stopWatch.start(); Object result = proceedingJoinPoint.proceed(); stopWatch.stop(); //Log method execution time LOGGER.info("Execution time of " + className + "." + methodName + " :: " + stopWatch.getTotalTimeMillis() + " ms"); return result; } }
3. Classes and intercepted methods
For demo purpose, we are writing a very simple manager class and a single method. AOP will intercept the method and apply advice around the method. The advice is actually measuring the execution time of the method.
package com.company.service; import java.util.HashMap; import org.springframework.stereotype.Service; import com.company.domain.Employee; @Service public class EmployeeManager { static HashMap<Long, Employee> db = new HashMap<>(); static { db.put(1L, new Employee(1L, "Alex", "Gussin")); db.put(2L, new Employee(2L, "Brian", "Schultz")); } public Employee getEmployeeById(Long id) { return db.get(id); } }
package com.company.domain; import java.io.Serializable; public class Employee implements Serializable { private static final long serialVersionUID = 5517244812959569947L; private Long id; private String firstName; private String lastName; public Employee() { super(); } public Employee(Long id, String firstName, String lastName) { super(); this.id = id; this.firstName = firstName; this.lastName = lastName; } //Getters and setters @Override public String toString() { return "Employee [id=" + id + ", firstName=" + firstName + ", lastName=" + lastName + "]"; } }
4. Spring boot performance logging example
To check the logging, start the spring boot application and access the method.
package com.company; import org.springframework.beans.factory.annotation.Autowired; import org.springframework.boot.CommandLineRunner; import org.springframework.boot.SpringApplication; import org.springframework.boot.autoconfigure.SpringBootApplication; import org.springframework.context.ApplicationContext; import org.springframework.context.annotation.Bean; import com.company.service.EmployeeManager; @SpringBootApplication public class Application { @Autowired private EmployeeManager employeeManager; public static void main(String[] args) { SpringApplication.run(Application.class, args); } @Bean public CommandLineRunner commandLineRunner(ApplicationContext ctx) { return args -> { System.out.println(employeeManager.getEmployeeById(1L)); }; } }
Program output.
16:29:25.031 [main] INFO com.company.aop.LoggingAspect - Execution time of EmployeeManager.getEmployeeById :: 9 ms Employee [id=1, firstName=Alex, lastName=Gussin]
Clearly, now we are able to measure and log the performance in terms of method execution time for all intercepted methods.
Happy Learning !!
Hi Thanks for this tutorial snippet, by the way, I want to write the logs into file or database systems. Is it possible to do that so? (using spring AOP)
Everything is possible. I would suggest putting logs in files. Today tools, like Splunk, can perform any kind of reporting.