使用Aop记录Controller层日志信息

为了记录controller的请求参数，请求地址，类名方法等日志信息，以及相关的RT请求耗时时间。在之前总结过RT时间的记录博客java实现监听每个服务的RT，以下将会介绍一种更加优雅的方式。

一. 实现思路

使用切面编程，将controller的请求前后或者环绕进行编织获取HttpServletRequest的参数，并以此作为计算rt耗时时长。

二. 具体实现

talk is cheap, show me the code.

1. 实现切面

import com.alibaba.fastjson.JSONObject;
import com.alibaba.ttl.TransmittableThreadLocal;
import com.yourpackagename.MyCustomPropertyFilter;
import lombok.extern.slf4j.Slf4j;
import org.apache.commons.lang3.time.StopWatch;
import org.aspectj.lang.JoinPoint;
import org.aspectj.lang.ProceedingJoinPoint;
import org.aspectj.lang.Signature;
import org.aspectj.lang.annotation.Around;
import org.aspectj.lang.annotation.Aspect;
import org.aspectj.lang.annotation.Before;
import org.aspectj.lang.annotation.Pointcut;
import org.springframework.stereotype.Component;
import org.springframework.web.context.request.RequestContextHolder;
import org.springframework.web.context.request.ServletRequestAttributes;
import org.springframework.web.multipart.MultipartFile;

import javax.servlet.ServletRequest;
import javax.servlet.ServletResponse;
import javax.servlet.http.HttpServletRequest;

@Aspect
@Component
@Slf4j
public class CustomLogAspect {
    private final TransmittableThreadLocal<StopWatch> invokeTimeTL = new TransmittableThreadLocal<>();

    @Pointcut("@within(org.springframework.web.bind.annotation.RequestMapping)")
    public void controllerPointcut() {
    }

    @Before("controllerPointcut()")
    public void doBefore(JoinPoint joinPoint) throws Throwable {

        ServletRequestAttributes attributes = (ServletRequestAttributes) RequestContextHolder.getRequestAttributes();
        HttpServletRequest request = attributes.getRequest();
        Signature signature = joinPoint.getSignature();
        String name = signature.getName();

        log.info("controller执行开始-请求方法: {}, 请求地址: {}, 类名方法: {}.{}, 远程地址: {}", request.getMethod(), request.getRequestURL().toString(), signature.getDeclaringTypeName(), name, request.getRemoteAddr());
        Object[] args = joinPoint.getArgs();
        int argsLength = args.length;
        Object[] arguments = new Object[argsLength];
        for (int i = 0; i < argsLength; i++) {
                if (args[i] instanceof ServletRequest
                        || args[i] instanceof ServletResponse
                        || args[i] instanceof MultipartFile) {
                    continue;
                }
            arguments[i] = args[i];
        }
        // 此处过滤无需打印的参数，例如password
        MyCustomPropertyFilter.MyCustomSimplePropertyPreFilter excludeFilter = filterProperties(new String[]{"password"});
        log.info("controller执行开始-请求参数: {}", JSONObject.toJSONString(arguments, excludeFilter));

    }

    @Around("controllerPointcut()")
    public Object doAround(ProceedingJoinPoint proceedingJoinPoint) throws Throwable {
        StopWatch stopWatch = new StopWatch();
        invokeTimeTL.set(stopWatch);
        stopWatch.start();
        Object result = proceedingJoinPoint.proceed();
        MyCustomPropertyFilter.MyCustomSimplePropertyPreFilter excludeFilter = filterProperties(new String[]{"password"});
        stopWatch = invokeTimeTL.get();
        stopWatch.stop();
        log.info("controller执行结束-耗时：{} ms, 返回结果: {}", stopWatch.getTime(), JSONObject.toJSONString(result, excludeFilter));
        invokeTimeTL.remove();
        return result;
    }

    private MyCustomPropertyFilter.MyCustomSimplePropertyPreFilter filterProperties(String[] excludeProperties){
        MyCustomPropertyFilter myCustomPropertyFilter = new MyCustomPropertyFilter();
        MyCustomPropertyFilter.MyCustomSimplePropertyPreFilter excludeFilter = myCustomPropertyFilter.addFilter();
        excludeFilter.addExcludes(excludeProperties);
        return excludeFilter;
    }

}

2. 实现自定义属性过滤器

import com.alibaba.fastjson.serializer.SerializeFilter;
import com.alibaba.fastjson.serializer.SimplePropertyPreFilter;

import java.util.ArrayList;
import java.util.List;

/**
 * 重写fastjson过滤器,用于兼容老版本filter
 */
public class MyCustomPropertyFilter {

    private List<MyCustomSimplePropertyPreFilter> filters = new ArrayList<MyCustomSimplePropertyPreFilter>();


    public MyCustomSimplePropertyPreFilter addFilter(){
        MyCustomSimplePropertyPreFilter filter = new MyCustomSimplePropertyPreFilter();
        filters.add(filter);
        return filter;
    }

    public MyCustomSimplePropertyPreFilter addFilter(String... properties){
        MyCustomSimplePropertyPreFilter filter = new MyCustomSimplePropertyPreFilter(properties);
        filters.add(filter);
        return filter;
    }

    public MyCustomSimplePropertyPreFilter addFilter(Class<?> clazz, String... properties){
        MyCustomSimplePropertyPreFilter filter = new MyCustomSimplePropertyPreFilter(clazz,properties);
        filters.add(filter);
        return filter;
    }

    public List<MyCustomSimplePropertyPreFilter> getFilters() {
        return filters;
    }

    public void setFilters(List<MyCustomSimplePropertyPreFilter> filters) {
        this.filters = filters;
    }

    public MyCustomSimplePropertyPreFilter[] toFilters(){
        return filters.toArray(new MyCustomSimplePropertyPreFilter[]{});
    }

    public class MyCustomSimplePropertyPreFilter extends SimplePropertyPreFilter implements SerializeFilter {

        public MyCustomSimplePropertyPreFilter(){}

        public MyCustomSimplePropertyPreFilter(String... properties){
            super(properties);
        }

        public MyCustomSimplePropertyPreFilter(Class<?> clazz, String... properties){
            super(clazz,properties);
        }

        public MyCustomSimplePropertyPreFilter addExcludes(String... filters){
            for (int i = 0; i < filters.length; i++) {
                this.getExcludes().add(filters[i]);
            }
            return this;
        }

        public MyCustomSimplePropertyPreFilter addIncludes(String... filters){
            for (int i = 0; i < filters.length; i++) {
                this.getIncludes().add(filters[i]);
            }
            return this;
        }
    }
}

三. 实现效果

controller执行开始-请求方法: GET, 请求地址: http://ip:port/controller_path, 类名方法: com.xxx.vainycos.controller.TestController.testMethodName, 远程地址: ip

controller执行开始-请求参数: [{"param1": "testValue1","param2": "testValue2"}]

controller执行结束-耗时：36 ms, 返回结果: {"code":200,"msg":"查询成功"}

此处我们还可以结合tlog进行traceId的追踪，可以使日志更加直观。具体可以参考使用Tlog记录traceId/spanId