只要日志打得多,定位BUG一把梭

本文涉及到的完整代码:GITEE

或者访问:https://gitee.com/topanda/spring-boot-security-quickly-start/tree/jpanda-spring-boot-security-api/src/main/java/cn/jpanda/demo/manager/configuration/log

代码写多了,难免有BUG,作为一个常年走夜路的程序员,偶尔遇到一次线上BUG,说出来也不算多么罕见的事情.

提到线上BUG,不管大小,总是能让人惊起一身冷汗,自发现线上BUG到解决BUG这段时间,无人不是寒毛炸起,坐立难安.

再看解决BUG的场景,往往是一人编码,全组围观,仿似不如此,就是对BUG的不尊重.

其间只闻键盘声噼里啪啦作响,小组成员时坐时立,来回踱步,显示器中shell,log,code混作一团,密密麻麻.

编码人员双目紧盯屏幕,从一行行日志中获取信息,和代码一一对应,时而微笑,时而蹙眉,若是发现丢失了关键日志还会如同失魂一般,双目无神.

不怪编程人员大题小做,老板可不管阿尔卑斯的雪崩和你喜马拉雅的雪花有没有关系,问题解决不了,阿尔卑斯的雪崩就是你造成的.

这时候,一份详细有序的日志记录或许能够救你于水火之中.

确定日志记录数据

常见的线上的BUG,往往是因为用户调用时,传入的数据超出了编程时设想的阈值所造成的.

因此,除了具体的业务日志之外,我们还有必要记录下用户传入的参数值.

针对一次调用来说,比较关键的信息主要有:用户请求地址,请求方式,命中方法,请求入参,响应状态.

针对部分接口甚至还可以记录请求的响应数据以及请求头,若是为了分析接口性能着想,还可以考虑记录用户请求的处理时长,调用时间,为了方便定位异常原因,还可以额外记录异常信息以及异常堆栈信息.

当然,为了更好的区分接口,我们还可以为不同的接口请求配置不同的可读性较高的名称.

综合上诉的需求,我们提供了一个LogInfo对象,该对象负责维护一次访问涉及到的关键数据:

import com.fasterxml.jackson.annotation.JsonInclude;
import lombok.Data;
import org.springframework.http.HttpMethod;
import org.springframework.http.HttpStatus;

import java.util.Date;
import java.util.Map;

@Data
@JsonInclude(JsonInclude.Include.NON_NULL)
public class LogInfo {
    /**
     * 请求路径
     */
    private String uri;

    /**
     * 请求方法
     */
    private HttpMethod httpMethod;

    /**
     * 请求头
     */
    private Map<String, String> headers;

    /**
     * 命中Controller
     */
    private Signature signature;

    /**
     * 请求参数
     */
    private Param[] args;
    /**
     * 方法描述
     */
    private String description;
    /**
     * 请求来源IP
     */
    private String requestIp;

    /**
     * 请求耗时
     */
    private Long duration;

    /**
     * 响应状态
     */
    private HttpStatus responseStatus;

    /**
     * 响应数据
     */
    private Object result;

    /**
     * 错误日志
     */
    private Object errMessage;

    /**
     * 异常堆栈信息
     */
    private Object errTrace;

    /**
     * 调用时间戳
     */
    private Date requestTime;
}

值得注意的是,为了减少日志持久化时的产生的数据量,针对于LogInfo中的null值数据,我们选择丢弃,因此我们在LogInfo的类定义上标注了@JsonInclude(JsonInclude.Include.NON_NULL).

标注了该注解的原因,是我在后续持久化日志时选择通过jackson-databind将日志对象转换为JSON数据.

明确控制日志记录的方式

LogInfo对象记录的数据相对而言属于大而全的,在实际使用中,我们可能并不需要这么详细的日志,或者因为特殊的原因,需要屏蔽掉部分数据,比如,禁用掉异常堆栈信息和响应数据

针对这种场景,我们考虑提供一个全局配置对象AccessLogProperties用来控制具体每个参数的有效性:

