ReactiveCrudRepository.save is loosing Tracing context

[mzalewski82]

I'm using Spring Boot 3.2.2 with reactive stack. When I added micrometer tracing I noticed that calls to ReactiveCrudRepository are dropping/resetting tracing context. Call to a repo and all subsequent calls in the same flow are exported to Jaeger with a new TraceID.

I tried other flows. Spring Cloud Stream consumer is passing tracing context downstream, producer too. Custom class annotated with @Observed behave as expected too.
The problem appears only if Spring Cloud Stream is the entry point to the app, if it's using REST API (webflux) everything works as expected. I tried to save data to MongoDB and MariaDB (using R2DBC)ReactiveCrudRepository both behave the same way.

I prepared an example app that contains a couple of modules.
https://github.com/mzalewski82/spring-data-reactive-repo-tracing

web exposes REST API, sends data to Kafka using Spring Cloud Stream, saves data to MongoDB using ReactiveCrudRepository.
kafka-stream-reactive-proxy Pure Spring Cloud Stream, read from one Kafka topic and forwards it to another used by other apps.
kafka-stream-reactive-client and kafka-stream-r2dbc-client both read from Kafka using Spring Cloud Stream and save to MongoDB and R2DBC.
kafka-stream-client used to compare with non-reactive flow. Here everything works perfectly.
All reactive modules contain a class HelloSpan annotated with @Observed, to add more visibility to the issue I'm reporting.

1. In web trace started in the endpoint is propagated correctly. Full flow is visible in Jaeger.
2. kafka-stream-reactive-proxy no problems with the tracing context.
3. kafka-stream-reactive-client and kafka-stream-r2dbc-client tracing context is ok until ReactiveCrudRepository call.

I added docker-compose to make it easy to run my example. kafka-stream-r2dbc-client contains a simple sql script too to create necessary schema and table.

[mp911de]

I was able to reproduce the issue running web, kafka-stream-reactive-proxy, and kafka-stream-r2dbc-client.

I'm not quite sure why the issue happens as generally Reactor's Context is being passed on properly. However, once the threads switch from the Kafka container thread (e.g. container-0-C-1) to the Event Loop thread of the driver (e.g. reactor-tcp-nio-10) the thread-local context is gone.

Paging @jonatan-ivanov for further guidance as I'm not familiar with how Project Reactor applies context capture/restore across threads.

[jonatan-ivanov]

The problem appears only if Spring Cloud Stream is the entry point to the app, if it's using REST API (webflux) everything works as expected.

Spring Cloud Stream does not instrument reactive user functions so it can happen that the "scope" is "closed" before your function is invoked which means the context is restored so will not see it any more. Please see the docs, you can also find more details in this issue: spring-cloud/spring-cloud-stream#2782

In order to resolve this, you need to instrument your function which opens a new scope, please see the docs how to do it:

.tap(Micrometer.observation(observationRegistry));

Since this is basically instrumenting Reactor, you can find even more details in the Reactor docs.

You should also add Hooks.enableAutomaticContextPropagation(); to the first line of the main method of every app that should be instrumented and use Reactor. Also, @Observed does not work for methods that return Flux/Mono so I would remove that from the class level (you should use .tap instead).

/cc @olegz, @chemicL

[mp911de]

Thanks a lot, Jonatan. Closing this issue with the intent that Spring Cloud provides the correct instrumentation.