SpringCloud 远程调用日志记录traceId和spanId

最近在项目开发中遇到了一些问题，项目为多机部署，大量日志输出导致很难筛出指定请求的全部相关日志，以及下游服务调用对应的日志。因此计划对项目日志打印进行一些小改造，使用一个traceId跟踪请求的全部路径，前提是不修改原有的打印方式。

简单的解决思路

想要跟踪请求，第一个想到的就是当请求来时生成一个traceId放在ThreadLocal里，然后打印时去取就行了。但在不改动原有输出语句的前提下自然需要日志框架的支持了，搜索的一番发现主流日志框架都提供了MDC功能。

MDC 介绍
MDC（Mapped Diagnostic Context，映射调试上下文）是 log4j 和 logback 提供的一种方便在多线程条件下记录日志的功能。MDC 可以看成是一个与当前线程绑定的Map，可以往其中添加键值对。MDC 中包含的内容可以被同一线程中执行的代码所访问。当前线程的子线程会继承其父线程中的 MDC 的内容。当需要记录日志时，只需要从 MDC 中获取所需的信息即可。MDC 的内容则由程序在适当的时候保存进去。对于一个 Web 应用来说，通常是在请求被处理的最开始保存这些数据。

简而言之，MDC就是日志框架提供的一个InheritableThreadLocal，项目代码中可以将键值对放入其中，然后使用指定方式取出打印即可。

简单总结一下主要思路：

1. 当请求来的时候，用Filter拦截，主要初始化请求的上下文，包括MDC
2. 配置文件中打印MDC中的traceId和spanId
3. 微服务之间调用时，服务调用方需要传递当前的上线文，这个时候解析上下文，spanId自增。

具体代码

• 定义请求上下文，用ThradLocal存储，代码如下：

@Getter
@Setter
public class ProjectContext {

    public static final String CONTEXT_KEY = "CONTEXT_KEY";
    private static final String DEFAULT_SPAN = "1";
    private static final Random RANDOM = new Random();

    /**
     * 每次请求唯一记录值
     */
    private String traceId;

    /**
     * 一次请求的多次处理唯一标记
     */
    private String spanId;

    /**
     * 请求ip
     */
    private String ip;

    private static ThreadLocal<ProjectContext> LOCAL = new TransmittableThreadLocal<>();

    public static ProjectContext getContext() {
        ProjectContext context = LOCAL.get();
        if (Objects.isNull(context)) {
            context = new ProjectContext();
        }

        return context;
    }

    static void nextSpan() {
        if (Objects.isNull(getContext())) {
            initContext();
            return;
        }
        if (Objects.isNull(getContext().getSpanId())) {
            getContext().setSpanId(DEFAULT_SPAN);
            return;
        }

        // 获取当前的spanId
        String span = getContext().getSpanId();
        if (span.endsWith(".")) {
            span = span.substring(0, span.length() - 1);
        }
        // 找到切割位置
        int p = span.lastIndexOf(".");
        String last = span.substring(p + 1);
        // 最后需要自增的原数据
        int lastId = Integer.parseInt(last);
        // 完成自增并设置设置到spanId中
        if (p < 0) {
            getContext().setSpanId(String.valueOf(lastId + 1));
        } else {
            getContext().setSpanId(span.substring(0, p) + (lastId + 1));
        }
    }

    /**
     * 透传上下文
     *
     * @param contextString 被序列化的上下文字符串
     */
    public static void fromString(String contextString) {
        ProjectContext context = GsonUtil.toBean(contextString, ProjectContext.class);

        fromContext(context);
    }

    public static void fromContext(ProjectContext context) {
        LOCAL.set(context);

        nextSpan();
    }

    static void setContext(ProjectContext context) {
        LOCAL.set(context);
    }

    public static void initContext(String ip) {
        initContext();

        ProjectContext context = getContext();

        context.setIp(ip);

        setContext(context);
    }

    public static void initContext() {
        ProjectContext context = new ProjectContext();
        context.setTraceId(String.valueOf(genLogId()));
        context.setSpanId(DEFAULT_SPAN);

        setContext(context);
    }

    public void release() {

    }

    public static long genLogId() {
        return Math.round(((System.currentTimeMillis() % 86400000L) + RANDOM.nextDouble()) * 100000.0D);
    }

    @Override
    public String toString() {
        return GsonUtil.toJson(this);
    }
}

• 定义过滤器，用于拦截所有的请求，初始化traceId和spanId，RequestFilter

@Slf4j
@WebFilter(filterName = "requestWrapperFilter", urlPatterns = "/*")
public class RequestFilter implements Filter {
    public static final String TRACE_ID = "trace";
    public static final String SPAN_ID = "span";

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

    /**
     * 初始化请求链路信息：唯一key，日志初始化，body包装防止获取日志打印时后续不能继续使用
     */
    @Override
    public void doFilter(ServletRequest request, ServletResponse response, FilterChain chain) throws IOException, ServletException {
        String contextString = ((HttpServletRequest) request).getHeader(ProjectContext.CONTEXT_KEY);
        if (Objects.nonNull(contextString)) {
            ProjectContext.fromString(contextString);
        } else {
            // 无内容时，也自动初始化
            ProjectContext.initContext();
        }
        initLog();
        chain.doFilter(request, response);
    }

    @Override
    public void destroy() {
    }

    public static void initLog() {
        MDC.put(TRACE_ID, ProjectContext.getContext().getTraceId());
        MDC.put(SPAN_ID, ProjectContext.getContext().getSpanId());
    }
}

• 定义feign的请求拦截器，传递当前上下文信息，FeignClientInterceptor

public class FeignClientInterceptor implements RequestInterceptor {
    @Override
    public void apply(RequestTemplate requestTemplate) {
        try {
            ProjectContext projectContext = ProjectContext.getContext();
            if (Objects.nonNull(projectContext)) {
                requestTemplate.header(CONTEXT_KEY, projectContext.toString());
            }
        } catch (Exception e) {
            e.printStackTrace();
        }
    }
}

测试

• 启动service-hi服务，代码位置：https://github.com/fafeidou/fast-cloud-nacos/tree/master/fast-cloud-nacos-examples/cloud-rpc-examples/service-hi

• 启动service-feign服务，代码位置：https://github.com/fafeidou/fast-cloud-nacos/tree/master/fast-cloud-nacos-examples/cloud-rpc-examples/service-feign

访问 http://localhost:9100/hi?name=456

可以看到spanId 的自增，同一个请求traceId是一样的。