Use Aop + SpEl to record more detailed request logs

Spring powerful expressions (SpEL) , you can dynamically access the properties of Java objects , call the object’s methods . In the request logging through Aop with SpEL can make the log information more detailed and flexible.

This article will not explain the detailed techniques related to spel and aop. If you are not familiar with them, you can visit the official documentation to learn them.

Practicing

OperationLog

Handler methods annotated with @OperationLog will be logged with detailed access logs. The content of the log can be flexibly defined by the expression expression.

package io.springcloud.demo.annotation;
import java.lang.annotation.ElementType;
import java.lang.annotation.Retention;
import java.lang.annotation.RetentionPolicy;
import java.lang.annotation.Target;

@Target(ElementType.METHOD)
@Retention(RetentionPolicy.RUNTIME)
public @interface OperationLog {

    /**
        * SpEL
        * @return
        */
    String expression();
}

OperationLogAop

The implementation of Aop. Parse log messages before handler method execution.

package io.springcloud.demo.aop;

import java.lang.reflect.Method;


import org.aspectj.lang.JoinPoint;
import org.aspectj.lang.annotation.Aspect;
import org.aspectj.lang.annotation.Before;
import org.aspectj.lang.annotation.Pointcut;
import org.aspectj.lang.reflect.MethodSignature;
import org.springframework.core.annotation.Order;
import org.springframework.expression.EvaluationContext;
import org.springframework.expression.ExpressionParser;
import org.springframework.expression.common.TemplateParserContext;
import org.springframework.expression.spel.standard.SpelExpressionParser;
import org.springframework.expression.spel.support.StandardEvaluationContext;
import org.springframework.stereotype.Component;

import io.springcloud.demo.annotation.OperationLog;
import lombok.extern.slf4j.Slf4j;

@Aspect  
@Component 
@Order(-1)
@Slf4j
public class OperationLogAop {

    // Template prefixes and suffixes that need to be parsed by SpEl.
    // {{ expression }} Similar to template expressions in Go
    public static final TemplateParserContext TEMPLATE_PARSER_CONTEXT = new TemplateParserContext("{{", "}}");

    // SpEL Parser
    public static final ExpressionParser EXPRESSION_PARSER = new SpelExpressionParser();


    @Pointcut(value="@annotation(io.springcloud.demo.annotation.OperationLog)")
    public void controller() {};

    @Before(value = "controller()")
    public void actionLog (JoinPoint joinPoint) throws Throwable {
        
        MethodSignature signature = (MethodSignature) joinPoint.getSignature();

        // Parameters of controller method
        Object[] args = joinPoint.getArgs();
        
        // Parameter Name
        String[] parameterNames = signature.getParameterNames();

        // Handler Method
        Method targetMethod = signature.getMethod();

        // The @OperationLog annotation on the method
        OperationLog operationLog = targetMethod.getAnnotation(OperationLog.class);

        // request
        // HttpServletRequest request = ((ServletRequestAttributes) RequestContextHolder.getRequestAttributes()).getRequest();

        // response
        // HttpServletResponse response = ((ServletRequestAttributes) RequestContextHolder.getRequestAttributes()).getResponse();
        
        /**
            * SpEL context, add all parameters of the HandlerMethod to the context and use the parameter names as KEY.
            */
        EvaluationContext evaluationContext = new StandardEvaluationContext();
        for (int i = 0; i < args.length; i ++) {
            evaluationContext.setVariable(parameterNames[i], args[i]);
        }
        
        // Parsing expressions
        String logContent = EXPRESSION_PARSER.parseExpression(operationLog.expression(), TEMPLATE_PARSER_CONTEXT).getValue(evaluationContext, String.class);
        
        log.info("operationLog = {}", logContent);
    }
}

UserController

Simulates business requests. This Controller is responsible for creating a new user.

package io.springcloud.demo.controller;


import javax.servlet.http.HttpServletRequest;
import javax.servlet.http.HttpServletResponse;

import org.springframework.web.bind.annotation.PostMapping;
import org.springframework.web.bind.annotation.RequestBody;
import org.springframework.web.bind.annotation.RequestMapping;
import org.springframework.web.bind.annotation.RestController;

import io.springcloud.demo.annotation.OperationLog;
import lombok.Data;

@Data
class User {
    String name;
    String email;
}

@RestController
@RequestMapping("/api/user")
public class UserController {

    // Access the properties of the objects in the parameters and the methods through spel expressions.
    @OperationLog(expression = """
                A new user is created, name={{ #user.name }}, email={{ #user.email }}, userAgent={{ #request.getHeader('User-Agent') }}.""")
    @PostMapping
    public Object handle(HttpServletRequest request, HttpServletResponse response, @RequestBody User user) {
        return user;
    }
}

@EnableAspectJAutoProxy

Finally, don’t forget to annotate @EnableAspectJAutoProxy.

package io.springcloud.demo;

import org.springframework.boot.SpringApplication;
import org.springframework.boot.autoconfigure.SpringBootApplication;
import org.springframework.context.annotation.EnableAspectJAutoProxy;

@SpringBootApplication
@EnableAspectJAutoProxy
public class DemoApplication {
    public static void main(String[] args) {
        SpringApplication.run(DemoApplication.class, args);
    }
}

Testing

Client Request Log

POST /api/user HTTP/1.1
Content-Type: application/json
User-Agent: PostmanRuntime/7.28.4
Accept: */*
Postman-Token: 197e4a6f-db8c-4919-95e5-d59904e5eb9f
Host: localhost
Accept-Encoding: gzip, deflate, br
Connection: keep-alive
Content-Length: 42
 
{"name": "Jack","email": "jack@gmail.com"}
 
HTTP/1.1 200 OK
Connection: keep-alive
Transfer-Encoding: chunked
Content-Type: application/json
Date: Mon, 14 Mar 2022 09:20:16 GMT
 
{"name":"Jack","email":"jack@gmail.com"}

Console output logs

022-03-14 17:20:16.933  INFO 1708 --- [  XNIO-1 task-1] io.springcloud.demo.aop.OperationLogAop  : operationLog = A new user is created. name=Jack, email=jack@gmail.com, userAgent=PostmanRuntime/7.28.4

As you can see, the log messages were successfully parsed.

Table of Contents