Thursday, July 9, 2009

Using Spring AOP to trace invocations

How often do you write something like this?

public void foo(){
logger.debug("entering foo");
....
logger.debug("leaving foo");
}


If your answer is "often enough", then you should consider the following info. Anyone using Spring framework can seamlessly integrate trace logging into his application, just with slight modification to their spring context configs. In this post I will describe how to trace your code using DebugInterceptor (or any other interceptor of your choice).

The idea behind the proposed solution is to wrap the bean, which invocations you are going to trace, with a proxy that has SimpleTraceInterceptor or DebugInterceptor in the interceptorNames property. The interceptors mentioned are implementations of around advice that will write all the invocations' details to some logger (the way we choose our logger is discussed later on). This Interceptors are provided with Spring core library along with CustomizableTraceInterceptor, PerformanceMonitorInterceptor and few others. I guess, an example is the best way to show how it works.

Consider this simple program: two beans, one Spring context config, and one entry-point class, that just calls the first bean's method( so it is omitted on this page).

Bean1:


Bean2:


The Spring Context:



Running this code we get the following output:

23:13:04,348 TRACE [com.blogspot.mikler.java.Bean1] - Entering method 'entryPoint' of class [com.blogspot.mikler.java.Bean1]
23:13:04,349 TRACE [com.blogspot.mikler.java.Bean2] - Entering method 'importantMethod' of class [com.blogspot.mikler.java.Bean2]
23:13:04,349 INFO [com.blogspot.mikler.java.Bean2] - Doing job for 3 seconds
23:13:07,349 TRACE [com.blogspot.mikler.java.Bean2] - Exiting method 'importantMethod' of class [com.blogspot.mikler.java.Bean2]
23:13:07,350 TRACE [com.blogspot.mikler.java.Bean2] - Entering method 'doSomethingQuick' of class [com.blogspot.mikler.java.Bean2]
23:13:07,351 INFO [com.blogspot.mikler.java.Bean2] - doing something quick with param = a job
23:13:07,351 TRACE [com.blogspot.mikler.java.Bean2] - Exiting method 'doSomethingQuick' of class [com.blogspot.mikler.java.Bean2]
23:13:07,351 INFO [com.blogspot.mikler.java.Bean1] - All jobs done
23:13:07,351 TRACE [com.blogspot.mikler.java.Bean1] - Exiting method 'entryPoint' of class [com.blogspot.mikler.java.Bean1]


I hope the source code tells the story.

Several points that should be stressed:
  • One should decide to use Dynamic Logger or not (see useDynamicLogger property of the DebugInterceptor). If the dynamic logger is used, then invocations' log messages will be written to the logger of respective bean class (log4j.logger.com.blogspot.mikler.java.* loggers in our case). Otherwise the logger of the respective Interceptor will be used, one for all of the beans.
  • Make sure you enable the trace level for the selected logger. Because for optimization purposes the Interceptors don't make any job, saving your operation time, if this logging level for the logger they look up is not enabled.
To try yourself you can checkout sourcecode of this sample by running
svn co http://miklerjava.googlecode.com/svn/trunk/samples/SpringTracing springtracingsample

4 comments:

Unknown said...

very interesting article
http://www.bestjavatraining.in

intileo said...

Are you searching affordable java developer? there are so many java developers but noone compare with intileo technologies. Now you will ask “how you can say that intileo technologies is best company rather than other ?” yes i am saying this with a security “intileo technologies “ is the oldest & bestest it company ever… they are providing many other services also like php web development , dot net development , softwaredevelopment also for any kind of query feel free to contact with them :- 918470058143

intileo said...

Project Outsourcing isn’t the answer to everything. Lots of internet marketing pundits will tell you to outsource, outsource, outsource. Having a trusted team like Intileo Technologies that knows each other and enjoys working together is good, too. Visit us :- https://intileo.com/ E mail us :- info@intileo.com Call us :- +91 8700016281

Qmoniqs Software Pvt Ltd said...

Good Post. I like your blog. Thanks for Sharing
Cyber Security Solutions Company in Gurugram