public interface InventoryService {
public Inventory create(Inventory inventory);
public List<inventory> list();
public Inventory findByVin(String vin);
public Inventory update(Inventory inventory);
public boolean delete(Long id);
public Inventory compositeUpdateService(String vin, String newMake);
}
and its default implementation:
public class DefaultInventoryService implements InventoryService{
@Override
public Inventory create(Inventory inventory) {
logger.info("Create Inventory called");
inventory.setId(1L);
return inventory;
}
@Override
public List<inventory> list(){
return new ArrayList<inventory>();
}
@Override
public Inventory update(Inventory inventory) {
return inventory;
}
@Override
public boolean delete(Long id) {
logger.info("Delete Inventory called");
return true;
}
....
This is just one service. Assume that there are many more services in this project.
So now, if there were a requirement to record the time taken by each of the service methods, the option without AOP would be something along the following lines. Create a decorator for the service:
public class InventoryServiceDecorator implements InventoryService{
private static Logger logger = LoggerFactory.getLogger(InventoryServiceDecorator.class);
private InventoryService decorated;
@Override
public Inventory create(Inventory inventory) {
logger.info("before method: create");
long start = System.nanoTime();
Inventory inventoryCreated = decorated.create(inventory);
long end = System.nanoTime();
logger.info(String.format("%s took %d ns", "create", (end-start)) );
return inventoryCreated;
}
This decorator would essentially intercept the call on behalf of the decorated, record the time taken for the method call while delegating the call to the decorated object.
Imagine doing this for all the methods and all the services in the project. This is the scenario that AOP addresses, it provides a way for the cross cutting concerns(Recording time for the service method calls for eg.) to be modularized – to be packaged up separately without polluting the core of the classes.
To end the session, a different way to implement the decorator would be using the dynamic proxy feature of Java:
public class AuditProxy implements java.lang.reflect.InvocationHandler {
private static Logger logger = LoggerFactory.getLogger(AuditProxy.class);
private Object obj;
public static Object newInstance(Object obj) {
return java.lang.reflect.Proxy.newProxyInstance(obj.getClass().getClassLoader(), obj
.getClass().getInterfaces(), new AuditProxy(obj));
}
private AuditProxy(Object obj) {
this.obj = obj;
}
public Object invoke(Object proxy, Method m, Object[] args) throws Throwable {
Object result;
try {
logger.info("before method " + m.getName());
long start = System.nanoTime();
result = m.invoke(obj, args);
long end = System.nanoTime();
logger.info(String.format("%s took %d ns", m.getName(), (end-start)) );
} catch (InvocationTargetException e) {
throw e.getTargetException();
} catch (Exception e) {
throw new RuntimeException("unexpected invocation exception: " + e.getMessage());
} finally {
logger.info("after method " + m.getName());
}
return result;
}
}
So now, when creating an instance of InventoryService, I would create it through the AuditProxy dynamic proxy:
InventoryService inventoryService = (InventoryService)AuditProxy.newInstance(new DefaultInventoryService());
the overridden invoke method of java.lang.reflect.InvocationHandler would intercept all calls to the InventoryService created in this manner, where the cross cutting concern of auditing the method call time is recorded. This way the cross cutting concern is modularized to one place(AuditProxy), but still needs to be explicitly known by the clients of InventoryService, when instantiating InventoryService.
Now, I will show how the cross-cutting concern can be implemented using Spring AOP – Spring offers multiple ways of implementing Aspects – XML configuration based, @AspectJ based. In this specific example, I will use XML configuration file based way of defining the aspect
Spring AOP works in the context of a Spring container, so the service implementation that was defined in the previous session needs to be a Spring bean, I am defining it using the @Service annotation:
@Service
public class DefaultInventoryService implements InventoryService{
...
}
Now, I want to record the time taken for each of the method calls of my DefaultInventoryService – I am first going to modularize this as an “advice”:
package org.bk.inventory.aspect;
import org.aspectj.lang.ProceedingJoinPoint;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
public class AuditAdvice {
private static Logger logger = LoggerFactory.getLogger(AuditAdvice.class);
public void beforeMethod() {
logger.info("before method");
}
public void afterMethod() {
logger.info("after method");
}
public Object aroundMethod(ProceedingJoinPoint joinpoint) {
try {
long start = System.nanoTime();
Object result = joinpoint.proceed();
long end = System.nanoTime();
logger.info(String.format("%s took %d ns", joinpoint.getSignature(), (end - start)));
return result;
} catch (Throwable e) {
throw new RuntimeException(e);
}
}
}
This advice is expected to capture the time taken by the methods in DefaultInventoryService. So now to wire this advice to the DefaultInventoryService spring bean:
<bean id="auditAspect" class="org.bk.inventory.aspect.AuditAdvice" /> <aop:config> <aop:aspect ref="auditAspect"> <aop:pointcut id="serviceMethods" expression="execution(* org.bk.inventory.service.*.*(..))" /> <aop:before pointcut-ref="serviceMethods" method="beforeMethod" /> <aop:around pointcut-ref="serviceMethods" method="aroundMethod" /> <aop:after-returning pointcut-ref="serviceMethods" method="afterMethod" /> </aop:aspect> </aop:config>
This works by first defining the “pointcut” – the places(in this example, the service methods) to add the cross cutting concern(capturing the method execution time in this example) to. Here I have defined it using a pointcut expression –
execution(* org.bk.inventory.service.*.*(..))
, which is essentially selecting all methods of all the types in the org.bk.inventory.service package. Once the pointcut is defined, it defines what needs to be done around the pointcut(the advice), using the expression:
<aop:around pointcut-ref="serviceMethods" method="aroundMethod" />
This basically says, that around every method of any service type, execute the aroundMethod of AspectAdvice that was defined earlier. Now, if the service methods are executed, I would see the advice getting invoked during the method execution, the following is a sample output if DefaultInventoryService, createInventory method is called:
org.bk.inventory.service.InventoryService - Create Inventory called org.bk.inventory.aspect.AuditAdvice - Inventory org.bk.inventory.service.InventoryService.create(Inventory) took 82492 ns
Spring’s AOP implementation works by generating a dynamic proxy at runtime for all the target beans, based on the defined pointcut.
Another way of defining an Aspect is using @AspectJ annotaions – which is natively understood by Spring:
package org.bk.inventory.aspect;
import org.aspectj.lang.ProceedingJoinPoint;
import org.aspectj.lang.annotation.After;
import org.aspectj.lang.annotation.Around;
import org.aspectj.lang.annotation.Aspect;
import org.aspectj.lang.annotation.Before;
import org.aspectj.lang.annotation.Pointcut;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
@Aspect
public class AuditAspect {
private static Logger logger = LoggerFactory.getLogger(AuditAspect.class);
@Pointcut("execution(* org.bk.inventory.service.*.*(..))")
public void serviceMethods(){
//
}
@Before("serviceMethods()")
public void beforeMethod() {
logger.info("before method");
}
@Around("serviceMethods()")
public Object aroundMethod(ProceedingJoinPoint joinpoint) {
try {
long start = System.nanoTime();
Object result = joinpoint.proceed();
long end = System.nanoTime();
logger.info(String.format("%s took %d ns", joinpoint.getSignature(), (end - start)));
return result;
} catch (Throwable e) {
throw new RuntimeException(e);
}
}
@After("serviceMethods()")
public void afterMethod() {
logger.info("after method");
}
}
The @Aspect annotation on the class identifies it as an aspect definition. It starts by defining the pointcuts:
@Pointcut("execution(* org.bk.inventory.service.*.*(..))")
public void serviceMethods(){}
The above basically identifies all the methods of all types in org.bk.inventory.service package, this pointcut is identified by the name of the method on which the annotation is placed – in this case “serviceMethods”. Next, the advice is defined using the @Before(serviceMethods()), @After(serviceMethods()) and @Around(serviceMethods()) annotation and the specifics of what needs to happen is the body of the methods with those annotations. Spring AOP natively understands the @AspectJ annotations, if this Aspect is defined as a bean:
<bean id="auditAspect" class="org.bk.inventory.aspect.AuditAspect" />
Spring would create a dynamic proxy to apply the advice on all the target beans identified as part of the pointcut notation.
Yet another way to define an aspect – this time using native aspectj notation.
package org.bk.inventory.aspect;
import org.bk.inventory.types.Inventory;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
public aspect AuditAspect {
private static Logger logger = LoggerFactory.getLogger(AuditAspect.class);
pointcut serviceMethods() : execution(* org.bk.inventory.service.*.*(..));
pointcut serviceMethodsWithInventoryAsParam(Inventory inventory) : execution(* org.bk.inventory.service.*.*(Inventory)) && args(inventory);
before() : serviceMethods() {
logger.info("before method");
}
Object around() : serviceMethods() {
long start = System.nanoTime();
Object result = proceed();
long end = System.nanoTime();
logger.info(String.format("%s took %d ns", thisJoinPointStaticPart.getSignature(),
(end - start)));
return result;
}
Object around(Inventory inventory) : serviceMethodsWithInventoryAsParam(inventory) {
Object result = proceed(inventory);
logger.info(String.format("WITH PARAM: %s", inventory.toString()));
return result;
}
after() : serviceMethods() {
logger.info("after method");
}
}
This maps to the previously defined @AspectJ notation
Since this is a DSL specifically for defining Aspects, it is not understood by the java compiler. AspectJ provides a tool(ajc) to compile these native aspectj files and to weave the aspects into the targeted pointcuts. Maven provides a plugin which seamlessly invokes ajc at the point of compilation:
<plugin>
<groupId>org.codehaus.mojo</groupId>
<artifactId>aspectj-maven-plugin</artifactId>
<version>1.0</version>
<dependencies>
<dependency>
<groupId>org.aspectj</groupId>
<artifactId>aspectjrt</artifactId>
<version>${aspectj.version}</version>
</dependency>
<dependency>
<groupId>org.aspectj</groupId>
<artifactId>aspectjtools</artifactId>
<version>${aspectj.version}</version>
</dependency>
</dependencies>
<executions>
<execution>
<goals>
<goal>compile</goal>
<goal>test-compile</goal>
</goals>
</execution>
</executions>
<configuration>
<outxml>true</outxml>
<aspectLibraries>
<aspectLibrary>
<groupId>org.springframework</groupId>
<artifactId>spring-aspects</artifactId>
</aspectLibrary>
</aspectLibraries>
<source>1.6</source>
<target>1.6</target>
</configuration>
</plugin>
This will be a wrap up of the AOP intro, with an example that will comprehensively exercise the concepts introduced in the previous sessions.
The use case is simple, I am going to define a custom annotation, PerfLog, I expect the calls to methods annotated with this annotation to be timed and logged. Let me start by defining the annotation:
package org.bk.annotations;
import java.lang.annotation.ElementType;
import java.lang.annotation.Retention;
import java.lang.annotation.RetentionPolicy;
import java.lang.annotation.Target;
@Target({ElementType.TYPE, ElementType.METHOD})
@Retention(RetentionPolicy.RUNTIME)
public @interface PerfLog {
}
Now to annotate some service methods with this annotation:
@Service
public class DefaultInventoryService implements InventoryService{
private static Logger logger = LoggerFactory.getLogger(InventoryService.class);
@Override
public Inventory create(Inventory inventory) {
logger.info("Create Inventory called");
inventory.setId(1L);
return inventory;
}
@Override
public List<Inventory> list() {
return new ArrayList<Inventory>();
}
@Override
@PerfLog
public Inventory update(Inventory inventory) {
return inventory;
}
@Override
public boolean delete(Long id) {
logger.info("Delete Inventory called");
return true;
}
@Override
@PerfLog
public Inventory findByVin(String vin) {
logger.info("find by vin called");
return new Inventory("testmake", "testmodel","testtrim","testvin" );
}
@Override
@PerfLog
public Inventory compositeUpdateService(String vin, String newMake) {
logger.info("composite Update Service called");
Inventory inventory = findByVin(vin);
inventory.setMake(newMake);
update(inventory);
return inventory;
}
}
Here three methods of DefaultInventoryService have been annotated with @PerfLog annotation – update, findByVin, compositeUpdateService which internally invokes the methods findByVin and update.
Now for the Aspect which will intercept all calls to methods annotated with @PerfLog and log the time taken for the method call:
package org.bk.inventory.aspect;
import org.aspectj.lang.ProceedingJoinPoint;
import org.aspectj.lang.annotation.Around;
import org.aspectj.lang.annotation.Aspect;
import org.aspectj.lang.annotation.Pointcut;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
@Aspect
public class AuditAspect {
private static Logger logger = LoggerFactory.getLogger(AuditAspect.class);
@Pointcut("execution(@org.bk.annotations.PerfLog * *.*(..))")
public void performanceTargets(){}
@Around("performanceTargets()")
public Object logPerformanceStats(ProceedingJoinPoint joinpoint) {
try {
long start = System.nanoTime();
Object result = joinpoint.proceed();
long end = System.nanoTime();
logger.info(String.format("%s took %d ns", joinpoint.getSignature(), (end - start)));
return result;
} catch (Throwable e) {
throw new RuntimeException(e);
}
}
}
Here the pointcut expression –
@Pointcut("execution(@org.bk.annotations.PerfLog * *.*(..))")selects all methods annotated with @PerfLog annotation, and the aspect method logPerformanceStats logs the time taken by the method calls.
To test this:
package org.bk.inventory;
import static org.hamcrest.CoreMatchers.*;
import static org.junit.Assert.*;
import org.bk.inventory.service.InventoryService;
import org.bk.inventory.types.Inventory;
import org.junit.Test;
import org.junit.runner.RunWith;
import org.springframework.beans.factory.annotation.Autowired;
import org.springframework.test.context.ContextConfiguration;
import org.springframework.test.context.junit4.SpringJUnit4ClassRunner;
@RunWith(SpringJUnit4ClassRunner.class)
@ContextConfiguration("classpath:/testApplicationContextAOP.xml")
public class AuditAspectTest {
@Autowired
InventoryService inventoryService;
@Test
public void testInventoryService() {
Inventory inventory = this.inventoryService.create(new Inventory("testmake", "testmodel","testtrim","testvin" ));
assertThat(inventory.getId(), is(1L));
assertThat(this.inventoryService.delete(1L), is(true));
assertThat(this.inventoryService.compositeUpdateService("vin","newmake").getMake(),is("newmake"));
}
}
When this test is invoked the output is the following:
2011-09-08 20:54:03,521 org.bk.inventory.service.InventoryService - Create Inventory called 2011-09-08 20:54:03,536 org.bk.inventory.service.InventoryService - Delete Inventory called 2011-09-08 20:54:03,536 org.bk.inventory.service.InventoryService - composite Update Service called 2011-09-08 20:54:03,536 org.bk.inventory.service.InventoryService - find by vin called 2011-09-08 20:54:03,536 org.bk.inventory.aspect.AuditAspect - Inventory org.bk.inventory.service.DefaultInventoryService.findByVin(String) took 64893 ns 2011-09-08 20:54:03,536 org.bk.inventory.aspect.AuditAspect - Inventory org.bk.inventory.service.DefaultInventoryService.update(Inventory) took 1833 ns 2011-09-08 20:54:03,536 org.bk.inventory.aspect.AuditAspect - Inventory org.bk.inventory.service.DefaultInventoryService.compositeUpdateService(String, String) took 1371171 ns
the advice is correctly invoked for findByVin, update and compositeUpdateService.
This sample is available at : git://github.com/bijukunjummen/AOP-Samples.git
Reference: A simple introduction to AOP from our JCG partner Biju Kunjummen at the all and sundry blog.
Hi,
Is there any way that I can get an eclipse project for the examples?
Thanks
Hassan
Hi,
I have done the exact configuration mentioned.
But when i create a war file and deploy it on Weblogic server, the AuditAdvice class methods are not called.
is there any separate configuration need to be done for weblogic server
I am using XML configuration .
weblogic version 12.1.3