前言

在微服务里，业务出现问题或者程序出的任何问题，都少不了查看日志，一般我们使用 ELK 相关的日志收集工具，服务多的情况下，业务问题也是有些难以排查，只能确定大致时间定位相关日志。因此实现一个请求对应一个traceId，在整个请求的全链路中都可以关联起来，可以极大地帮助我们更方便地查询日志。

使用效果

日志内容

2023-06-19 15:26:58,272 INFO 9f8362dfedd048cc969e88e06fd672db --- [main] c.r.t.common.log.aspect.TraceLogAspect   : url[ /TestTraceId/normal ], request  params[[]]
2023-06-19 15:26:58,273 INFO 9f8362dfedd048cc969e88e06fd672db --- [main] c.r.t.common.log.aspect.TraceLogAspect   : url[ /TestTraceId/normal ], response [{"code":0,"data":"正常返回数据"}]

9f8362dfedd048cc969e88e06fd672db 就是 traceId

响应头

每个请求的响应头里都会有个 traceId，根据这个traceId 即可在日志系统中进行追踪。

原理

MDC (org.slf4j.MDC)是门面日志框架 slf4j 中的上下文对象，保存了每次请求（一个线程）的日志打印相关信息（日期请求的requestId 时间日志内容等）。我们将每个请求生成的 traceId 保存到MDC 中即可实现在整个请求的过程中，打印的日志信息都可以带上同一 traceId。

实现步骤

过滤器生成traceId

自定义过滤器

 @Slf4j  
public class TraceIdFilter implements Filter {  
  
    @Override  
    public void doFilter(ServletRequest servletRequest, ServletResponse servletResponse, FilterChain filterChain) throws IOException, ServletException {  

    try {  
    HttpServletRequest request = (HttpServletRequest) servletRequest;  
    HttpServletResponse response = (HttpServletResponse) servletResponse;  

    String traceId = MDCUtils.getOrGenerateTraceId(request);  
    MDCUtils.setTraceId(traceId);  
    response.setHeader(MDCUtils.TRACE_ID_KEY, traceId);  
    } catch (Exception e) {  
    log.error("设置traceId出现异常", e);  
    }  

    filterChain.doFilter(servletRequest, servletResponse);  
    MDC.clear();  
    }  
  
}

需要将该过滤器以bean的方式注入到Spring 容器。直接使用 @Component 或者在 configuration 类中使用 @bean 。
如果是单独地模块供其他服务调用，建议使用starter的方式，在 spring.factories中配置自动配置类，在配置中加载bean.

spring.factories

org.springframework.boot.autoconfigure.EnableAutoConfiguration=\  
com.xxx.xxx.common.log.LogAutoConfiguration,\

配置类

@Configuration  
@AllArgsConstructor  
@ConditionalOnWebApplication  
public class LogAutoConfiguration {  
  
    @Bean  
    public TraceLogAspect traceLogAspect() {  
    return new TraceLogAspect();  
    }  

    @Bean  
    public RequestInterceptor traceIdInterceptor() {  

    return new OpenFeignRequestInterceptor();  
    }  

    @Bean  
    public Filter traceIdFilter() {  
    return new TraceIdFilter();  
    }  
  
}

MDC 工具类

public class MDCUtils {

    /**
     * traceId 的key
     * 在日志文件中配置
     */
    public static final String TRACE_ID_KEY = "traceId";

    //子线程中新生成的 traceId 前缀
    private static final String NEW_TRACE_ID_KEY_PREFIX = "new_";

    public static String getTraceId() {
        return MDC.get(TRACE_ID_KEY);
    }

    public static void setTraceId(String traceId) {
        MDC.put(TRACE_ID_KEY, traceId);
    }
    
    /**
     * 生成或获取 traceId
     * @param request
     * @return
     */
    public static String getOrGenerateTraceId(HttpServletRequest request) {

        return Optional.ofNullable(request.getHeader(TRACE_ID_KEY))
                .orElseGet(MDCUtils::generateTraceId);
    }


