Tuesday, January 12th, 2010

Spring AOP Example: Profiling method execution time tutorial

I have already written about the Spring Aspect Oriented Programming (AOP) with the use of simple logging example. But, somehow I felt that the example code was little confusing for the newcomers. So, I decided to write a new Spring AOP example code that explains how to use Spring AOP for profiling method execution time.

Using Spring AOP to profile method execution time:

The example I chose is very simple – our application has a business class and a business method. We are going to profile how much time does it take to execute the business method. We will use Spring AOP for profiling the execution time. Since, profiling is a best example for cross cutting concern, it’s a good decision to use Spring AOP for implementing it. I’ll explain these in step by step. Meanwhile, you can download the source code (excluding dependent JAR file, for which you can see the download links below).

And, here’s the library versions I’m using: Spring 2.5.4, JDK 1.6, Commons-logging-1.0.4, aspectjrt-1.2, aspectjweaver-1.5.3.

1. Setting up the project structure:

Launch your preferred IDE (I use Eclipse) and Create New Java Project. And then create the file structure as shown below (off course, no need to follow the package naming convention, ;-) ).

Spring AOP - Project Structure

You need to download all the JARs that are in Referenced Libraries and add them to the project’s class path. You can find these JARs here: Spring, Commons-logging, aspectjrt, aspectjweaver. Also, please note that the file Business.java is an Interface. Other than this, all other java files are plain Classes.

2. Writing our Business Logic:

We will first write our business logic and then we will add Spring AOP to profile our business methods. Open Business.java interface and copy the below code into it.

package com.veerasundar.spring.aop;

public interface Business {
        void doSomeOperation();
}

Now, open the BusinessImpl.java and copy the below code into it.

package com.veerasundar.spring.aop;

public class BusinessImpl implements Business {

        public void doSomeOperation() {
                System.out.println("I do what I do best, i.e sleep.");
                try {
                        Thread.sleep(2000);
                } catch (InterruptedException e) {
                        System.out.println("How dare you to wake me up?");
                }
                System.out.println("Done with sleeping.");
        }

}

I guess this code is self explanatory. Our business method just sleeps for 2 seconds (good business, isn’t it!?) and then write some text on the console.

3. Writing a Spring Aspect to profile business method:

Lets write a Aspect which will profile our business method. I’m gonna use @Around advice (Lost in the jargons? Spring AOP basics). Open the BusinessProfiler.java file and copy the below code into it.

package com.veerasundar.spring.aop;

import org.aspectj.lang.ProceedingJoinPoint;
import org.aspectj.lang.annotation.Around;
import org.aspectj.lang.annotation.Aspect;
import org.aspectj.lang.annotation.Pointcut;

@Aspect
public class BusinessProfiler {

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

        @Around("businessMethods()")
        public Object profile(ProceedingJoinPoint pjp) throws Throwable {
                long start = System.currentTimeMillis();
                System.out.println("Going to call the method.");
                Object output = pjp.proceed();
                System.out.println("Method execution completed.");
                long elapsedTime = System.currentTimeMillis() - start;
                System.out.println("Method execution time: " + elapsedTime + " milliseconds.");
                return output;
        }

}

Here’s what this code does:

  1. Using @AspectJ annotation, we have declared that this class is an Aspect.
  2. Using @Pointcut annotation, we have defined a pointcut that will match the execution of all public method inside com.veerasundar.spring.aop package. [read more about pointcut]
  3. Using @Around annotation, we have defined a Around advice which will be invoked before and after our business method. i.e. @Around advice will wrap our business method. As you can see in the above code, pjp.proceed(). This is when our business method gets called from @Around advice.

4. Configuring Spring AOP and @AspectJ support:

Open the applicationContext.xml file and copy the below code into it.

<?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:aop="http://www.springframework.org/schema/aop"
        xsi:schemaLocation="http://www.springframework.org/schema/beans http://www.springframework.org/schema/beans/spring-beans-2.5.xsd
http://www.springframework.org/schema/aop http://www.springframework.org/schema/aop/spring-aop-2.5.xsd">

        <!-- Enable the @AspectJ support -->
        <aop:aspectj-autoproxy />

        <bean id="businessProfiler" class="com.veerasundar.spring.aop.BusinessProfiler" />
        <bean id="myBusinessClass" class="com.veerasundar.spring.aop.BusinessImpl" />
</beans>

Here’s what we are doing in the above XML file:

  1. We have added the required AOP schemas on the top of the XML file.
  2. Using <aop:aspectj-autoproxy />, we’ve enabled the @AspectJ support to our application.
  3. And then we defined two normal Spring beans – one for our Business class and the other for Business Profiler (i.e. our aspect).

