Spring Aspects - Logging debugging information of service methods

Method Tracing Aspects

Following aspects enable method tracing by using Spring AOP. The following information will be gathered and logged:

1. Types and values of input parameters
2. Type and value of return object
3. Types and details of exceptions

@Configuration @Aspect public class MethodTracingAspect {   private static Logger logger = LoggerFactory.getLogger(MethodTracingAspect.class);   @Autowired private LoggerCache loggerCache;   @PostConstruct   protected void init() {     logger.warn("###-AOP-### DebuggableAspect initialized...");   }   @Before(       "(com.yourcorp.common.aspect.CommonPointcut.servicePackageMethodDebugEnabled() "           + "|| com.yourcorp.common.aspect.CommonPointcut.implPackageMethodDebugEnabled()) && "           + "!com.yourcorp.common.aspect.CommonPointcut.nonTraceableAnnotationEnabled()")   public void logDebugInformationMethodBeforeEntering(JoinPoint joinPoint) {     final Logger mLogger = loggerCache.getLogger(joinPoint);     mLogger.debug(         "Entering class:{} - method : {} with input parameters {}",         joinPoint.getTarget().getClass().getSimpleName(),         joinPoint.getSignature().getName(),         joinPoint.getArgs());   }   @AfterReturning(     value =         "(com.yourcorp.common.aspect.CommonPointcut.servicePackageMethodDebugEnabled() "             + "|| com.yourcorp.common.aspect.CommonPointcut.implPackageMethodDebugEnabled()) && "             + "!com.yourcorp.common.aspect.CommonPointcut.nonTraceableAnnotationEnabled()",     returning = "result"   )   public void logDebugInformationMethodAfterReturning(JoinPoint joinPoint, Object result) {     final Logger mLogger = loggerCache.getLogger(joinPoint);     mLogger.debug(         "Returning from class:{} - method : {} with return type: {} - value {}",         joinPoint.getTarget().getClass().getSimpleName(),         joinPoint.getSignature().getName(),         ((MethodSignature) (joinPoint.getSignature())).getReturnType().getSimpleName(),         result);   } } @Configuration @Aspect public class ExceptionHandlingAspect {   @Autowired private LoggerCache loggerCache;   @AfterThrowing(     value = "com.yourcorp.common.aspect.CommonPointcut.servicePackageMethodDebugEnabled()",     throwing = "exception"   )   public void logRecoverableFailureException(       JoinPoint joinPoint, RecoverableFailureException exception) {     Logger logger = loggerCache.getLogger(joinPoint);     logger.warn("\t " + exception.getFullMessage(), exception);   }   @AfterThrowing(     value = "com.yourcorp.common.aspect.CommonPointcut.servicePackageMethodDebugEnabled()",     throwing = "exception"   )   public void logUnRecoverableFailureException(       JoinPoint joinPoint, UnRecoverableFailureException exception) {     Logger logger = loggerCache.getLogger(joinPoint);     logger.error("\t " + exception.getFullMessage(), exception);   } }

Common Pointcuts

