This example shows you how to configure Spring AOP method profiling. We can use Spring AOP with any method in any service (or other) classes without writing a single line of profiling code in any of the service classes. Aspect Oriented Programming (AOP) allows us to separate the (usually duplicated and boilerplate) profiling code from the service code.
Spring AOP Method Profiling
We write our profiler code only once in a separated class (SimpleProfiler.java), and that’s all, the rest is only AOP configuration in spring.xml that has to be done for working.
So we are able to do method profiling for following.
- profiling any (service) classes,
- without touching (service) classes’ code,
- through Spring-AOP approach.
Spring AOP method profiling project structure
Spring AOP Maven dependencies
We will first look into our pom.xml file for all the required dependencies and their versions. We are using Spring 4 in this example.
|
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 29 30 31 32 33 34 35 36 37 38 39 40 41 42 43 44 45 46 47 48 49 50 |
<project xmlns="https://maven.apache.org/POM/4.0.0" xmlns:xsi="https://www.w3.org/2001/XMLSchema-instance" xsi:schemaLocation="https://maven.apache.org/POM/4.0.0 https://maven.apache.org/xsd/maven-4.0.0.xsd"> <modelVersion>4.0.0</modelVersion> <groupId>hu.daniel.hari.learn.spring</groupId> <artifactId>Tutorial-SpringAop-Profiling</artifactId> <version>1.0</version> <packaging>jar</packaging> <properties> <!-- Generic properties --> <project.build.sourceEncoding>UTF-8</project.build.sourceEncoding> <java.version>1.7</java.version> <!-- SPRING --> <spring.version>4.0.0.RELEASE</spring.version> </properties> <dependencies> <!-- Spring (includes spring-aop)--> <dependency> <groupId>org.springframework</groupId> <artifactId>spring-context</artifactId> <version>${spring.version}</version> </dependency> <!-- AspectJ (required spring-aop dependency) --> <dependency> <groupId>org.aspectj</groupId> <artifactId>aspectjweaver</artifactId> <version>1.8.5</version> </dependency> <!-- LOG --> <dependency> <groupId>log4j</groupId> <artifactId>log4j</artifactId> <version>1.2.17</version> </dependency> </dependencies> <build> <plugins> <!-- This plugin is needed to define the java version in maven project. --> <plugin> <groupId>org.apache.maven.plugins</groupId> <artifactId>maven-compiler-plugin</artifactId> <version>3.1</version> <configuration> <source>${java.version}</source> <target>${java.version}</target> </configuration> </plugin> </plugins> </build> </project> |
- We need spring-context as Spring dependency.
- spring-aop also comes with spring-context as it’s dependent library, so no need to add it.
- aspectjweaver is spring-aop’s dependency, but we have to add it since it is not defined explicitly for spring-aop.
Spring Service class (to be profiled)
We write our service class first, that has methods for simulate short and long processes, and one more that throws exception.
|
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 29 |
package hu.daniel.hari.learn.spring.aop.profiling.service; import org.springframework.stereotype.Component; /** * Example service class that we want to profile through AOP. * (Notice that no need to insert any line of profiling code!) * * @author Daniel Hari */ @Component public class FooService { public void doShortJob() { sleep(10l); } public void doLongJob() { sleep(300l); } public void doSomethingThatThrowsException() { throw new RuntimeException("Simulated Exception."); } private void sleep(long millis) { try { Thread.sleep(millis); } catch (InterruptedException e) { e.printStackTrace(); } } } |
Please note that we didn’t put any profiling code in the service class.
Spring AOP Profiler class
Our profiler class do a simple measurement of the ms of processing time for a method execution.
|
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 29 30 31 32 33 34 35 36 37 38 |
package hu.daniel.hari.learn.spring.aop.profiling.core.profiler; import org.aspectj.lang.ProceedingJoinPoint; import org.springframework.util.StopWatch; import org.springframework.util.StopWatch.TaskInfo; /** * Our profiler that * logs process time, and remark if process had exception. * * @author Daniel Hari */ public class SimpleProfiler { /** * Spring AOP 'around' reference method signature is bounded like this, the * method name "profile" should be same as defined in spring.xml aop:around * section. **/ public Object profile(ProceedingJoinPoint proceedingJoinPoint) throws Throwable { StopWatch stopWatch = new StopWatch(); stopWatch.start(proceedingJoinPoint.toShortString()); boolean isExceptionThrown = false; try { // execute the profiled method return proceedingJoinPoint.proceed(); } catch (RuntimeException e) { isExceptionThrown = true; throw e; } finally { stopWatch.stop(); TaskInfo taskInfo = stopWatch.getLastTaskInfo(); // Log the method's profiling result String profileMessage = taskInfo.getTaskName() + ": " + taskInfo.getTimeMillis() + " ms" + (isExceptionThrown ? " (thrown Exception)" : ""); System.out.println(profileMessage); } } } |
- As you can see our profile method use a Stopwatch for measuring method execution.
- The method receives ProceedingJoinPoint object from Spring-AOP that represents a method execution joint point in this case before executing the method. This object has informations also about the method to be executed that we can get.
- We are responsible for executing the method by calling it’s proceed().
- We do aware about exceptions thrown also in the executed method for logging it, but we throw it forward to be transparent, we do not want to handle exceptions in this level, only logging it.
(The “profile” method signature is bounded as Spring AOP will call it, but the method name can be anything else that will be set in spring.xml.)
Spring AOP configuration XML
Now we have ready with every working classes needed in our mini application. Let’s create Spring’s configuration file:
spring.xml
|
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 29 30 |
<?xml version="1.0" encoding="UTF-8"?> <beans xmlns="https://www.springframework.org/schema/beans" xmlns:context="https://www.springframework.org/schema/context" xmlns:xsi="https://www.w3.org/2001/XMLSchema-instance" xmlns:aop="https://www.springframework.org/schema/aop" xsi:schemaLocation=" https://www.springframework.org/schema/beans https://www.springframework.org/schema/beans/spring-beans-4.0.xsd https://www.springframework.org/schema/context https://www.springframework.org/schema/context/spring-context-4.0.xsd https://www.springframework.org/schema/aop https://www.springframework.org/schema/aop/spring-aop.xsd "> <!-- Scans the classpath for annotated components that will be auto-registered as Spring beans --> <context:component-scan base-package="hu.daniel.hari.learn.spring.aop.profiling" /> <!-- Activates various annotations to be detected in bean classes e.g: @Autowired --> <context:annotation-config /> <!-- AOP Configuration for profiling --> <!-- Our profiler class that we want to use to measure process time of service methods. --> <bean id="profiler" class="hu.daniel.hari.learn.spring.aop.profiling.core.profiler.SimpleProfiler" /> <!-- Spring AOP --> <aop:config> <aop:aspect ref="profiler"> <!-- Catch all method in the service package through AOP. --> <aop:pointcut id="serviceMethod" expression="execution(* hu.daniel.hari.learn.spring.aop.profiling.service.*.*(..))" /> <!-- For these methods use the profile named method in the profiler class we defined below. --> <aop:around pointcut-ref="serviceMethod" method="profile" /> </aop:aspect> </aop:config> </beans> |
- First we tell spring that we want to use classpath scanning for Spring components (rather than unconveniently defining them one by one in this xml), and also we enable Spring annotation detection.
- We configure Spring-AOP, to catch all methods in all classes in service package:
- We define an aspect that “pointcut”-s every service method,
- and we define an “around” method for these pointcuts that targets our SimpleProfiler’s “profile” named method.
Spring AOP Method Profiling Test Class
That’s it! The rest is only a testing class for our application.
|
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 29 30 |
package hu.daniel.hari.learn.spring.aop.profiling.main; import hu.daniel.hari.learn.spring.aop.profiling.service.FooService; import org.springframework.context.support.ClassPathXmlApplicationContext; /** * Example test class for Spring AOP Profiling. * * (remark: Exceptional calls should be put in try catch and handle ctx.close * properly but we missed to keep simleness of this example.) * * @author Daniel Hari */ public class Main { public static void main(String[] args) { // Create Spring application context that configured by xml. ClassPathXmlApplicationContext ctx = new ClassPathXmlApplicationContext("classpath:/spring.xml"); // Get our service from the spring context (that we want to be profiled). FooService fooService = ctx.getBean(FooService.class); // Test profiling through methods calls. for (int i = 0; i < 10; i++) { fooService.doShortJob(); } fooService.doLongJob(); // Test that profiler also can handle Exceptions in profiled method. fooService.doSomethingThatThrowsException(); // Close the spring context ctx.close(); } } |
You can see how simple we can start the Spring container from a main method, and getting our first dependency injected entry point, the service class instance.
If you run, you get below log:
|
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 |
execution(FooService.doShortJob()): 38 ms execution(FooService.doShortJob()): 10 ms execution(FooService.doShortJob()): 10 ms execution(FooService.doShortJob()): 10 ms execution(FooService.doShortJob()): 10 ms execution(FooService.doShortJob()): 10 ms execution(FooService.doShortJob()): 10 ms execution(FooService.doShortJob()): 10 ms execution(FooService.doShortJob()): 10 ms execution(FooService.doShortJob()): 10 ms execution(FooService.doLongJob()): 300 ms execution(FooService.doSomethingThatThrowsException()): 0 ms (thrown Exception) Exception in thread "main" java.lang.RuntimeException: Simulated Exception. at hu.daniel.hari.learn.spring.aop.profiling.service.FooService.doSomethingThatThrowsException(FooService.java:23) ... |
You can see that profiling logs generated for every service method call. You can create other service classes in the same package or below, that will be also profiled.
If you want to learn how AOP concepts works check below reference link.
If you use log4j.properties file from attached source, and uncomment first line(s) you can see what’s going on under the hood.
References:
Aspect Oriented Programming with Spring
You can download the full maven project source from below link.