import com.live.configuration.log.handler.filters.Filter;
import com.live.configuration.log.handler.filters.NoneFilter;
import lombok.Data;
import org.springframework.boot.context.properties.ConfigurationProperties;

import java.io.Serializable;

/**
 * @author HanQi [Jpanda@aliyun.com]
 * @version 1.0
 * @since 2020/6/6 15:34:35
 */
@Data
@ConfigurationProperties("access.log")
public class AccessLogProperties implements Serializable, Cloneable {

    /**
     * 是否记录请求地址,核心数据,建议开启.
     */
    private boolean uri = true;
    /**
     * 是否记录请求头,用于特殊场景,默认关闭
     */
    private boolean headers = false;
    /**
     * 请求头过滤器
     */
    private Class<? extends Filter> headersFilter = NoneFilter.class;
    /**
     * 是否记录请求方法
     */
    private boolean httpMethod = true;
    /**
     * 是否记录命中方法
     */
    private boolean signature = true;
    /**
     * 是否记录请求参数
     */
    private boolean params = true;

    /**
     * 是否记录请求来源IP
     */
    private boolean ip = true;
    /**
     * 是否记录请求耗时
     */
    private boolean duration = true;
    /**
     * 是否记录响应状态
     */
    private boolean status = true;
    /**
     * 是否记录响应体
     */
    private boolean result = true;

    /**
     * 关键异常日志
     */
    private boolean errMessage = true;
    /**
     * 因此堆栈信息
     */
    private boolean errTrace = false;


    /**
     * 调用时间
     */
    private boolean requestTime;

    @Override
    public AccessLogProperties clone() {

        AccessLogProperties clone = new AccessLogProperties();
        clone.setUri(this.uri);
        clone.setHeaders(this.headers);
        clone.setHeadersFilter(this.headersFilter);
        clone.setHttpMethod(this.httpMethod);
        clone.setSignature(this.signature);
        clone.setParams(this.params);
        clone.setIp(this.ip);
        clone.setDuration(this.duration);
        clone.setStatus(this.status);
        clone.setResult(this.result);
        clone.setErrMessage(this.errMessage);
        clone.setErrTrace(this.errTrace);
        clone.setRequestTime(this.requestTime);
        return clone;
    }
}

在AccessLogProperties中涉及到一个名为headersFilter的Filter属性,该属性指向一个Filter的有效实例,Filter用来筛选需要记录的请求头信息,从设计上来看,我们限制了Filter的实例必须提供一个无参构造方法.

public interface Filter {
    boolean filter(String str);
}

默认的Filter实现NoneFilter将会过滤掉所有的请求头:

public class NoneFilter implements Filter {
    @Override
    public boolean filter(String str) {
        return false;
    }
}

除此之外,AccessLogProperties中的属性定义和LogInfo中的属性一一对应,控制着的相应属性是否生效.

除了全局配置之外,针对于部分接口,我们可能不需要记录这么多信息,比如文件下载,文件上传之类的接口定义,是不需要记录入参和出参数据的.

为此,我们提供了LogOptions注解,该注解的属性定义以及行为都和AccessLogProperties完全一致,LogOptions注解用于局部日志配置,其优先级要高于全局默认配置:

import com.live.configuration.log.handler.filters.Filter;
import com.live.configuration.log.handler.filters.NoneFilter;

/**
 * 日志选项,该选项可以覆盖,日志的默认行为
 *
 * @author HanQi [Jpanda@aliyun.com]
 * @version 1.0
 * @since 2020/6/8 9:57:13
 */
public @interface LogOptions {

    /**
     * 是否记录请求地址,核心数据,建议开启.
     */
    boolean uri() default true;

    /**
     * 是否记录请求头,用于特殊场景,默认关闭
     */
    boolean headers() default false;

    /**
     * 请求头过滤器
     */
    Class<? extends Filter> headersFilter() default NoneFilter.class;

    /**
     * 是否记录请求方法
     */
    boolean httpMethod() default true;

