自定义日志-日志追踪篇

0.先导

在使用有赞云进行自定义开发时,无法获取到springboot的启动类,开发完的程序只能提交代码后,在有赞云提供的沙箱中进行测试。有日志延迟不说,还存在着日志时间混乱的问题。此外,当有多位开发人员在使用时,打印出来的日志无法分辨,不知道哪些日志是自己的请求触发,哪些是别人的请求触发的。

1.解决方案

无法进行本地调试,只能对日志进行改造,所以最后决定对输出的日志进行自定义改造。

2.涉及知识点

  • log4j 自定义配置
  • slf4j Mdc(Mapped Diagnostic Contexts)
  • springboot配置自定义注解
  • springboot配置Aop切面
  • springboot配置过滤器

3.正文

3.1设计思路

在slf4j打出的日志中,通过全局拦截器,为每一次的请求创建requestId。 在需要关注的方法上,打上自定义日志注解,在切面中,项Mdc中添加sessionId和requestId。在请求前打出请求参数的日志,在请求结束后,打出返回结果的日志,在被自定义注解注视的方法中,所有的日志都带有sessionId和requestId,便于日志的追溯。

3.2代码实现

3.3配置springboot拦截器

3.3.1创建类RequestIdFilter并实现Filter接口
public class RequestIdFilter implements Filter {}
3.3.2添加@Component注解
3.3.3重写doFilter()方法
@Override
    public void doFilter(ServletRequest servletRequest, ServletResponse servletResponse, FilterChain filterChain) throws IOException, ServletException {
        String requestId = UUID.randomUUID().toString().replace("-", "");
        servletRequest.setAttribute("requestId", requestId);
        filterChain.doFilter(servletRequest, servletResponse);
    }

生成requestId的方式可以按照各自的喜好生成。

3.4配置自定义注解

3.4.1@MyLog注解
/**
 * 自定义日志注解
 */
@Target({ElementType.TYPE, ElementType.METHOD})
@Retention(RetentionPolicy.RUNTIME)
@Documented
@Inherited
public @interface MyLog {

    /**
     * 打印日志类型,{@link LogTypeEnum}
     *
     * @return
     */
    LogTypeEnum value() default LogTypeEnum.ALL;

    /**
     * 日志输出前缀(建议配置接口名称)
     *
     * @return
     */
    String prefix() default "";
}
3.4.2@MyLog注解
/**
 * 指定参数名字
 */
@Retention(RetentionPolicy.RUNTIME)
@Target({ElementType.FIELD, ElementType.PARAMETER})
public @interface LogMask {

    /**
     * 参数名称
     *
     * @return
     */
    String paramName() default "";
}
3.4.3输出参数还是结果的枚举类
public enum LogTypeEnum {
    /**
     * 方法前后执行
     */
    ALL,

    /**
     * 只输出参数
     */
    PARAMETER,

    /**
     * 只输出结果
     */
    RESULT
}

3.5配置切面

3.5.1配置切入点
    /**
     * 切入点
     */
    @Pointcut("@annotation(link.xuchen.testlog.annotation.MyLog)")
    public void pointcut() {
    }
3.5.2使用@Around来处理日志

在切面中,拿到请求中携带的sessionId和过滤器中添加的requestId,将sessionId和requestId放入Mdc中,并且搭配自定义的slf4j的配置,在日志中输出sessionId和requestId。 日志的配置,其中[%X{sessionId}, %X{requestId}]和Mdc中名称要相同。

logging:
  level:
    ROOT: info
  pattern:
    console: "${CONSOLE_LOG_PATTERN:-%clr(%d{yyyy-MM-dd HH:mm:ss.SSS}){faint} %boldCyan([%X{sessionId}, %X{requestId}]) %clr(${LOG_LEVEL_PATTERN:-%5p}) %clr(${PID:- }){magenta} %clr(---){faint} %clr([%15.15t]){faint} %clr(%-40.40logger{39}){cyan} %clr(:){faint} %m%n${LOG_EXCEPTION_CONVERSION_WORD:-%wEx}}"

切面代码

@Aspect
@Component
@Slf4j
public class LogAspect {

    /**
     * 切入点
     */
    @Pointcut("@annotation(link.xuchen.testlog.annotation.MyLog)")
    public void pointcut() {
    }

    /**
     * 环绕通知
     * @param joinPoint
     * @return
     * @throws Throwable
     */
    @Around("pointcut()")
    public Object doLog(ProceedingJoinPoint joinPoint) throws Throwable {
        Method method = this.getSpecificmethod(joinPoint);

        // 获取sessionId
        RequestAttributes requestAttributes = RequestContextHolder.getRequestAttributes();
        String sessionId = requestAttributes.getSessionId();
        String requestId = (String)requestAttributes.getAttribute("requestId", 0);
        MyLog myLog = this.getMethodAnnotations(method, MyLog.class);
        if (Objects.isNull(myLog)) {
            myLog = AnnotationUtils.findAnnotation(joinPoint.getTarget().getClass(), MyLog.class);
        }

        boolean isSuccess = setMdc(sessionId, requestId);
        try {
            // 获取日志输出前缀
            String prefix = getPrefix(myLog, method);
            // 执行方法前输出日志
            logBefore(myLog, prefix, method, joinPoint.getArgs());
            // 执行方法,并获取返回值
            Object result = joinPoint.proceed();
            // 执行方法后输出日志
            logAfter(myLog, prefix, result);
            return null;
        } catch (Throwable t) {
            throw t;
        } finally {
            try {
                if (isSuccess) {
                    MDC.remove(MdcConstant.SESSION_KEY);
                    MDC.remove(MdcConstant.REQUEST_KEY);
                }
            } catch (Exception e) {
                log.warn(e.getMessage(), e);
            }
        }
    }

