Spring AOP统一处理日志

AOP统一处理日志

注:日志记录是系统非业务功能的重要一环,而日志中比较重要的是Controller层的请求日志,需要记录的信息包括登录用户、访问时间,访问接口,请求参数,响应结果等。本文基于Spring AOP、logback,在统一的切面对象中实现请求日志的统一处理。

依赖

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

登录用户持有器

@Component
public class HostHolder {

    private ThreadLocal<User> users = new ThreadLocal<>();

    public UserLoginResp getUser() {
        return users.get();
    }

    public void setUser(UserLoginResp user) {
        users.set(user);
    }

    public void clear() {
        users.remove();
    }
}

切面类实现一

@Component
@Aspect
public class ApiLogAspect {

	private static final Logger logger = LoggerFactory.getLogger(ApiLogAspect.class);

	/**
     * 指定切面对象,Controller层所有暴露给前端的接口方法
     */
    @Pointcut("execution(public * com.itcampus.controller.*.*(..))")
    public void pointcut() {}

	/**
     * 记录接口入参日志
     */
    @Before(value = "pointcut()")
    public void beforeMethod(JoinPoint joinPoint) {
        ServletRequestAttributes sra = (ServletRequestAttributes)RequestContextHolder.getRequestAttributes();
        HttpServletRequest request = sra.getRequest();
		// 获取接口路径
        String path = request.getRequestURI();
        // 获取登录用户
		User user = hostHolder.getUser();
		// 获取请求参数
        Object[] args = joinPoint.getArgs();
        // 获取时间
        long time = LocalDateTime.now().toInstant(ZoneOffset.ofHours(8)).toEpochMilli();
        // 记录入参日志
        logger.info(String.format("req->user:[%s],time:[%s],path:[%s],args:[%s].",
                    JSON.toJSONString(user), time, path, JSON.toJSONString(args)));       
    }

	/**
     * 记录接口出参日志
     */
    @AfterReturning(value="pointcut()" ,returning="result")
    public void afterReturning(Object result) {
        ServletRequestAttributes sra = (ServletRequestAttributes)RequestContextHolder.getRequestAttributes();
        HttpServletRequest request = sra.getRequest();
		// 获取接口路径
        String path = request.getRequestURI();
        // 获取登录用户
		User user = hostHolder.getUser();
        // 获取时间
        long time = LocalDateTime.now().toInstant(ZoneOffset.ofHours(8)).toEpochMilli();
        // 记录出参日志
        logger.info(String.format("resp->user:[%s],time:[%s],path:[%s],return:[%s].",
                    JSON.toJSONString(user), time, path, JSON.toJSONString(result)));
    }
	
	/**
     * 记录接口抛出的异常
     */
    @AfterThrowing(value="pointcut()" ,throwing="e")
    public void afterThrowing(JoinPoint joinPoint, Exception e) {
    	// 获取方法名(也可以像上面一样获取接口路径)
        String method = String.format("%s.%s", joinPoint.getSignature().getDeclaringTypeName(), 
        joinPoint.getSignature().getName());
        // 记录异常日志
        logger.error(String.format("ex->method:[%s],ex:[%s].", method, e.getMessage()));
    }
}

注:上述切面类比较清晰直观,入参日志、出餐日志以及异常抛出日志利用AOP注解@Before、@AfterReturning、@AfterThrowing实现。但是,上述切面类存在一些问题。
1、对于接口的出参日志,我们更希望记录接口的耗时时间,不想手动计算入参时间和出参时间的差值。另外,一般logback.xml在定义日志输出格式时,都是已经携带时间的,AOP中重复打印时间的意义不大。
2、对于抛出异常日志,AOP切面不知道这是我们自定义的异常还是未知异常。通常程序中会设计一个统一异常处理器处理程序员能预见的自定义异常,这些异常已经被程序处理,不能算作error级别。但也存在一些未知异常,异常日志应该重点处理这类异常。当然,未知异常也能交给统一异常处理器处理。
综上,如果我们有意记录接口响应时间,并且在程序中使用到了统一异常处理器,上述切面类不太合适。

切面类实现二

Controller层切面类

该切面类用于Controller层所有暴露给前端的接口,利用@Around注解、ProceedingJoinPoint参数实现接口响应计时。

@Component
@Aspect
public class ApiLogAspect {

    private static final Logger logger = LoggerFactory.getLogger(ApiLogAspect.class);

    @Resource
    private HostHolder hostHolder;

    /**
     * 指定切面对象,Controller类中所有方法
     */
    @Pointcut("execution(public * com.itcampus.controller.*.*(..))")
    public void pointcut() {
    }

    /**
     * 打印出入参记录
     *
     * @param joinPoint 切面连接点对象
     */
    @Around("pointcut()")
    public Object before(ProceedingJoinPoint joinPoint) throws Throwable {
        ServletRequestAttributes sra = (ServletRequestAttributes)RequestContextHolder.getRequestAttributes();
        HttpServletRequest request = sra.getRequest();
		// 获取接口路径
        String path = request.getRequestURI();
        // 获取登录用户
		User user = hostHolder.getUser();
        // 获取参数
        Object[] args = joinPoint.getArgs();
        // 记录入参日志
        logger.info(String.format("req->user:[%s],path:[%s],args:[%s].",
                    JSON.toJSONString(user), path, JSON.toJSONString(args)));
        long start = System.currentTimeMillis();
        Object result = joinPoint.proceed();
        long executeTime = System.currentTimeMillis() - start;
        // 记录出参日志
        logger.info(String.format("resp->user:[%s],ms:[%s],path:[%s],return:[%s].",
                    JSON.toJSONString(user), executeTime, path, JSON.toJSONString(result)));
        return result;
    }
}
ControllerAdvice层切面类

