In a previous article, Kelvin commented that it is still possible to mess up in multithreading, and suggested using MDC to print traceId for full link call tracing. Everyone in nuggets is talented, nice to talk, love inside. Digging gold makes me improve. Enthusiastic net friends can always make suggestions for improvement

Writing in the front

In this article, you will learn what MDC is, the problems with MDC applications, and how to solve the problems

MDC is introduced

Brief introduction:

MDC (Mapped Diagnostic Context) is a feature provided by LOG4J, LogBack, and Log4j2 to facilitate logging in multi-threaded conditions. MDC can be thought of as a hash table bound to the current thread to which you can add key-value pairs. The content contained in MDC can be accessed by code executing in the same thread. Children of the current thread inherit MDC content from their parent thread. To record logs, you only need to obtain the required information from the MDC. The MDC contents are saved by the program at the appropriate time. For a Web application, this data is usually saved at the very beginning of the request being processed

API specification:
  • Clear () => Remove all MDC nodes
  • Get (String key) => Obtains the value of the specified key in the current MDC thread
  • GetContext () => Get the MDC of the current thread MDC
  • Put (String key, Object O) => Stores the specified key-value pair to the MDC of the current thread
  • Remove (String key) => Delete the key/value pairs specified in the current MDC thread
Advantages:
  • Simple code, uniform log style, do not need to manually spell traceId in log printing, that is, logger. info(“traceId:{} “, traceId)

That’s all I can think of for now