    /**
     * 是否记录命中方法
     */
    boolean signature() default true;

    /**
     * 是否记录请求参数
     */
    boolean params() default true;

    /**
     * 是否记录请求来源IP
     */
    boolean ip() default true;

    /**
     * 是否记录请求耗时
     */
    boolean duration() default true;

    /**
     * 是否记录响应状态
     */
    boolean status() default true;

    /**
     * 是否记录响应体
     */
    boolean result() default false;

    /**
     * 日志关键信息
     */
    boolean errMessage() default true;

    /**
     * 日志堆栈信息
     */
    boolean errTrace() default false;

    /**
     * 调用时间
     */
    boolean requestTime() default true;
}

明确日志记录使用方式

在确定了日志记录数据和配置内容之后,我们需要为其提供相应的解决方案,在实现上,基本思路是借助于OncePerRequestFilter对象拦截每次请求,从而记录方法调用时间,请求处理耗时以及响应状态,并根据持久化策略完成日志持久化的工作.

不过,因为在OncePerRequestFilter中无法便捷的取得接口命中方法的相关数据,因此额外提供StaticMethodMatcherPointcutAdvisor切面来拦截需要记录日志的方法,完成LogInfo数据的获取工作.

OncePerRequestFilter和StaticMethodMatcherPointcutAdvisor之间的数据传递通过LogHolder来完成,LogHolder借助于ThreadLocal缓存了本次请求中相关的日志数据和日志配置数据.

import java.util.Optional;

/**
 * 日志记录器
 *
 * @author HanQi [Jpanda@aliyun.com]
 * @version 1.0
 * @since 2020/6/8 11:31:06
 */
public class LogHolder {
    private static AccessLogProperties DEFAULT_ACCESS_LOG_PROPERTIES = new AccessLogProperties();

    /**
     * 当前记录的日志数据
     */
    private static final ThreadLocal<LogInfo> LOG_THREAD_LOCAL = new ThreadLocal<>();

    private static final ThreadLocal<AccessLogProperties> CONFIG_THREAD_LOCAL = ThreadLocal.withInitial(LogHolder::createDefaultConfig);

    public static boolean hasLog() {
        return Optional.ofNullable(LOG_THREAD_LOCAL.get()).isPresent();
    }

    public static LogInfo log() {
        return LOG_THREAD_LOCAL.get();
    }

    public static void log(LogInfo log) {
        LOG_THREAD_LOCAL.set(log);
    }

    public static void clear() {
        LOG_THREAD_LOCAL.remove();
        CONFIG_THREAD_LOCAL.remove();
    }

    public static AccessLogProperties config() {
        return CONFIG_THREAD_LOCAL.get();
    }

    public static void config(AccessLogProperties accessLogProperties) {
        CONFIG_THREAD_LOCAL.set(accessLogProperties);
    }

    public static AccessLogProperties createDefaultConfig() {
        return DEFAULT_ACCESS_LOG_PROPERTIES.clone();
    }

    public static void initDefaultConfig(AccessLogProperties accessLogProperties) {
        DEFAULT_ACCESS_LOG_PROPERTIES = accessLogProperties;
    }
}

因为在一次请求的调用链中,方法调用无法获取准确的响应状态码,所以还需要配置OncePerRequestFilter一起使用.

OncePerRequestFilter的实现类AccessLogOncePerRequestFilter的业务不算复杂,他主要做四件事:

记录请求调用时间
记录请求处理耗时
记录请求响应状态
调用LogPersistence完成日志持久化工作

import com.live.configuration.log.entitys.AccessLogProperties;
import com.live.configuration.log.entitys.LogHolder;
import com.live.configuration.log.entitys.LogInfo;
import com.live.configuration.log.persistence.LogPersistence;
import lombok.extern.slf4j.Slf4j;
import org.springframework.http.HttpStatus;
import org.springframework.web.filter.OncePerRequestFilter;

