SpringBoot Reactive WebClient - TraceId is not propagated to scope function

TraceId is not correctly propagated to scope function after a reactive WebClient call.

Demo project is available here

current output:

[6750294cfcbdfb64f056ab0605a90d48-f056ab0605a90d48] com.example.demo.Service                 : Hello, World!
[6750294cfcbdfb64f056ab0605a90d48-f056ab0605a90d48] com.example.demo.Service                 : another log message
[6750294cfcbdfb64f056ab0605a90d48-f056ab0605a90d48] com.example.demo.ServiceClient           : Response received
[                                                 ] com.example.demo.ServiceClient           : Log from also block

expected:

[6750294cfcbdfb64f056ab0605a90d48-f056ab0605a90d48] com.example.demo.Service                 : Hello, World!
[6750294cfcbdfb64f056ab0605a90d48-f056ab0605a90d48] com.example.demo.Service                 : another log message
[6750294cfcbdfb64f056ab0605a90d48-f056ab0605a90d48] com.example.demo.ServiceClient           : Response received
[6750294cfcbdfb64f056ab0605a90d48-f056ab0605a90d48] com.example.demo.ServiceClient           : Log from also block

Comment From: philwebb

I believe this is the expected behavior, @bclozel or @sdeleuze might be able to confirm for sure. The observation is only active whilst the exchange is in progress (see this code).

Your .also { log.info("Log from also block") } call happens after the exchange has completed and therefore outside of the observation.

Comment From: philwebb

Actually, I take that back. I see now that the trace ID should remain since it's a child of the Service call. I think this will need input from the Framework or Micrometer team.

Comment From: bclozel

This log statement does not print the traceId because there is no traceId in the current coroutine execution context; "also" is a coroutine operator:

.also {
    log.info("Log from also block")
}

"map" is a reactor operator and reactor reinstates threadlocals registered with the context propagation library; this log statement prints the traceId because the TraceId has been reinstated by reactor as a threadlocal. This has been enabled with Hooks.enableAutomaticContextPropagation() in your main application class (also see https://docs.spring.io/spring-boot/appendix/application-properties/index.html#application-properties.core.spring.reactor.context-propagation if you would like to use a property instead):

.map {
    log.info("Response received")
    it
}

So to summarize: * blocking code is executed on a thread with ThreadLocals * reactor is non-blocking and operators can reinstate threadlocals in operators, by looking at the reactor context * coroutines are non-blocking and it can reinstate threadlocals in operators, but this must be done manually with the coroutine context

I've amended your sample with the PropagationContextElement class taken from https://github.com/spring-projects/spring-framework/issues/32165#issuecomment-1920986138 and the following:

suspend fun getString(): String {
    return withContext(PropagationContextElement(coroutineContext)) {
        client
            .get()
            .retrieve()
            .toEntity(String::class.java)
            .map {
                log.info("Response received")
                it
            }
            .awaitSingle()
            .body!!
            .also {
                log.info("Log from also block")
            }
    }
}

This logs:

2024-12-05T08:53:59.143+01:00  INFO [,67515c1779afeb3d47c600ee55d23b98,47c600ee55d23b98] 7306 --- [ctor-http-nio-3] [67515c1779afeb3d47c600ee55d23b98-47c600ee55d23b98] com.example.demo.Service                 : Hello, World!
2024-12-05T08:53:59.143+01:00  INFO [,67515c1779afeb3d47c600ee55d23b98,47c600ee55d23b98] 7306 --- [ctor-http-nio-3] [67515c1779afeb3d47c600ee55d23b98-47c600ee55d23b98] com.example.demo.Service                 : another log message
2024-12-05T08:53:59.406+01:00  INFO [,67515c1779afeb3d47c600ee55d23b98,47c600ee55d23b98] 7306 --- [ctor-http-nio-3] [67515c1779afeb3d47c600ee55d23b98-47c600ee55d23b98] com.example.demo.ServiceClient           : Response received
2024-12-05T08:53:59.407+01:00  INFO [,67515c1779afeb3d47c600ee55d23b98,47c600ee55d23b98] 7306 --- [ctor-http-nio-3] [67515c1779afeb3d47c600ee55d23b98-47c600ee55d23b98] com.example.demo.ServiceClient           : Log from also block

I'm closing this as a duplicate of I think this is a duplicate of https://github.com/spring-projects/spring-framework/issues/32165

If you believe this feature should be supported, please vote for https://github.com/Kotlin/kotlinx.coroutines/issues/4187