Spring Cloud 框架使用 Zipkin 打印调用链日志

2019-01-31 本文已影响14人 _晓__

背景

现在使用 Spring Cloud 框架的公司越来越多了，也希望写这篇文章对刚入手 Spring Cloud 的同学有所帮助，对系统做出更好更多的功能。

问题举例

打印 traceId 有何意义？
如何在日志中打印 Zipkin traceId？
如何在子线程或线程池中如何获取 Zipkin traceId 并打印？

所需知识

如何在子线程和线程池中使用 ThreadLocal 传输上下文

问题解决

打印 traceId 意义

分布式环境下，微服务之间的调用错综复杂，如果突然爆出一个错误，虽然有日志记录，但到底是哪个服务出了问题呢？是前端传的参数错误，还是系统X或系统Y提供的接口导致？在这种情况下，错误排查起来就非常费劲。
为了追踪一个请求完整的流转过程，可以给每次请求分配一个唯一的 traceId，当请求调用其他服务时，通过传递这个 traceId。在输出日志时，将这个 traceId 打印到日志文件中，再使用日志分析工具（ELK）从日志文件中搜索，使用 traceId 就可以分析一个请求完整的调用过程，若更进一步，还可以做性能分析。

日志中打印 Zipkin traceId

使用 Spring Cloud 框架整合 Zipkin 特别方便，只需要在 maven pom 文件中配置 spring-cloud-sleuth-zipkin-stream（还需依赖其他 pom，可自行百度），再到 logback-spring.xml 文件中配置日志格式模板，Zipkin 默认 traceId 名称为 X-B3-TraceId。

<property name="log.console_log_pattern" value="[%date] %clr([%level]) [%thread] [traceId:%clr(%X{X-B3-TraceId}){blue}] %clr([%logger]:%L){cyan} >>> %msg %n"/>

子线程或线程池中获取 Zipkin traceId 并打印

经过阅读 Spring Cloud Sleuth 源码，发现 Zipkin 使用 ThreadLocal 来存储 traceId，只能在当前线程获取，无法子线程传递或线程池传递，获取需要改造 Zipkin 使用 TransmittableThreadLocal 存储 traceId，对 TransmittableThreadLocal 不熟悉的同学，可以看 https://www.jianshu.com/p/4093add7f2cd。
通过看源码，发现存储 traceId 的代码逻辑在 SpanContextHolder

class SpanContextHolder {
    private static final ThreadLocal<SpanContextHolder.SpanContext> CURRENT_SPAN = new NamedThreadLocal("Trace Context");
}

而 NamedThreadLocal 继承于 ThreadLocal

public class NamedThreadLocal<T> extends ThreadLocal<T> {
}

然后我们再看哪里调用了 SpanContextHolder 类，我们发现在 DefaultTracer 类中调用了 SpanContextHolder，再看哪里初始化了 DefaultTracer，再追踪到了 TraceAsyncConfiguration类

@Configuration
@ConditionalOnProperty(
    value = {"spring.sleuth.enabled"},
    matchIfMissing = true
)
@EnableConfigurationProperties({TraceKeys.class, SleuthProperties.class})
public class TraceAutoConfiguration {
    @Bean
    @ConditionalOnMissingBean({Tracer.class})
    public DefaultTracer sleuthTracer(Sampler sampler, Random random, SpanNamer spanNamer, SpanLogger spanLogger, SpanReporter spanReporter, TraceKeys traceKeys) {
        return new DefaultTracer(sampler, random, spanNamer, spanLogger, spanReporter, this.properties.isTraceId128(), traceKeys);
    }
}

看到这里，发现 DefaultTracer 的创建使用了 @ConditionalOnMissingBean({Tracer.class}) ，那就说明了只要我们自定义一个 Tracer，TraceAutoConfiguration 中的 DefaultTracer 就不再创建了。

获取 Zipkin traceId 步骤
第一步：
创建自己的 TraceAutoConfiguration 配置类

@Order
@Configuration
@ConditionalOnClass(TraceAsyncAspect.class)
@ConditionalOnProperty(value = {"spring.sleuth.async.enabled", "spring.sleuth.enabled"}, matchIfMissing = true)
@EnableConfigurationProperties({TraceKeys.class, SleuthProperties.class})
public class HtTraceAsyncConfiguration {

    @Autowired
    private SleuthProperties properties;

    @Bean
    public HtTracer sleuthTracer(Sampler sampler, Random random,
                                 SpanNamer spanNamer, SpanLogger spanLogger,
                                 SpanReporter spanReporter, TraceKeys traceKeys) {
        return new HtTracer(sampler, random, spanNamer, spanLogger,
                spanReporter, this.properties.isTraceId128(), traceKeys);
    }
}

第二步：
该配置类里面创建的 Trace 类则是我们自定义类，把原有的 DefaultTracer 拷贝出来改名成我们自定义类名（如上面的 HtTracer）,把 HtTracer 类中使用了 SpanContextHolder 替换成自定义的 SpanContextHolder。

第三步：
创建自定义的 SpanContextHolder ，拷贝 SpanContextHolder 进行改造，把里面使用的 NamedThreadLocal 替换成自定义的 NamedThreadLocal。

class HtSpanContextHolder {
    private static final ThreadLocal<SpanContext> CURRENT_SPAN = new NamedTransmittableThreadLocal<>("Trace Context");
}

第四步：
把 NamedThreadLocal 拷贝进行改造，继承于 TransmittableThreadLocal 即可。

public class NamedTransmittableThreadLocal<T> extends TransmittableThreadLocal<T> {
}

traceId 在子线程或线程池打印到日志中

Log4j2 MDC 集成 TTL

<dependency>
    <groupId>com.alibaba</groupId>
    <artifactId>log4j2-ttl-thread-context-map</artifactId>
    <version>1.2.0</version>
</dependency>

Logback MDC 集成 TTL

<dependency>
    <groupId>com.ofpay</groupId>
    <artifactId>logback-mdc-ttl</artifactId>
    <version>1.0.2</version>
</dependency>

具体使用，可以参考 TTL GitHub：https://github.com/alibaba/transmittable-thread-local