import javax.servlet.FilterChain;
import javax.servlet.ServletException;
import javax.servlet.http.HttpServletRequest;
import javax.servlet.http.HttpServletResponse;
import java.io.IOException;
import java.util.Date;

/**
 * 记录日志
 *
 * @author HanQi [Jpanda@aliyun.com]
 * @version 1.0
 * @since 2020/6/8 11:05:24
 */
@Slf4j
public class AccessLogOncePerRequestFilter extends OncePerRequestFilter {

    private LogPersistence logPersistence;

    public AccessLogOncePerRequestFilter(LogPersistence logPersistence) {
        this.logPersistence = logPersistence;
    }

    @Override
    protected void doFilterInternal(HttpServletRequest httpServletRequest, HttpServletResponse httpServletResponse, FilterChain filterChain) throws ServletException, IOException {

        try {
            doFilter(httpServletRequest, httpServletResponse, filterChain);
        } finally {
            LogHolder.clear();
        }
    }

    private void doFilter(HttpServletRequest httpServletRequest, HttpServletResponse httpServletResponse, FilterChain filterChain) throws ServletException, IOException {
        // 记录请求时间
        long start = System.currentTimeMillis();
        Date now = new Date();
        try {
            filterChain.doFilter(httpServletRequest, httpServletResponse);
        } finally {
            // 记录响应时间和响应状态1
            long end = System.currentTimeMillis();
            if (LogHolder.hasLog()) {
                AccessLogProperties config = LogHolder.config();
                LogInfo log = LogHolder.log();
                if(config.isRequestTime()){
                    log.setRequestTime(now);
                }
                if (config.isDuration()) {
                    log.setDuration(end - start);
                }
                if (config.isStatus()) {
                    log.setResponseStatus(HttpStatus.valueOf(httpServletResponse.getStatus()));
                }
                doLog(log);
            }

        }

    }

    protected void doLog(LogInfo logInfo) {
        logPersistence.persistence(logInfo);
    }

}

其中LogPersistence负责完成具体的日志持久化工作,它定义了一个void persistence()方法来提供相对应的能力:

import com.live.configuration.log.entitys.LogInfo;

/**
 * 日志持久化
 *
 * @author HanQi [Jpanda@aliyun.com]
 * @version 1.0
 * @since 2020/6/8 13:18:54
 */
public interface LogPersistence {

    void persistence(LogInfo log);
}

基于目前的需求来看,借助于常规的日志记录体系,我提供了DefaultLogPersistence实现,完成简单的日志记录工作:

import com.fasterxml.jackson.databind.ObjectMapper;
import com.live.configuration.log.entitys.LogInfo;
import lombok.SneakyThrows;
import lombok.extern.slf4j.Slf4j;

/**
 * 默认的日志持久化策略
 *
 * @author HanQi [Jpanda@aliyun.com]
 * @version 1.0
 * @since 2020/6/8 13:20:00
 */
@Slf4j
public class DefaultLogPersistence implements LogPersistence {
    ObjectMapper objectMapper = new ObjectMapper();

    @Override
    @SneakyThrows
    public void persistence(LogInfo logInfo) {
        log.info("访问日志:{}", objectMapper.writeValueAsString(logInfo));
    }

}

实际的日志持久化策略,可以根据自己的需求来定制化提供.

负责使AccessLogOncePerRequestFilter生效的代码是AccessLogAutoConfiguration,在该类中我们将AccessLogOncePerRequestFilter对象转换成了spring-bean,并引入了全局配置对象AccessLogProperties:

import com.live.configuration.log.entitys.AccessLogProperties;
import com.live.configuration.log.persistence.DefaultLogPersistence;
import org.springframework.context.annotation.Bean;
import org.springframework.context.annotation.Import;
import org.springframework.web.filter.OncePerRequestFilter;

/**
 * @author HanQi [Jpanda@aliyun.com]
 * @version 1.0
 * @since 2020/6/8 14:50:15
 */
