Logback: availability of MDCs in forks created inside a StructuredTaskScope

Question

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).

Metanephros

Have you checked this discussion? – Security

@Security yes, although there's no conclusion there - ScopedValues are inherited, while ThreadLocals are not, and virtual threads encourage a style of programming where forking new threads is cheap. I tried substituting the MDCAdapter, but it doesn't seem to work. – Metanephros

As for Logback not using MDC values I have different impression. Could you check out this small example? In this example Logback does use MDC values injected by a web app filter. However, everything depends on your usage of MDC. Is it similar to my example? Or something like here? As for Scoped Values, the answer will also depend on your MDC and threads usage. – Security

I edited the question, hopefully it is clearer now and will get reopened – Metanephros

@Security Oh yes, logback does use MDCs as long as they are used (via a logging statement) in the same thread, in which they are added. The problem is they don't get inherited when there are child virtual threads created (as in the example above) – Metanephros

Thanks for clarification, now your issue is crystal clear. I applied for reopening. I think I might have some kind of solution for this problem, at the moment I am unsure where to place it... Logback MDC handling, however, does not allow to have custom MDC adapter in a clean way. – Security

Looks like the reopening won't happen too soon, if ever. Please have a look on my draft solution. In a case you want to discuss something there, I opened a discussion. Please feel free to push your changes. – Security

Ah the ScopedValueServiceProvider was the component that I was missing - thank you! That answers the question, though you probably might write a proper answer (not in a comment), so that it can get accepted. – Metanephros

Sure, will do as the question is now reopened. Please be aware that this custom Provider is to large extent a copy-paste job from LogbackServiceProvider which is not good, but ... – Security

@Security yeah I saw that, but I guess until Logback itself provides better hooks, that's as good as it gets :) – Metanephros

Please see if my answer corresponds your vision. I had to explain few things I didn't quite realize before. – Security

Answer 1

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.

Security