MDC轻量化日志链路跟踪的若干种应用场景

"If debugging is the process of removing software bugs, then programming must be the process of putting them in." - Edsger Dijkstra

“如果调试是消除软件Bug的过程,那么编程就是产出Bug的过程。” —— 艾兹格·迪杰斯特拉

0x00 大纲

0x01 前言

当你的应用程序同时处理多个用户的请求时,你会看到日志文件或者控制台中的输出通常都是交错的,而非线性连续的。尤其是在分布式系统中,一个用户请求可能包含了若干次的服务节点调用,它的日志也因此变得碎片化,如果缺乏一个用于归类和关联的标识,就会导致这笔交易难以被跟踪和追查。

MDC(Mapped Diagnostic Context)是一种用于区分来自不同来源日志的工具。它的本质是一个由日志框架维护的Map存储结构,应用程序可以向其中写入键值对,并被日志框架访问。我们常用的日志门面SLF4J就对MDC的实现进行了抽象,由日志框架提供真正的实现。在SLF4J的文档中写道:

This class hides and serves as a substitute for the underlying logging system's MDC implementation.

If the underlying logging system offers MDC functionality, then SLF4J's MDC, i.e. this class, will delegate to the underlying system's MDC. Note that at this time, only two logging systems, namely log4j and logback, offer MDC functionality. For java.util.logging which does not support MDC, BasicMDCAdapter will be used. For other systems, i.e. slf4j-simple and slf4j-nop, NOPMDCAdapter will be used.

Thus, as a SLF4J user, you can take advantage of MDC in the presence of log4j, logback, or java.util.logging, but without forcing these systems as dependencies upon your users.

目前为止只有logbacklog4j(log4j2)提供了较为完备的实现,其余日志框架下会使用SLF4J内部实现的BasicMDCAdapter或者NOPMDCAdapter.

0x02 应用场景

CLI 程序

logback为例,我们创建一个简单的logback.xml配置文件:

<?xml version="1.0" encoding="UTF-8"?>
<configuration scan="false">
    <property name="log.pattern" value="[%thread][%level][%logger{42}][%X{traceId:--}] %msg%n%ex"/>

    <appender name="stdout" class="ch.qos.logback.core.ConsoleAppender">
        <layout class="ch.qos.logback.classic.PatternLayout">
            <pattern>${log.pattern}</pattern>
        </layout>
    </appender>

    <root level="INFO">
        <appender-ref ref="stdout"/>
    </root>
</configuration>

一个简单的类用于测试,我们用一个循环来模拟用户两个独立的请求:

import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
import org.slf4j.MDC;
import java.util.UUID;

public class Main {
    private static final Logger LOGGER = LoggerFactory.getLogger(Main.class);

    public static void main(String[] args) {
        for (int i = 0; i < 2; i++) {
            try {
                LOGGER.info("Empty MDC Before Putting Data.");
                MDC.put("traceId", UUID.randomUUID().toString());
                LOGGER.info("Hello MDC.");
                LOGGER.info("GoodBye MDC.");
                throw new RuntimeException("Test Exception");
            } catch (RuntimeException e) {
                LOGGER.error("Test MDC", e);
            } finally {
                MDC.clear();
                LOGGER.info("Empty MDC After Clearing Data.");
            }
        }
    }
}

运行之后,我们会得到类似这样的日志输出:

[main][INFO][com.example.Main][-] Empty MDC Before Putting Data.
[main][INFO][com.example.Main][9ed7cc12-3880-4a38-94d4-b7ba96f37234] Hello MDC.
[main][INFO][com.example.Main][9ed7cc12-3880-4a38-94d4-b7ba96f37234] GoodBye MDC.
[main][ERROR][com.example.Main][9ed7cc12-3880-4a38-94d4-b7ba96f37234] Test MDC
java.lang.RuntimeException: Test Exception
	at com.example.Main.main(Main.java:19)
[main][INFO][com.example.Main][-] Empty MDC After Clearing Data.
[main][INFO][com.example.Main][-] Empty MDC Before Putting Data.
[main][INFO][com.example.Main][ab94804a-4f9a-4474-ba23-98542884d0ea] Hello MDC.
[main][INFO][com.example.Main][ab94804a-4f9a-4474-ba23-98542884d0ea] GoodBye MDC.
[main][ERROR][com.example.Main][ab94804a-4f9a-4474-ba23-98542884d0ea] Test MDC
java.lang.RuntimeException: Test Exception
	at com.example.Main.main(Main.java:19)
[main][INFO][com.example.Main][-] Empty MDC After Clearing Data.

可以看到,两次请求的traceId是不一样的,这样就能在日志中将它们区分和识别开来。通常来说,最好在请求完成后对MDC中的数据进行清理,尤其是使用了线程池的情况,由于线程是复用的,除非对原来的键值进行了覆盖,否则它将保留上一次的值。

Web 应用(服务端)

CLI程序中,我们可以用上面的写法来设置traceId,当时对于 Web 应用,由于Controller入口众多,不可能每个控制器都这样子写,可以使用拦截器实现公共逻辑,避免对Controller的方法造成污染。先增加一个简单的Controller,它有两个请求处理方法,一个同步,一个异步:

import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
import org.slf4j.MDC;
import org.springframework.context.annotation.Configuration;
import org.springframework.web.bind.annotation.GetMapping;
import org.springframework.web.bind.annotation.RestController;
import org.springframework.web.servlet.config.annotation.InterceptorRegistry;
import org.springframework.web.servlet.config.annotation.WebMvcConfigurer;
import java.util.Map;
import java.util.concurrent.Callable;

@RestController
public class MDCController {
    private static final Logger LOGGER = LoggerFactory.getLogger(MDCController.class);

    @Configuration
    public class WebMvcConfig implements WebMvcConfigurer {
        @Override
        public void addInterceptors(InterceptorRegistry registry) {
            registry.addInterceptor(new LogInterceptor()).addPathPatterns("/**");
        }
    }

    @GetMapping("/syncMDC")
    public String mdcSync() {
        LOGGER.info("sync MDC test.");
        return "syncMDC";
    }

    @GetMapping("/asyncMDC")
    public Callable<String> mdcAsync() {
        LOGGER.info("async MDC test.");
        Map<String, String> mdcMap = MDC.getCopyOfContextMap();
        return () -> {
            try {
                MDC.setContextMap(mdcMap);
                LOGGER.info("异步业务逻辑处理");
                return "asyncMDC";
            } finally {
                MDC.clear();
            }
        };
    }
}

然后是关键的MDC拦截器:

import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
import org.slf4j.MDC;
import org.springframework.web.servlet.AsyncHandlerInterceptor;
import javax.servlet.DispatcherType;
import javax.servlet.http.HttpServletRequest;
import javax.servlet.http.HttpServletResponse;
import java.util.UUID;

/**
 * 日志增强拦截器,给输出日志加上链路跟踪号
 *
 * @author YanFaBu
 **/
public class LogInterceptor implements AsyncHandlerInterceptor {
    private static final Logger LOGGER = LoggerFactory.getLogger(LogInterceptor.class);

    @Override
    public boolean preHandle(HttpServletRequest request, HttpServletResponse response, Object handler) {
        if (request.getDispatcherType() != DispatcherType.REQUEST) {
            // 非 DispatcherType.REQUEST 分发类型,尝试从 Attribute 获取 LOG_TRACE_ID
            MDC.put("traceId", (String) request.getAttribute("traceId"));
            LOGGER.info("preHandle Non DispatcherType.REQUEST type with DispatcherType {}", request.getDispatcherType());
            return true;
        }
        // 如果本次调用来自上游服务,那么尝试从请求头获取上游传递的 traceId
        String traceId = request.getHeader("traceId");
        if (traceId == null) {
            // 本服务节点是起始服务节点,设置 traceId
            traceId = UUID.randomUUID().toString();
        }
        MDC.put("traceId", traceId);
        // 异步处理会在内部进行 Request 转发,通过 Attribute 携带 traceId
        request.setAttribute("traceId", traceId);
        LOGGER.info("preHandle DispatcherType.REQUEST type with DispatcherType {}", request.getDispatcherType());
        return true;
    }

    @Override
    public void afterConcurrentHandlingStarted(HttpServletRequest request, HttpServletResponse response, Object handler) throws Exception {
        // 清理 MDC
        LOGGER.info("afterConcurrentHandlingStarted Clearing MDC.");
        MDC.clear();
    }

    @Override
    public void afterCompletion(HttpServletRequest request, HttpServletResponse response, Object handler, Exception exception) {
        // 清理 MDC
        LOGGER.info("afterCompletion Clearing MDC with DispatcherType {}", request.getDispatcherType());
        MDC.clear();
    }
}

分别访问这两个Controller方法,应当看到类似这样的日志输出:

[http-nio-8080-exec-7][INFO][com.example.LogInterceptor][e828f77b-9c0d-42c5-83db-15f19153bf19] preHandle DispatcherType.REQUEST type with DispatcherType REQUEST
[http-nio-8080-exec-7][INFO][com.example.MDCController][e828f77b-9c0d-42c5-83db-15f19153bf19] sync MDC test.
[http-nio-8080-exec-7][INFO][com.example.LogInterceptor][e828f77b-9c0d-42c5-83db-15f19153bf19] afterCompletion Clearing MDC with DispatcherType REQUEST

[http-nio-8080-exec-8][INFO][com.example.LogInterceptor][7dc0878c-c014-44de-97d4-92108873a030] preHandle DispatcherType.REQUEST type with DispatcherType REQUEST
[http-nio-8080-exec-8][INFO][com.example.MDCController][7dc0878c-c014-44de-97d4-92108873a030] async MDC test.
[http-nio-8080-exec-8][INFO][com.example.LogInterceptor][7dc0878c-c014-44de-97d4-92108873a030] afterConcurrentHandlingStarted Clearing MDC.
[task-3][INFO][com.example.MDCController][7dc0878c-c014-44de-97d4-92108873a030] 异步业务逻辑处理
[http-nio-8080-exec-9][INFO][com.example.LogInterceptor][7dc0878c-c014-44de-97d4-92108873a030] preHandle Non DispatcherType.REQUEST type with DispatcherType ASYNC
[http-nio-8080-exec-9][INFO][com.example.LogInterceptor][7dc0878c-c014-44de-97d4-92108873a030] afterCompletion Clearing MDC with DispatcherType ASYNC

注意到异步请求处理中的线程号的变化,请求受理-业务处理-请求应答历经了3个不同的线程,凡是跨线程的处理逻辑,必然需要对MDC的传递进行处理,否则链路跟踪会丢失。网上看到过很多例子,都忽略了对DispatcherType的处理,这样就会导致异步请求中,有一部分日志会失去追踪,导致最终排查问题时链路不完整。通过Attribute传递不是唯一的方式,也可以借助其他上下文来传递。

Web 应用(客户端)

OkHttp 同步请求

import okhttp3.OkHttpClient;
import okhttp3.Request;
import okhttp3.Response;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
import org.slf4j.MDC;

import java.io.IOException;
import java.util.Objects;
import java.util.UUID;

public class Client {
    private static final Logger LOGGER = LoggerFactory.getLogger(LogInterceptor.class);

    public static void main(String[] args) throws IOException {
        okHttpSync();
    }

    public static void okHttpSync() throws IOException {
        try {
            String traceId = UUID.randomUUID().toString();
            MDC.put("traceId", traceId);
            LOGGER.info("okHttpSync request syncMDC");
            OkHttpClient client = new OkHttpClient().newBuilder()
                    .build();
            Request request = new Request.Builder()
                    .url("http://localhost:8080/syncMDC")
                    .method("GET", null)
                    .addHeader("traceId", traceId)
                    .build();
            try (Response response = client.newCall(request).execute()) {
                LOGGER.info("okHttpSync response:{}", Objects.requireNonNull(response.body()).string());
            }
        } finally {
            MDC.clear();
        }
    }
}

OkHttp 异步请求

import okhttp3.*;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
import org.slf4j.MDC;
import java.io.IOException;
import java.util.Map;
import java.util.Objects;
import java.util.UUID;

public class Client {
    private static final Logger LOGGER = LoggerFactory.getLogger(LogInterceptor.class);

    public static void main(String[] args) {
        okHttpAsync();
    }

    public static void okHttpAsync() {
        try {
            String traceId = UUID.randomUUID().toString();
            MDC.put("traceId", traceId);
            LOGGER.info("okHttpAsync request syncMDC");
            OkHttpClient client = new OkHttpClient().newBuilder()
                    .build();
            Request request = new Request.Builder()
                    .url("http://localhost:8080/syncMDC")
                    .method("GET", null)
                    .addHeader("traceId", traceId)
                    .build();
            Map<String, String> mdcMap = MDC.getCopyOfContextMap();
            client.newCall(request).enqueue(new Callback() {
                @Override
                public void onFailure(Call call, IOException e) {
                    try {
                        MDC.setContextMap(mdcMap);
                        LOGGER.error("okHttpAsync error", e);
                    } finally {
                        MDC.clear();
                    }
                }

                @Override
                public void onResponse(Call call, Response response) throws IOException {
                    try {
                        MDC.setContextMap(mdcMap);
                        LOGGER.info("okHttpAsync response:{}", Objects.requireNonNull(response.body()).string());
                    } finally {
                        MDC.clear();
                    }
                }
            });
        } finally {
            MDC.clear();
        }
    }
}

顺利的话,在客户端应该会得到类似下面的日志输出(注意线程名称的变化):

[main][INFO][com.example.Client][53924455-0fcd-442b-a5aa-aaa33005d299] okHttpSync request syncMDC
[main][INFO][com.example.Client][53924455-0fcd-442b-a5aa-aaa33005d299] okHttpSync response:syncMDC