That’s it. With all the above code is done, we have successfully added Spring AOP support to our project and configured it. In the next step, lets test our code.

5. Testing the Spring AOP profiler:

Open the file SpringAOPDemo.java and copy the below lines into it.

package com.veerasundar.spring.aop;

import org.springframework.context.ApplicationContext;
import org.springframework.context.support.ClassPathXmlApplicationContext;

public class SpringAOPDemo {

        /**
         * @param args
         */
        public static void main(String[] args) {
                ApplicationContext context = new ClassPathXmlApplicationContext(
                                "applicationContext.xml");
                Business bc = (Business) context.getBean("myBusinessClass");
                bc.doSomeOperation();
        }

}

In the above code we are loading our Business bean from Spring Context and then calling our business method. If you run this class, it will produce the following output on the console.

Going to call the method.
I do what I do best, i.e sleep.
Done with sleeping.
Method execution completed.
Method execution time: 2000 milliseconds.

 

I hope this tutorial helps you to understand the basics of Spring Aspect Oriented programming. If you have any questions regarding the above example, feel free to leave a comment.

{ 53 comments… read them below or add one }

Nick Stolwijk January 14, 2010 at 3:45 am

May I suggest the JAMon API in combination with this approach. It gives very good information about your application timings.

Your AOP code will look something like this:
public Object profile(ProceedingJoinPoint pjp) throws Throwable {
Monitor mon = MonitorFactory.start(“myFirstMonitor”);
try {
return pjp.proceed();
} finally {
mon.stop();
System.out.println(mon);
}
}

Which gives you the following output:
http://jamonapi.sourceforge.net/console1.gif

For more information: http://jamonapi.sourceforge.net/

Reply

Veera January 14, 2010 at 5:44 am

the API looks useful. Will give it a try. :)

Reply

Ashaar Riaz January 14, 2010 at 11:10 am

Veera:
You have explained AOP in a very simple and efficient manner. My question is that using AOP in my application, will it will affect the performance? Does AOP degrade the performance? Is there any benchmark?

Reply

Veera January 14, 2010 at 12:42 pm

Hi Ashaar,

Thanks for the feedback.

On the performance, while in my project, we didn’t face any major AOP performance issues. But still, in my project I was the only developer who were coding the aspects. So, I was in full control of AOP. But if there is a big project with lots of developer are coding their own aspect, then it might impact the performance when all the aspects are integrated.

This article from StackOverflow could give you some guidance: http://stackoverflow.com/questions/433475/performance-impact-of-using-aop

Reply

Veera January 14, 2010 at 12:43 pm

btw, here’s the benchmark data for AspectJ – http://docs.codehaus.org/display/AW/AOP+Benchmark

Reply

evernat January 14, 2010 at 3:24 pm

The aspectj benchmark you give is of 2004 and so not very relevant.
It is not up to date with JDK 1.6 and neither with JDK 1.7 : it can be very different now.

