SprigBoot日志：使用traceId跟踪全局请求

Trace ID 简介

Trace ID是一种用于在分布式系统中跟踪请求的唯一标识符。

当一个请求进入系统时，它会被分配一个唯一的Trace ID。随着请求穿过系统中的每个服务，Trace ID会被传递下去，并在每个服务中记录。

利用Trace ID，我们可以追踪请求的路径，并查看请求在每个服务中的处理状态和结果。通过跟踪请求的生命周期，我们也可以确定每个请求需要多长时间才能完成，并且可以查看每个服务的处理时间和性能。

使用Logback的MDC实现请求跟踪

Logback的MDC（Mapped Diagnostic Context）是一种用于在应用程序中跟踪请求或事件的日志记录技术。MDC允许我们在应用程序中存储上下文信息，并在日志记录期间将该信息注入到日志消息中。

MDC的工作方式是将上下文信息存储在一个线程本地的映射（比如 ThreadLocal）中。在应用程序中，可以通过调用MDC.put(key, value)方法将信息存储在MDC中。然后，在记录日志消息时，可以使用类似于${key}的占位符将上下文信息嵌入到日志消息中。

以下是使用Logback的MDC记录日志消息的示例：

日志配置

<?xml version="1.0" encoding="UTF-8"?>
<Configuration>
    <Properties>
        <Property name="LOG_PATTERN">%d{yyyy-MM-dd HH:mm:ss.SSS} [%t] [%X{traceId}] %-5level %logger{36} - %msg%n</Property>
    </Properties>

    <Appenders>
        <Console name="Console" target="SYSTEM_OUT" follow="true">
            <PatternLayout pattern="${LOG_PATTERN}"/>
        </Console>
        <Async name="AsyncConsole" bufferSize="16384" queueSize="500" ringBufferSize="1024" blocking="false">
            <AppenderRef ref="Console"/>
        </Async>
    </Appenders>

    <Loggers>
        <Root level="info">
            <AppenderRef ref="AsyncConsole"/>
        </Root>
    </Loggers>
</Configuration>

Trace ID 生成

package com.teochew;

import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
import org.slf4j.MDC;

import java.util.UUID;

public class MyService {

    private static final Logger log = LoggerFactory.getLogger(MyService.class);

    public static void main(String[] args) {
        String traceId = UUID.randomUUID().toString();
        MDC.put("traceId", traceId);
        log.info("test log");
    }
}

运行结果

在上面的示例中，我们在处理请求之前将请求ID存储在MDC中，然后在日志消息中使用%X{traceId}

占位符引用该值。

线程传递traceId

由于MDC是基于ThreadLocal实现，上下文信息是线程私有的，所以如果代码中使用了多线程，traceId是无法自动传递的。比如下面这段代码及其输出

import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
import org.slf4j.MDC;

import java.util.UUID;
import java.util.concurrent.LinkedBlockingQueue;
import java.util.concurrent.ThreadFactory;
import java.util.concurrent.ThreadPoolExecutor;

import static java.util.concurrent.TimeUnit.SECONDS;

public class MyService {
    private static final ThreadPoolExecutor DEFAULT_EXECUTOR = new ThreadPoolExecutor(20, 80,
            10L, SECONDS, new LinkedBlockingQueue<>(),
            (r) -> {
                int count = 0;
                return new Thread(r, "Thread-" + (++count));
            });

    private static final Logger log = LoggerFactory.getLogger(MyService.class);

    public static void main(String[] args) {
        String traceId = UUID.randomUUID().toString();
        MDC.put("traceId", traceId);
        DEFAULT_EXECUTOR.execute(() -> {
            log.info("test log");
        });
    }
}

我们可以看到，在日志输出中 traceId信息为空，

package com.teochew;

import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
import org.slf4j.MDC;
import org.springframework.scheduling.concurrent.ThreadPoolTaskExecutor;

import java.util.Map;
import java.util.UUID;

public class MyService {
    private static final Logger log = LoggerFactory.getLogger(MyService.class);

    public static void main(String[] args) {
        String traceId = UUID.randomUUID().toString();
        MDC.put("traceId", traceId);
        ThreadPoolTaskExecutor executor = new ThreadPoolTaskExecutor();
				// 修饰器 传递traceId
        executor.setTaskDecorator(runnable -> wrapAsync(runnable, MDC.getCopyOfContextMap()));
        executor.initialize();
        executor.execute(() -> {
            log.info("test log");
        });
    }

    public static Runnable wrapAsync(Runnable task, Map<String, String> context) {
        return () -> {
            if (context == null) {
                MDC.clear();
            } else {
                MDC.setContextMap(context);
            }
            if (MDC.get("traceId") == null) {
                MDC.put("traceId", UUID.randomUUID().toString());
            }
            try {
                task.run();
            } finally {
                MDC.clear();
            }
        };
    }

}

以上代码，我们通过线程修饰器来做traceId的传递，除这种方式外，我们也可以通过ThreadLocal来传递traceId

分布式系统间传递traceId (dubbo)

Dubbo默认集成了Zipkin，在Dubbo服务调用时，Dubbo会自动将TraceId和SpanId等信息写入MDC中，然后在服务调用链路中传递。

在Dubbo服务实现类中，可以使用MDC来获取TraceId：

public class XxxServiceImpl implements XxxService {

    @Override
    public String xxxMethod(String arg) {
        String traceId = MDC.get("traceId");
        // ...
    }
}

在客户端中主动设置TraceId的方式如下

public class XxxClient {

    private static final String TRACE_ID_KEY = "traceId";

    public String xxxMethod(String arg) {
        StringtraceId = UUID.randomUUID().toString();  // 生成新的TraceId
        MDC.put(TRACE_ID_KEY, traceId);  // 将TraceId设置到MDC中
        try {
            // 调用Dubbo服务
            return xxxService.xxxMethod(arg);
        } finally {
            MDC.remove(TRACE_ID_KEY);  // 最后记得从MDC中移除TraceId
        }
    }
}