Spring Boot 实现日志追踪

yangkai100522208

已于 2023-06-13 11:14:41 修改

阅读量2.1k

点赞数

CC 4.0 BY-SA版权

文章标签： java 后端 spring boot

于 2023-06-13 11:13:21 首次发布

本文链接：https://blog.youkuaiyun.com/yangkai100522208/article/details/125390138

文章介绍了在非微服务的SpringBoot项目中，如何利用MDC（MappedDiagnosticContext）进行日志跟踪，以解决大量日志难以定位特定请求的问题。通过封装MDC工具类，配置日志过滤器，确保traceId在请求过程中被正确传递，并处理多线程环境下的日志上下文。此外，还展示了如何在自定义线程池、@Async异步方法和定时任务中保持traceId的连贯性。

摘要生成于 C知道，由 DeepSeek-R1 满血版支持，前往体验 >

参考学习：https://blog.youkuaiyun.com/Little_fxc/article/details/129519352

背景

非微服务架构的springboot项目，由于日志量较大，不容易拉出同一条请求的所有相关日志，不容易通过日志进行问题分析。所以想将同一个请求的所有相关日志当上一个唯一标记，便于进行区分与分析。由于不是微服务架构，暂时无法引入sleuth进行链路追踪，所以使用网上比较常用的MDC 进行单体服务的日志追踪。

一、为什么要跟踪日志

1, 假如我们需要分析用户 a 的请求日志，但是程序的访问量很大，还有 b、c、d 用户同时访问，无法确定哪一条日志是 a 用户的请求。

2. 微服务调用，我们很难确定某条日志是从哪台机器请求的，这时候也需要进行链路追踪。

二、MDC存储日志原理

MDC（Mapped Diagnostic Context）是一个可以追踪程序上下文日志的东西，是springboot项目自带的org.slf4j包下的类，无需引入额外依赖即可使用。MDC 使用 ThreadLocal 存储日志数据，所以它是线程安全的，它可以把同一个请求的日志都存储一个相同的值，每次打印日志的时候，会自动打印出当前日志的键值value，我们查询日志的时候就可以根据value来查询。

三、代码

1、封装MDC工具类

此工具类定义了一个traceId作为日志的key，使用UUID为不同的请求生成不同的traceId值，作为value, 另外定义了一个spanId区分不同的线程。

public class MdcUtil {

    public static final String TRACE_ID = "traceId";

    public static final String SPAN_ID = "spanId";

    public static String generateUuId() {
        return UUID.randomUUID().toString().replace("-", "");
    }

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

    public static void setTraceId(String traceId) {
        MDC.put(TRACE_ID, traceId);
    }

    public static void setContextMap(Map<String, String> context) {
        MDC.setContextMap(context);
    }

    public static void removeTraceId() {
        MDC.remove(TRACE_ID);
        MDC.remove(SPAN_ID);
    }

    public static void clear() {
        MDC.clear();
    }

    // 每个线程都会产生一个属于自己的ID
    public static void initSpanId() {
        MDC.put(SPAN_ID, generateUuId());
    }
}

2、配置日志过滤器

需要注意几点：

1. 过滤器的优先级最好调整为最高，否则优先级更高的过滤器相关代码日志打印时无法携带traceId

2. 可设置从header中获取traceId，放入到当前请求MDC上下文，可用于微服务间的调用串联

3. 此处我们设置响应头增加traceId，以便进行问题请求的日志定位

@Configuration
public class FilterConfig {

    @Bean
    public FilterRegistrationBean<TraceFilter> registrationTrackFilter() {

        FilterRegistrationBean<TraceFilter> filterRegistrationBean = new FilterRegistrationBean<>();
        filterRegistrationBean.setFilter(new TraceFilter());
        filterRegistrationBean.addUrlPatterns("/*");
        filterRegistrationBean.setName("trackFilter");
        filterRegistrationBean.setOrder(2);
        return filterRegistrationBean;
    }
}

public class MdcTraceFilter implements Filter {

    @Override
    public void init(FilterConfig filterConfig) throws ServletException {

    }

