reactor / reactor-core

Non-Blocking Reactive Foundation for the JVM
http://projectreactor.io
Apache License 2.0
4.93k stars 1.2k forks source link

Automatic context propagation not working with subscribed sink mono #3887

Closed mrodal-onlab closed 3 weeks ago

mrodal-onlab commented 3 weeks ago

Expected Behavior

Found the issue using spring-statemachine. Somewhere in the statemachine the logging context was getting lost. Debugging I found the part where this was happening, and could extract a small code sample that reproduces the error. The error happens when using Hooks.enableAutomaticContextPropagation(); and it works as expected when not using it.

Actual Behavior

Context is not being propagated when using Hooks.enableAutomaticContextPropagation();

Steps to Reproduce

void reproCase() {
  log.info(MDC.getCopyOfContextMap().toString()); // Logging context found
  var sink = Sinks.one();

  sink.asMono().flatMap(s->{
      log.info(MDC.getCopyOfContextMap().toString()); // Logging context missing
      return Mono.just(1);
  }).subscribe();

  sink.emitValue("", Sinks.EmitFailureHandler.FAIL_FAST);
}

Your Environment

chemicL commented 3 weeks ago

Can you share how you are populating the MDC and what you expect would propagate the MDC?

mrodal commented 3 weeks ago

Im not populating the MDC, it is being populated by micrometer I believe. Heres a sample application: https://github.com/mrodal/issue-context-propagation

Its just a controller with the code above and the application starter with the Hooks.enableAutomaticContextPropagation();

chemicL commented 3 weeks ago

Ok. I'm not sure what exactly you are trying to achieve, but you are creating a disconnected pipeline when you call .subscribe(). Essentially, all that is present in the MDC is coming from Context associated with the incoming request. The gist is - you return some Flux/Mono in your controllers to which the framework subscribes. A Subscriber carries a Context that represents an Observation associated with that request processing. Micrometer-Tracing takes care of populating the MDC with trace-id/span-id metadata taken from the Observation that is present in the Context. Once you create another Flux/Mono which does not form a reactive chain with the existing Subscriber then it contains an empty Context that does not have that Observation. This fire-and-forget pattern can lead to such issues. Consider asking a question on Gitter or StackOverflow how to best structure your code for the actual use case that you have and make sure you consult our reference documentation on this.

mrodal commented 3 weeks ago

The example code is a simplification of the spring-statemachine library code. I'll check over there if they can find a workaround Thank you