In my last post we covered how to use some of the Spring AOP Interceptors in our Grails project for things like simple trace logging and basic performance monitoring.

One thing that I mentioned in that post, is that because we where using pointcuts that were being configured in the resources.groovy file, we lacked some of the fine grain control as to what was getting output in the logs. Specifically, this is what we where seeing in the logs:

Output in performanceMonitor.log

2010-10-03 16:04:00,852 [http-8080-1] TRACE grailsee.performanceMonitor
   - StopWatch 'grailsee.FooService.getMetaClass': running time (millis) = 0
2010-10-03 16:04:00,853 [http-8080-1] TRACE grailsee.performanceMonitor
   - StopWatch 'grailsee.FooService.getMetaClass': running time (millis) = 3
2010-10-03 16:04:00,855 [http-8080-1] TRACE grailsee.performanceMonitor
   - StopWatch 'grailsee.FooService.getMetaClass': running time (millis) = 0
2010-10-03 16:04:00,855 [http-8080-1] TRACE grailsee.performanceMonitor
   - StopWatch 'grailsee.FooService.getMetaClass': running time (millis) = 0
2010-10-03 16:04:00,893 [http-8080-1] TRACE grailsee.performanceMonitor
   - StopWatch 'grailsee.FooService.go': running time (millis) = 13
2010-10-03 16:04:00,895 [http-8080-1] TRACE grailsee.performanceMonitor
   - StopWatch 'grailsee.FooService.go': running time (millis) = 40

Because this is a Grails project, all of our classes have a ‘getMetaClass’ method call that was getting caught up in our pointcut.

So instead of creating our pointcut in the resources.groovy file as a bean declaration, today we will:

– provide a brief introduction to some AspectJ annotations
– externalize our ponitcuts into there own class
– finally show how to combine pointcuts to reduce the noise in our logs.

In case you didn’t read the last post here is how we initially set up our PerformanceMonitorInterceptor in our resources.groovy file:

	beans = {
		xmlns aop:"http://www.springframework.org/schema/aop"

		aop {
			config("proxy-target-class":true) {
                pointcut(id:"interceptorPointcut", expression:"execution(* grailsee..*Service.*(..))") //[1]
                advisor( 'pointcut-ref': "interceptorPointcut", 'advice-ref':"preformanceMonitoringInterceptorAdvice") //[2]
			}
		}

		preformanceMonitoringInterceptorAdvice(org.springframework.aop.interceptor.PerformanceMonitorInterceptor, true){
			loggerName = "grailsee.performanceMonitor"
		}

	}

Here we are declaring our pointcut [1] and assigning a reference to it in our adviser[2]

The first thing we are going to do is to create a MonitorAspect.groovy file and put in src/groovy directory. This will allow us to externalize our pointcuts.

    package grailsee

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

    @Aspect
    class MonitorAspect {

        @Pointcut("execution(* grailsee.*Service.*(..))")
        public void grailseeServices() {}

    }

Here we introduce two of the AspectJ annotations that are available to us in Spring.

– @Aspect is an annotation that allows Spring to detect this class and configure Spring AOP to use it.

– @Pointcut annotation is a method level annotation that allows us to assign a pointcut to a given method.

All we have to do now is reconfigure our resources.groovy file use this new pointcut method.

	beans = {
		xmlns aop:"http://www.springframework.org/schema/aop"   //[1]

		aop {
			config("proxy-target-class":true) {  //[2]
                advisor( pointcut: "grailsee.MonitorAspect.grailseeServices()", 'advice-ref':"preformanceMonitoringInterceptorAdvice") [4]
			}
		}

		preformanceMonitoringInterceptorAdvice(org.springframework.aop.interceptor.PerformanceMonitorInterceptor, true){
			loggerName = "grailsee.performanceMonitor"
		}

	}

As you can see we removed the ‘pointcut’ bean under the aop config closure. We also added the fully qualified reference to our pointcut method in our ‘adviser’ bean.

With this configuration Spring will wire up everything and give us the exact same logging that we had in our original configuration.

This bring us to our final point; combining pointcuts to reduce the noise in our log file, by not logging all the ‘getMetaClass’method calls.

In order do this, all we need to do is go back to the MonitorAspect.groovy file and added two additional pointcut methods:

	@Pointcut("!execution(* grailsee.*Service.getMetaClass(..))")
	public void noMetaClassMethods() {}

	@Pointcut("grailseeServices() && noMetaClassMethods()")
	public void onlyServiceMethods() {}

The first poitcut uses the exclusionary ‘!’. This pointcut states “exclude all execution for getMetaClass method calls in all classes in the grailsee package that are suffixed by Service”

And the last pointcut creates a new pointcut method that is a combination of our original pointcut and our exclusionary pontcut.

Now if we change our aop bean in our resources.groovy file to use this new combined pointcut method our Performance Monitoring log output will look like this:

    2010-10-15 13:21:37,601 [http-8080-1] TRACE grailsee.performanceMonitor  - StopWatch 'grailsee.FooService.go': running time (millis) = 5002
    2010-10-15 13:21:37,602 [http-8080-1] TRACE grailsee.performanceMonitor  - StopWatch 'grailsee.FooService.go': running time (millis) = 5003

Ahh..That’s much better.

By using the AspectJ style annotations we can create fine-grained and specialized pointcuts that do one thing and do it well.
You can then mix and match these small pointcuts to give you the desired benefits you need.