【日志全链路traceId】异步任务跟踪

【日志全链路traceId】异步任务跟踪

**线上问题：**线上服务产生的日志量非常大；由于之前服务只对每个用户请求线程内进行全链路traceId管理；异步任务只能根据时间点和日志内容进行定位；
效率非常低；基于以上问题进行异步任务日志全链路traceId跟踪; 提高线上快速定位bug效率！

逻辑流程图

实现逻辑

1.请求过滤器设置：

MDC.put()方法本质上调用mdcAdapter.put(); mdcAdapter是一个ThreadLocal;

@Component
@Order(1)   //值越小越先执行
public class RequestFilter implements Filter {
    // 初始化日志
    private static final Logger log = LoggerFactory.getLogger(RequestFilter.class);
    private Boolean isOpen = true;

    public RequestFilter() {}

    @Override
    public void init(FilterConfig filterConfig) throws ServletException {
        System.out.println("requestFilter init...");
    }

    @Override
    public void doFilter(ServletRequest servletRequest, ServletResponse servletResponse, FilterChain filterChain) throws IOException, ServletException {

        HttpServletRequest request = (HttpServletRequest) servletRequest;
        // 获取请求头中"x-request-id
        Strring traceId = request.getHeader("x-request-id");
        // 往日志中MDC适配器中添加traceId(未获取到默认使用uUID)
        MDC.put("traceId", StringUtils.hasText(traceId) ? traceId : UUID.randomUUID().toString());

        if (!this.isOpen) {
            // 执行过来请求
            chain.doFilter(request, response);
        } else {
            long start = System.currentTimeMillis();
            chain.doFilter(request, response);
            long spend = System.currentTimeMillis() - start;
            log.info("耗时： [{}]ms, 服务： 【{}】", spend, request.getRequestURI());
        }
    }

    public void destroy() {
        System.out.println("requestFilter destory...");
    }

    public Boolean getIsOpen() {
        return this.isOpen;
    }

    public void setIsOpen(Boolean isOpen) {
        this.isOpen = isOpen;
    }
}

2.异步任务线程池配置：

@Configuration
public class AsyncConfig {
    // 异步线程池名称
    @Bean("asyncTaskDecorator") 
    public Executor asyncExecutor() {
        ThreadPoolTaskExecutor executor = new ThreadPoolTaskExecutor();
        // 设置最大核心线程数量
        executor.setCorePoolSize(40);
        // 设置最大线程数量
        executor.setMaxPoolSize(40);
        // 设置线程生存时间；即线程空闲多长时间后归还给操作系统
        executor.setKeepAliveSeconds(300);
        // 设置任务队列容量
        executor.setQueueCapacity(3000);
        // 设置线程前缀名称
        executor.setThreadNamePrefix("Dispatch-");
        // 设置线程任务装饰器
        executor.setTaskDecorator(new AsyncTaskDecorator());
        // 设置拒绝策略：用调用者所在的线程来执行任务
        executor.setRejectedExecutionHandler(new ThreadPoolExecutor.CallerRunsPolicy());
        // 设置等待线程任务结束
        executor.setWaitForTasksToCompleteOnShutdown(true);
        executor.initialize();
        return executor;
    }

}

3.重写异步任务装饰器

注意：异步任务结束需要清空掉MDC；不然可能出现OOM问题

public class AsyncTaskDecorator implements TaskDecorator {
    
    @Override
    public Runnable decorate(Runnable runnable) {
        try {
            // 获取主线程的MDC上下文
            Map mdcMap = MDC.getCopyOfContextMap();
            return () -> {
                try {
                    // 将主线程MDC上下文设置到异步任务MDC
                    MDC.setContextMap(mdcMap);
                    runnable.run();
                } finally {
                    // 由于线程池任务一致重复使用; 所以每个异步任务结束都需要清理掉MDC上下文
                    MDC.clear();
             }
            };
        } catch (IllegalStateException e) {
            return runnable;
        }
    }
}

4.日志输出配置：

<?xml version="1.0" encoding="UTF-8"?>
<configuration debug="false" scan="false" scanPeriod="10 seconds">
    <springProperty scope="context" name="profile" source="spring.profile.active"/>
    <springProperty scope="context" name="appName" source="spring.application.name"/>
    <!--编码-->
    <property name="LOG_CHARSET" value="UTF-8"/>
    <property name="LOG_DIR" value="/file/logs/services"/>
    <!--日志输出格式： 日期 | 日志等级 | 线程名称 | 打印日志的类 ： 全链路跟踪唯一id | 消息主体-->
    <property name="LOG_FMT_COLOUR" value="%d{yyyy-MM-dd HH:mm:ss.SSS} | %highlight(%-5level) | %boldYellow(%thread) | %boldGreen(%logger) | %X{trace_id} | %msg%n"/>

    <!-- 指定日志输出位置 -->
    <appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">
        <!--根据上面属性定义赋值日志解析格式和编码-->
        <encoder>
            <pattern>${LOG_FMT_COLOUR}</pattern>
            <charset>${LOG_CHARSET}</charset>
        </encoder>
    </appender>

    <appender name="ROLLing_FILE" class="ch.qos.logback.core.rolling.RollingFileAppender">
        <File>${LOG_DIR}/${appName}.log</File>
        <!--按照固定窗口模式生成日志文件；当日志文件大于1024MB, 生成新的日志；窗口大小1 -> 3 保存了3个日志文件后，将覆盖最早的日志-->
        <rollingPolicy class="ch.qos.logback.core.rolling.SizeAndTimeBasedRollingPolicy">
            <fileNamePattern>${LOG_DIR}/${appName}.%d.%i.log</fileNamePattern> <!-- %i 窗口值-->
            <minIndex>1</minIndex> <!--最小窗口值-->
            <maxIndex>3</maxIndex> <!--最大窗口值-->
            <maxHistory>30</maxHistory>
            <maxFileSize>1024MB</maxFileSize>
        </rollingPolicy>
        <encoder>
            <pattern>${LOG_FMT_COLOUR}</pattern>
            <charset>${LOG_CHARSET}</charset>
        </encoder>
    </appender>
    <!--window环境日志输出-->
    <if condition='property("os.name").contains("Windows")'>
        <then>
            <!--设置全局日志级别-->
            <root level="DEBUG">
                <!--打印方式引用 STDOUT-->
                <appender-ref ref="STDOUT"/>
            </root>
        </then>
        <!--linux环境日志输出-->
        <else>
            <!--设置全局日志级别-->
            <root level="INFO">
                <!--打印方式引用 STDOUT-->
                <appender-ref ref="STDOUT"/>
                <appender-ref ref="ROLLing_FILE"/>
            </root>
        </else>

</configuration>

总结：

异步任务下保持全链路traceId唯一；本质上是利用ThreadLocal传递主线程和子线程的上下文; 当线上异步任务出现bug时，可以根据traceId快速定位异步任务问题