2

我正在尝试为 Spring Boot 微服务的分布式跟踪实现 Slueth,这些微服务通过消息传递通道相互通信。

其中一个微服务是一个调度程序,它可以挑选一天创建的新消费者。然后它以异步方式为每个消费者的数据运行分组过程。

现在我正在使用 traceableExeucutorService 将调度程序线程生成的侦探跟踪传递给每个消费者的子线程。

跟踪配置

@EnableScheduling
@Configuration
public class TracingConfig implements SchedulingConfigurer {

    @Override
    public void configureTasks(ScheduledTaskRegistrar scheduledTaskRegistrar) {
        scheduledTaskRegistrar.setScheduler(schedulingExecutor());
    }

    @Bean(destroyMethod = "shutdown")
    public Executor schedulingExecutor() {
        return Executors.newScheduledThreadPool(1);
    }

    @Bean
    public Executor traceAbleExecutorService(BeanFactory factory) {
        return new TraceableExecutorService(factory, Executors.newFixedThreadPool(10));
    }

} 

调度服务

@Slf4j
@Service
public class ConsumerScheduler {

    @Autowired
    Executor traceAbleExecutorService;

    @Scheduled(cron = "0/5 * * * * *")
    public void testScheduler() {

        log.info("Running scheduler");

        List<String> consumers = new ArrayList<>();
        consumers.add("Consumer1");
        consumers.add("Consumer2");

        consumers.forEach(
                consumer -> CompletableFuture.runAsync(() -> getConsumerData(consumer), traceAbleExecutorService));

        log.info("Completed scheduler");

    }

    private void getConsumerData(String consumer) {

        log.info("Running {}", consumer);
        log.info("Logging Data for {}", consumer);

    }

}

这最终会为每个消费者使用相同的 traceId,因此所有下游服务都会为每个消费者记录相同的 traceId。

我希望每个消费者线程都有自己的 traceId 的原因是这些子线程将依次将消息发布到下游服务。由于调度程序应该每天只运行一次,因此每个消费者一天的日志最终都会具有相同的 traceId 并破坏了跟踪的整个目的。

两个调度程序的原始日志运行,每个消费者使用相同的 traceId

2020-02-01 13:22:05.025  INFO [,c4b8535556794e6d,c4b8535556794e6d,false] 6528 --- [pool-2-thread-1] com.example.demo.ConsumerScheduler       : Running scheduler
2020-02-01 13:22:05.036  INFO [,c4b8535556794e6d,c4b8535556794e6d,false] 6528 --- [pool-2-thread-1] com.example.demo.ConsumerScheduler       : Completed scheduler
2020-02-01 13:22:05.036  INFO [,c4b8535556794e6d,3a05952293179b5f,false] 6528 --- [pool-1-thread-2] com.example.demo.ConsumerScheduler       : Running Consumer2
2020-02-01 13:22:05.036  INFO [,c4b8535556794e6d,cba00b8dd7edc99c,false] 6528 --- [pool-1-thread-1] com.example.demo.ConsumerScheduler       : Running Consumer1
2020-02-01 13:22:05.040  INFO [,c4b8535556794e6d,cba00b8dd7edc99c,false] 6528 --- [pool-1-thread-1] com.example.demo.ConsumerScheduler       : Logging Data for Consumer1
2020-02-01 13:22:05.040  INFO [,c4b8535556794e6d,3a05952293179b5f,false] 6528 --- [pool-1-thread-2] com.example.demo.ConsumerScheduler       : Logging Data for Consumer2
2020-02-01 13:22:10.002  INFO [,5ad7e1a6ddc176e4,5ad7e1a6ddc176e4,false] 6528 --- [pool-2-thread-1] com.example.demo.ConsumerScheduler       : Running scheduler
2020-02-01 13:22:10.003  INFO [,5ad7e1a6ddc176e4,5ad7e1a6ddc176e4,false] 6528 --- [pool-2-thread-1] com.example.demo.ConsumerScheduler       : Completed scheduler
2020-02-01 13:22:10.003  INFO [,5ad7e1a6ddc176e4,e2fe5d0c4abc0f4b,false] 6528 --- [pool-1-thread-3] com.example.demo.ConsumerScheduler       : Running Consumer1
2020-02-01 13:22:10.003  INFO [,5ad7e1a6ddc176e4,e2fe5d0c4abc0f4b,false] 6528 --- [pool-1-thread-3] com.example.demo.ConsumerScheduler       : Logging Data for Consumer1
2020-02-01 13:22:10.003  INFO [,5ad7e1a6ddc176e4,d3d0d18d896a2602,false] 6528 --- [pool-1-thread-4] com.example.demo.ConsumerScheduler       : Running Consumer2
2020-02-01 13:22:10.003  INFO [,5ad7e1a6ddc176e4,d3d0d18d896a2602,false] 6528 --- [pool-1-thread-4] com.example.demo.ConsumerScheduler       : Logging Data for Consumer2

