javalogbackmdcvirtual-threadsproject-loom

Logback: availability of MDCs in forks created inside a StructuredTaskScope


When using StructuredTaskScope from JEP 453 in Java 21+ and forking multiple tasks, I'd like to have MDC values propagated to the forks, so that all logs are properly correlated.

Extending the example from the JEP, I'd like all three logs to carry the same MDC values:

Response handle() throws ExecutionException, InterruptedException {
  try (var scope = new StructuredTaskScope.ShutdownOnFailure()) {
    // TODO: set MDC "somehow"

    Supplier<String>  user  = scope.fork(() -> logger.info("1"));
    Supplier<Integer> order = scope.fork(() -> logger.info("2"));

    scope.join().throwIfFailed();

    logger.info("3");
    return new Response(user.get(), order.get());
  }
}

The problem is that MDCs aren't inherited, which might be less of a problem in pre-virtual-threads Java. However, now that creating new threads is cheap & encouraged, inheriting MDCs might be much more useful and common.

My initial attempts to solve this centred around using ScopedValues (JEP 429). Unlike ThreadLocals, such values are inherited by scope's forks, so they seem good candidates to carry the MDC markers.

To implement this, I'd have to either directly access a ScopedValue from within Logback's logging components (is that possible?), or to manipulate the MDC. I tried overwriting the MDCAdapter, but this has failed (Logback doesn't seem to use e.g. MDCAdapter.get to actually read the MDC's value).


Solution

  • The OP's idea of using ScopedValaue for storing and accessing MDC context of subtasks, created by StructuredTaskScope.fork, seems to be a most natural way to extend MDC context to them.

    This approach is implemented in a small POC Spring Boot application here.

    Custom implementation of MDCContext aggregates two MDC Contexts, one is root context, ThreadLocal-bound in the most cases. This root context holds the values, set in a "main" thread, in the terms of the code snippet, brought in the question, it corresponds to line // TODO: set MDC "somehow". Another one, subtask context, is used for accessing and setting the MDC context values in the subtasks' threads when root ThreadLocal-bound MDC context is unavailable.

    A ScopedValaue variable, which holds the subtask context, is declared inside of this custom MDCContext, it binds to an instance of this context at the time of constructing of StructuredTaskScope:

    ScopedValue.runWhere(SUBTASK_CONTEXT, new SubtaskContext()),  () -> {
        try (var scope = new StructuredTaskScope.ShutdownOnFailure()) {
    
            Supplier<String>  user  = scope.fork(() -> logger.info("1"));
            Supplier<Integer> order = scope.fork(() -> logger.info("2"));
    
            scope.join().throwIfFailed();
    
            ...
        }
    });
    

    Upon a creation of SubtaskContext instance it is necessary to copy the root context into this subtask context to make root values available for subtask threads.

    Finally, to enable this custom implementation of MDCAdapter an implementation of SLF4JServiceProvider returns an instance of this adapter in getMDCAdapter method.

    public class ScopedValueServiceProvider extends ... implements SLF4JServiceProvider {
        
        @Override
        public MDCAdapter getMDCAdapter() {
            // ... return our custom MDC Adapter;
        }
        
    }
        
    

    , this implementation must be specified as a system property, for example, as JVM argument -slf4j.provider=...ScopedValueServiceProvider in the command line.

    Note that, although it has not been targeted in the question, this design is suitable not only for forking by StructuredTaskScope, but also for threads started with ScopedValue.Carrier.run method, like it is discussed in Propagating context through StructuredTaskScope by ScopedValue SO question.