java多線程使用mdc追蹤日志方式

更新時間：2021年09月23日 09:48:14 作者：致林

這篇文章主要介紹了java多線程使用mdc追蹤日志方式，具有很好的參考價值，希望對大家有所幫助。如有錯誤或未考慮完全的地方，望不吝賜教

多線程使用mdc追蹤日志

背景

多線程情況下，子線程的sl4j打印日志缺少traceId等信息，導致定位問題不方便

解決方案

打印日志時添加用戶ID、trackId等信息，缺點是每個日志都要手動添加
使用mdc直接拷貝父線程值

實現(xiàn)

// 新建線程時：
Map<String, String> mdcContextMap = MDC.getCopyOfContextMap()
// 子線程運行時：
if(null != mdcContextMap){
    MDC.setContextMap(mdcContextMap);
}
// 銷毀線程時
MDC.clear();

參考

import org.slf4j.MDC;
import java.util.Map;
import java.util.concurrent.*;
/**
 * A SLF4J MDC-compatible {@link ThreadPoolExecutor}.
 * <p/>
 * In general, MDC is used to store diagnostic information (e.g. a user's session id) in per-thread variables, to facilitate
 * logging. However, although MDC data is passed to thread children, this doesn't work when threads are reused in a
 * thread pool. This is a drop-in replacement for {@link ThreadPoolExecutor} sets MDC data before each task appropriately.
 * <p/>
 * Created by jlevy.
 * Date: 6/14/13
 */
public class MdcThreadPoolExecutor extends ThreadPoolExecutor {
    final private boolean useFixedContext;
    final private Map<String, Object> fixedContext;
    /**
     * Pool where task threads take MDC from the submitting thread.
     */
    public static MdcThreadPoolExecutor newWithInheritedMdc(int corePoolSize, int maximumPoolSize, long keepAliveTime,
                                                            TimeUnit unit, BlockingQueue<Runnable> workQueue) {
        return new MdcThreadPoolExecutor(null, corePoolSize, maximumPoolSize, keepAliveTime, unit, workQueue);
    }
    /**
     * Pool where task threads take fixed MDC from the thread that creates the pool.
     */
    @SuppressWarnings("unchecked")
    public static MdcThreadPoolExecutor newWithCurrentMdc(int corePoolSize, int maximumPoolSize, long keepAliveTime,
                                                          TimeUnit unit, BlockingQueue<Runnable> workQueue) {
        return new MdcThreadPoolExecutor(MDC.getCopyOfContextMap(), corePoolSize, maximumPoolSize, keepAliveTime, unit,
                workQueue);
    }
    /**
     * Pool where task threads always have a specified, fixed MDC.
     */
    public static MdcThreadPoolExecutor newWithFixedMdc(Map<String, Object> fixedContext, int corePoolSize,
                                                        int maximumPoolSize, long keepAliveTime, TimeUnit unit,
                                                        BlockingQueue<Runnable> workQueue) {
        return new MdcThreadPoolExecutor(fixedContext, corePoolSize, maximumPoolSize, keepAliveTime, unit, workQueue);
    }
    private MdcThreadPoolExecutor(Map<String, Object> fixedContext, int corePoolSize, int maximumPoolSize,
                                  long keepAliveTime, TimeUnit unit, BlockingQueue<Runnable> workQueue) {
        super(corePoolSize, maximumPoolSize, keepAliveTime, unit, workQueue);
        this.fixedContext = fixedContext;
        useFixedContext = (fixedContext != null);
    }
    @SuppressWarnings("unchecked")
    private Map<String, Object> getContextForTask() {
        return useFixedContext ? fixedContext : MDC.getCopyOfContextMap();
    }
    /**
     * All executions will have MDC injected. {@code ThreadPoolExecutor}'s submission methods ({@code submit()} etc.)
     * all delegate to this.
     */
    @Override
    public void execute(Runnable command) {
        super.execute(wrap(command, getContextForTask()));
    }
    public static Runnable wrap(final Runnable runnable, final Map<String, Object> context) {
        return new Runnable() {
            @Override
            public void run() {
                Map previous = MDC.getCopyOfContextMap();
                if (context == null) {
                    MDC.clear();
                } else {
                    MDC.setContextMap(context);
                }
                try {
                    runnable.run();
                } finally {
                    if (previous == null) {
                        MDC.clear();
                    } else {
                        MDC.setContextMap(previous);
                    }
                }
            }
        };
    }
}

多線程日志追蹤

主要目的是記錄工作中的一些編程思想和細節(jié)，以便后來查閱。

1.問題描述