    public static String getOrGenerateTraceId() {
        ServletRequestAttributes attributes = (ServletRequestAttributes) RequestContextHolder.getRequestAttributes();
        HttpServletRequest request = attributes.getRequest();
        return getOrGenerateTraceId(request);
    }


    /**
     * 包装 Callable
     * 把主线程的 现场变量 复制到 异步线程里
     * @param callable 需要返回执行结果的任务
     * @param context 提交任务者的本地变量
     * @return
     * @param <T>
     */
    public static <T> Callable<T> wrap(final Callable<T> callable, final Map<String, String> context) {
        return () -> {
            setMDCContextMap(context);
            try {
                return callable.call();
            } finally {//清除子线程的，避免内存溢出，就和ThreadLocal.remove()一个原因
                MDC.clear();
            }
        };
    }

    /**
     * 包装 Runnable
     * @param runnable
     * @param context
     * @return
     */
    public static Runnable wrap(final Runnable runnable, final Map<String, String> context) {
        return () -> {
            setMDCContextMap(context);
            try {
                runnable.run();
            } finally {
                MDC.clear();
            }
        };
    }

    /**
     * 设置上下文MDC
     * @param context 主线程context
     */
    private static void setMDCContextMap(final Map<String, String> context) {
        if (CollectionUtils.isEmpty(context)) {
            MDC.clear();
            //如果提交任务的线程已经结束或其他情况，导致已经没有MDC变量了 则新生成要给并标识
            setTraceId(NEW_TRACE_ID_KEY_PREFIX + generateTraceId());
        } else {
            //将主线程的context设置到当前线程
            MDC.setContextMap(context);
        }
    }

    /**
     * 生成 traceId
     * @return traceId
     */
    private static String generateTraceId() {
        UUID uuid = UUID.randomUUID();
        String uuidStr = uuid.toString().replace("-", "");
        return uuidStr;
    }

}

使用 UUID生成 traceId 。往 MDC 中新增变量 traceId ，后续在日志中打印的线程变量就是这个。

controller切面打印参数

对 servlert 请求做额外处理，常见的有过滤器、拦截器、AOP 3种方式。
这里选用的是AOP进行处理，以所有 @RequestMapping 为切点。
其中有两点需要注意：

因为post get 等类型的请求都会有，建议把相关注解全部包括，另外不能只写一个@RequestMapping（亲测不行，具体原因后续来补）
由于在RPC调用时，也需要写 @RequestMapping 。因此需要排除掉，否则日志内容会出现混乱（实际看项目情况）。

/**
 *  链路追踪日志切面
 *  对所有 servletRequest  打印请求 和响应日志，并在日志中添加 traceId
 *  返回响应时也会添加 traceId ，
 *  在日志输出配置文件中添加 %X{traceId} 即可
 * @Author:xxx
 * @Date: 2023/6/16
 * @Version: V1.0
 * @Description:
 **/
@Aspect
@RequiredArgsConstructor
@Slf4j
public class TraceLogAspect {

    @Pointcut("@annotation(org.springframework.web.bind.annotation.RequestMapping) "
            + "||@annotation(org.springframework.web.bind.annotation.PostMapping)"
            + "||@annotation(org.springframework.web.bind.annotation.GetMapping)"
            + "||@annotation(org.springframework.web.bind.annotation.DeleteMapping)"
            + "||@annotation(org.springframework.web.bind.annotation.PutMapping)")
    private void controllerPointcut(){}

    @Around(value = "controllerPointcut()")
    public Object controllerAround(ProceedingJoinPoint joinPoint){
        //目标对象不是controller ,则是调用其他服务，不打印日志
        Object target = joinPoint.getTarget();
        RestController restController = target.getClass().getAnnotation(RestController.class);
        Controller controller = target.getClass().getAnnotation(Controller.class);
        if (Objects.isNull(restController) && Objects.isNull(controller)) {
            try {
                return joinPoint.proceed();
            } catch (Throwable e) {
                throw new RuntimeException(e);
            }
        }

        ServletRequestAttributes attributes = (ServletRequestAttributes) RequestContextHolder.getRequestAttributes();
        HttpServletRequest request = attributes.getRequest();
        String requestURI = request.getRequestURI();
        log.info("url[ {} ], request  params[{}]", requestURI, joinPoint.getArgs());
        Object result = null;
        try {
            result = joinPoint.proceed();
        } catch (Throwable e) {
            log.info("url[ {} ], response [{}]", requestURI, "出现异常");
            throw new RuntimeException(e);
        }
        log.info("url[ {} ], response [{}]", requestURI, JSONUtil.toJsonStr(result));
        return result;
    }

}

