Я пытаюсь реализовать Slueth для распределенной трассировки микросервисов весенней загрузки, которые взаимодействуют друг с другом по каналу обмена сообщениями.
Один из этих микросервисов - это планировщик, который выбирает новых потребителей, созданных за день. Затем он запускает процесс группировки данных каждого потребителя в асинхронном режиме.
Теперь я использую 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, заключается в том, что эти дочерние потоки, в свою очередь, будут публиковать сообщения для нижестоящих служб. Поскольку планировщик должен запускаться только один раз в день, журнал каждого потребителя в течение дня в конечном итоге будет иметь один и тот же идентификатор трассировки, что приведет к поражению всей цели трассировки.
Исходные журналы для двух запусков планировщика с одинаковым идентификатором трассировки для каждого потребителя
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. Это ожидаемый способ реализации этого или есть более элегантное решение, в котором просто запуск новой трассировки добавит значения в 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