The MDC use

  • Adding interceptors

    public class LogInterceptor implements HandlerInterceptor {
    @Override
    public boolean preHandle(HttpServletRequest request, HttpServletResponse response, Object handler) throws Exception {
        // If there are upper-level calls, use the upper-level ID
        String traceId = request.getHeader(Constants.TRACE_ID);
        if (traceId == null) {
            traceId = TraceIdUtil.getTraceId();
        }

        MDC.put(Constants.TRACE_ID, traceId);
        return true;
    }

    @Override
    public void postHandle(HttpServletRequest request, HttpServletResponse response, Object handler, ModelAndView modelAndView)
            throws Exception {}@Override
    public void afterCompletion(HttpServletRequest request, HttpServletResponse response, Object handler, Exception ex)
            throws Exception {
        // Delete after the callMDC.remove(Constants.TRACE_ID); }}Copy the code

  • Changing the Log Format

    <property name="pattern">[TRACEID:%X{traceId}] %d{HH:mm:ss.SSS} %-5level %class{-1}.%M()/%L - %msg%xEx%n</property>
Copy the code

    The important thing is that %X{traceId}, traceId and the key names in MDC are the same. Simple use is as easy as this, but in some cases traceId will not be available

Problems with the MDC

  • Description The log traceId of the child thread is lost

  • Description HTTP invocation traceId is lost

    . If the traceId is lost, solve the problem one by one and never optimize it in advance

Resolve MDC problems

Description The traceId of child thread logs is lost

The traceId is lost when the child thread prints the log. The solution is to rewrite the thread pool, which is nothing more than encapsulating the task

  • The thread pool wrapper class: ThreadPoolExecutorMdcWrapper. Java

    public class ThreadPoolExecutorMdcWrapper extends ThreadPoolExecutor {
    public ThreadPoolExecutorMdcWrapper(int corePoolSize, int maximumPoolSize, long keepAliveTime, TimeUnit unit,
                                        BlockingQueue<Runnable> workQueue) {
        super(corePoolSize, maximumPoolSize, keepAliveTime, unit, workQueue);
    }

    public ThreadPoolExecutorMdcWrapper(int corePoolSize, int maximumPoolSize, long keepAliveTime, TimeUnit unit,
                                        BlockingQueue<Runnable> workQueue, ThreadFactory threadFactory) {
        super(corePoolSize, maximumPoolSize, keepAliveTime, unit, workQueue, threadFactory);
    }

    public ThreadPoolExecutorMdcWrapper(int corePoolSize, int maximumPoolSize, long keepAliveTime, TimeUnit unit,
                                        BlockingQueue<Runnable> workQueue, RejectedExecutionHandler handler) {
        super(corePoolSize, maximumPoolSize, keepAliveTime, unit, workQueue, handler);
    }

    public ThreadPoolExecutorMdcWrapper(int corePoolSize, int maximumPoolSize, long keepAliveTime, TimeUnit unit,
                                        BlockingQueue<Runnable> workQueue, ThreadFactory threadFactory,
                                        RejectedExecutionHandler handler) {
        super(corePoolSize, maximumPoolSize, keepAliveTime, unit, workQueue, threadFactory, handler);
    }

    @Override
    public void execute(Runnable task) {
        super.execute(ThreadMdcUtil.wrap(task, MDC.getCopyOfContextMap()));
    }

    @Override
    public <T> Future<T> submit(Runnable task, T result) {
        return super.submit(ThreadMdcUtil.wrap(task, MDC.getCopyOfContextMap()), result);
    }

    @Override
    public <T> Future<T> submit(Callable<T> task) {
        return super.submit(ThreadMdcUtil.wrap(task, MDC.getCopyOfContextMap()));
    }

    @Override
    publicFuture<? > submit(Runnable task) {return super.submit(ThreadMdcUtil.wrap(task, MDC.getCopyOfContextMap())); }}Copy the code

    Description:

    • A method that reexecutes a task by inheriting the ThreadPoolExecutor class
    • The task is wrapped once through ThreadMdcUtil

  • Thread traceId encapsulates the utility class threadMDcutil.java

    public class ThreadMdcUtil {
    public static void setTraceIdIfAbsent(a) {
        if (MDC.get(Constants.TRACE_ID) == null) { MDC.put(Constants.TRACE_ID, TraceIdUtil.getTraceId()); }}public static <T> Callable<T> wrap(final Callable<T> callable, final Map<String, String> context) {
        return() - > {if (context == null) {
                MDC.clear();
            } else {
                MDC.setContextMap(context);
            }
            setTraceIdIfAbsent();
            try {
                return callable.call();
            } finally{ MDC.clear(); }}; }public static Runnable wrap(final Runnable runnable, final Map<String, String> context) {
        return() - > {if (context == null) {
                MDC.clear();
            } else {
                MDC.setContextMap(context);
            }
            setTraceIdIfAbsent();
            try {
                runnable.run();
            } finally{ MDC.clear(); }}; }}Copy the code

    [Take encapsulation Runnable as an example] :

    • Check whether the MDC Map of the current thread exists
    • If the value does not exist, a new traceId value is generated. If the value is not a child thread, the traceId value is not null
    • Execute the run method

    The code is equivalent to the following, which is more intuitive

    public static Runnable wrap(final Runnable runnable, final Map<String, String> context) {
        return new Runnable() {
            @Override
            public void run(a) {
                if (context == null) {
                    MDC.clear();
                } else {
                    MDC.setContextMap(context);
                }
                setTraceIdIfAbsent();
                try {
                    runnable.run();
                } finally{ MDC.clear(); }}}; }Copy the code

    Runnable.run () sets the main thread Map to the current thread (mdC.setContextMap (context)) before the task is executed, so that the thread and the main MDC Map are the same

Description HTTP invocation traceId is lost

The traceId will be lost when the third-party service interface is invoked using HTTP. Therefore, you need to modify the HTTP invocation tool. Add traceId to the Request header when sending the request, and add interceptors to the lower layer of the invoked party to obtain the traceId in the header and add the traceId to the MDC

There are many ways to call HTTP. The most common ones are HttpClient, OKHttp, and RestTemplate. Therefore, only these methods are given

HttpClient:

  • Implement the HttpClient interceptor
public class HttpClientTraceIdInterceptor implements HttpRequestInterceptor {
    @Override
    public void process(HttpRequest httpRequest, HttpContext httpContext) throws HttpException, IOException {
        String traceId = MDC.get(Constants.TRACE_ID);
        // If the current thread invocation contains traceId, the traceId is transparently transmitted
        if(traceId ! =null) {
            // Add the request bodyhttpRequest.addHeader(Constants.TRACE_ID, traceId); }}}Copy the code

Implement the HttpRequestInterceptor interface and rewrite the process method

If the calling thread contains traceId, the obtained traceId needs to be transparently transmitted down through the header in the request

  • Add interceptors for HttpClient

    private static CloseableHttpClient httpClient = HttpClientBuilder.create()
            .addInterceptorFirst(new HttpClientTraceIdInterceptor())
            .build();
Copy the code

    Add an interceptor to HttpClient using the addInterceptorFirst method

OKHttp:

  • Implement the OKHttp interceptor

    public class OkHttpTraceIdInterceptor implements Interceptor {
    @Override
    public Response intercept(Chain chain) throws IOException {
        String traceId = MDC.get(Constants.TRACE_ID);
        Request request = null;
        if(traceId ! =null) {
            // Add the request body
            request = chain.request().newBuilder().addHeader(Constants.TRACE_ID, traceId).build();
        }
        Response originResponse = chain.proceed(request);

        returnoriginResponse; }}Copy the code

    Implement the Interceptor Interceptor, rewrite the Interceptor method, implement the same logic as HttpClient, if you can get the current thread traceId pass down

  • Add an interceptor for OkHttp

      private static OkHttpClient client = new OkHttpClient.Builder()
            .addNetworkInterceptor(new OkHttpTraceIdInterceptor())
            .build();
Copy the code

    Call the addNetworkInterceptor method to add an interceptor

RestTemplate:

  • Implement the RestTemplate interceptor

    public class RestTemplateTraceIdInterceptor implements ClientHttpRequestInterceptor {
    @Override
    public ClientHttpResponse intercept(HttpRequest httpRequest, byte[] bytes, ClientHttpRequestExecution clientHttpRequestExecution) throws IOException {
        String traceId = MDC.get(Constants.TRACE_ID);
        if(traceId ! =null) {
            httpRequest.getHeaders().add(Constants.TRACE_ID, traceId);
        }

        returnclientHttpRequestExecution.execute(httpRequest, bytes); }}Copy the code

    Implement ClientHttpRequestInterceptor interface, and rewrite intercept method, not to repeat that the rest of the logic is the same

  • Add interceptors for the RestTemplate

    restTemplate.setInterceptors(Arrays.asList(new RestTemplateTraceIdInterceptor()));
Copy the code

    Call the setInterceptors method to add an interceptor

Third-party service interceptors:

TraceId requires the cooperation of the third-party service. The third-party service needs to add an interceptor to get the traceId in the Request header and add the interceptor to the MDC

public class LogInterceptor implements HandlerInterceptor {
    @Override
    public boolean preHandle(HttpServletRequest request, HttpServletResponse response, Object handler) throws Exception {
        // If there are upper-level calls, use the upper-level ID
        String traceId = request.getHeader(Constants.TRACE_ID);
        if (traceId == null) {
            traceId = TraceIdUtils.getTraceId();
        }
        
        MDC.put("traceId", traceId);
        return true;
    }

    @Override
    public void postHandle(HttpServletRequest request, HttpServletResponse response, Object handler, ModelAndView modelAndView)
            throws Exception {}@Override
    public void afterCompletion(HttpServletRequest request, HttpServletResponse response, Object handler, Exception ex)
            throws Exception { MDC.remove(Constants.TRACE_ID); }}Copy the code

Description:

  • Obtain the traceId from the Request header
  • If the traceId cannot be obtained from the Request header, a new traceId is generated
  • Save the generated traceId to the MDC

In addition to the need to add interceptors, you also need to add traceId printing to the log format as follows:

 <property name="pattern">[TRACEID:%X{traceId}] %d{HH:mm:ss.SSS} %-5level %class{-1}.%M()/%L - %msg%xEx%n</property>
Copy the code

Need to add %X{traceId}

Finally: project code, welcome fork and star, raise a little star, humble begging

Previous articles are recommended

2. Why did Alibaba disable Executors to create a thread pool?

Using traceId to trace request logs in Java projects 2.MDC Introduction — a log management practice in multithreading