由于項目中設計高并發(fā)內容，涉及到一個線程創(chuàng)建多個子線程的情況。那么，如何跟蹤日志，識別子線程是由哪個主線程創(chuàng)建的，屬于哪個request請求。

例如，在現(xiàn)有項目中，一個設備信息上傳的請求（包括基本數(shù)據和異常數(shù)據兩種數(shù)據），然后主線程創(chuàng)建兩個子線程，來處理基本數(shù)據和異常數(shù)據。

簡化代碼如下：

public class mainApp {
    public static void main(String[] args) {
        Thread t = new Thread(new Runnable() {
            @Override
            public void run() {
                //接收到一個request
                System.out.println("[Thread-"+ Thread.currentThread().getId() +"]開始發(fā)起請求");
                String[] data = {"異常數(shù)據","基本數(shù)據"};
                //創(chuàng)建子線程1，處理異常數(shù)據
                MThread mThread1 = new MThread(new Runnable() {
                    @Override
                    public void run() {
                        System.out.println("[Thread-"+ Thread.currentThread().getId() +"]處理了" + data[0]);
                    }
                });
                創(chuàng)建子線程2，處理普通數(shù)據
                MThread mThread2 = new MThread(new Runnable() {
                    @Override
                    public void run() {
                        System.out.println("[Thread-"+ Thread.currentThread().getId() +"]處理了"  + data[1]);
                    }
                });
                new Thread(mThread1).start();
                new Thread(mThread2).start(); 
            }
        });
        t.start();
    }
}
 
class MThread implements Runnable { 
    private Runnable r; 
    public MThread(Runnable r) {
        this.r = r;
    }
 
    @Override
    public void run() {
        r.run();
    }
}

運行結果如下：

一個請求有三個線程，如果有多個請求，運行結果如下：

從日志中無法看出他們之間的所屬關系（判斷不出來他們是否是處理同一個request請求的）。如果某一個線程出現(xiàn)問題，我們也很難快速定位是哪個請求的處理結果。

2. 代理實現(xiàn)日志追蹤

因此，我們使用MDC來在日志中增加traceId（同一個請求的多個線程擁有同一個traceId）。

思路如下：

1. 在request進來的時候，利用AOP為每個request創(chuàng)建一個traceId（保證每個request的traceId不同，同一個request的traceId相同）

2. 創(chuàng)建子線程的時候，將traceId通過動態(tài)代理的方式，傳遞到子線程中

public class mainApp {
    public static void main(String[] args) {
        Runnable runnable = new Runnable() {
            @Override
            public void run() {
                //AOP 生成一個traceId
                MDC.put("traceId", UUID.randomUUID().toString().replace("-", ""));
                //接收到一個request
                System.out.println("[Thread-"+ Thread.currentThread().getId() +"]traceId["+ MDC.get("traceId") +"]開始發(fā)起請求");
                String[] data = {"異常數(shù)據","基本數(shù)據"};
 
                MThread mThread1 = new MThread(new Runnable() {
                    @Override
                    public void run() {
                        System.out.println("[Thread-"+ Thread.currentThread().getId() +"]traceId["+ MDC.get("traceId") +"]處理了" + data[0]);
                    }
                }, MDC.getCopyOfContextMap());
                MThread mThread2 = new MThread(new Runnable() {
                    @Override
                    public void run() {
                        System.out.println("[Thread-"+ Thread.currentThread().getId() +"]traceId["+ MDC.get("traceId") +"]處理了"  + data[1]);
                    }
                }, MDC.getCopyOfContextMap());
                new Thread(mThread1).start();
                new Thread(mThread2).start(); 
            }
        };
        new Thread(runnable).start();
        new Thread(runnable).start();
    }
}
 
class MThread implements Runnable { 
    private Runnable r; 
    public MThread(Runnable r, Map<String, String> parentThreadMap) {
        LogProxy logProxy = new LogProxy(r, parentThreadMap);
        Runnable rProxy = (Runnable) Proxy.newProxyInstance(r.getClass().getClassLoader(), r.getClass().getInterfaces(), logProxy);
        this.r = rProxy;
    }
 
    @Override
    public void run() {
        r.run();
    }
}
 
//日志代理
class LogProxy implements InvocationHandler {
    private Runnable r;
    private  Map<String, String> parentThreadMap;
    public LogProxy(Runnable r, Map<String, String> parentThreadMap) {
        this.r = r;
        this.parentThreadMap = parentThreadMap;
    }
 
    @Override
    public Object invoke(Object proxy, Method method, Object[] args) throws Throwable {
        if (method.getName().equals("run")) {
            MDC.setContextMap(parentThreadMap);
        }
        return method.invoke(r, args);
    }
}

運行結果如下：