解决使用 Spring Cloud Sleuth 在线程池日志中打印 traceId

概述

随着 Spring Cloud 微服务架构的流行,一次请求往往需要涉及到多个服务,因此服务性能监控和排查就变得更复杂。 通过 APM 帮助理解系统行为、用于分析性能问题的工具,以便发生故障的时候,能够快速定位和解决问题。而 Spring Cloud 提供了 Spring Cloud Sleuth 可快速集成 Zipkin。

问题举例

  • 打印 traceId 有何意义?

  • 如何在日志中打印 Zipkin traceId?

  • 如何在子线程或线程池中如何获取 Zipkin traceId 并打印?

问题解决

打印 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。 通过看源码,发现存储 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}) ,那就说明了只要自定义一个 TracerTraceAutoConfiguration 中的 DefaultTracer 就不再创建了。

解决步骤

第一步: 创建自己的 TraceAutoConfiguration 配置类

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

    @Autowired
    private SleuthProperties properties;

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

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

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

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

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

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

扩展话题

通过上面的问题可以举一反三,只要是跟子线程或者线程池之间的数据传输问题,都可以通过 TransmittableThreadLocal 来处理,如果是在子线程或者线程池内的日志中打印 ThrealLocal 的数据,可以通过如下方式解决:

  • 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>

总结

在上述问题中,使用 TransmittableThreadLocal 解决子线程或者线程池之间的数据传输问题,在我们平时开发过程中,也有很多类似的场景,比如我们使用 ThreadLocal 存储用户信息,但是需要在子线程或者线程池中获取用户数据,我们常用的 shiroAPI SecurityUtils.getSubject()也是通过 InheritableThreadLocal存储 Subject

最后编辑于
©著作权归作者所有,转载或内容合作请联系作者
  • 序言:七十年代末,一起剥皮案震惊了整个滨河市,随后出现的几起案子,更是在滨河造成了极大的恐慌,老刑警刘岩,带你破解...
    沈念sama阅读 206,602评论 6 481
  • 序言:滨河连续发生了三起死亡事件,死亡现场离奇诡异,居然都是意外死亡,警方通过查阅死者的电脑和手机,发现死者居然都...
    沈念sama阅读 88,442评论 2 382
  • 文/潘晓璐 我一进店门,熙熙楼的掌柜王于贵愁眉苦脸地迎上来,“玉大人,你说我怎么就摊上这事。” “怎么了?”我有些...
    开封第一讲书人阅读 152,878评论 0 344
  • 文/不坏的土叔 我叫张陵,是天一观的道长。 经常有香客问我,道长,这世上最难降的妖魔是什么? 我笑而不...
    开封第一讲书人阅读 55,306评论 1 279
  • 正文 为了忘掉前任,我火速办了婚礼,结果婚礼上,老公的妹妹穿的比我还像新娘。我一直安慰自己,他们只是感情好,可当我...
    茶点故事阅读 64,330评论 5 373
  • 文/花漫 我一把揭开白布。 她就那样静静地躺着,像睡着了一般。 火红的嫁衣衬着肌肤如雪。 梳的纹丝不乱的头发上,一...
    开封第一讲书人阅读 49,071评论 1 285
  • 那天,我揣着相机与录音,去河边找鬼。 笑死,一个胖子当着我的面吹牛,可吹牛的内容都是我干的。 我是一名探鬼主播,决...
    沈念sama阅读 38,382评论 3 400
  • 文/苍兰香墨 我猛地睁开眼,长吁一口气:“原来是场噩梦啊……” “哼!你这毒妇竟也来了?” 一声冷哼从身侧响起,我...
    开封第一讲书人阅读 37,006评论 0 259
  • 序言:老挝万荣一对情侣失踪,失踪者是张志新(化名)和其女友刘颖,没想到半个月后,有当地人在树林里发现了一具尸体,经...
    沈念sama阅读 43,512评论 1 300
  • 正文 独居荒郊野岭守林人离奇死亡,尸身上长有42处带血的脓包…… 初始之章·张勋 以下内容为张勋视角 年9月15日...
    茶点故事阅读 35,965评论 2 325
  • 正文 我和宋清朗相恋三年,在试婚纱的时候发现自己被绿了。 大学时的朋友给我发了我未婚夫和他白月光在一起吃饭的照片。...
    茶点故事阅读 38,094评论 1 333
  • 序言:一个原本活蹦乱跳的男人离奇死亡,死状恐怖,灵堂内的尸体忽然破棺而出,到底是诈尸还是另有隐情,我是刑警宁泽,带...
    沈念sama阅读 33,732评论 4 323
  • 正文 年R本政府宣布,位于F岛的核电站,受9级特大地震影响,放射性物质发生泄漏。R本人自食恶果不足惜,却给世界环境...
    茶点故事阅读 39,283评论 3 307
  • 文/蒙蒙 一、第九天 我趴在偏房一处隐蔽的房顶上张望。 院中可真热闹,春花似锦、人声如沸。这庄子的主人今日做“春日...
    开封第一讲书人阅读 30,286评论 0 19
  • 文/苍兰香墨 我抬头看了看天上的太阳。三九已至,却和暖如春,着一层夹袄步出监牢的瞬间,已是汗流浃背。 一阵脚步声响...
    开封第一讲书人阅读 31,512评论 1 262
  • 我被黑心中介骗来泰国打工, 没想到刚下飞机就差点儿被人妖公主榨干…… 1. 我叫王不留,地道东北人。 一个月前我还...
    沈念sama阅读 45,536评论 2 354
  • 正文 我出身青楼,却偏偏与公主长得像,于是被迫代替她去往敌国和亲。 传闻我的和亲对象是个残疾皇子,可洞房花烛夜当晚...
    茶点故事阅读 42,828评论 2 345

推荐阅读更多精彩内容