Запуск нового Sleuth Tracer для Completable Futures - PullRequest
Новая
       59

Запуск нового Sleuth Tracer для Completable Futures

0 голосов
/ 01 февраля 2020

Я пытаюсь внедрить Slueth для распределенной трассировки для микросервисов с пружинной загрузкой, которые взаимодействуют друг с другом по каналу обмена сообщениями.

Одним из этих микросервисов является планировщик, который отбирает новых потребителей, созданных за день. Затем он запускает процесс группировки данных каждого потребителя асинхронно c.

Теперь я использую traceableExeucutorService для передачи трассировки секретности, созданной для потока планировщика, дочерним потокам для каждого потребителя.

TracingConfig 

@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, заключается в том, что эти дочерние потоки, в свою очередь, публикуют sh сообщения для последующих служб. Поскольку планировщик должен запускаться только один раз в день, каждый журнал потребителя в течение дня будет иметь один и тот же 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 в методе, вызываемом операцией asyn c, но я все еще вижу, что traceId основного потока регистрируется. Поэтому мне пришлось вручную извлечь traceId и spanId, а затем добавить это в ThreadContext. Является ли это ожидаемым способом реализации этого или есть более элегантное решение, при котором простой запуск новой трассировки добавит значения в 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
...