logback是个比较好用的java日志输出工具包，可配置型高，而且性能优秀。
背景
在日志记录过程中，如果处理请求是单线程的，那么在日志中定位问题很方便。但是如果处理请求是多线程或者异步处理的时候，查找日志会带来很多问题，同一请求的日志难以都找到。如下：
示例
单线程
@PostMapping("/")public String add(){return "aaaaaaa";}
通过线程号就可以查找到某一请求的具体日志。
多线程
@PutMapping("/")public String edit(){// 打印日志log.info("log in main thread 1");log.info("log in main thread 2");log.info("log in main thread 3");new Thread(new Runnable() {@Overridepublic void run() {log.info("log in other thread");}}).start();return "eeeeeee";}
同一请求不同线程处理，这样很难找到具体是哪一个请求的日志
使用logback的MDC指定同意请求的id
在logback.xml中如果想输出MDC中的自定义属性，可以通过%X{propertyName}方式
比如：
%X{requestId}
这里的requestId就是MDC指定的key
单线程
private static final String KEY = "requestId";@GetMapping("/")public RestResponse get(){System.out.println("ssss");// 入口传入请求IDMDC.put(KEY, UUID.randomUUID().toString());// 打印日志log.info("log in main thread 1");log.info("log in main thread 2");log.info("log in main thread 3");// 出口移除请求IDMDC.remove(KEY);return RestResponse.SUCCESS;}
可以看到同一请求的requestid相同
多线程
private static final String KEY = "requestId";@GetMapping("/")public RestResponse get(){System.out.println("ssss");// 入口传入请求IDMDC.put(KEY, UUID.randomUUID().toString());// 打印日志log.info("log in main thread 1");log.info("log in main thread 2");log.info("log in main thread 3");new Thread(new Runnable() {@Overridepublic void run() {log.info("log in other thread");}}).start();// 出口移除请求IDMDC.remove(KEY);return RestResponse.SUCCESS;}
多线程对于同一请求依然存在问题
MDC之所以在异步线程中不生效是因为底层采用ThreadLocal 作为数据结构，我们调用MDC.put()方法传入的请求ID只在当前线程有效。
解决方法
使用装饰器模式，新写一个MDCRunnable类对Runnable接口进行一层装饰。
在创建MDCRunnable类时保存当前线程的MDC值，在执行run()方法时再将保存的MDC值拷贝到异步线程中去。
public class MDCRunnable implements Runnable{private final Runnable runnable;private final Map<String, String> map;public MDCRunnable(Runnable runnable) {this.runnable = runnable;// 保存当前线程的MDC值this.map = MDC.getCopyOfContextMap();}@Overridepublic void run() {// 传入已保存的MDC值for (Map.Entry<String, String> entry : map.entrySet()) {MDC.put(entry.getKey(), entry.getValue());}// 装饰器模式，执行run方法runnable.run();// 移除已保存的MDC值for (Map.Entry<String, String> entry : map.entrySet()) {MDC.remove(entry.getKey());}}}
private static final String KEY = "requestId";private static final ExecutorService EXECUTOR = Executors.newSingleThreadExecutor();@GetMapping("/")public RestResponse get(){System.out.println("ssss");// 入口传入请求IDMDC.put(KEY, UUID.randomUUID().toString());// 打印日志log.info("log in main thread 1");log.info("log in main thread 2");log.info("log in main thread 3");new Thread(new MDCRunnable(new Runnable() {@Overridepublic void run() {log.info("log in other thread");}})).start();// 异步线程池打印日志，用MDCRunnable装饰RunnableEXECUTOR.execute(new MDCRunnable(new Runnable() {@Overridepublic void run() {log.debug("log in other thread pool");}}));EXECUTOR.shutdown();// 出口移除请求IDMDC.remove(KEY);return RestResponse.SUCCESS;}
可以看到requestid都是相同的
本文参考文章:
文章一
文章二
如果觉得《logback 之 使用MDC记录同一请求的异步处理日志》对你有帮助，请点赞、收藏，并留下你的观点哦！
