Utilizing Logging MDC with Virtual Threads

Question

In a typical servlet environment, each request gets its own thread. Adding logging MDC to generate a unique request ID to the request can be achieved with a simple servlet filter.

public void doFilter(ServletRequest request, ServletResponse response, FilterChain chain) throws IOException, ServletException {
    try {
        String requestId = UUID.randomUUID().toString();
        HttpServletResponse httpServletResponse = (HttpServletResponse)response;
        httpServletResponse.setHeader("requestId", requestId);
        MDC.put("requestId", requestId);
        chain.doFilter(request, response);
    } finally {
        MDC.remove("requestId");
    }
}

Logging configuration.

<Pattern>%d %-5level %X{requestId} [%t] %C{10}:%L %m%n</Pattern>

Sample logging.

2024-02-04 10:29:55,160 INFO  99cd4d64-5d7c-4577-a5d3-cb8d48d1dfd5 [http-nio-8080-exec-6] c.s.q.UserController:65 Deleteing user 'test'
2024-02-04 10:29:55,260 INFO  99cd4d64-5d7c-4577-a5d3-cb8d48d1dfd5 [http-nio-8080-exec-6] c.s.q.UserController:70 Successfully deleted user 'test'

With Virtual Threads in Java 21+, I'm under the impression a thread can automatically suspended a request while it's waiting on any IO and the thread can begin working on other requests. In this scenario it seems like the logging MDC can "bleed" into other request logs as the thread begins serving other requests. How can I work around this so I can continue to have a unique value added to each request's logging statements?

Answer 1

If the MDC Adapter you use is the one that uses ThreadLocal, e.g. LogbackMDCAdapter, then the filter you posted will work fine for virtual threads as well as for platform threads. If your virtual thread would be suspended and then continued on another Carrier (platform) thread, then its ThreadLocals would be correctly transferred (at least Project Loom so promises).

"Don't Cache Expensive Reusable Objects in Thread-Local Variables" of Virtual Threads doc says:

Virtual threads support thread-local variables just as platform threads do

However, the users of virtual threads are warned against excessive usage of ThreadLocals on virtual threads (which could be very well understood as these ThreadLocals have to be transferred between Carrier threads of our virtual thread - this is pretty rough picture of what is going on "under the hood").

Instead, Project Loom advises to use ScopedValue. However, in the scope of your question, 1) a usage of ScopedValue should be initiated at the point of virtual thread spawning, i.e. somewhere in Servlet Container (if Tomcat is used then it would be a Connector) and 2) a special ScopedValue-oriented MDCAdapter implementation should be used 3) ScopedValue is still a preview in Java 21. Some plans in that direction have been laid out in How to propagating context through StructuredTaskScope by ScopedValue... how about the MDC ThreadContextMap in StructuredTaskScope?. It seems to me that, as ScopedValue is designed, the efforts should be applied at two levels: Servlet Container, where the virtual thread is spawned, and special MDCAdapter implementation. More on usage of ScopedValues for MDC on Logback: availability of MDCs in forks created inside a StructuredTaskScope.