Spring AOP实现零侵入日志记录

软件系统的日志输出是必不可少的，目前在做的RESTful系统中，需要考虑比较复杂的日志处理，但又不想让开发人员在写每个API的时候都去考虑日志的处理，干扰正常的开发，于是决定采用AOP实现零侵入的日志处理。以下是核心思路。

引入AOP依赖

在项目的pom.xml中引入AOP依赖，对于Spring Boot来说应如下。

<dependency>
          <groupId>org.springframework.boot</groupId>
          <artifactId>spring-boot-starter-aop</artifactId>
      </dependency>

编写Aspect类

package com.lefer.demo4doc.aspect;

import com.fasterxml.jackson.databind.ObjectMapper;
import com.lefer.demo4doc.common.Result;
import io.swagger.annotations.ApiOperation;
import org.apache.log4j.Logger;
import org.aspectj.lang.JoinPoint;
import org.aspectj.lang.annotation.AfterReturning;
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.stereotype.Component;
import org.springframework.web.context.request.RequestContextHolder;
import org.springframework.web.context.request.ServletRequestAttributes;

import javax.servlet.http.HttpServletRequest;
import java.lang.reflect.Method;
import java.util.Iterator;
import java.util.Map;

/**
 * @author fang
 * @creatdate 17-7-31
 */
@Component
@Aspect
public class LogAspect {
    private Logger logger = Logger.getLogger(getClass());

    ThreadLocal<Long> startTime = new ThreadLocal<>();

    //@Pointcut("within(com.test.spring.aop.pointcutexp..*)")
    //@Pointcut("this(com.test.spring.aop.pointcutexp.Intf)")
    //@Pointcut("target(com.test.spring.aop.pointcutexp.Intf)")
    //@Pointcut("@within(org.springframework.transaction.annotation.Transactional)")
    //@Pointcut("@annotation(org.springframework.transaction.annotation.Transactional)")
    //@Pointcut("args(String)")
    @Pointcut("execution(public * com.lefer.demo4doc.controller..*.*(..))")
    public void webLog() {
    }

    //在切入点前的操作，按order的值由小到大执行
    //在切入点后的操作，按order的值由大到小执行
    @Before("webLog()")
    @Order(5)
    public void doBefore(JoinPoint joinPoint) throws Throwable {
        startTime.set(System.currentTimeMillis());

        // 接收到请求，记录请求内容
        ServletRequestAttributes attributes = (ServletRequestAttributes) RequestContextHolder.getRequestAttributes();
        HttpServletRequest request = attributes.getRequest();

        // 记录下请求内容
        // 调用方法名
        MethodSignature signature = (MethodSignature) joinPoint.getSignature();
        Method method = signature.getMethod();
        logger.info(method.getAnnotation(ApiOperation.class).value());
        //被调用的URL
        logger.info("URL : " + request.getRequestURL().toString());
        logger.info("HTTP_METHOD : " + request.getMethod());
        //调用者的IP
        logger.info("IP : " + request.getRemoteAddr());
        //调用的类和方法
        logger.info("CLASS_METHOD : " + joinPoint.getSignature().getDeclaringTypeName() + "." + joinPoint.getSignature().getName());
        //logger.info("ARGS : " + Arrays.toString(joinPoint.getArgs()));
        //请求参数和值
        Map map = request.getParameterMap();
        Iterator iterator = map.entrySet().iterator();
        while (iterator.hasNext()) {
            Map.Entry entry = (Map.Entry) iterator.next();
            Object objectValue = entry.getValue();
            if (null == objectValue) {
                logger.info("参数名:" + entry.getKey() + " 参数值: ");
            } else if (objectValue instanceof String[]) {
                String[] values = (String[]) objectValue;
                StringBuilder sb = new StringBuilder();
                for (String val : values) {
                    sb.append(val);
                }
                String value = sb.toString();
                logger.info("ARGS : " + entry.getKey() + " : " + value);
            }
        }
    }

    @AfterReturning(returning = "ret", pointcut = "webLog()")
    public void doAfter(Result ret) throws Throwable {
        // 处理完请求，返回内容
        logger.info("RESPONSE : " + new ObjectMapper().writeValueAsString(ret));
        logger.info("SPEND TIME : " + (System.currentTimeMillis() - startTime.get()));
    }
}

通过@Aspect注解标明这是一个Aspect类
@Pointcut注解标明切面规则
- execution：指明对哪些类或者方法切面注入，public * com.lefer.demo4doc.controller..*.*(..)public 指方法应为public，第一个*指方法的返回值类型不限，..*.*指匹配controller包下及其子包下的所有方法，如果只想匹配controller包下的方法，限定方式是.*.*，最后的(..)代表参数类型不限。可以在这里限定参数类型，如(String,String)，表示方法的入参必须是2个String。
- args：指明匹配入参
- @annotation：匹配包含该注解的所有方法
- @within：匹配包含该注解的类的所有方法
- within：匹配包里的任意类
- this：匹配实现了该接口的任意类，如果括号里的参数不是接口名，那么就是限定单一类
@Before @AfterReturning 切入点
@Order：在切入点前的操作，按order的值由小到大执行；在切入点后的操作，按order的值由大到小执行

执行结果

自此业务控制器上不需要做任何处理，就已经实现了日志的处理和记录。

com.lefer.demo4doc.aspect.LogAspect : 连接字符串
com.lefer.demo4doc.aspect.LogAspect : URL : http://localhost:4000/api/joinstr
com.lefer.demo4doc.aspect.LogAspect : HTTP_METHOD : POST
com.lefer.demo4doc.aspect.LogAspect : IP : 127.0.0.1
com.lefer.demo4doc.aspect.LogAspect : CLASS_METHOD : com.lefer.demo4doc.controller.ApiController.joinStr
com.lefer.demo4doc.aspect.LogAspect : ARGS : str1 : 123
com.lefer.demo4doc.aspect.LogAspect : ARGS : str2 : 456
com.lefer.demo4doc.aspect.LogAspect : RESPONSE : {“status”:200,”message”:”SUCCESS”,”data”:”123456”}
com.lefer.demo4doc.aspect.LogAspect : SPEND TIME : 35

示例源码

GitHub