import org.aspectj.lang.annotation.Pointcut; /**  * The pointcuts defined here are the service classes most likely logging, metrics and tracing  * concerns will be the applied.  */ @Aspect public class CommonPointcut {   // All method in service packages   @Pointcut("execution(* com.yourcorp.app..service.*.*(..))")   public void servicePackageMethodDebugEnabled() {     // no implementation.   }   // All method in impl packages   @Pointcut("execution(* com.yourcorp.app..impl..*.*(..))")   public void implPackageMethodDebugEnabled() {     // no implementation.   }   // Methods with @MethodDebuggingDisable   @Pointcut("@annotation(com.yourcorp.app.common.aspect.debug.MethodDebuggingDisable))")   public void nonTraceableAnnotationEnabled() {     // no implementation.   } }

Custom Annotation

/**  * If a method is very sensitive to  */ @Target({ElementType.METHOD}) @Retention(RetentionPolicy.RUNTIME) public @interface MethodTracingDisable {}

Logger Cache

/**  * Cache logger according to type, the logger search operation is expensive.  */ @Service public class LoggerCacheImpl implements LoggerCache {   private Map<Class<?>, Logger> loggerCache = new ConcurrentReferenceHashMap<>();   @Override   @MethodTracingDisable   public Logger getLogger(JoinPoint joinPoint) {     final Class<?> clazz = joinPoint.getTarget().getClass();     return loggerCache.computeIfAbsent(clazz, e -> LoggerFactory.getLogger(e));   } }

Spring AOP Examples - Core Concepts and Practical Usages

Spring AOP Limits

Spring AOP supports only method execution join points, so it provides advising the execution of methods on Spring beans.

Spring AOP uses standard JDK dynamic proxies for AOP proxies as default. It mean it requires interfaces as base types. Spring is able to use CGLIB to provide AOP proxies against concrete classes, however it is a good practice to program to interfaces.

Core AOP concepts

Aspect

    a modularization of a cross-cutting concern

Join point

    a exposable point during the execution of a program

Advice

    actions taken by an aspect at a particular join point

Pointcut

    a predicate that matches join points

Introduction

    declaring additional methods or fields on behalf of a type

Target Object

    object being advised by one or more aspects

AOP Proxy

    an object created by the AOP framework in order to implement the aspect contracts

Weaving

    linking aspects with other application types or objects to create an advised object

Type of advices

Before

After returning

After throwing

After(final)

Around

Enable AOP

@Configuration @EnableAspectJAutoProxy public class AppConfig { }

<aop:aspectj-autoproxy/>

Supported Pointcut Designators

execution

within

this

target

args

@target

@args

@within

@annotation

execution(public * *(..)) execution(* set*(..)) execution(* com.xyz.service.AccountService.*(..)) execution(* com.xyz.service.*.*(..)) execution(* com.xyz.service.*.*(..)) within(com.xyz.service.*) within(com.xyz.service..*) execution(* com.xyz.sample.aspect.AspectTestInterface+.*(..)) the following could be used in a binding form too: this(com.xyz.service.AccountService) target(com.xyz.service.AccountService) args(java.io.Serializable) @target(org.springframework.transaction.annotation.Transactional) @within(org.springframework.transaction.annotation.Transactional) @annotation(org.springframework.transaction.annotation.Transactional) @args(com.xyz.security.Classified) bean(tradeService) bean(*Service)

Good poitcuts

·        Kinded designators are those which select a particular kind of join point. For example: execution, get, set, call, handler

·        Scoping designators are those which select a group of join points of interest (of probably many kinds). For example: within, withincode

·        Contextual designators are those that match (and optionally bind) based on context. For example: this, target, @annotation

A well written pointcut should try and include at least the first two types (kinded and scoping).

Argument Binding Examples

/**  * When compiling without debug info, or when interpreting pointcuts at runtime,  * the names of any arguments used in the advice declaration are not available.  * Under these circumstances only, it is necessary to provide the arg names in  * the annotation - these MUST duplicate the names used in the annotated method.  * Format is a simple comma-separated list.  */ @Before(value="com.xyz.lib.Pointcuts.anyPublicMethod() && target(bean) && @annotation(auditable)", argNames="bean,auditable") public void audit(Object bean, Auditable auditable) {         AuditCode code = auditable.value();         // ... use code and bean } @Before(value="com.xyz.lib.Pointcuts.anyPublicMethod() && target(bean) && @annotation(auditable)", argNames="bean,auditable") public void audit(JoinPoint jp, Object bean, Auditable auditable) {         AuditCode code = auditable.value();         // ... use code, bean, and jp } @Around("execution(List<Account> find*(..)) && " +                 "com.xyz.myapp.SystemArchitecture.inDataAccessLayer() && " +                 "args(accountHolderNamePattern)") public Object preProcessQueryPattern(ProceedingJoinPoint pjp,                 String accountHolderNamePattern) throws Throwable {         String newPattern = preProcess(accountHolderNamePattern);         return pjp.proceed(new Object[] {newPattern}); }

Advice Ordering

When two pieces of advice defined in the same aspect both need to run at the same join point, the ordering is undefined. 

When two pieces of advice defined in different aspects both need to run at the same join point, unless you specify otherwise the order of execution is undefined. Or @Order annotation could be used together with @Aspect annotation.

Test Examples

@RunWith(SpringJUnit4ClassRunner.class) @ContextConfiguration() public class AspectTest {        @Resource(name = "aspectTestInterfaceImpl")        private AspectTestInterface ati;        @Autowired        private AspectTestInterfaceExt atiExt;        @Test        public void testBeforeM1() {              System.out.println("test");              ati.m1("m1 run");              ati.m2("m2 run");              ati.m3("m3 run");              ((AspectTestInterface)ati).m2("m2 run");              atiExt.m1("ext m1 run");              atiExt.m10("ext m10 run");              atiExt.m11("ext m11 run");        }        @Configuration        @ComponentScan("com.xyz.sample.aspect")        @EnableAspectJAutoProxy        public static class SpringConfig {              // do nothing.        } } @Retention(RetentionPolicy.RUNTIME) @Target({ ElementType.METHOD, ElementType.ANNOTATION_TYPE }) public @interface AspectTestAnnotation {        String name(); } @AspectTestAnnotation(name="ext") public @interface AspectTestAnnotation2 { } public interface AspectTestInterface {        String m1(String arg1);        String m2(String arg1);        String m3(String arg1); } public interface AspectTestInterfaceExt extends AspectTestInterface {        String m10(String arg1);        String m11(String arg1); } @Component public class AspectTestInterfaceImpl implements AspectTestInterface {        @Override        public String m1(String arg1) {              System.out.println("m1:" + arg1);              return "m1:" + arg1;        }        @Override        @AspectTestAnnotation(name="testName")        public String m2(String arg1) {              System.out.println("m2:" + arg1);              return "m2:" + arg1;        }               @Override        @AspectTestAnnotation2        public String m3(String arg1) {              System.out.println("m3:" + arg1);              return "m3:" + arg1;        }               public String m4(String arg1) {              System.out.println("m4:" + arg1);              return "m4:" + arg1;        } } @Component public class AspectTestInterfaceImplExt extends AspectTestInterfaceImpl implements AspectTestInterfaceExt {        @Override        public String m10(String arg1) {              System.out.println("m10:" + arg1);              return "m10:" + arg1;        }        @Override        public String m11(String arg1) {              System.out.println("m11:" + arg1);              return "m11:" + arg1;        } } @Aspect @Order(1) @Component public class AspectTestAspect {        @Pointcut("execution(* com.xyz.sample.aspect.AspectTestInterface+.*(..))")        public void methodInAspectTestIntefaceAndSubInterfaces() {              // do nothing.        };        @Pointcut("target(com.xyz.sample.aspect.AspectTestInterface)")        public void methodInAspectTestInteface() {              // do nothing.        };        @Pointcut("@annotation(com.xyz.sample.aspect.AspectTestAnnotation)")        public void methodHasAspectTestAnnotation() {              // do nothing.        };        @Before("com.xyz.sample.aspect.AspectTestAspect.methodInAspectTestInteface() && target(bean)")        public void beforeMethodInAspectTestInteface(Object bean) {              System.out.println("=1= beforeMethodInAspectTestInteface...");              if (bean instanceof AspectTestInterface) {                     System.out.println("=1= the target is an AspectTestInterface.");              }              if (bean instanceof AspectTestInterfaceImpl) {                     System.out.println("=1= the target is an AspectTestInterfaceImpl.");              }        }        @Before("com.xyz.sample.aspect.AspectTestAspect.methodInAspectTestInteface() && com.xyz.sample.aspect.AspectTestAspect.methodHasAspectTestAnnotation() && target(bean) && @annotation(aspectTestAnnotation)")        public void beforeMethodHasAspectTestAnnotation(Object bean, AspectTestAnnotation aspectTestAnnotation) {              System.out.println("=2= beforeMethodHasAspectTestAnnotation...");              if (bean instanceof AspectTestInterface) {                     System.out.println("=2= the target is an AspectTestInterface.");              }              if (bean instanceof AspectTestInterfaceImpl) {                     System.out.println("=2= the target is an AspectTestInterfaceImpl.");              }              System.out.println("=2= anotation name is " + aspectTestAnnotation.name());        }               @Before("com.xyz.sample.aspect.AspectTestAspect.methodInAspectTestIntefaceAndSubInterfaces()")        public void beforeMethodInAspectTestIntefaceAndSubInterfaces() {              System.out.println("=3= beforeMethodInAspectTestIntefaceAndSubInterfaces...");        } }