@Import({AccessLogProperties.class})
public class AccessLogAutoConfiguration {
    @Bean
    public OncePerRequestFilter oncePerRequestFilter() {
        return new AccessLogOncePerRequestFilter(new DefaultLogPersistence());
    }
}

定义了大致的实现方案之后,具体记录哪些方法的访问日志成为下一个需要考虑的问题,业界最常见也是最简单的方法就是提供一个单独的注解,做注解切面完成日志记录的工作,为此,我们提供了一个AccessLog注解,该注解只有一个value()属性为接口维护一个可读性较高的别名:

import java.lang.annotation.*;

/**
 * 日志注解
 *
 * @author HanQi [Jpanda@aliyun.com]
 * @version 1.0
 * @since 2020/6/6 15:39:59
 */
@Documented
@Target(ElementType.METHOD)
@Retention(RetentionPolicy.RUNTIME)
public @interface AccessLog {
    /**
     * 日志名称,可选
     */
    String value() default "";
}

除此之外,考虑到有些时候我们可能需要记录所有的访问日志,因此在简单调研后,选择了spring原生的Mapping注解作为另一个候选切面:

import java.lang.annotation.ElementType;
import java.lang.annotation.Retention;
import java.lang.annotation.RetentionPolicy;
import java.lang.annotation.Target;

/**
 * Meta annotation that indicates a web mapping annotation.
 *
 * @author Juergen Hoeller
 * @since 3.0
 * @see RequestMapping
 */
@Target({ElementType.ANNOTATION_TYPE})
@Retention(RetentionPolicy.RUNTIME)
public @interface Mapping {

}

毕竟Mapping是spring中接口映射相关注解的元注解,为了兼容对元注解的切面支持,我们提供了一个AnnotationAspectPointCutAdvisor,他是StaticMethodMatcherPointcutAdvisor的实现类,该对象有一个名为interceptionAnnotation的注解属性,维护了当前需要进行切面处理的方法注解,同时该对象的matches()方法实现借助于AnnotationUtils.findAnnotation()方法,因此该方法支持获取方法注解上的元注解:

import com.live.configuration.log.handler.AccessLogProceedingJoinPointHandler;
import org.aopalliance.intercept.MethodInterceptor;
import org.springframework.aop.support.StaticMethodMatcherPointcutAdvisor;
import org.springframework.core.annotation.AnnotationUtils;

import java.lang.annotation.Annotation;
import java.lang.reflect.Method;

/**
 * 同意拦截日志
 *
 * @author HanQi [Jpanda@aliyun.com]
 * @version 1.0
 * @since 2020/6/9 9:37:10
 */
public class AnnotationAspectPointCutAdvisor extends StaticMethodMatcherPointcutAdvisor {
    AccessLogProceedingJoinPointHandler handler;
    private Class<? extends Annotation> interceptionAnnotation;


    public AnnotationAspectPointCutAdvisor(Class<? extends Annotation> interceptionAnnotation, AccessLogProceedingJoinPointHandler handler) {
        this.interceptionAnnotation = interceptionAnnotation;
        this.handler = handler;
        setAdvice((MethodInterceptor) handler::handler);
    }

    @Override
    public boolean matches(Method method, Class<?> aClass) {
        return AnnotationUtils.findAnnotation(method, interceptionAnnotation) != null;
    }
}

除此之外,该方法还维护了一个AccessLogProceedingJoinPointHandler处理器,该处理器负责完成具体的LogInfo的填充工作.

不要太过关注于AccessLogProceedingJoinPointHandler这个名称,最初从设计上其不是用来处理MethodInvocation而是处理ProceedingJoinPoint对象的.

AnnotationAspectPointCutAdvisor有两个实现类,分别用来处理AccessLog和Mapping注解:

MappingAnnotationAspectPointCutAdvisor:

import com.live.configuration.log.handler.AccessLogProceedingJoinPointHandler;
import org.springframework.web.bind.annotation.Mapping;

/**
 * @author HanQi [Jpanda@aliyun.com]
 * @version 1.0
 * @since 2020/6/9 10:04:04
 */
