Logging MDC with @Async and TaskDecorator
Asked Answered
D

3

13

Using Spring MVC, I have the following setup:

  1. An AbstractRequestLoggingFilter derived filter for logging requests.
  2. A TaskDecorator to marshal the MDC context mapping from the web request thread to the @Async thread.

I'm attempting to collect context info using MDC (or a ThreadLocal object) for all components involved in handling the request.

I can correctly retrieve the MDC context info from the @Async thread. However, if the @Async thread were to add context info to the MDC, how can I now marshal the MDC context info to the thread that handles the response?

TaskDecorator

public class MdcTaskDecorator implements TaskDecorator {
@Override
public Runnable decorate(Runnable runnable) {
    // Web thread context
    // Get the logging MDC context
    Map<String, String> contextMap = MDC.getCopyOfContextMap();

    return () -> {
        try {
            // @Async thread context
            // Restore the web thread MDC context
            if(contextMap != null) {
                MDC.setContextMap(contextMap);
            }
            else {
                MDC.clear();
            }

            // Run the new thread
            runnable.run();
        }
        finally {
            MDC.clear();
        }
    };
}

}

Async method

@Async
public CompletableFuture<String> doSomething_Async() {
    MDC.put("doSomething", "started");
    return doit();
}

Logging Filter

public class ServletLoggingFilter extends AbstractRequestLoggingFilter {
@Override
protected void beforeRequest(HttpServletRequest request, String message) {
    MDC.put("webthread", Thread.currentThread().getName()); // Will be webthread-1
}

@Override
protected void afterRequest(HttpServletRequest request, String message) {
    MDC.put("responsethread", Thread.currentThread().getName()); // Will be webthread-2
    String s = MDC.get("doSomething"); // Will be null

    // logthis();
}

}

Doud answered 25/8, 2017 at 22:31 Comment(0)
K
9

Create a bean that will pass the MDC properties from parent thread to the successor thread.

@Configuration
@Slf4j
public class AsyncMDCConfiguration {
  @Bean
  public Executor asyncExecutor() {
    ThreadPoolTaskExecutor executor = new ThreadPoolTaskExecutor();
    executor.setTaskDecorator(new MDCTaskDecorator());//MDCTaskDecorator i s a custom created  class thet implements  TaskDecorator  that is reponsible for passing on the MDC properties 
    executor.initialize();
    return executor;
  }
}


@Slf4j
public class MDCTaskDecorator implements TaskDecorator {

  @Override
  public Runnable decorate(Runnable runnable) {
    Map<String, String> contextMap = MDC.getCopyOfContextMap();
    return () -> {
      try {
        MDC.setContextMap(contextMap);
        runnable.run();
      } finally {
        MDC.clear();
      }
    };
  }
}

All Good now. Happy Coding

