✨ Enhancement for LoggerContextHolder

README.md

@@ -74,6 +74,8 @@ _`@Logger` 注解已经支持在 IDEA 中自动 SpringEL 表达式高亮并且
   // 可以使用纯字符串或SpringEL表达式，自由发挥
   tag = "'Create Order'"
   ```
+- prelude: 日志在业务代码执行前解析还是在执行后解析（true：执行前解析；false：执行后解析），非必须，默认为 false。若为 true，在注解中的表达式无法使用 result 变量。
+- returning: 是否需要返回业务代码执行结果，非必须，默认为true。
 - additional: 日志额外的信息，非必需，可自由发挥，支持 SpringEL 表达式。
   ```java
   // 从数据库中查询用户名称和会员等级

src/main/java/com/lzhpo/logger/Logger.java

@@ -74,6 +74,25 @@
     @Language(LoggerConstant.SpEL)
     String tag() default LoggerConstant.EMPTY;
 
+    /**
+     * The prelude means logger will resolve before execute business logic.
+     *
+     * <p>If true, will cannot use result in SpringEL expression. <br/>
+     * e.g: {@code @Logger(condition = "#result.getSuccess()", message = "xxx")}
+     *
+     * @return execution pointcut
+     */
+    boolean prelude() default false;
+
+    /**
+     * Return the result of the business method execution.
+     *
+     * <p>If not use result, can set false, the {@link LoggerEvent} will not set result.
+     *
+     * @return returning
+     */
+    boolean returning() default true;
+
     /**
      * The logger additional information.
      *

src/main/java/com/lzhpo/logger/LoggerAspect.java

@@ -48,89 +48,104 @@ public class LoggerAspect {
     /**
      * Around aspect for {@link Logger} annotation.
      *
-     * @param point  {@link ProceedingJoinPoint}
-     * @param logger {@link Logger}
+     * @param joinPoint {@link ProceedingJoinPoint}
+     * @param logger    {@link Logger}
      * @return the result
      * @throws Throwable if the invoked proceed throws anything
      */
     @Around("@annotation(logger)")
