调用链追踪利器 MDC日常工作中排查线上问题，经常会遇到一些问题：线上系统某次调用异常，是哪笔订单的什么操作造成的？是

站长

2024年09月06日 10:43 · 阅读数 35

一、前言

日常工作中排查线上问题，经常会遇到一些问题：

线上系统某次调用异常，是哪笔订单的什么操作造成的？是哪个服务调用的？来自哪台机子？
异常订单操作，对数据有哪些造成了影响？
用户在某个时段分别进行了哪些操作?

而日趋复杂的分布式系统，

微服务
分布式中间价：消息队列、分布式缓存、分布式对象存储
不同调用：跨机房、跨区域调用、第三方调用

调用链追踪利器 MDC日常工作中排查线上问题，经常会遇到一些问题：线上系统某次调用异常，是哪笔订单的什么操作造成的？是

调用链作为排查问题的核心，通过其可以将各类数据关联在一起，提高问题排查能力。

调用链追踪利器 MDC日常工作中排查线上问题，经常会遇到一些问题：线上系统某次调用异常，是哪笔订单的什么操作造成的？是

啥是 MDC ？

MDC（Mapped Diagnostic Context） ：映射诊断上下文，是 Logback框架中一个特征。（Logback是 SpringBoot 的默认框架）

它可以在日志消息中存储上下文消息，在日志事件之间传播键值。

快速入门

在 pom.xml 中添加 logback-classic 依赖

<dependency>
    <groupId>ch.qos.logback</groupId>
    <artifactId>logback-classic</artifactId>
    <version>1.2.3</version>
</dependency>

在 logback.xml中配置日志信息

<configuration>
    <appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">
        <encoder>
            <pattern>%d{HH:mm:ss.SSS} [%thread] %-5level %logger{36} - %mdc - %msg%n</pattern>
        </encoder>
    </appender>

    <root level="debug">
        <appender-ref ref="STDOUT" />
    </root>
</configuration>

<PatternLayout pattern="[%date{yyyy-MM-dd HH:mm:ss,SSS}] [%level] [%C{1}:%line] [%thread] [%traceId] -- %mdc{operator} %mdc{request} %m%n"/>

通过 MDC 设置 key

@Component
public class RequestInterceptor implements HandlerInterceptor {
    @Override
    public boolean preHandle(HttpServletRequest request, HttpServletResponse response, Object handler) throws Exception {
        String userId = request.getHeader("traceId");
        MDC.put("traceId", traceId);
        return true;
    }

    @Override
    public void afterCompletion(HttpServletRequest request, HttpServletResponse response, Object handler, Exception ex) throws Exception {
        MDC.remove("traceId");
    }
}

调用链追踪利器 MDC日常工作中排查线上问题，经常会遇到一些问题：线上系统某次调用异常，是哪笔订单的什么操作造成的？是

啥是traceId ？

traceId：用于标识某一次具体的请求ID。通过 traceId 来将一个请求在各个服务器上的调用日志串联起来。

traceId 一般由接收请求经过的第一个服务产生。

traceId 与 spanId 区别：

traceId 是用于串联某一次请求在系统中经过的所有路径
spanId是用于区分系统不同服务之间调用的先后关系

traceId 生成规则

SkyWalking里TraceId 组成规则：

github.com/apache/skyw…

这里我们参考阿里的鹰眼组件的 TraceId 生成的规则。

生成规则如下：服务器 IP + ID 产生的时间 + 自增序列 + 当前进程号，比如：

0ad1348f1403169275002100356696
共 30 位

0	1	2	3	4	5	6	7	8	9	10	11	12	13	14	15	16	17	18	19	20	21	22	23	24	25	26	27	28	29
服务器IP，十六进制：0ad1348f	时间戳，1403169275002	自增序列，1003	当前进程ID

前8位：0-7，产生 TraceId 的机器的 IP，这是一个十六进制的数字，每两位代表 IP 中的一段。

- 按每两位转成 10 进制即可得到常见的 IP 地址表示方式 10.209.52.143

再13位：8-20，产生 TraceId 的时间
再4位：自增的序列，从 1000 -> 9000，到9000后再回到 1000
最后5位：当前的进程 ID，防止单机多进程出现 TraceId 冲突的情况

- Thread.currentThread().getId();

二、最佳实践

前端交互

前端与后端交互，诉求只想知道这次调用对应后端哪次调用链，方便排查问题。所以只需要告诉前端，这次请求的 traceId 是多少。

traceId：一般会在返回体的 Header 和 Body 中体现。

举个 🌰 栗子，在 HTTP 的 Response 的 Header中体现：X-Tracking-Id

调用链追踪利器 MDC日常工作中排查线上问题，经常会遇到一些问题：线上系统某次调用异常，是哪笔订单的什么操作造成的？是