The documentation of Spring AOP advises to use JDK dynamic proxies and not CGLIB (http://static.springsource.org/spring/docs/2.5.6/reference/aop.html#aop-proxying)

Reply

Veera January 14, 2010 at 3:37 pm

//The aspectj benchmark you give is of 2004 and so not very relevant//

Oops. my bad.

//Spring AOP advises to use JDK dynamic proxies and not CGLIB //

I think this is beacuse it is easy to create proxy for interfaces. but when you want to weave aspects to your classes, you need the CGLIB and it takes a performance hit.

Reply

Ashaar Riaz January 14, 2010 at 3:26 pm

Hi Veera:
Thanks for your reply. In my project I also suggested to use AOP. Only the problem I am facing is the performance issue. One of the developer said that AOP is using Reflection and it is slow, so it will create performance issue.
I have seen this benchmark, but when I am trying to download the load and reconfirm the benchmark, I was not be able to download the code. Can you try it and let me know what it works.

Cheers,

Ashaar Riaz

Cheers,

Reply

Veera January 14, 2010 at 3:38 pm

sure. will get back to you once I done with that.

Reply

Satish January 17, 2010 at 1:47 pm

Nice article!

Reply

Veera January 17, 2010 at 7:07 pm

you are welcome.

Reply

Rohit January 29, 2010 at 11:12 am

Hi Veera,

Can we have more than one pointcut defined on a spring bean declared as an Aspect?

Reply

Veera January 29, 2010 at 11:21 am

Yes Rohit. You can define as many pointcuts as you want in an Aspect.

In fact, you can even seperate these two in two different class file to organize them logically (like, Aspect in one class and pointcuts defined in another class). This way, you can even reuse the pointcuts in some other places too.

Reply

surender April 13, 2012 at 9:03 am

Hi Veera
its very nice and is to understand . can u please give an example of seperating the pointcuts and aspect into two different classes

Reply

Tulio Domingos August 23, 2010 at 8:55 pm

Hi Veera nice article you got there! Quick question, any ideas on how to integrate this with DWR?
Say for example you had DWR remote tags on the “myBusinessClass” bean that would potentially clash with Spring AOP…

Including the in the bean declaration doesn’t seem to help..

Cheers

Tulio

Reply

Veera August 24, 2010 at 9:50 am

Sorry Tulio.. I have never used DWR in any of my project. So I have no idea about the integration between DWR and Spring.

Reply

Tulio Domingos August 24, 2010 at 2:34 pm

No worries Veera it was just a thought. Cheers tho
Tulio

Reply

Sudha August 25, 2010 at 1:40 pm

Useful article for a beginner…cheers !!!

Reply

Veera August 25, 2010 at 6:29 pm

you are welcome, Sudha.

Reply

Bhanu September 3, 2010 at 1:02 pm

hi Veera,

Nice article. how to integrate this AOP into JSF.

Reply

Veera September 5, 2010 at 2:25 pm

Hi Bhanu,

I have never done the integration of JSF + AOP.. So, couldn’t comment on that.

Reply

Tim Jowers September 20, 2010 at 6:46 pm

Thanks for the article. Is AspectJ a separate product or part of Spring? I think Spring has performance pointcuts also. Overall, seems like a painful way to do performance measurements. I’m continually amazed how the Java folks seem dead set on making the most work possible for every task. A decade and 1/2 ago we would have just used a profiler and had the task done in an hour. I guess part of the fun with Java is rolling your own rather than simplifying and using tools. Kinda like using Maven or Ant instead of an IDE. Certainly it is the greediest strategy for a consulting firm who bills by the hour – and i’ve certainly seen that horse run before.

Reply

Veera September 20, 2010 at 8:18 pm

//Is AspectJ a separate product or part of Spring?//

AspectJ is a separate product. It’s not part of Spring. While Spring it’s own style of AOP, it also supports AspectJ.

@on your rest part of the comment

To clarify, the profiling that I explained is not for measuring the application during development time. I still use/suggest the IDE based profiling tools for that purpose.

When the application goes to production and somehow it lacks the performance that we expected, at that time we can’t use profiling tools to identify the bottlenecks. So, in such scenarios, our only source of information is the log files. So, to profile a application at production, we could use AOP to measure the performance and log the details which we could use for analysis.

thanks for noting this point.

Reply

Abdul Mohsin September 21, 2010 at 12:56 am

Nice explanation !

Reply

Kumaresan October 5, 2010 at 1:10 am

I have done everything about sample above, but still it does not invoke the profile(BusinessProfiler) , iam getting the output only
I do what I do best, i.e sleep.
Done with sleeping.

Any idea where i went wrong. No compilation errors anywhere.

Thanks – Kumaresan.M.

Reply

Zahid August 26, 2011 at 7:50 am

I was having the same issue after I modified package name in Pointcut annotation, thinking of making it generic for every package but….. I got the log messages from BusinessImpl but not from aspect. The trick was to fully qualify package name in Pointcut annotation and it started working again.

Reply

Shankar October 27, 2010 at 1:25 pm

Nice article. I have looked at many tutorials for AOP, but did not get to the roots. Now it is clear. Thanks a lot for such nice articles….

Reply

George October 27, 2010 at 7:52 pm

Nice article. I was wondering if it is possible to define the pointcut in log statements. ie There if there are lots of log statements spread over many classes would it be possible to create an aspect to intercept each one?
Something like: @Pointcut(“execution(* org.apache.log4j.Logger.*.*(String))”)

Thanks George

Reply

James December 6, 2010 at 1:59 am

I was trying to replicate this example using spring3 and only annotations, but I cant get it working. I post a comment with the problematic code at springsource forum, if you wish to take a look and help me I will really appreciate it : http://forum.springsource.org/showthread.php?p=332925#post332925

Reply

Veera December 6, 2010 at 10:16 am

Haven’t used the Spring 3.. but let me try.. :)

Reply

Shankar Dutt Mishra December 6, 2010 at 10:30 am

Very nice article. Now I will try to use AOP in my projects.

Reply

Veera December 6, 2010 at 10:32 am

you’re welcome. :)

Reply

Candy December 7, 2010 at 12:50 pm

I’m new to Aspect-Oriented Programming, and I’m using Spring Framework.
I just looked for some Spring AOP examples and found your awesome article.
It help me to understand the basic idea quickly.
Good work and Thanks.

Reply

Rao December 14, 2010 at 12:56 pm