-    public Object doAround(ProceedingJoinPoint point, Logger logger) throws Throwable {
-        Date createTime = new Date();
-        Object result;
-
+    public Object doAround(ProceedingJoinPoint joinPoint, Logger logger) throws Throwable {
         LoggerEvent event = new LoggerEvent(this);
-        event.setCreateTime(createTime);
+        event.setCreateTime(new Date(event.getTimestamp()));
         event.setErrors(new ArrayList<>());
 
+        if (logger.prelude()) {
+            resolveLogger(joinPoint, logger, event);
+        }
+
         try {
-            result = point.proceed();
-            event.setResult(result);
-        } catch (Exception exception) {
-            event.getErrors().add(exception);
-            throw exception;
+            Object result = joinPoint.proceed();
+            event.setResult(logger.returning() && !logger.prelude() ? result : null);
+            return result;
+        } catch (Throwable e) {
+            event.getErrors().add(new Exception(e.getMessage(), e));
+            throw e;
         } finally {
-            resolveLogger(point, logger, event);
+            if (!logger.prelude()) {
+                resolveLogger(joinPoint, logger, event);
+            }
+
+            LoggerContextHolder.clearContext();
+            CompletableFuture.runAsync(() -> SpringUtil.publishEvent(event))
+                    .thenRunAsync(() -> log.debug("Published LoggerEvent."))
+                    .exceptionally(e -> {
+                        log.error("Publishing LoggerEvent error: {}", e.getMessage(), e);
+                        return null;
+                    });
         }
-        return result;
     }
 
     /**
      * Resolve {@link Logger} annotation and publish {@link LoggerEvent}.
      *
-     * @param point  {@link ProceedingJoinPoint}
-     * @param logger {@link Logger}
-     * @param event  {@link LoggerEvent}
+     * @param joinPoint {@link ProceedingJoinPoint}
+     * @param logger    {@link Logger}
+     * @param event     {@link LoggerEvent}
      */
-    private void resolveLogger(ProceedingJoinPoint point, Logger logger, LoggerEvent event) {
-        Object object = point.getThis();
-        MethodSignature signature = (MethodSignature) point.getSignature();
-        Method method = signature.getMethod();
-        Object[] args = point.getArgs();
-
-        LoggerExpressionEvaluator evaluator = new LoggerExpressionEvaluator();
-        ParameterNameDiscoverer discoverer = evaluator.getParameterNameDiscoverer();
-        LoggerContextHolder.initialize(object, method, event.getResult(), args, discoverer);
-
+    private void resolveLogger(ProceedingJoinPoint joinPoint, Logger logger, LoggerEvent event) {
         try {
-            LoggerEvaluationContext context = LoggerContextHolder.getContext();
+            Object object = joinPoint.getThis();
+            MethodSignature signature = (MethodSignature) joinPoint.getSignature();
+            Method method = signature.getMethod();
+            Object[] args = joinPoint.getArgs();
+
+            LoggerExpressionEvaluator evaluator = new LoggerExpressionEvaluator();
+            ParameterNameDiscoverer discoverer = evaluator.getParameterNameDiscoverer();
+            LoggerEvaluationContext context =
+                    LoggerContextHolder.getContext(object, method, event.getResult(), args, discoverer);
             if (!Boolean.parseBoolean(evalExpression(logger.condition(), event, context, evaluator))) {
                 log.debug("The resolved condition is false in @Logger.");
                 return;
             }
 
-            String operatorId = Optional.ofNullable(logger.operatorId())
-                    .filter(StringUtils::hasText)
-                    .map(operator -> evalExpression(operator, event, context, evaluator))
-                    .orElseGet(() -> Optional.ofNullable(operatorAwareObjectProvider.getIfAvailable())
-                            .map(OperatorAware::getCurrentOperatorId)
-                            .orElseGet(() -> {
-                                log.debug("No operatorId was entered, also cannot be obtained using OperatorAware.");
-                                return null;
-                            }));
-            event.setOperatorId(operatorId);
-
             event.setLogId(IdUtil.fastSimpleUUID());
             event.setSuccess(CollectionUtils.isEmpty(event.getErrors()));
+            event.setOperatorId(getOperatorId(logger.operatorId(), event, context, evaluator));
             event.setTag(evalExpression(logger.tag(), event, context, evaluator));
             event.setMessage(evalExpression(logger.message(), event, context, evaluator));
             event.setCategory(evalExpression(logger.category(), event, context, evaluator));
             event.setBusinessId(evalExpression(logger.businessId(), event, context, evaluator));
             event.setAdditional(evalExpression(logger.additional(), event, context, evaluator));
-            event.setTakeTime(System.currentTimeMillis() - event.getCreateTime().getTime());
-
-            CompletableFuture.runAsync(() -> SpringUtil.publishEvent(event))
-                    .thenRunAsync(() -> log.debug("Published LoggerEvent."))
-                    .exceptionally(e -> {
-                        log.error("Publishing LoggerEvent error: {}", e.getMessage(), e);
-                        return null;
-                    });
         } catch (Exception e) {
             log.error("Resolve @Logger error: {}", e.getMessage(), e);
+            event.getErrors().add(e);
         } finally {
-            LoggerContextHolder.clearContext();
+            event.setTakeTime(System.currentTimeMillis() - event.getCreateTime().getTime());
         }
     }
 
+    /**
+     * Get operatorId.
+     *
+     * @param operatorId the operatorId
+     * @param event      the logger event
+     * @param context    the logger evaluation context
+     * @param evaluator  the logger expression evaluator
+     * @return the operatorId
+     */
+    // spotless:off
+    private String getOperatorId(String operatorId, LoggerEvent event, LoggerEvaluationContext context, LoggerExpressionEvaluator evaluator) {
+        return Optional.ofNullable(operatorId)
+                .filter(StringUtils::hasText)
+                .map(operator -> evalExpression(operator, event, context, evaluator))
+                .orElseGet(() -> Optional.ofNullable(operatorAwareObjectProvider.getIfAvailable())
+                        .map(OperatorAware::getCurrentOperatorId)
+                        .orElseGet(() -> {
+                            log.debug("No operatorId was entered, also cannot be obtained using OperatorAware.");
+                            return null;
+                        }));
+    }
+
     /**
      * Evaluate condition expression to get result.
      *
@@ -140,12 +155,7 @@ private void resolveLogger(ProceedingJoinPoint point, Logger logger, LoggerEvent
      * @param evaluator  the logger expression evaluator
      * @return the evaluated result
      */
-    private String evalExpression(
-            String expression,
-            LoggerEvent event,
-            LoggerEvaluationContext context,
-            LoggerExpressionEvaluator evaluator) {
-
+    private String evalExpression(String expression, LoggerEvent event, LoggerEvaluationContext context, LoggerExpressionEvaluator evaluator) {
         try {
             return evaluator.evalExpression(expression, context);
         } catch (Exception exception) {
@@ -154,4 +164,5 @@ private String evalExpression(
             return expression;
         }
     }
+    // spotless:on
 }

src/main/java/com/lzhpo/logger/LoggerContextHolder.java

@@ -22,6 +22,7 @@
 import lombok.extern.slf4j.Slf4j;
 import org.springframework.core.ParameterNameDiscoverer;
 import org.springframework.expression.spel.support.StandardEvaluationContext;
+import org.springframework.util.Assert;
 
 /**
  * @author lzhpo
@@ -34,30 +35,24 @@ public class LoggerContextHolder {
     private static final TransmittableThreadLocal<LoggerEvaluationContext> EVALUATION_CONTEXT = new TransmittableThreadLocal<>();
 
     /**
-     * Initialize {@link #EVALUATION_CONTEXT}.
+     * Get {@link #EVALUATION_CONTEXT}.
      *
      * @param rootObject the root object
      * @param method     the method
      * @param result     the result
      * @param args       the arguments
      * @param discoverer the parameter name discoverer
-     */
-    public static void initialize(Object rootObject, Method method, Object result, Object[] args, ParameterNameDiscoverer discoverer) {
-        LoggerEvaluationContext context = new LoggerEvaluationContext(rootObject, method, args, discoverer);
-        context.setVariable(LoggerConstant.VARIABLE_RESULT, result);
-        LoggerFunctionRegistrar.registerFunction(context);
-
-        EVALUATION_CONTEXT.set(context);
-        log.debug("Initialized logger context, currently thread name: {}", Thread.currentThread().getName());
-    }
-
-    /**
-     * Get {@link #EVALUATION_CONTEXT}.
-     *
      * @return {@link LoggerEvaluationContext}
      */
-    public static LoggerEvaluationContext getContext() {
-        return Optional.ofNullable(EVALUATION_CONTEXT.get()).orElseGet(LoggerEvaluationContext::new);
+    public static LoggerEvaluationContext getContext(Object rootObject, Method method, Object result, Object[] args, ParameterNameDiscoverer discoverer) {
+        return Optional.ofNullable(EVALUATION_CONTEXT.get()).orElseGet(() -> {
+            LoggerEvaluationContext context = new LoggerEvaluationContext(rootObject, method, args, discoverer);
+            context.setVariable(LoggerConstant.VARIABLE_RESULT, result);
+            LoggerFunctionRegistrar.registerFunction(context);
+            EVALUATION_CONTEXT.set(context);
+            log.debug("The evaluation context is null, created new context, current thread name: {}", Thread.currentThread().getName());
+            return context;
+        });
     }
 
     /**
@@ -67,7 +62,8 @@ public static LoggerEvaluationContext getContext() {
      * @param value the variable value
      */
     public static void putVariable(String name, Object value) {
-        StandardEvaluationContext context = getContext();
+        StandardEvaluationContext context = EVALUATION_CONTEXT.get();
+        Assert.notNull(context, "The evaluation context is null");
         context.setVariable(name, value);
     }
 
@@ -78,7 +74,8 @@ public static void putVariable(String name, Object value) {
      * @return the variable value
      */
     public static Object lookupVariable(String name) {
-        StandardEvaluationContext context = getContext();
+        StandardEvaluationContext context = EVALUATION_CONTEXT.get();
+        Assert.notNull(context, "The evaluation context is null");
         return context.lookupVariable(name);
     }
 
@@ -87,7 +84,7 @@ public static Object lookupVariable(String name) {
      */
     public static void clearContext() {
         EVALUATION_CONTEXT.remove();
-        log.debug("Cleared logger context, currently thread name: {}", Thread.currentThread().getName());
+        log.debug("Cleared evaluation context, current thread name: {}", Thread.currentThread().getName());
     }
 }
 // spotless:on

src/main/java/com/lzhpo/logger/LoggerEvaluationContext.java

@@ -18,7 +18,6 @@
 import java.lang.reflect.Method;
 import java.util.Arrays;
 import lombok.Getter;
-import lombok.NoArgsConstructor;
 import lombok.extern.slf4j.Slf4j;
 import org.springframework.core.ParameterNameDiscoverer;
 import org.springframework.expression.spel.support.StandardEvaluationContext;
@@ -40,18 +39,18 @@
  */
 @Slf4j
 @Getter
-@NoArgsConstructor
 public class LoggerEvaluationContext extends StandardEvaluationContext {
 
-    private Method method;
-    private Object[] arguments;
-    private ParameterNameDiscoverer discoverer;
+    private final Method method;
+    private final Object[] arguments;
+    private final ParameterNameDiscoverer discoverer;
     private boolean argumentsLoaded = false;
 
-    public LoggerEvaluationContext(Object rootObject, Method method, Object[] arg, ParameterNameDiscoverer discoverer) {
+    public LoggerEvaluationContext(
+            Object rootObject, Method method, Object[] arguments, ParameterNameDiscoverer discoverer) {
         super(rootObject);
         this.method = method;
-        this.arguments = arg;
+        this.arguments = arguments;
         this.discoverer = discoverer;
     }
 

src/main/java/com/lzhpo/logger/LoggerEvent.java

@@ -71,7 +71,7 @@ public class LoggerEvent extends ApplicationEvent {
     private Date createTime;
 
     /**
-     * The business method take time (unit: milliseconds).
+     * The business method with generate log take time (unit: milliseconds).
      */
     private Long takeTime;
 

src/test/java/com/lzhpo/logger/controller/OrderController.java

@@ -37,12 +37,14 @@ public class OrderController {
 
     private final OrderService orderService;
 
+    // @el(request: com.lzhpo.logger.domain.CreateOrderRequest)
+    // @el(result: com.lzhpo.logger.domain.CreateOrderResponse)
     @PostMapping
     @Logger(
             condition = "#result.getSuccess()",
             category = "'Operation Log'",
             tag = "'Create Order'",
-            businessId = "#getBusinessId(#result.orderId)",
+            businessId = "#getBusinessId(#result.getOrderId())",
             operatorId = "#findUserName(#request.getUserId())",
             message = "#findUserName(#request.getUserId()) + '使用' + #request.getPaymentType() + '下单了' + #findProductName(#request.getProductId()) + '产品'",
             additional = "#findUserName(#request.getUserId()) + '等级是' + #findUserVip(#request.getUserId()) + '，请求日期' + T(java.time.LocalDateTime).now()"
@@ -55,16 +57,21 @@ public CreateOrderResponse createOrder(@RequestBody CreateOrderRequest request)
     // @el(result: com.lzhpo.logger.domain.ModifyOrderResponse)
     @PutMapping
     @Logger(
-            condition = "#result.getSuccess()",
             category = "'Operation Log'",
             tag = "'Modify Order'",
-            businessId = "#getBusinessId(#result.orderId)",
-            operatorId = "#findUserName(#request.getUserId())",
+            prelude = true,
+            returning = false,
+            businessId = "#request.getOrderId()",
+            operatorId = "#request.getUserId()",
             message = "#findUserName(#request.getUserId()) + '将地址从' + #findOldAddress(#request.getOrderId()) + '修改为' + #findNewAddress(#request.getAddressId())",
             additional = "#findUserName(#request.getUserId()) + '等级是' + #findUserVip(#request.getUserId()) + '，请求日期' + T(java.time.LocalDateTime).now()"
     )
     public ModifyOrderResponse modifyOrder(@RequestBody ModifyOrderRequest request) {
-        return orderService.modifyOrder(request);
+        ModifyOrderResponse response = orderService.modifyOrder(request);
+        request.setOrderId("");
+        request.setUserId("");
+        request.setAddressId("");
+        return response;
     }
 }
 // spotless:on