    @Override
    public void doFilter(ServletRequest servletRequest, ServletResponse servletResponse, FilterChain filterChain) throws IOException, ServletException {
        HttpServletRequest request = (HttpServletRequest) servletRequest;
        String tid = request.getHeader("tid");
        ThreadMdcUtil.setTraceId(tid);
        // 响应头设置tid
        if (servletResponse instanceof HttpServletResponse) {
            ((HttpServletResponse) servletResponse).addHeader("tid", MdcUtil.getTraceId());
        }
        filterChain.doFilter(servletRequest, servletResponse);
    }

    @Override
    public void destroy() {
        MdcUtil.removeTraceId();
    }
}

3、解决 traceId 的传递问题

新开线程或线程池中线程的MDC上下文无法获取到主线程中的traceId，需要重写，再创建新线程或者线程池启动新线程之前，复制主线程的 traceId，并创建新线程的spanId


public class ThreadMdcUtil {

    public static void setTraceId(String traceId) {
        MdcUtil.setTraceId(traceId);
        MdcUtil.initSpanId();
    }

    public static void resetTraceId() {
        MdcUtil.setTraceId(MdcUtil.generateUuId());
        MdcUtil.initSpanId();
    }

    public static void setTraceIdIfAbsent() {
        if (MdcUtil.getTraceId() == null) {
            MdcUtil.setTraceId(MdcUtil.generateUuId());
        }
        MdcUtil.initSpanId();
    }

    public static <T> Callable<T> wrap(final Callable<T> callable, final Map<String, String> context) {
        return () -> {
            if (context == null) {
                MdcUtil.clear();
            } else {
                MdcUtil.setContextMap(context);
            }
            setTraceIdIfAbsent();
            try {
                return callable.call();
            } finally {
                MdcUtil.clear();
            }
        };
    }

    public static Runnable wrap(final Runnable runnable, final Map<String, String> context) {
        return () -> {
            if (context == null) {
                MdcUtil.clear();
            } else {
                MdcUtil.setContextMap(context);
            }
            //设置traceId
            setTraceIdIfAbsent();
            try {
                runnable.run();
            } finally {
                MdcUtil.clear();
            }
        };
    }
}

1. 针对代码中的自定义线程池

public class MdcThreadPoolExecutor extends ThreadPoolExecutor {

    public MdcThreadPoolExecutor(int corePoolSize, int maximumPoolSize, long keepAliveTime, TimeUnit unit, BlockingQueue<Runnable> workQueue) {
        super(corePoolSize, maximumPoolSize, keepAliveTime, unit, workQueue);
    }

    public MdcThreadPoolExecutor(int corePoolSize, int maximumPoolSize, long keepAliveTime, TimeUnit unit, BlockingQueue<Runnable> workQueue, ThreadFactory threadFactory) {
        super(corePoolSize, maximumPoolSize, keepAliveTime, unit, workQueue, threadFactory);
    }

    public MdcThreadPoolExecutor(int corePoolSize, int maximumPoolSize, long keepAliveTime, TimeUnit unit, BlockingQueue<Runnable> workQueue, RejectedExecutionHandler handler) {
        super(corePoolSize, maximumPoolSize, keepAliveTime, unit, workQueue, handler);
    }

    public MdcThreadPoolExecutor(int corePoolSize, int maximumPoolSize, long keepAliveTime, TimeUnit unit, BlockingQueue<Runnable> workQueue, ThreadFactory threadFactory, RejectedExecutionHandler handler) {
        super(corePoolSize, maximumPoolSize, keepAliveTime, unit, workQueue, threadFactory, handler);
    }

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

2. 针对@Async注解的异步线程

@Configuration
@EnableAsync
public class AsyncListenerConfiguration implements AsyncConfigurer {

    /**
     * 重写默认线程池配置，@Async异步会使用这个线程池
     *
     * @return
     */
    @Override
    public Executor getAsyncExecutor() {
        ThreadPoolTaskExecutor threadPoolTaskExecutor = new MdcThreadPoolTaskExecutor();
        threadPoolTaskExecutor.setCorePoolSize(50);
        threadPoolTaskExecutor.setMaxPoolSize(1000);
        threadPoolTaskExecutor.setQueueCapacity(100000);
        // 设置线程名称前缀
        threadPoolTaskExecutor.setThreadNamePrefix("logTraceAsyncPool-");
        threadPoolTaskExecutor.initialize();
        return threadPoolTaskExecutor;
    }