所以我在异步操作调用的方法中创建了一个新的 Tracer,但我仍然看到主线程的 traceId 被记录。所以我不得不手动提取traceId和spanId,然后将其添加到ThreadContext。这是实现这一点的预期方式,还是有一个更优雅的解决方案,只需启动一个新的 Trace 就会将值添加到 ThreadContext。

更新了 getConsumerData

private void getConsumerData(String consumer) {

        Span span = Tracing.currentTracer().newTrace().start();

        try {

            String traceId = span.context().traceIdString();
            String spanId = span.context().spanIdString();
            String parentId = span.context().parentIdString();

            ThreadContext.put("traceId", traceId);
            ThreadContext.put("X-B3-TraceId", traceId);
            ThreadContext.put("spanId", spanId);
            ThreadContext.put("X-B3-SpanId", spanId);
            ThreadContext.put("parentId", parentId);
            ThreadContext.put("X-B3-ParentId", parentId);

            log.info("Running {}", consumer);
            log.info("Logging Data for {}", consumer);

        } finally {
            span.finish();
        }
    }

使用消费者级别 TraceId 更新日志

2020-02-01 13:30:40.022  INFO [,46fb0ea5afb9accc,46fb0ea5afb9accc,false] 14796 --- [pool-2-thread-1] com.example.demo.ConsumerScheduler       : Running scheduler
2020-02-01 13:30:40.029  INFO [,46fb0ea5afb9accc,46fb0ea5afb9accc,false] 14796 --- [pool-2-thread-1] com.example.demo.ConsumerScheduler       : Completed scheduler
2020-02-01 13:30:40.048  INFO [,06eacdb987cafe11,06eacdb987cafe11,false] 14796 --- [pool-1-thread-1] com.example.demo.ConsumerScheduler       : Running Consumer1
2020-02-01 13:30:40.048  INFO [,9273140d294add25,9273140d294add25,false] 14796 --- [pool-1-thread-2] com.example.demo.ConsumerScheduler       : Running Consumer2
2020-02-01 13:30:40.052  INFO [,9273140d294add25,9273140d294add25,false] 14796 --- [pool-1-thread-2] com.example.demo.ConsumerScheduler       : Logging Data for Consumer2
2020-02-01 13:30:40.052  INFO [,06eacdb987cafe11,06eacdb987cafe11,false] 14796 --- [pool-1-thread-1] com.example.demo.ConsumerScheduler       : Logging Data for Consumer1
2020-02-01 13:30:45.002  INFO [,ba63c9342b2bb82d,ba63c9342b2bb82d,false] 14796 --- [pool-2-thread-1] com.example.demo.ConsumerScheduler       : Running scheduler
2020-02-01 13:30:45.003  INFO [,ba63c9342b2bb82d,ba63c9342b2bb82d,false] 14796 --- [pool-2-thread-1] com.example.demo.ConsumerScheduler       : Completed scheduler
2020-02-01 13:30:45.003  INFO [,dac9c7bbc7c4a312,dac9c7bbc7c4a312,false] 14796 --- [pool-1-thread-3] com.example.demo.ConsumerScheduler       : Running Consumer1
2020-02-01 13:30:45.003  INFO [,dac9c7bbc7c4a312,dac9c7bbc7c4a312,false] 14796 --- [pool-1-thread-3] com.example.demo.ConsumerScheduler       : Logging Data for Consumer1
2020-02-01 13:30:45.003  INFO [,4eda4d2c9ec95b50,4eda4d2c9ec95b50,false] 14796 --- [pool-1-thread-4] com.example.demo.ConsumerScheduler       : Running Consumer2
2020-02-01 13:30:45.003  INFO [,4eda4d2c9ec95b50,4eda4d2c9ec95b50,false] 14796 --- [pool-1-thread-4] com.example.demo.ConsumerScheduler       : Logging Data for Consumer2
4

1 回答 1

0

问题是跨度不负责使自己成为当前(范围)。示踪剂是。你需要更新这个:

 Span span = Tracing.currentTracer().newTrace().start();

对此:

Span newSpan = Tracing.currentTracer().newTrace().start();
tracer.withSpanInScope( newSpan );

跟踪器的实例可以自动装配:

@Autowired
private Tracer tracer;
于 2021-04-01T13:58:37.827 回答