    /**
     * 为每个请求设置唯一标示到MDC容器中
     *
     * @return
     */
    private boolean setMdc(String sessionId, String requestId) {
        try {
            // 设置SessionId
            if (StringUtils.isEmpty(MDC.get(MdcConstant.SESSION_KEY))) {
                MDC.put(MdcConstant.SESSION_KEY, sessionId);
                MDC.put(MdcConstant.REQUEST_KEY, requestId);
                return true;
            }
        } catch (Exception e) {
            log.warn(e.getMessage(), e);
        }
        return false;
    }
    /**
     * 输出方法执行结果
     *
     * @param myLog    log注解
     * @param prefix 输出前缀
     * @param result 方法执行结果
     */
    private void logAfter(MyLog myLog, String prefix, Object result) {
        // 判断是否是方法之前输出日志,不是就输出参数日志
        if (!LogTypeEnum.PARAMETER.equals(myLog.value())) {
            log.info("【返回参数 {}】:{}", prefix, JSON.toJSON(result));
        }
    }

    /**
     * 输出方法调用参数
     *
     * @param myLog    log注解
     * @param prefix 输出日志前缀
     * @param method 代理方法
     * @param args   方法参数
     */
    private void logBefore(MyLog myLog, String prefix, Method method, Object[] args) {
        // 判断是否是方法之后输出日志,不是就输出参数日志
        if (!LogTypeEnum.RESULT.equals(myLog.value())) {
            Map<String, Object> paramMap = new LinkedHashMap<>();
            // 获取参数注解
            Annotation[][] parameterAnnotations = method.getParameterAnnotations();

            for (int i = 0; i < parameterAnnotations.length; i++) {
                Annotation[] parameterAnnotation = parameterAnnotations[i];
                // 找到参数上面的注解,并根据注解获取脱敏的类型
                LogMask logMask = getLogMask(parameterAnnotation);
                String paramName = "args" + (i + 1);
                if (logMask != null) {
                    paramName = StringUtils.isEmpty(logMask.paramName()) ? paramName : logMask.paramName();
                }

                // 忽略这些类型参数的输出
                if (args[i] instanceof ServletResponse || args[i] instanceof ServletRequest
                        || args[i] instanceof HttpSession || args[i] instanceof Model) {

                    break;
                }

                paramMap.put(paramName, args[i]);
            }
            log.info("【请求参数 {}】:{}", prefix, JSON.toJSON(paramMap));
        }
    }

    /**
     * 获取日志前缀对象
     *
     * @param myLog       日志注解对象
     * @param method    注解日志的方法对象
     * @return
     */
    private String getPrefix(MyLog myLog, Method method) {
        // 日志格式:流水号 + 注解的日志前缀 + 方法的全类名
        StringBuilder sb = new StringBuilder();
        sb.append(myLog.prefix());
        sb.append(":");
        sb.append(method.getDeclaringClass().getName());
        sb.append(".");
        sb.append(method.getName());
        sb.append("() ");

        return sb.toString();
    }

    /**
     * 获取参数上的LogMask注解
     *
     * @param parameterAnnotation
     * @return
     */
    private LogMask getLogMask(Annotation[] parameterAnnotation) {
        for (Annotation annotation : parameterAnnotation) {
            // 检查参数是否需要脱敏
            if (annotation instanceof LogMask) {
                return (LogMask) annotation;
            }
        }
        return null;
    }

    private <T extends Annotation> T getMethodAnnotations(AnnotatedElement ae, Class<T> annotationType) {
        // look for raw annotation
        T ann = ae.getAnnotation(annotationType);
        return ann;
    }

    private Method getSpecificmethod(ProceedingJoinPoint pjp) {
        MethodSignature methodSignature = (MethodSignature) pjp.getSignature();
        Method method = methodSignature.getMethod();
        // The method may be on an interface, but we need attributes from the
        // target class. If the target class is null, the method will be
        // unchanged.
        Class<?> targetClass = AopProxyUtils.ultimateTargetClass(pjp.getTarget());
        if (targetClass == null && pjp.getTarget() != null) {
            targetClass = pjp.getTarget().getClass();
        }
        Method specificMethod = ClassUtils.getMostSpecificMethod(method, targetClass);
        // If we are dealing with method with generic parameters, find the
        // original method.
        specificMethod = BridgeMethodResolver.findBridgedMethod(specificMethod);
        return specificMethod;
    }
}

3.6实现效果

日志效果

3.7代码地址

github