该切面类用于统一异常处理器使用

@Component
@Aspect
public class ApiAdviceLogAspect {

    private static final Logger logger = LoggerFactory.getLogger(ApiAdviceLogAspect.class);
    
    /**
     * 指定切面对象,ControllerAdvice类中所有方法
     */
    @Pointcut("execution(* com.itcampus.handler.GlobalExceptionHandler.*(..))")
    public void pointcut() {
    }
	
	/**
     * 当Controller层抛出异常,由ControllerAdvice层记录出参记录
     *
     * @param result 响应结果
     */
    @AfterReturning(value = "pointcut()", returning = "result")
    public void afterReturning(Object result) {
        ServletRequestAttributes sra = (ServletRequestAttributes)RequestContextHolder.getRequestAttributes();
        HttpServletRequest request = sra.getRequest();
		// 获取接口路径
        String path = request.getRequestURI();
        // 获取登录用户
		User user = hostHolder.getUser();
        // 记录出参日志
        logger.warn(String.format("resp(ex)->user:[%s],path:[%s],return:[%s].",
                    JSON.toJSONString(user), path, JSON.toJSONString(result)));
    }
}

注:上述切面类默认处理Controller层所有的接口,但有时候,我们只希望记录某些接口,比如增删改接口,而查询接口不做记录。这时候,AOP切面的使用就需要更加灵活。

切面类实现三

自定义注解

用于标识某个接口方法需要记录日志

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 LogRequired {

}
切面类增加注解判断
@Component
@Aspect
public class ApiLogAspect {

    private static final Logger logger = LoggerFactory.getLogger(ApiLogAspect.class);

    @Resource
    private HostHolder hostHolder;

    /**
     * 指定切面对象,Controller类中所有方法
     */
    @Pointcut("execution(public * com.itcampus.controller.*.*(..))")
    public void pointcut() {
    }

    /**
     * 打印出入参记录
     *
     * @param joinPoint 切面连接点对象
     */
    @Around("pointcut()")
    public Object before(ProceedingJoinPoint joinPoint) throws Throwable {
    	MethodSignature signature = (MethodSignature) pjp.getSignature();
        Method method = signature.getMethod();
        LogRequired logRequired = method.getAnnotation(LogRequired.class);
        // 该接口方法没有加LogRequired注解,表示不记录日志
        if(ObjectUtils.isEmpty(logRequired)){
        	return joinPoint.proceed();
        }
        // 该接口方法有LogRequired注解,记录日志
       	// TODO
    }
}

请求日志唯一追踪ID

注:由于入参日志和出参日志是分开打印的,而logback底层是异步处理机制,所以需要一个唯一ID标识确定某些出入参日志属于同一个请求,并且把这个唯一标识返回给前端,方便异常追踪。你可能会说,出入参打印为一条日志不就行了么,在AOP @Around注解方法中是可以做到的。但是,Controller层切面和ControllerAdvice的日志记录就无法打印成一条了。所以,单独设置一个追踪ID是有必要的。

logback.xml日志输出格式修改

日志文件所有的appender标签输出表达式增加一个traceId占位符

<appender>
    <encoder>
        <pattern>%date{yyyy-MM-dd HH:mm:ss.SSS} %level [%thread] [%X{traceId}] %logger{10}:%line %msg%n</pattern>
        <charset>utf-8</charset>
    </encoder>
</appender>
过滤器设置traceId
import org.slf4j.MDC;

import javax.servlet.*;
import java.io.IOException;
import java.util.UUID;

public class LogMDCFilter implements Filter {

    public static final String TRACE_ID = "traceId";

    @Override
    public void doFilter(ServletRequest servletRequest, ServletResponse servletResponse,
                         FilterChain filterChain) throws IOException, ServletException {
        MDC.put(TRACE_ID, UUID.randomUUID().toString().replace("-", ""));
        try {
            filterChain.doFilter(servletRequest, servletResponse);
        } finally {
            MDC.remove(TRACE_ID);
        }
    }
}
配置过滤器
import org.springframework.boot.web.servlet.FilterRegistrationBean;
import org.springframework.context.annotation.Bean;
import org.springframework.context.annotation.Configuration;

@Configuration
public class FilterConfig {

    @Bean
    public FilterRegistrationBean<LogMDCFilter> logFilterRegistration() {
        FilterRegistrationBean<LogMDCFilter> registration = new FilterRegistrationBean<>();
        // 注入过滤器
        registration.setFilter(new LogMDCFilter());
        // 拦截规则
        registration.addUrlPatterns("/*");
        // 过滤器名称
        registration.setName("logMDCFilter");
        // 过滤器顺序
        registration.setOrder(0);
        return registration;
    }
}
统一返回对象增加traceId
import lombok.Data;
import org.slf4j.MDC;

@Data
public class ResultBean<T> {

    /**
     * 返回业务码
     */
    private Integer code;

    /**
     * 返回提示信息
     */
    private String message;

    /**
     * 返回的实际数据
     */
    private T data;

    /**
     * 异常响应日志追踪ID
     */
    private String traceId = MDC.get(LogMDCFilter.TRACE_ID);

    /**
     * 返回提示信息
     *
     * @param code 业务码
     * @param msg  提示信息
     */
    public ResultBean(Integer code, String msg) {
        this.code = code;
        this.message = msg;
    }

    /**
     * 返回数据并提示信息
     *
     * @param code 业务码
     * @param msg  提示信息
     * @param data Object
     */
    public ResultBean(Integer code, String msg, T data) {
        this.code = code;
        this.message = msg;
        this.data = data;
    }
}