java多线程使用mdc追踪日志方式
作者：致林
这篇文章主要介绍了java多线程使用mdc追踪日志方式，具有很好的参考价值，希望对大家有所帮助。如有错误或未考虑完全的地方，望不吝赐教
多线程使用mdc追踪日志
背景
多线程情况下，子线程的sl4j打印日志缺少traceId等信息，导致定位问题不方便
解决方案
- 打印日志时添加用户ID、trackId等信息，缺点是每个日志都要手动添加
- 使用mdc直接拷贝父线程值
实现
// 新建线程时：
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);
}
}
}
};
}
}
多线程日志追踪
主要目的是记录工作中的一些编程思想和细节，以便后来查阅。
1.问题描述
由于项目中设计高并发内容，涉及到一个线程创建多个子线程的情况。 那么，如何跟踪日志，识别子线程是由哪个主线程创建的，属于哪个request请求。
例如， 在现有项目中，一个设备信息上传的请求（包括基本数据和异常数据两种数据），然后主线程创建两个子线程，来处理基本数据和异常数据。
简化代码如下：
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() +"]开始发起请求");
String[] data = {"异常数据","基本数据"};
//创建子线程1，处理异常数据
MThread mThread1 = new MThread(new Runnable() {
@Override
public void run() {
System.out.println("[Thread-"+ Thread.currentThread().getId() +"]处理了" + data[0]);
}
});
创建子线程2，处理普通数据
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请求的）。如果某一个线程出现问题，我们也很难快速定位是哪个请求的处理结果。
2. 代理实现日志追踪
因此，我们使用MDC来在日志中增加traceId（同一个请求的多个线程拥有同一个traceId）。
思路如下：
1. 在request进来的时候， 利用AOP为每个request创建一个traceId（保证每个request的traceId不同， 同一个request的traceId相同）
2. 创建子线程的时候， 将traceId通过动态代理的方式，传递到子线程中
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") +"]开始发起请求");
String[] data = {"异常数据","基本数据"};
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);
}
}
运行结果如下：
两个请求， 同一个请求的traceId相同，不同请求的traceId不同。 完美实现多线程的日志追踪。
实际WEB项目中，只需要在logback日志配置文件中，
logging.pattern.console参数增[%X{traceId}]即可在LOGGER日志中打印traceId的信息。
以上为个人经验，希望能给大家一个参考，也希望大家多多支持脚本之家。