举个 🌰 栗子，在 HTTP 的 Response 的 Body 中体现：traceId

{
    "code": 0,
    "success": true,
    "message": null,
    "traceId": "933ce7302b0b4396a89b1a81747b0e46",
    "data": {}
}

服务间交互

（1）服务间交互：Feign、Dubbo

Feign 请求拦截器中塞入 traceId：

@Slf4j
public class FeignRequestInterceptor extends BasicAuthRequestInterceptor {
    @Override
    public void apply(RequestTemplate template) {
        
        template.header("X-Tracking-ID", MDC.get("traceId"));
    }
}

Dubbo 消费者获取 traceId：

@Slf4j
@Activate(group = {Constants.CONSUMER}, order = -99999)
public class TrackIdConsumerFilter implements Filter {

    @Override
    public Result invoke(Invoker<?> invoker, Invocation invocation) throws RpcException {
        String tid = MDC.get("traceId");
        if (StringUtils.isBlank(tid)) {
            tid = UUIDUtils.UUID32();
        }
        RpcContext.getContext().setAttachment("traceId", tid);
        return invoker.invoke(invocation);
    }

    @Override
    public Result onResponse(Result result, Invoker<?> invoker, Invocation invocation) {
        return Filter.super.onResponse(result, invoker, invocation);
    }
}

Dubbo 生产者塞入 traceId：

@Slf4j
@Activate(group = {Constants.PROVIDER}, order = -99999)
public class TrackIdProviderFilter implements Filter {

    @Override
    public Result invoke(Invoker<?> invoker, Invocation invocation) throws RpcException {
        String tid = invocation.getAttachment("traceId");
        if (StringUtils.isBlank(tid)) {
            tid = UUIDUtils.UUID32();
        }
        MDC.put("traceId", tid);
        try {
            return invoker.invoke(invocation);
        } finally {
            MDC.clear();
        }
    }

    @Override
    public Result onResponse(Result result, Invoker<?> invoker, Invocation invocation) {
        return Filter.super.onResponse(result, invoker, invocation);
    }
}

（2）MQ消息 / XXL-JOB 传递

这类可以封装对应注解，用 AOP 来统一处理下。

注解：@TraceId
AOP：TraceIdAspect

@Target({ElementType.METHOD})
@Retention(RetentionPolicy.RUNTIME)
public @interface XTraceId {
}

@Aspect
@Component
@Slf4j
public class TraceIdAspect {

    @Pointcut("@annotation(com.server.annotation.TraceId)")
    public void annotationPointCut() {
    }

    @Around("annotationPointCut()")
    public Object doAround(ProceedingJoinPoint pjp) throws Throwable {
        String traceId = UUIDUtils.nextId("");
        MDC.put("traceId", traceId);
        try {
            return pjp.proceed();
        } finally {
            
            MDC.remove("traceId");
        }
    }
}

举个 🌰 栗子，在 RocketMQ 中消息者消费消息时：

消费者执行消息时，用 traceId 把单次调用链串联起来。

@Slf4j
@Component
@RequiredArgsConstructor
public class ConsumerListener implements MessageListener {
    @TraceId
    @Override
    public Action consume(Message message, ConsumeContext context) {
        try {
            // 业务处理
            return Action.CommitMessage;
        } catch (Exception e) {
            // 异常处理
            return Action.ReconsumeLater;
        }
    }
}

举个 🌰 栗子，XXL-JOB 中使用：

@Slf4j
@Component
@JobHandler
@RequiredArgsConstructor
public class PushXXRobotContactJob extends IJobHandler {
    // 加上注解
    @TraceId
    @Override
    public ReturnT<String> execute(String param) {
        return ReturnT.SUCCESS;
    }
}

（3）多线程（父子线程）

由于 MDC 是基于 ThreadLocal 实现，上下文信息是线程私有的，并且 ThreadLocal 变量具有不继承性，所以如果代码中使用了多线程，traceId 是无法自动传递的。

官方建议： https://logback.qos.ch/manual/mdc.html

在父线程新建子线程之前调用 MDC.getCopyOfContextMap() 方法将 MDC 内容取出来传给子线程
子线程在执行操作前先调用 MDC.setContextMap() 方法将父线程的 MDC 内容设置到子线程

方式一：使用 Decorator

public class TraceIdTaskDecorator implements TaskDecorator {
    @Override
    public Runnable decorate(Runnable runnable) {
        Map<String, String> context = MDC.getCopyOfContextMap();
        
        return () -> {
            try {
                MDC.setContextMap(context);
                
                runnable.run();
            } finally {
                
                MDC.clear();
            }
        };
    }
}

🌰 栗子1： @Async

@Slf4j
@Configuration
@EnableAsync
public class AsyncConfig implements AsyncConfigurer {

    @Override
    public Executor getAsyncExecutor() {
        ThreadPoolTaskExecutor executor = new ThreadPoolTaskExecutor();
        executor.setCorePoolSize(3);
        executor.setMaxPoolSize(10);
        executor.setQueueCapacity(100);
        executor.setThreadNamePrefix("AsyncThread-");
        executor.setTaskDecorator(MdcTaskDecorator::new);
        executor.initialize();
        return executor;
    }

    private static class MdcTaskDecorator implements Runnable {

        private final Runnable delegate;

        public MdcTaskDecorator(Runnable delegate) {
            this.delegate = delegate;
        }

        @Override
        public void run() {
            String traceId = MDC.get("traceId");
            if (StringUtils.isNotBlank(traceId)) {
                MDC.put("traceId", traceId);
            }
            try {
                delegate.run();
            } finally {

                MDC.clear();
            }
        }
    }
}

方式二：使用 InheritableThreadLocal 对象

public class UserInheritableUtils {
    private static final InheritableThreadLocal<String> THREAD_LOCAL = new InheritableThreadLocal<>();

    public static String get(){
        return THREAD_LOCAL.get();
    }
    public static void set(String val){
        THREAD_LOCAL.set(val);
    }

    public static void clear(){
        THREAD_LOCAL.remove();
    }
}

ThreadLocal 变量的不继承性

在使用 ThreadLocal 存储本地变量时，主线程与子线程之间不具有继承性。

在主线程中使用 ThreadLocal 对象保存本地变量后，无法通过同一个 ThreadLocal 对象获取到主线程中保存的只。

🌰 栗子1：子线程获取主线程的值

public class ThreadLocalTest {
    private static final ThreadLocal<String> THREAD_LOCAL = new ThreadLocal<>();

    public static void main(String[] args) {
        THREAD_LOCAL.set("main_thread_donald"); // 主线程保存值

        new Thread(() -> {
            // 子线程获取对应的值
            System.out.println("在子线程中获取到的本地变量的值为：" + THREAD_LOCAL.get());
        }).start();

        System.out.println("在主线程中获取到的本地变量的值为：" + THREAD_LOCAL.get());
    }
}

输出结果如下：

结论：在主线程中通过 ThreadLocal 对象保存值后，在子线程中通过相同的 ThreadLocal 对象是无法获取到这个值的。

在主线程中获取到的本地变量的值为：main_thread_donald
在子线程中获取到的本地变量的值为：null

Process finished with exit code 0

🌰 栗子2：InheritableThreadLocal 使用

如果需要在子线程中获取到主线程中保存的值，则可以使用 InheritableThreadLocal 对象。

public class InheritableThreadLocalTest {
    private static final ThreadLocal<String> THREAD_LOCAL = new InheritableThreadLocal<>();

    public static void main(String[] args) {
        THREAD_LOCAL.set("main_thread_donald"); // 主线程保存值

        new Thread(() -> {
            // 子线程获取对应的值
            System.out.println("在子线程中获取到的本地变量的值为：" + THREAD_LOCAL.get());
        }).start();

        System.out.println("在主线程中获取到的本地变量的值为：" + THREAD_LOCAL.get());
    }
}

输出结果如下：

结论：在主线程中通过 InheritableThreadLocal 对象保存值后，在子线程中通过相同的 InheritableThreadLocal 对象是可以获取到这个值的。

在主线程中获取到的本地变量的值为：main_thread_donald
在子线程中获取到的本地变量的值为：main_thread_donald

Process finished with exit code 0

（4）sls 接入日志/查看

日常工作中，查询日志依赖阿里云的 sls。排查问题，会跟根据告警信息中的 traceId 进行查询。

接收告警信息：文本中带有 traceId
根据 traceId 查询调用链

调用链追踪利器 MDC日常工作中排查线上问题，经常会遇到一些问题：线上系统某次调用异常，是哪笔订单的什么操作造成的？是

转载自:https://juejin.cn/post/7410951286861316134

调用链追踪利器 MDC日常工作中排查线上问题，经常会遇到一些问题： 线上系统某次调用异常，是哪笔订单的什么操作造成的？是

一、前言

啥是 MDC ？

快速入门

啥是traceId ？

traceId 生成规则

二、最佳实践

前端交互

服务间交互

（1）服务间交互：Feign、Dubbo

（2）MQ消息 / XXL-JOB 传递

（3）多线程（父子线程）

方式一：使用 Decorator

方式二：使用 InheritableThreadLocal 对象

（4）sls 接入日志/查看

调用链追踪利器 MDC日常工作中排查线上问题，经常会遇到一些问题：线上系统某次调用异常，是哪笔订单的什么操作造成的？是