RPC调用传递traceId

OpenFeign 调用的时候，可以通过自定义拦截器的方式进行额外处理。
拦截器可以多个，且无法指定拦截器的执行顺序。
拦截器会在切面之前执行，比如我们这个 traceLogAspect 就会在OpenFeign拦截器之前运行

public class OpenFeignRequestInterceptor implements RequestInterceptor {

    /**
     * 往 template 上添加 traceId
     * @param requestTemplate
     */
    @Override
    public void apply(RequestTemplate requestTemplate) {
        String traceId = MDCUtils.getTraceId();
        requestTemplate.header(MDCUtils.TRACE_ID_KEY, traceId);
    }

}

多线程之间传递traceId

多线程之间传递 traceId , 解决思路就是自定义线程池。创建任务的时候把主线程的 traceId 包装到子线程中的MDC中去。 需要结合上面的 MDC 工具类一起看。

public  class ThreadPoolMdcWrapper extends ThreadPoolTaskExecutor {

    public ThreadPoolMdcWrapper() {

    }

    @Override
    public void execute(Runnable task) {
        super.execute(MDCUtils.wrap(task, MDC.getCopyOfContextMap()));
    }

    @Override
    public void execute(Runnable task, long startTimeout) {
        super.execute(MDCUtils.wrap(task, MDC.getCopyOfContextMap()), startTimeout);
    }

    @Override
    public <T> Future<T> submit(Callable<T> task) {
        return super.submit(MDCUtils.wrap(task, MDC.getCopyOfContextMap()));
    }

    @Override
    public Future<?> submit(Runnable task) {
        return super.submit(MDCUtils.wrap(task, MDC.getCopyOfContextMap()));
    }

    @Override
    public ListenableFuture<?> submitListenable(Runnable task) {
        return super.submitListenable(MDCUtils.wrap(task, MDC.getCopyOfContextMap()));
    }

    @Override
    public <T> ListenableFuture<T> submitListenable(Callable<T> task) {
        return super.submitListenable(MDCUtils.wrap(task, MDC.getCopyOfContextMap()));
    }

}

创建线程池时必须使用上面的包装类

/**
     * 一个线程池示例
     * @return
     */
    @Bean("poolConfigDemo")
    @ConditionalOnMissingBean(ThreadPoolTaskExecutor.class)
    public ThreadPoolTaskExecutor taskExecutor() {
        ThreadPoolTaskExecutor taskExecutor = new ThreadPoolMdcWrapper();
        taskExecutor.setThreadGroupName("test-threadGroup");
        //最大线程数
        taskExecutor.setMaxPoolSize(1);
        //核心线程数
        taskExecutor.setCorePoolSize(1);
        //最大线程数，默认为Integer.MAX_VALUE
        taskExecutor.setMaxPoolSize(200);
        //队列最大长度，一般需要设置值>=notifyScheduledMainExecutor.maxNum；默认为Integer.MAX_VALUE
        taskExecutor.setQueueCapacity(2000);
        //线程池维护线程所允许的空闲时间，默认为60s
        taskExecutor.setKeepAliveSeconds(60);
        //线程池对拒绝任务（无线程可用）的处理策略
        taskExecutor.setRejectedExecutionHandler(new ThreadPoolExecutor.AbortPolicy());
        // 初始化线程池
        taskExecutor.initialize();
        return  taskExecutor;
    }

日志配置文件

在 logback.xml 中添加 %X{traceId} 即可

<pattern>%date [%thread] %-5level [%logger{50}] %X{traceId} %file:%line - %msg%n</pattern>

轻量级日志链路追踪实现（traceID)

前言