User Case
We want to create @Loggable so developers can use it to specify log level and what to log before or after the method being called. developers can use #p0, #p1 to log param values, use #result to log response or specify any valid spring expression.
Learning How to Do it from Spring Code
We know that spring cache annotations supports spring expression language, we can use #p0, #p1 in @Cacheable, use #result in @CachePut. So we can debug spring cache code to figure it how it works.
Relate code in Spring CacheAspectSupport.execute
CacheAspectSupport.generateKey(CacheOperationContext, Object)
CacheOperationExpressionEvaluator.createEvaluationContext
if (result != NO_RESULT) evaluationContext.setVariable(RESULT_VARIABLE, result);
- To support #result, we just put method return result value into the varaible: result.
The Implementation
We want to create @Loggable so developers can use it to specify log level and what to log before or after the method being called. developers can use #p0, #p1 to log param values, use #result to log response or specify any valid spring expression.
Learning How to Do it from Spring Code
We know that spring cache annotations supports spring expression language, we can use #p0, #p1 in @Cacheable, use #result in @CachePut. So we can debug spring cache code to figure it how it works.
Relate code in Spring CacheAspectSupport.execute
CacheAspectSupport.generateKey(CacheOperationContext, Object)
CacheOperationExpressionEvaluator.createEvaluationContext
if (result != NO_RESULT) evaluationContext.setVariable(RESULT_VARIABLE, result);
- To support #result, we just put method return result value into the varaible: result.
The Implementation
@Retention(RetentionPolicy.RUNTIME)
@Target(ElementType.METHOD)
public @interface Loggable {
Level level() default Level.INFO;
/**
* This value has to be a valid spring expression<br>
* Example: "'-begin'" or use #p0, #p1 to refer method params.
*
* @return
*/
String beginMessage() default "";
/**
* This value has to be a valid spring expression<br>
* Example: "#result", "'-end'"
*
* @return
*/
String endMessage() default "";
}
@Aspect
@Component
public class LoggableAspect {
@Value("${throw.exception.if.invalid.expression:true}")
private boolean throwExceptionIfInvalidExpression;
public static final String RESULT_VARIABLE = "result";
/**
* It is recommended to reuse ParameterNameDiscoverer instances as far as possible.
*/
private static final ParameterNameDiscoverer parameterNameDiscoverer =
new LocalVariableTableParameterNameDiscoverer();
/**
* SpEL parser. Instances are reusable and thread-safe.
*/
private static final ExpressionParser parser = new SpelExpressionParser();
@Around("@annotation(com.sony.sie.kamaji.vue.metadata.aop.Loggable)")
public Object logExecutionTime(ProceedingJoinPoint joinPoint) throws Throwable {
Method method = ((MethodSignature) joinPoint.getSignature()).getMethod();
final Class<?> declaringClass = method.getDeclaringClass();
final Logger logger = LoggerFactory.getLogger(declaringClass);
final Loggable loggable = method.getAnnotation(Loggable.class);
Object result = null;
if (loggable != null) {
final Level logLevel = loggable.level();
if (whetherParseExpression(loggable.beginMessage(), logger, logLevel)) {
final EvaluationContext beginContext = new MethodBasedEvaluationContext(invocation.getThis(), method,
invocation.getArguments(), parameterNameDiscoverer);
parseExpressionValue(logger, logLevel, loggable.beginMessage(), beginContext);
}
try {
result = invocation.proceed();
if (whetherParseExpression(loggable.endMessage(), logger, logLevel)) {
final EvaluationContext context = new MethodBasedEvaluationContext(invocation.getThis(), method,
invocation.getArguments(), parameterNameDiscoverer);
context.setVariable(RESULT_VARIABLE, result);
parseExpressionValue(logger, logLevel, loggable.endMessage(), context);
}
return result;
} catch (final RuntimeException e) {
logValues(logger, "Failed with exception: " + e.getMessage(), logLevel);
throw e;
}
}
return invocation.proceed();
}
private void parseExpressionValue(final Logger logger, final Level logLevel, final String expression,
final EvaluationContext context) {
if (StringUtils.isBlank(expression)) {
return;
}
Object value = null;
try {
value = parser.parseExpression(expression).getValue(context);
} catch (final Exception e) {
if (throwExceptionIfInvalidExpression) {
throw new VMSBusinessException(ErrorCode.internal_error, e,
"Failed to parse expression: " + expression);
}
}
logValues(logger, value != null ? value.toString() : expression, logLevel);
}
/**
* If the log level is not enabled, no need to do anything at all.
*/
private boolean whetherParseExpression(String expression, final Logger logger, final Level logLevel) {
if (StringUtils.isBlank(expression)) {
return false;
}
switch (logLevel) {
case INFO:
return logger.isInfoEnabled();
case ERROR:
return logger.isErrorEnabled();
case WARN:
return logger.isWarnEnabled();
case DEBUG:
return logger.isDebugEnabled();
case TRACE:
return logger.isTraceEnabled();
default:
return false;
}
}
}