[main][INFO][com.example.Client][5cb52293-c8ac-4bc5-87fc-dbeb1e727eba] okHttpAsync request syncMDC
[OkHttp http://localhost:8080/...][INFO][com.example.Client][5cb52293-c8ac-4bc5-87fc-dbeb1e727eba] okHttpAsync response:syncMDC

在服务端对应的日志如下,可以看到traceId是一致的(如果不一致或者没有看到traceId,应该检查下上一章提到的拦截器是否有被正确实现):

[http-nio-8080-exec-2][INFO][com.example.LogInterceptor][53924455-0fcd-442b-a5aa-aaa33005d299] preHandle DispatcherType.REQUEST type with DispatcherType REQUEST
[http-nio-8080-exec-2][INFO][com.example.MDCController][53924455-0fcd-442b-a5aa-aaa33005d299] sync MDC test.
[http-nio-8080-exec-2][INFO][com.example.LogInterceptor][53924455-0fcd-442b-a5aa-aaa33005d299] afterCompletion Clearing MDC with DispatcherType REQUEST

[http-nio-8080-exec-3][INFO][com.example.LogInterceptor][5cb52293-c8ac-4bc5-87fc-dbeb1e727eba] preHandle DispatcherType.REQUEST type with DispatcherType REQUEST
[http-nio-8080-exec-3][INFO][com.example.MDCController][5cb52293-c8ac-4bc5-87fc-dbeb1e727eba] sync MDC test.
[http-nio-8080-exec-3][INFO][com.example.LogInterceptor][5cb52293-c8ac-4bc5-87fc-dbeb1e727eba] afterCompletion Clearing MDC with DispatcherType REQUEST

处理思路都是通过HTTP Header携带traceId到下游服务,让下游服务可以跟踪来源。注意异步请求时,请求处理和应答处理回调线程不在同一个线程,需要对MDC的传递进行处理,否则链路跟踪会丢失。其他的客户端,如HttpClientUnirest等 HTTP 请求库原理与之相似,这里就不一一列举了。

Spring WebClient

OkHttp异步调用类似,注意要在Mono或者Fluxsubscribe方法中传递MDC上下文。其实WebClient中有Context传递的概念,但是这块资料比较少,异步非阻塞的代码又看得头痛,暂时不想去研究了。下面的代码出于演示目的使用,请勿直接使用:

import okhttp3.*;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
import org.slf4j.MDC;
import org.springframework.web.reactive.function.client.WebClient;

import java.io.IOException;
import java.util.Map;
import java.util.Objects;
import java.util.UUID;
import java.util.concurrent.CountDownLatch;

public class Client {
    private static final Logger LOGGER = LoggerFactory.getLogger(LogInterceptor.class);

    public static void main(String[] args) throws InterruptedException {
        webClient();
    }

    public static void webClient() throws InterruptedException {
        String traceId = UUID.randomUUID().toString();
        MDC.put("traceId", traceId);
        LOGGER.info("webClient request syncMDC");
        WebClient client = WebClient.create("http://localhost:8080/syncMDC");
        Map<String, String> mdcMap = MDC.getCopyOfContextMap();
        CountDownLatch latch = new CountDownLatch(1);
        client.get()
                .uri("/")
                .retrieve()
                .bodyToMono(String.class)
                .subscribe(result -> {
                    try {
                        MDC.setContextMap(mdcMap);
                        LOGGER.info("webClient response:{}", result);
                    } finally {
                        MDC.clear();
                        latch.countDown();
                    }
                }, throwable -> {
                    try {
                        MDC.setContextMap(mdcMap);
                        LOGGER.error("webClient error", throwable);
                    } finally {
                        MDC.clear();
                    }
                });
        latch.await();
    }
}

输出日志如下,注意线程的变化:

[main][INFO][com.example.Client][8c984fa8-e3cd-4914-875e-ba333d31c7a9] webClient request syncMDC
[reactor-http-nio-2][INFO][com.example.Client][8c984fa8-e3cd-4914-875e-ba333d31c7a9] webClient response:syncMDC

Dubbo 服务

与 HTTP 调用类似,基于Dubbo的 RPC 调用也是可以跟踪的,利用DubboFilterSPI注册机制,我们可以增加自己的过滤器实现日志链路跟踪:

import org.apache.dubbo.common.extension.Activate;
import org.apache.dubbo.rpc.*;
import org.slf4j.MDC;
import java.util.UUID;

/**
 * 服务链路跟踪过滤器
 */
@Activate
public class RpcTraceFilter implements Filter {
    @Override
    public Result invoke(Invoker<?> invoker, Invocation invocation) throws RpcException {
        RpcContext context = RpcContext.getContext();
        boolean shouldRemove = false;
        if (context.isProviderSide()) {
            // 获取消费端设置的参数
            String traceId = context.getAttachment("traceId");
            if (traceId == null || traceId.isEmpty()) {
                traceId = MDC.get("traceId");
                if (traceId == null || traceId.isEmpty()) {
                    traceId = UUID.randomUUID().toString();
                    shouldRemove = true;
                }
            }
            // 设置 traceId
            MDC.put("traceId", traceId);
            // 继续设置下游参数,供在提供方里面作为消费端时,其他服务提供方使用这些参数
            context.setAttachment("traceId", traceId);
        } else if (context.isConsumerSide()) {
            // 如果连续调用多个服务,则会使用同个线程里之前设置的traceId
            String traceId = MDC.get("traceId");
            if (traceId == null || traceId.isEmpty()) {
                traceId = UUID.randomUUID().toString();
                // 设置 traceId
                MDC.put("traceId", traceId);
                shouldRemove = true;
            }
            // 设置传递到提供端的参数
            context.setAttachment("traceId", traceId);
        }
        try {
            return invoker.invoke(invocation);
        } finally {
            // 调用完成后移除MDC属性
            if (shouldRemove) {
                MDC.clear();
            }
        }
    }
}

在需要用到的服务模块的resource/META-INF/dubbo/org.apache.dubbo.rpc.Filter文件中注册过滤器(注意路径和名称不能错):

rpcTraceFilter=com.example.RpcTraceFilter

SpringBootapplication.properties中增加配置(为了简单验证,这里没有使用注册中心。如果你想更严谨地测试,建议在本地启动两个独立的工程,并使用ZooKeeper进行服务注册):

dubbo.application.name=MDCExample
dubbo.scan.base-packages=com.example
dubbo.registry.address=N/A
# dubbo filter
dubbo.consumer.filter=rpcTraceFilter
dubbo.provider.filter=rpcTraceFilter

增加一个简单的Dubbo服务:

import org.apache.dubbo.config.annotation.DubboService;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;

@DubboService
public class RpcService implements IRpcService {
    private static final Logger LOGGER = LoggerFactory.getLogger(RpcService.class);

    public String mdcRpc() {
        LOGGER.info("Calling RPC service.");
        return "mdcRpc";
    }
}

Controller中增加一个方法,进行验证:

import org.apache.dubbo.config.annotation.DubboReference;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
import org.slf4j.MDC;
import org.springframework.context.annotation.Configuration;
import org.springframework.web.bind.annotation.GetMapping;
import org.springframework.web.bind.annotation.RestController;
import org.springframework.web.servlet.config.annotation.InterceptorRegistry;
import org.springframework.web.servlet.config.annotation.WebMvcConfigurer;

import java.util.Map;
import java.util.concurrent.Callable;

@RestController
public class MDCController {
    // ......(省略前面的代码)
    @DubboReference
    private IRpcService rpcService;

    @GetMapping("/mdcRpc")
    public String mdcRpc() {
        LOGGER.info("rpc MDC test.");
        return rpcService.mdcRpc();
    }
}

访问Controller方法,应该能得到类似下面的输出:

[http-nio-8080-exec-1][INFO][com.example.LogInterceptor][f003f750-2044-41ae-a041-8a76eb0c415b] preHandle DispatcherType.REQUEST type with DispatcherType REQUEST
[http-nio-8080-exec-1][INFO][com.example.MDCController][f003f750-2044-41ae-a041-8a76eb0c415b] rpc MDC test.
[http-nio-8080-exec-1][INFO][com.example.RpcService][f003f750-2044-41ae-a041-8a76eb0c415b] Calling RPC service.
[http-nio-8080-exec-1][INFO][com.example.LogInterceptor][f003f750-2044-41ae-a041-8a76eb0c415b] afterCompletion Clearing MDC with DispatcherType REQUEST

线程池

前面提到过跨线程调用时,需要自己处理MDC上下文的传递,如果是单个线程,可以手工进行处理,但如果是线程池,似乎就不能这么干了。线程池种类繁多,处理方式也有细微差别,这里不可能全部列举,以Spring项目中常用的 ThreadPoolTaskExecutor为例,我们可以利用它提供的setTaskDecorator方法对任务进行装饰:

import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
import org.slf4j.MDC;
import org.springframework.context.annotation.Bean;
import org.springframework.scheduling.concurrent.ThreadPoolTaskExecutor;
import java.util.Map;
import java.util.UUID;

public class MDCExecutor {
    private static final Logger LOGGER = LoggerFactory.getLogger(MDCExecutor.class);
    public static void main(String[] args) {
        MDC.put("traceId", UUID.randomUUID().toString());
        ThreadPoolTaskExecutor executor = asyncTaskExecutor();
        executor.initialize();
        executor.submit(() -> LOGGER.info("MDC Executor"));
        executor.shutdown();
    }
    @Bean
    public static ThreadPoolTaskExecutor asyncTaskExecutor() {
        ThreadPoolTaskExecutor executor = new ThreadPoolTaskExecutor();
        executor.setTaskDecorator(task -> {
            Map<String, String> mdcMap = MDC.getCopyOfContextMap();
            return () -> {
                try {
                    if (mdcMap != null) {
                        MDC.setContextMap(mdcMap);
                    }
                    task.run();
                } finally {
                    MDC.clear();
                }
            };
        });
        return executor;
    }
}

对于其他线程池,通用的思路是覆写其submit或者execute方法来实现MDC传递,比如我们下面提到的定时任务调度线程池。

定时任务

除了Controller和 RPC 接口发起的调用,最常见的就是定时任务了。如果是定时任务作为业务发起源,可以在任务调度的时候对MDC进行处理。这块处理比较复杂,暂时没有找到比较优雅的切入点:

增加一个实现RunnableScheduledFuture接口的DecoratedFuture类:

import org.slf4j.MDC;
import java.util.Map;
import java.util.Optional;
import java.util.UUID;
import java.util.concurrent.*;

class DecoratedFuture<V> implements RunnableScheduledFuture<V> {
    Runnable runnable;
    Callable<V> callable;
    final RunnableScheduledFuture<V> task;

    public DecoratedFuture(Runnable r, RunnableScheduledFuture<V> task) {
        this.task = task;
        runnable = r;
    }

    public DecoratedFuture(Callable<V> c, RunnableScheduledFuture<V> task) {
        this.task = task;
        callable = c;
    }

    @Override
    public boolean isPeriodic() {
        return task.isPeriodic();
    }

    @Override
    public void run() {
        try {
            Map<String, String> mdcMap = MDC.getCopyOfContextMap();
            Optional.ofNullable(mdcMap).ifPresent(MDC::setContextMap);
            String traceId = MDC.get("traceId");
            if (traceId == null || traceId.isEmpty()) {
                traceId = UUID.randomUUID().toString();
            }
            MDC.put("traceId", traceId);
            task.run();
        } finally {
            MDC.clear();
        }
    }

    @Override
    public boolean cancel(boolean mayInterruptIfRunning) {
        return task.cancel(mayInterruptIfRunning);
    }

    @Override
    public boolean isCancelled() {
        return task.isCancelled();
    }

    @Override
    public boolean isDone() {
        return task.isDone();
    }

    @Override
    public V get() throws InterruptedException, ExecutionException {
        return task.get();
    }

    @Override
    public V get(long timeout, TimeUnit unit) throws InterruptedException, ExecutionException, TimeoutException {
        return task.get(timeout, unit);
    }

    @Override
    public long getDelay(TimeUnit unit) {
        return task.getDelay(unit);
    }

    @Override
    public int compareTo(Delayed o) {
        return task.compareTo(o);
    }

    @Override
    public int hashCode() {
        return task.hashCode();
    }

    @Override
    public boolean equals(Object o) {
        if (this == o) {
            return true;
        }
        if (o == null || getClass() != o.getClass()) {
            return false;
        }
        DecoratedFuture<?> that = (DecoratedFuture<?>) o;
        return this.task.equals(that.task);
    }

    public Runnable getRunnable() {
        return runnable;
    }

    public RunnableScheduledFuture<V> getTask() {
        return task;
    }

    public Callable<V> getCallable() {
        return callable;
    }
}

增加一个实现ThreadPoolTaskScheduler接口的DecoratedThreadPoolTaskScheduler类:

import org.slf4j.MDC;
import org.springframework.scheduling.concurrent.ThreadPoolTaskScheduler;
import java.time.Duration;
import java.time.Instant;
import java.util.Map;
import java.util.Optional;
import java.util.concurrent.RejectedExecutionHandler;
import java.util.concurrent.ScheduledExecutorService;
import java.util.concurrent.ScheduledFuture;
import java.util.concurrent.ThreadFactory;

class DecoratedThreadPoolTaskScheduler extends ThreadPoolTaskScheduler {
    private static final long serialVersionUID = 1L;

    static Runnable withTraceId(Runnable task) {
        Map<String,String> mdcMap = MDC.getCopyOfContextMap();
        return ()-> {
            try {
                Optional.ofNullable(mdcMap).ifPresent(MDC::setContextMap);
                task.run();
            } finally {
                MDC.clear();
            }
        };
    }

    @Override
    protected ScheduledExecutorService createExecutor(int poolSize, ThreadFactory threadFactory, RejectedExecutionHandler rejectedExecutionHandler) {
        return new DecoratedScheduledThreadPoolExecutor(poolSize, threadFactory, rejectedExecutionHandler);
    }
    
    @Override
    public ScheduledFuture<?> schedule(Runnable task, Instant startTime) {
        return super.schedule(withTraceId(task), startTime);
    }
    
    @Override
    public ScheduledFuture<?> scheduleAtFixedRate(Runnable task, Instant startTime, Duration period) {
        return super.scheduleAtFixedRate(withTraceId(task), startTime, period);
    }
    
    @Override
    public ScheduledFuture<?> scheduleAtFixedRate(Runnable task, Duration period) {
        return super.scheduleAtFixedRate(withTraceId(task), period);
    }
    
    @Override
    public ScheduledFuture<?> scheduleWithFixedDelay(Runnable task, Instant startTime, Duration delay) {
        return super.scheduleWithFixedDelay(withTraceId(task), startTime, delay);
    }
    
    @Override
    public ScheduledFuture<?> scheduleWithFixedDelay(Runnable task, Duration delay) {
        return super.scheduleWithFixedDelay(withTraceId(task), delay);
    }
}

增加一个继承ScheduledThreadPoolExecutor类的DecoratedScheduledThreadPoolExecutor类,覆写它的两个decorateTask方法:

import java.util.concurrent.*;

class DecoratedScheduledThreadPoolExecutor extends ScheduledThreadPoolExecutor {
    public DecoratedScheduledThreadPoolExecutor(int poolSize, ThreadFactory threadFactory, RejectedExecutionHandler rejectedExecutionHandler) {
        super(poolSize, threadFactory, rejectedExecutionHandler);
    }

    @Override
    protected <V> RunnableScheduledFuture<V> decorateTask(Runnable runnable, RunnableScheduledFuture<V> task) {
        return new DecoratedFuture<>(runnable, task);
    }

    @Override
    protected <V> RunnableScheduledFuture<V> decorateTask(Callable<V> callable, RunnableScheduledFuture<V> task) {
        return new DecoratedFuture<>(callable, task);
    }
}

在定时任务Configuration中,创建DecoratedThreadPoolTaskScheduler作为调度线程池:

import org.springframework.context.annotation.Bean;
import org.springframework.context.annotation.Configuration;
import org.springframework.scheduling.annotation.EnableAsync;
import org.springframework.scheduling.annotation.EnableScheduling;
import org.springframework.scheduling.annotation.SchedulingConfigurer;
import org.springframework.scheduling.concurrent.ThreadPoolTaskScheduler;
import org.springframework.scheduling.config.ScheduledTaskRegistrar;

/**
 * 定时调度配置
 */
@Configuration
@EnableAsync
@EnableScheduling
public class SchedulingConfiguration implements SchedulingConfigurer {
    public static final String TASK_SCHEDULER = "taskScheduler";

    @Override
    public void configureTasks(ScheduledTaskRegistrar taskRegistrar) {
        taskRegistrar.setTaskScheduler(taskScheduler());
    }

    @Bean(TASK_SCHEDULER)
    public ThreadPoolTaskScheduler taskScheduler() {
        return new DecoratedThreadPoolTaskScheduler();
    }
}

添加一个简单定时任务:

import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
import org.springframework.boot.SpringApplication;
import org.springframework.boot.autoconfigure.SpringBootApplication;
import org.springframework.scheduling.annotation.Scheduled;

@SpringBootApplication
public class App {
    private static final Logger LOGGER = LoggerFactory.getLogger(App.class);
    public static void main(String[] args) {
        SpringApplication.run(App.class, args);
    }

    @Scheduled(fixedDelay = 1500)
    public void cronTaskConfigRefresh() {
        LOGGER.info("MDC task scheduler.");
    }
}

可以看到类似下面的输出,说明就成功了:

[taskScheduler-1][INFO][com.example.App][0959d1a6-4680-4a95-a29b-b62694f0d348] MDC task scheduler.
[taskScheduler-1][INFO][com.example.App][8f034b1e-db40-44cb-9fc2-986eb8f0da6d] MDC task scheduler.
[taskScheduler-1][INFO][com.example.App][02428e88-53f8-4151-aba0-86e069c96462] MDC task scheduler.
[taskScheduler-1][INFO][com.example.App][fcd5d925-95e0-4e28-aa68-39e765668dde] MDC task scheduler.
[taskScheduler-1][INFO][com.example.App][b8ed50c6-0d6d-40c0-b170-976717fe7d22] MDC task scheduler.
[taskScheduler-1][INFO][com.example.App][9d173a26-41d4-43dc-beae-731a9f267288] MDC task scheduler.
[taskScheduler-1][INFO][com.example.App][0257c93a-9bec-40b7-9447-5a938bd2ce5f] MDC task scheduler.

0x03 小结

在实际项目中,通过灵活组合上面的若干种手段,就可以实现轻量化的日志链路跟踪,在大部分情况下基本上已经够用了,当然你也可以引入SkyWalkingZipKin等探针框架,它们提供的功能也更全面更丰富。如何选择,需要根据具体项目自行权衡。

0x04 附录

样例工程下载

原文链接:https://www.cnblogs.com/mylibs/p/using-mdc-to-trace-log.html

本站文章如无特殊说明,均为本站原创,如若转载,请注明出处:MDC轻量化日志链路跟踪的若干种应用场景 - Python技术站

(1)
上一篇 2023年4月22日
下一篇 2023年4月22日

相关文章

  • Java异常处理 Throwable实现方法解析

    Java 中的异常(Exception)处理机制能够帮助程序员更加优雅地解决程序运行过程中出现的错误,避免了程序的中断和崩溃。而在 Java 的异常处理机制中,核心的接口就是Throwable。在本篇攻略中,我将为大家详细讲解 Java 异常处理中 Throwable 接口的使用方法和实现技巧,同时提供两个示例分别说明如何使用 Throwable 接口进行异…

    Java 2023年5月27日
    00
  • Java的Hibernate框架数据库操作中锁的使用和查询类型

    对于Java的Hibernate框架数据库操作中锁的使用和查询类型,我们需要掌握如下几个方面: 为什么使用锁? 在并发访问的情况下,多个客户端会同时对同一个数据库进行操作,如果不加锁就有可能会发生多用户同时修改同一条记录而导致数据不一致的问题,而加锁就可以使得同一时刻只有一个用户对同一个记录进行操作,避免了并发修改引起的不一致性问题。 如何使用锁? 在Hib…

    Java 2023年5月19日
    00
  • mybatis中的mapper.xml使用循环语句

    MyBatis是Java企业级应用中常用的持久化框架之一。在MyBatis中,mapper.xml是定义SQL语句的重要文件,循环语句是在mapper.xml中进行数据处理的常用方式之一。本文将从以下几个方面,详细讲解MyBatis中的mapper.xml使用循环语句的完整攻略: MyBatis中支持哪些类型的循环语句 MyBatis中如何编写循环语句 在M…

    Java 2023年5月20日
    00
  • ActiveMQ简单入门(新手必看篇)

    ActiveMQ简单入门(新手必看篇) ActiveMQ是一个流行的开源消息队列系统,它具有高可用性、高性能、多语言支持等诸多优点,被广泛应用于分布式系统的消息通信场景中。本篇文章将详细讲解ActiveMQ的入门步骤,帮助新手快速上手使用。 安装ActiveMQ 首先需要在官网(http://activemq.apache.org/)上下载ActiveMQ二…

    Java 2023年6月15日
    00
  • 学java得这样学,学习确实也得这样

    学习Java需要掌握必要的基础知识,同时要注重实践,不断尝试实现具体的代码,以下是学习Java的完整攻略: 基础知识 语言基础 一门编程语言的语言基础,即语法结构和语言特性是学习该语言的基础,Java也不例外。 Java编程语言语言基础包括变量、运算符、控制语句等,学习者需要先掌握语言基础部分,方能打好基础,后续的代码实现才能更加顺利。 面向对象 Java是…

    Java 2023年6月15日
    00
  • 深入浅出Java mvc_动力节点Java学院整理

    深入浅出Java MVC 介绍 Java MVC是一种设计模式,它将应用程序划分为三个主要部分:模型(Model)、视图(View)和控制器(Controller)。这种分层架构为应用程序提供了更好的可扩展性和灵活性。 MVC的基本原则 模型(Model) 模型是应用程序中的核心组件,它表示应用程序要处理的数据以及对数据进行操作的逻辑。在Java中,模型可以…

    Java 2023年6月15日
    00
  • springboot全局异常处理代码实例

    下面就给您详细讲解一下“springboot全局异常处理代码实例”的完整攻略。 什么是SpringBoot全局异常处理 SpringBoot是一种非常流行的Java Web框架,它具有快速构建应用、开箱即用等优点。然而,当我们的应用出现错误时,如果不进行有效的异常处理,就会给用户带来不好的使用体验。SpringBoot提供了全局异常处理机制,可以针对应用中的…

    Java 2023年5月27日
    00
  • Java中使用JWT生成Token进行接口鉴权实现方法

    为了在Java中使用JWT生成Token进行接口鉴权,我们需要以下步骤: 1. 引入依赖 我们需要在项目中引入一个JWT依赖,例如Java JWT(https://github.com/auth0/java-jwt)。 Maven坐标如下: <dependency> <groupId>com.auth0</groupId>…

    Java 2023年5月20日
    00
合作推广
合作推广
分享本页
返回顶部