    @Override
    public AsyncUncaughtExceptionHandler getAsyncUncaughtExceptionHandler() {
        return null;
    }


}

public class MdcThreadPoolTaskExecutor extends ThreadPoolTaskExecutor {

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

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

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

3. 针对定时任务线程

@Configuration
public class ScheduledConfig {

    @Bean
    public TaskScheduler taskScheduler() {
        ThreadPoolTaskScheduler scheduling = new MdcThreadPoolTaskScheduler();
        scheduling.setPoolSize(10);
        scheduling.initialize();
        return scheduling;
    }
}

public class MdcThreadPoolTaskScheduler extends ThreadPoolTaskScheduler {

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

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

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

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

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

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

    @Override
    protected void cancelRemainingTask(Runnable task) {
        super.cancelRemainingTask(ThreadMdcUtil.wrap(task, MDC.getCopyOfContextMap()));
    }

    @Override
    public ScheduledFuture<?> schedule(Runnable task, Trigger trigger) {
        return super.schedule(ThreadMdcUtil.wrap(task, MDC.getCopyOfContextMap()), trigger);
    }

    @Override
    public ScheduledFuture<?> schedule(Runnable task, Date startTime) {
        return super.schedule(ThreadMdcUtil.wrap(task, MDC.getCopyOfContextMap()), startTime);
    }

    @Override
    public ScheduledFuture<?> scheduleAtFixedRate(Runnable task, Date startTime, long period) {
        return super.scheduleAtFixedRate(ThreadMdcUtil.wrap(task, MDC.getCopyOfContextMap()), startTime, period);
    }

    @Override
    public ScheduledFuture<?> scheduleAtFixedRate(Runnable task, long period) {
        return super.scheduleAtFixedRate(ThreadMdcUtil.wrap(task, MDC.getCopyOfContextMap()), period);
    }

    @Override
    public ScheduledFuture<?> scheduleWithFixedDelay(Runnable task, Date startTime, long delay) {
        return super.scheduleWithFixedDelay(ThreadMdcUtil.wrap(task, MDC.getCopyOfContextMap()), startTime, delay);
    }

    @Override
    public ScheduledFuture<?> scheduleWithFixedDelay(Runnable task, long delay) {
        return super.scheduleWithFixedDelay(ThreadMdcUtil.wrap(task, MDC.getCopyOfContextMap()), delay);
    }

    @Override
    public ScheduledFuture<?> schedule(Runnable task, Instant startTime) {
        return super.schedule(ThreadMdcUtil.wrap(task, MDC.getCopyOfContextMap()), startTime);
    }

    @Override
    public ScheduledFuture<?> scheduleAtFixedRate(Runnable task, Instant startTime, Duration period) {
        return super.scheduleAtFixedRate(ThreadMdcUtil.wrap(task, MDC.getCopyOfContextMap()), startTime, period);
    }

    @Override
    public ScheduledFuture<?> scheduleAtFixedRate(Runnable task, Duration period) {
        return super.scheduleAtFixedRate(ThreadMdcUtil.wrap(task, MDC.getCopyOfContextMap()), period);
    }

    @Override
    public ScheduledFuture<?> scheduleWithFixedDelay(Runnable task, Instant startTime, Duration delay) {
        return super.scheduleWithFixedDelay(ThreadMdcUtil.wrap(task, MDC.getCopyOfContextMap()), startTime, delay);
    }

    @Override
    public ScheduledFuture<?> scheduleWithFixedDelay(Runnable task, Duration delay) {
        return super.scheduleWithFixedDelay(ThreadMdcUtil.wrap(task, MDC.getCopyOfContextMap()), delay);
    }
}

4、配置logback pattern

    <property name="PATTERN"
              value="%d{yyyy-MM-dd HH:mm:ss.SSS} [%X{traceId:-}/%X{spanId:-}] [%t] %-5level %logger{50}[%F:%L] - %msg%n"/>