Kantian answered 18/6, 2021 at 11:9 Comment(1)
This does work great for me! However, in the decorate(Runnable runnable), I added a null check for contextMap because it somehow null in my app: @Override public Runnable decorate(Runnable runnable) { ` Map<String, String> contextMap = MDC.getCopyOfContextMap(); if (contextMap != null) { return () -> { try { MDC.setContextMap(contextMap); runnable.run(); } finally { MDC.clear(); } } } else { return runnable}; }Arndt
L
5

I hope you have solved the problem, but if you did not, here comes a solution.
All you have to do can be summarized as following 2 simple steps:

  1. Keep your class MdcTaskDecorator.
  2. Extends AsyncConfigurerSupport for your main class and override getAsyncExecutor() to set decorator with your customized one as follows:
    public class AsyncTaskDecoratorApplication extends AsyncConfigurerSupport {
        @Override
        public Executor getAsyncExecutor() {
            ThreadPoolTaskExecutor executor = new ThreadPoolTaskExecutor();
            executor.setTaskDecorator(new MdcTaskDecorator());
            executor.initialize();
            return executor;
        }

        public static void main(String[] args) {
            SpringApplication.run(AsyncTaskdecoratorApplication.class, args);
        }
    }
Ludwigg answered 14/10, 2020 at 1:5 Comment(0)
S
-3

I have some solutions that roughly divided into Callable(for @Async), AsyncExecutionInterceptor(for @Async), CallableProcessingInterceptor(for controller).

1.The Callable solution for putting context infos into @Async thread:

The key is using the ContextAwarePoolExecutor to replace the default executor of @Async:

@Configuration

public class DemoExecutorConfig {

@Bean("demoExecutor")
public Executor contextAwarePoolExecutor() {
    return new ContextAwarePoolExecutor();
}

}

And the ContextAwarePoolExecutor overwriting submit and submitListenable methods with ContextAwareCallable inside:

public class ContextAwarePoolExecutor extends ThreadPoolTaskExecutor {

private static final long serialVersionUID = 667815067287186086L;

@Override
public <T> Future<T> submit(Callable<T> task) {
    return super.submit(new ContextAwareCallable<T>(task, newThreadContextContainer()));
}

@Override
public <T> ListenableFuture<T> submitListenable(Callable<T> task) {
    return super.submitListenable(new ContextAwareCallable<T>(task, newThreadContextContainer()));
}

/**
 * set infos what we need
 */
private ThreadContextContainer newThreadContextContainer() {
    ThreadContextContainer container = new ThreadContextContainer();
    container.setRequestAttributes(RequestContextHolder.currentRequestAttributes());
    container.setContextMapOfMDC(MDC.getCopyOfContextMap());
    return container;
}

}

The ThreadContextContainer is just a pojo to store infos for convenience:

public class ThreadContextContainer implements Serializable {

private static final long serialVersionUID = -6809291915300091330L;

private RequestAttributes requestAttributes;
private Map<String, String> contextMapOfMDC;

public RequestAttributes getRequestAttributes() {
    return requestAttributes;
}

public Map<String, String> getContextMapOfMDC() {
    return contextMapOfMDC;
}

public void setRequestAttributes(RequestAttributes requestAttributes) {
    this.requestAttributes = requestAttributes;
}

public void setContextMapOfMDC(Map<String, String> contextMapOfMDC) {
    this.contextMapOfMDC = contextMapOfMDC;
}

}

The ContextAwareCallable(a Callable proxy for original task) overwriting the call method to storage MDC or other context infos before the original task executing its call method:

public class ContextAwareCallable<T> implements Callable<T> {

/**
 * the original task
 */
private Callable<T> task;

/**
 * for storing infos what we need
 */
private ThreadContextContainer threadContextContainer;

public ContextAwareCallable(Callable<T> task, ThreadContextContainer threadContextContainer) {
    this.task = task;
    this.threadContextContainer = threadContextContainer;
}

@Override
public T call() throws Exception {
    // set infos
    if (threadContextContainer != null) {
        RequestAttributes requestAttributes = threadContextContainer.getRequestAttributes();
        if (requestAttributes != null) {
            RequestContextHolder.setRequestAttributes(requestAttributes);
        }
        Map<String, String> contextMapOfMDC = threadContextContainer.getContextMapOfMDC();
        if (contextMapOfMDC != null) {
            MDC.setContextMap(contextMapOfMDC);
        }
    }

    try {
        // execute the original task
        return task.call();
    } finally {
        // clear infos after task completed
        RequestContextHolder.resetRequestAttributes();
        try {
            MDC.clear();
        } finally {
        }
    }
}

}

In the end, using the @Async with the configured bean "demoExecutor" like this: @Async("demoExecutor") void yourTaskMethod();

2.In regard to your question of handling the response:

Regret to tell that I don't really have a verified solution. Maybe the org.springframework.aop.interceptor.AsyncExecutionInterceptor#invoke is possible to solve that.

And I do not think it has a solution to handle the response with your ServletLoggingFilter. Because the Async method will be returned instantly. The afterRequest method executes immediately and returns before Async method doing things. You won't get what you want unless you synchronously wait for the Async method to finish executing.

But if you just want to log something, you can add those codes into my example ContextAwareCallable after the original task executing its call method:

try {
        // execute the original task
        return task.call();
    } finally {
        String something = MDC.get("doSomething"); // will not be null
        // logthis(something);

        // clear infos after task completed
        RequestContextHolder.resetRequestAttributes();
        try {
            MDC.clear();
        } finally {
        }
    }
Scolopendrid answered 1/3, 2019 at 8:3 Comment(0)

© 2022 - 2024 — McMap. All rights reserved.