I'm logging method input and output parameters by a simple Aspect.
package com.mk.cache;
import org.aspectj.lang.ProceedingJoinPoint;
import org.aspectj.lang.annotation.Around;
import org.aspectj.lang.annotation.Aspect;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
import org.springframework.stereotype.Component;
import java.util.Arrays;
@Aspect
@Component
public class LoggingAspect {
@Around("within(@com.mk.cache.LoggedIO *) && execution(* *(..))")
public Object logAroundPublicMethod(ProceedingJoinPoint joinPoint) throws Throwable {
String wrappedClassName = joinPoint.getSignature().getDeclaringTypeName();
Logger LOGGER = LoggerFactory.getLogger(wrappedClassName);
String methodName = joinPoint.getSignature().getName();
LOGGER.info("LOG by AOP - invoking {}({})", methodName, Arrays.toString(joinPoint.getArgs()));
Object result = joinPoint.proceed();
LOGGER.info("LOG by AOP - result of {}={}", methodName, result);
return result;
}
}
which is attached by this Annotation.
package com.mk.cache;
public @interface LoggedIO {
}
I use this mechanism to log inputs and outputs of methods like this (notice @LoggedIO):
package com.mk.cache;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
import org.springframework.cache.annotation.Cacheable;
import org.springframework.stereotype.Service;
@Service
@LoggedIO
public class CachedService {
private static final Logger LOGGER = LoggerFactory.getLogger(CachedService.class);
@Cacheable("myCacheGet")
public int getInt(int input) {
LOGGER.info("Doing real work");
return input;
}
}
I also use Spring Cache. Here is the example application.
package com.mk.cache;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
import org.springframework.beans.factory.annotation.Autowired;
import org.springframework.boot.CommandLineRunner;
import org.springframework.boot.SpringApplication;
import org.springframework.boot.autoconfigure.SpringBootApplication;
import org.springframework.cache.annotation.EnableCaching;
@SpringBootApplication
@EnableCaching
public class CacheApplication implements CommandLineRunner {
private static final Logger LOGGER = LoggerFactory.getLogger(CacheApplication.class);
public static void main(String[] args) {
SpringApplication.run(CacheApplication.class, args);
}
@Autowired
private CachedService cachedService;
@Override
public void run(String... args) throws Exception {
LOGGER.info("cachedService.getInt(1)={}", cachedService.getInt(1));
LOGGER.info("cachedService.getInt(1)={}", cachedService.getInt(1));
}
}
The output looks like this:
LOG by AOP - invoking getInt([1])
Doing real work
LOG by AOP - result of getInt=1
cachedService.getInt(1)=1
cachedService.getInt(1)=1
My problem is, that when I call LOGGER.info("cachedService.getInt(1)={}", cachedService.getInt(1));
for the second time, the cached value is used, but the input and output parameters are not logged, as the cache is the first wrapper. Is it possible to somehow configure the LoggingAspect to be the first wrapper, so I will be able to use both AOP logging and both Spring Cache?
Just implement spring Ordered interface and in getOrder() method return 1.
@Aspect
@Component
public class LoggingAspect implements Ordered {
@Around("within(@com.mk.cache.LoggedIO *) && execution(* *(..))")
public Object logAroundPublicMethod(ProceedingJoinPoint joinPoint) throws Throwable {
String wrappedClassName = joinPoint.getSignature().getDeclaringTypeName();
Logger LOGGER = LoggerFactory.getLogger(wrappedClassName);
String methodName = joinPoint.getSignature().getName();
LOGGER.info("LOG by AOP - invoking {}({})", methodName, Arrays.toString(joinPoint.getArgs()));
Object result = joinPoint.proceed();
LOGGER.info("LOG by AOP - result of {}={}", methodName, result);
return result;
}
@Override
public int getOrder() {
return 1;
}
}
Read more here. Chapter 11.2.7