public class MappingAnnotationAspectPointCutAdvisor extends AnnotationAspectPointCutAdvisor {

    public MappingAnnotationAspectPointCutAdvisor(AccessLogProceedingJoinPointHandler handler) {
        super(Mapping.class, handler);
    }
}

AccessLogAnnotationAspectPointCutAdvisor:

import com.live.configuration.log.annotations.AccessLog;
import com.live.configuration.log.handler.AccessLogProceedingJoinPointHandler;

/**
 * @author HanQi [Jpanda@aliyun.com]
 * @version 1.0
 * @since 2020/6/9 10:04:31
 */
public class AccessLogAnnotationAspectPointCutAdvisor extends AnnotationAspectPointCutAdvisor {
    public AccessLogAnnotationAspectPointCutAdvisor(AccessLogProceedingJoinPointHandler handler) {
        super(AccessLog.class, handler);
    }
}

在设计上,这两个类之间具有互斥关系,同时只有一个类能够生效.

负责控制该行为的是EnableAccessLog注解,该注解需要被标注在SpringBoot启动类上,以启用日志切面:

import com.live.configuration.log.AccessLogAutoConfiguration;
import com.live.configuration.log.AccessLogImportSelector;
import org.springframework.context.annotation.Import;
import org.springframework.stereotype.Component;

import java.lang.annotation.*;

/**
 * 是否开启日志
 *
 * @author HanQi [Jpanda@aliyun.com]
 * @version 1.0
 * @since 2020/6/8 10:59:01
 */
@Component
@Documented
@Target(ElementType.TYPE)
@Retention(RetentionPolicy.RUNTIME)
@Import({AccessLogImportSelector.class, AccessLogAutoConfiguration.class})
public @interface EnableAccessLog {
    /**
     * 是否拦截所有的请求
     */
    boolean enableGlobal() default false;
}

该注解定义了一个默认值为false的enableGlobal()属性,该属性用于控制生效的切面,当该值为true时,则记录所有直接或间接标注了Mapping元注解的接口的访问日志,否则则记录标注了AccessLog注解的接口的访问日志.

EnableAccessLog注解通过Import注解引入了AccessLogImportSelector和AccessLogAutoConfiguration配置对象,完成日志记录所需对象的引入工作.

其中AccessLogImportSelector负责根据enableGlobal()的取值来决定引入MappingAnnotationAspectPointCutAdvisor或者AccessLogAnnotationAspectPointCutAdvisor:

import com.live.configuration.log.annotations.EnableAccessLog;
import com.live.configuration.log.visitors.AccessLogAnnotationAspectPointCutAdvisor;
import com.live.configuration.log.visitors.MappingAnnotationAspectPointCutAdvisor;
import org.springframework.context.annotation.ImportSelector;
import org.springframework.core.annotation.AnnotationAttributes;
import org.springframework.core.type.AnnotationMetadata;

/**
 * @author HanQi [Jpanda@aliyun.com]
 * @version 1.0
 * @since 2020/6/8 17:19:50
 */
public class AccessLogImportSelector implements ImportSelector {
    @Override
    public String[] selectImports(AnnotationMetadata annotationMetadata) {
        // 需要处理的注解名称
        Class<?> annotationType = EnableAccessLog.class;
        AnnotationAttributes annotationAttributes = AnnotationAttributes.fromMap(
                annotationMetadata.getAnnotationAttributes(annotationType.getName(), false)
        );
        // 常规场景下,该参数永远不会为null.
        assert annotationAttributes != null;
        boolean global = annotationAttributes.getBoolean("enableGlobal");
        return new String[]{
                (global ? MappingAnnotationAspectPointCutAdvisor.class : AccessLogAnnotationAspectPointCutAdvisor.class).getCanonicalName()
        };
    }
}

前面被我们忽略掉的AccessLogProceedingJoinPointHandler接口,我们为其提供了一个DefaultAccessLogProceedingJoinPointHandler实现类,来完成根据配置填充日志数据的能力:

import com.live.configuration.log.annotations.AccessLog;
import com.live.configuration.log.annotations.LogOptions;
import com.live.configuration.log.entitys.*;
import com.live.configuration.log.handler.filters.Filter;
import org.aopalliance.intercept.MethodInvocation;
import org.springframework.core.annotation.AnnotationUtils;
import org.springframework.http.HttpMethod;
import org.springframework.stereotype.Component;
import org.springframework.util.StringUtils;
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.lang.reflect.Parameter;
import java.util.*;

/**
 * @author HanQi [Jpanda@aliyun.com]
 * @version 1.0
 * @since 2020/6/8 16:35:40
 */
@Component
public class DefaultAccessLogProceedingJoinPointHandler implements AccessLogProceedingJoinPointHandler {
    @Override
    public Object handler(MethodInvocation point) throws Throwable {

        Object result = null;
        Throwable throwable = null;
        try {
            // 处理请求
            result = point.proceed();
        } catch (Exception e) {
            throwable = e;
        }


        // 处理日志参数
        ServletRequestAttributes requestAttributes = (ServletRequestAttributes) RequestContextHolder.getRequestAttributes();
        HttpServletRequest request = Objects.requireNonNull(requestAttributes).getRequest();


        Method method = point.getMethod();

        LogInfo logInfo = new LogInfo();
        logInfo.setDescription(readMethodDescription(method));

        // 获取配置对象
        AccessLogProperties config = loadCustomConfig(AnnotationUtils.findAnnotation(method, LogOptions.class));

        if (config.isUri()) {
            logInfo.setUri(request.getRequestURL().toString());
        }
        if (config.isHttpMethod()) {
            logInfo.setHttpMethod(HttpMethod.resolve(request.getMethod()));
        }
        if (config.isHeaders()) {
            // 加载获取
            Class<? extends Filter> headerFilter = config.getHeadersFilter();
            Filter filter = headerFilter.newInstance();
            Enumeration<String> enumeration = request.getHeaderNames();
            Map<String, String> matchHeaders = new HashMap<>();
            while (enumeration.hasMoreElements()) {
                String headerName = enumeration.nextElement();
                String headerValue = request.getHeader(headerName);
                if (filter.filter(headerName)) {
                    matchHeaders.put(headerName, headerValue);
                }
            }
            logInfo.setHeaders(matchHeaders);
        }

        if (config.isSignature()) {
            Signature signature1 = new Signature();
            signature1.setClassName(point.getThis().getClass().getCanonicalName());
            signature1.setMethodName(point.getMethod().getName());
            logInfo.setSignature(signature1);
        }

        if (config.isParams()) {
            logInfo.setArgs(castParams(method, point.getArguments()));
        }
        if (config.isIp()) {
            logInfo.setRequestIp(loadRealIp(request));
        }

        if (throwable != null) {
            if (config.isErrMessage()) {
                logInfo.setErrMessage(throwable.getMessage());
            }
            if (config.isErrTrace()) {
                logInfo.setErrTrace(throwable);
            }
        } else {
            if (config.isResult()) {
                logInfo.setResult(result);
            }

        }
        if (throwable != null) {
            throw throwable;
        }

        LogHolder.log(logInfo);
        // 返回请求结果
        return result;
    }


    public AccessLogProperties loadCustomConfig(LogOptions logOptions) {
        return Optional.ofNullable(logOptions).map(opt -> {
            AccessLogProperties properties = new AccessLogProperties();
            properties.setUri(opt.uri());
            properties.setHeaders(opt.headers());
            properties.setHeadersFilter(opt.headersFilter());
            properties.setHttpMethod(opt.httpMethod());
            properties.setSignature(opt.signature());
            properties.setParams(opt.params());
            properties.setIp(opt.ip());
            properties.setDuration(opt.duration());
            properties.setStatus(opt.status());
            properties.setResult(opt.result());
            properties.setErrMessage(opt.errMessage());
            properties.setErrTrace(opt.errTrace());

            LogHolder.config(properties);
            return properties;
        }).orElse(LogHolder.config());
    }