Hi veera,
Thanks for the article. You made it so simple to understand AOP.
I have a question. We have a Java application ( which does not use Spring) and have access to Jars only ( no source code available). We would like to log the method calls made during execution. Can you suggest a solution please.

Thanks
Rao

Reply

Veera December 14, 2010 at 1:03 pm

Rao,

You can still use the AOP even if you don’t use Spring. Since AspectJ is available as a separate library, you can integrate it with any Java project. Please check the AspectJ site for more details: http://www.eclipse.org/aspectj/

And, you don’t need to have the source code to weave the point cuts. All you need to know is the package names/method name around which you are going to wrap your intercept logic.

Reply

ihsan March 20, 2011 at 8:33 am

First of all, thanks for your example. I wonder if you could tell me where’s the benefits of using AOP. As many websites have mentioned that to separate the aspects of application such as the Authentication, Logging, and others. Here I wonder if you could write an authentication class that implements one function for logging in. And how AOP would maintain the whole code application.
Cheers,
Ihsan

Reply

Hiral April 12, 2011 at 1:23 pm

Was looking for a simple and helpful article on AOP and here I got

Reply

Kumar June 4, 2011 at 3:43 am

Very nice and simple AOP example. Request you to put some more of this kind using Spring 3 version.

Reply

Geng July 14, 2011 at 8:45 am

I was wondering if you have idea how to place a pointcut that points to methods in different project.

Thanks

Reply

Venkat August 4, 2011 at 3:51 pm

Hi Veera,
Nice article. Iam new to AOP. I have a doubt here like

Object output = pjp.proceed();
In the above code you are calling pjp.proceed(), How it internally calling doSomeOperation() method.
Could you please explain me this.

Thanks in advance.

Reply

Junaid Ansari August 9, 2011 at 5:02 am

Hi Veera,

This is really a nice article.I am beginner can you help me to profile execution time for nested methods calls.Let say I have a main method which is calling a method A() and B().I need to capture the execution time of A() and B() separately.How to define point cut for same.

Thank you..

Reply

Mike October 28, 2011 at 1:10 pm

I do not think it is a good practice to throw anything in method profile(). This can have a bad impact on your code. You should try / catch inside your method and return a message to show something was wrong.

Reply

Michael February 3, 2012 at 7:08 pm

Really good !!!

Reply

livaka February 5, 2012 at 10:08 am

really good example..need some more explain to understand

Reply

vidhya February 17, 2012 at 2:15 am

I downloaded the code and did the settings as mentioned in this article. I am not getting the response as expected. I am not getting the print statement mentioned in the BusinessProfiler. Only the print statements in the businessImpl class is displayed. Am I doing something wrong

Reply

Rajan March 11, 2012 at 4:08 pm

Hi Vidhya,

It is working fine for me. Please can you recheck whether the referenced libraries are properly configured?

Reply

Rajan March 11, 2012 at 4:07 pm

Nice article. Please can you clarify one thing, is aspectj part of spring framework? If not what benefit do we get from using aspectj and aspectjweaver jars? Can’t we achieve the same using spring framework itself?

Reply

Ravi Gupta March 28, 2012 at 1:46 pm

Hi Veera,

This is a very good article.
Can you please explain how we can define pointcuts in a class file and reuse it in another class file.

Please explain with example.

Guys who need to know how basic AOP works in Spring can refer the below link

http://www.mkyong.com/spring/spring-aop-example-pointcut-advisor/

Regards,
Ravi Gupta

Reply

david April 10, 2012 at 5:14 am

Hi nice ariticle,
but i need a sample AOP logging file appender example in spring.could you advise me how can i implement.

Thanks
David

Reply

Raghava April 20, 2012 at 6:48 am

It’s explained in impressive way…

Reply

appu April 24, 2012 at 5:29 am

Hi,
I’m trying to implement this article in my application. but I’m getting error like
Caused by: java.lang.NoClassDefFoundError: org.aspectj.weaver.tools.PointcutDesignatorHandler
I have added in aspectjrt.jar and aspectweaver.jar in my classpath..but also getting the same error..
Anything more I need to do..
This is my first Spring application..
Could you please help me on this issue..

Reply

mayuri April 30, 2012 at 6:11 am

Hi,
I’m doing my project using Aspectj in spring by using annotations but since my project has dependency on other projects also which are using Spring AOP, so if i am disabling my AOP they are still getting proxied by the spring aop which is creating problem. How can I exclude an aspect in Spring AOP, in asject j it is possible by using exlude in aop.xml but i m not able to do that in spring aop.

Reply

kvic kaizen May 11, 2012 at 7:39 am

Great!
Excellent tutorial.
I just try and it works.

Reply

Leave a Comment

Previous post:

Next post: