欢迎您访问程序员文章站本站旨在为大家提供分享程序员计算机编程知识！
您现在的位置是： 首页

springboot实现日志追踪

程序员文章站 2022-07-03 15:40:45
...

一、MDC介绍

​ MDC（Mapped Diagnostic Context，映射调试上下文）是 log4j 、logback及log4j2 提供的一种方便在多线程条件下记录日志的功能。MDC 可以看成是一个与当前线程绑定的哈希表，可以往其中添加键值对。MDC 中包含的内容可以被同一线程中执行的代码所访问。当前线程的子线程会继承其父线程中的 MDC 的内容。当需要记录日志时，只需要从 MDC 中获取所需的信息即可。MDC 的内容则由程序在适当的时候保存进去。对于一个 Web 应用来说，通常是在请求被处理的最开始保存这些数据。

二、API说明

  • clear() => 移除所有MDC
  • get (String key) => 获取当前线程MDC中指定key的值
  • getContext() => 获取当前线程MDC的MDC
  • put(String key, Object o) => 往当前线程的MDC中存入指定的键值对
  • remove(String key) => 删除当前线程MDC中指定的键值对

三、优点

  • 代码简洁，日志风格统一，不需要在log打印中手动拼写traceId，即LOGGER.info("traceId:{} ", traceId)

四、代码实现

4.1 请求没有子线程

4.1.1 实现日志拦截器
@Component
public class LogInterceptor implements HandlerInterceptor {
@Override
public boolean preHandle(HttpServletRequest request, HttpServletResponse response, Object handler) throws Exception {
    System.out.println("进入拦截器");
    //如果有上层调用就用上层的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 {
    //调用结束后删除
    System.out.println("调用结束");
    MDC.remove(Constants.TRACE_ID);
}
}
4.2.2 注册拦截器
@Configuration
public class MvcInterceptorConfig extends WebMvcConfigurationSupport {
@Autowired
private LogInterceptor logInterceptor;

@Override
protected void addInterceptors(InterceptorRegistry registry) {
    // 多个拦截器组成一个拦截器链
    // addPathPatterns 用于添加拦截规则，/**表示拦截所有请求
    // excludePathPatterns 用户排除拦截
    registry.addInterceptor(logInterceptor).addPathPatterns("/**");
    super.addInterceptors(registry);
}
}
4.3.3 日志输出格式设置
<property name="LOG_PATTERN_CONSOLE">
	[TRACEID:%X{traceId}] %clr{%d{HH:mm:ss.SSS}}{faint} %clr{%5p} %clr{[%15.15t]}{faint} %clr{%C{1.}(%M:%L)}{cyan} %clr{:}{faint} %m%n%xwEx
</property>

需要注意%X{traceId}中的threadId 需要和日志拦截中MDC put的key是一样的

4.2 请求有子线程的情况

​ slf4j的MDC机制其内部基于ThreadLocal实现。所以我们调用 MDC.put()方法传入的请求ID只在当前线程有效。所以，主线程中设置的MDC数据，在其子线程（线程池）中是无法获取的。

官方建议

1）在父线程新建子线程之前调用MDC.getCopyOfContextMap()方法将MDC内容取出来传给子线程

2）子线程在执行操作前先调用MDC.setContextMap()方法将父线程的MDC内容设置到子线程

代码实现：

1）使用Aop拦截请求，与上面相同

2）log4j日志配置与上面相同

3）装饰器模式装饰子线程，有两种方式

4.2.1 实现方式1——装饰Runnable

​ 使用装饰器模式，对Runnable接口进行一层装饰，在创建MDCRunnable类对Runnable接口进行一层装饰。

在创建MDCRunnable类时保存当前线程的MDC值，再执行run()方法

public class MDCRunnable implements Runnable{

private Runnable runnable;

/**
 * 保存当前主线程的MDC值
 */
private final Map<String, String> mainMdcMap;

public MDCRunnable(Runnable runnable) {
    this.runnable = runnable;
    this.mainMdcMap = MDC.getCopyOfContextMap();
}

@Override
public void run() {
    // 将父线程的MDC值赋给子线程
    for (Map.Entry<String, String> entry : mainMdcMap.entrySet()) {
        MDC.put(entry.getKey(), entry.getValue());
    }
    // 执行被装饰的线程run方法
    runnable.run();
    // 执行结束移除MDC值
    for (Map.Entry<String, String> entry : mainMdcMap.entrySet()) {
       MDC.remove(entry.getKey());
    }
  }
}

测试：使用MDCRunnable代替Runnable

@PostMapping("/test")
public String test(@RequestBody String str){
    log.info("进入test请求方法");
    SmsThreadPoolUtil.getInstance().execute(new MDCRunnable(new Runnable() {
        @Override
        public void run() {
            log.info("子线程1执行任务");
        }
    }));
    executorService.execute(new MDCRunnable(new Runnable() {
        @Override
        public void run() {
            log.info("子线程2执行任务");
        }
    }));

    log.info("test方法执行结束");
    return str;
}

[TRACEID:4dead5ddd1a34d10a19ae286dea56ab3] 16:24:20.857 DEBUG [nio-9999-exec-1] o.s.c.l.LogFormatUtils(traceDebug:91) : Read "application/json;charset=UTF-8" to ["{
    "str":"11111111"
}"]
[TRACEID:4dead5ddd1a34d10a19ae286dea56ab3] 16:24:20.863  INFO [nio-9999-exec-1] c.t.c.TestController(test:41) : 进入test请求方法
[TRACEID:4dead5ddd1a34d10a19ae286dea56ab3] 16:24:20.865  INFO [pool-3-thread-1] c.t.c.TestController$1(run:45) : 子线程1执行任务
[TRACEID:4dead5ddd1a34d10a19ae286dea56ab3] 16:24:20.865  INFO [nio-9999-exec-1] c.t.c.TestController(test:55) : test方法执行结束
[TRACEID:4dead5ddd1a34d10a19ae286dea56ab3] 16:24:20.865  INFO [pool-2-thread-1] c.t.c.TestController$2(run:51) : 子线程2执行任务
[TRACEID:4dead5ddd1a34d10a19ae286dea56ab3] 16:24:20.871 DEBUG [nio-9999-exec-1] o.s.w.s.m.m.a.AbstractMessageConverterMethodProcessor(writeWithMessageConverters:268) : Using 'text/plain', given [*/*] and supported [text/plain, */*, application/json, application/*+json]
[TRACEID:4dead5ddd1a34d10a19ae286dea56ab3] 16:24:20.872 DEBUG [nio-9999-exec-1] o.s.c.l.LogFormatUtils(traceDebug:91) : Writing ["{
    "str":"11111111"
}"]
4.2.2 实现方式2——装饰线程池
public class MDCThreadPoolExecutor extends ThreadPoolExecutor {
public MDCThreadPoolExecutor(int corePoolSize, int maximumPoolSize, long keepAliveTime, TimeUnit unit, BlockingQueue<Runnable> workQueue) {
    super(corePoolSize, maximumPoolSize, keepAliveTime, unit, workQueue);
}

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

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

public MDCThreadPoolExecutor(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(final Runnable runnable) {
    // 获取父线程MDC中的内容，必须在run方法之前，否则等异步线程执行的时候有可能MDC里面的值已经被清空了，这个时候就会返回null
    final Map<String, String> context = MDC.getCopyOfContextMap();
    super.execute(new Runnable() {
        @Override
        public void run() {
            // 将父线程的MDC内容传给子线程
            MDC.setContextMap(context);
            try {
                // 执行异步操作
                runnable.run();
            } finally {
                // 清空MDC内容
                MDC.clear();
            }
        }
    });
  }
}

测试：用MDCThreadPoolExecutor 代替ThreadPoolExecutor

public class SmsThreadPoolUtil {
	//定义类型
	private static ThreadPoolExecutor pool=new MDCThreadPoolExecutor(10, 20,
			10, TimeUnit.SECONDS, new LinkedBlockingDeque<Runnable>(10000), new RejectedPoolUtils());
	
	public static ThreadPoolExecutor getInstance() {
		return pool;
	}
}

@Service
@Slf4j
public class RejectedPoolUtils implements RejectedExecutionHandler{
	@Override
	public void rejectedExecution(Runnable r, ThreadPoolExecutor executor) {
		log.info("队列达到最大数");
	}
}

@PostMapping("/test")
public String test(@RequestBody String str){
    log.info("进入test请求方法");
    SmsThreadPoolUtil.getInstance().execute(new Runnable() {
        @Override
        public void run() {
            log.info("子线程1执行任务");
        }
    });
    log.info("test方法执行结束");
    return str;
}
相关标签： java spring boot spring

上一篇： 项目开发经验总结-2012.12.24

下一篇： SLF4J(六) - MDC/MDCAdapter是什么？

推荐阅读