    /**
     * 读取方法描述
     *
     * @param method 方法
     * @return 方法描述或者方法名称
     */
    protected String readMethodDescription(Method method) {
        if (!method.isAccessible()) {
            method.setAccessible(true);
        }
        // 获取方法描述注解
        String description = method.getName();
        // 读取swagger注解
        AccessLog accessLog = AnnotationUtils.findAnnotation(method, AccessLog.class);
        if (accessLog != null) {
            // 获取参数描述
            description = accessLog.value();
        }
        return description;
    }

    protected Param[] castParams(Method method, Object[] args) {
        if (args == null) {
            return null;
        }
        Class<?>[] types = method.getParameterTypes();
        String[] argNames = Arrays.stream(method.getParameters()).map(Parameter::getName).toArray(String[]::new);

        Param[] params = new Param[args.length];
        for (int i = 0; i < args.length; i++) {
            Object o = args[i];
            // 读取swagger注解
            params[i] = Param.builder()
                    .argName(argNames[i])
                    .name(argNames[i])
                    .type(types[i])
                    .value(args[i])
                    .build();

        }
        return params;
    }

    protected String loadRealIp(HttpServletRequest request) {
        for (String header : Arrays.asList("x-forwarded-for"
                , "Proxy-Client-IP"
                , "WL-Proxy-Client-IP"
                , "HTTP_CLIENT_IP"
                , "HTTP_X_FORWARDED_FOR"
                , "X-Real-IP")) {
            String value = request.getHeader(header);
            if (StringUtils.hasText(value)) {
                if (value.contains(",")) {
                    String[] ips = value.split(",");
                    return ips[ips.length - 1];
                } else {
                    return value;
                }
            }
        }
        return "unknown";
    }
}

简单使用

@GetMapping("normal")
public Object forceWrapperResult() {
    //  {
    //  "success": true,
    //  "code": "200",
    //  "data": "normal",
    //  "errorMessage": "",
    //  "timestamp": 1591348788622
    //  }
    return "normal";
}
@AccessLog("测试日志注解")
@GetMapping("log")
public String log() {
    return "test";
}

@GetMapping("log-param")
public String logParam(@Param("name") String name) {
    return "log-param";
}

[INFO ] 11:26:48.422 [http-nio-8080-exec-7] [] c.l.c.l.p.DefaultLogPersistence - 访问日志:{"uri":"http://127.0.0.1:8080/live/examples/normal","httpMethod":"GET","signature":{"className":"com.live.controllers.ExamplesController","methodName":"forceWrapperResult"},"args":[],"description":"forceWrapperResult","requestIp":"unknown","duration":14,"responseStatus":"OK","result":"normal"}
[INFO ] 11:26:51.492 [http-nio-8080-exec-9] [] c.l.c.l.p.DefaultLogPersistence - 访问日志:{"uri":"http://127.0.0.1:8080/live/examples/log","httpMethod":"GET","signature":{"className":"com.live.controllers.ExamplesController","methodName":"log"},"args":[],"description":"测试日志注解","requestIp":"unknown","duration":2,"responseStatus":"OK","result":"test"}
[INFO ] 11:26:52.965 [http-nio-8080-exec-10] [] c.l.c.l.p.DefaultLogPersistence - 访问日志:{"uri":"http://127.0.0.1:8080/live/examples/log-param","httpMethod":"GET","signature":{"className":"com.live.controllers.ExamplesController","methodName":"logParam"},"args":[{"argName":"arg0","name":"arg0","type":"java.lang.String","value":null}],"description":"logParam","requestIp":"unknown","duration":2,"responseStatus":"OK","result":"log-param"}

扩展

当前本篇文章还有较多的可补充之处,比如整合session或者用户唯一标志一并存入到日志记录中.

如果请求在命中方法前触发异常,不能命中方法,那么该请求是不会记录到日志中的.