一、问题背景
在微服务架构中，我们没办法快速定位用户在一次请求中对应的所有日志，在排查生产问题的时候会非常困难，那是因为我们在输出的日志的时候没把请求的唯一标示输出到我们的日志中，导致我们没办法根据一个请求或者用户身份标识来做日志的过滤。
二、MDC简介
MDC（Mapped Diagnostic Context，映射调试上下文）是 log4j 和 logback 提供的一种方便在多线程条件下记录日志的功能。MDC 可以看成是一个与当前线程绑定的Map，可以往其中添加键值对。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中指定的键值对 。
三、实现方式
由于 MDC 内部使用的是 ThreadLocal 所以只有本线程才有效，子线程和下游的服务 MDC 里的值会丢失,所以方案主要的难点是解决值的传递问题;
1. 工具类
public class TraceIdUtil {
public static final String TRACE_ID = "traceId";
public static String getTraceId() {
String traceId = MDC.get(TRACE_ID);
return traceId == null ? "" : traceId;
}
public static void setTraceId(String traceId) {
MDC.put(TRACE_ID, traceId);
}
public static void remove() {
MDC.remove(TRACE_ID);
}
public static void clear() {
MDC.clear();
}
public static String generateTraceId() {
return UUID.randomUUID().toString().replace("-", "");
}
}
- logback日志,这里的
[%X{traceId}]就是MDC中的,切不可写错key
<property name="console.log.pattern"
value="%red(%d{yyyy-MM-dd HH:mm:ss}) %green([%thread]) %highlight(%-5level) %boldMagenta(%logger{36}) [%X{traceId}] - %msg%n"/>
2. 拦截器
- 通过拦截器拦截请求,判断请求头中是否存在traceId,如果存在则存入MDC上下文中,不存在则生成traceId存入MDC中.
public class MdcInterceptor implements HandlerInterceptor {
@Override
public boolean preHandle(HttpServletRequest request, HttpServletResponse response, Object handler) throws Exception {
//如果有上层调用就用上层的ID
String traceId = request.getHeader(TraceIdUtil.TRACE_ID);
if (StrUtil.isEmpty(traceId)) {
TraceIdUtil.setTraceId(TraceIdUtil.generateTraceId());
} else {
TraceIdUtil.setTraceId(traceId);
}
return true;
}
@Override
public void afterCompletion(HttpServletRequest request, HttpServletResponse response, Object handler, Exception ex) throws Exception {
//调用结束后删除
TraceIdUtil.remove();
}
}
- 注册拦截器
@Component
public class WebAppConfigurer implements WebMvcConfigurer {
@Override
public void addInterceptors(InterceptorRegistry registry) {
// 可添加多个
registry.addInterceptor(new MdcInterceptor()).addPathPatterns("/**");
}
}
3. 请求头传递
- 这里使用的是openFeign的解决方案,其他的类似,在请求头中塞入traceId
@Component
public class MyFeignRequestInterceptor implements RequestInterceptor {
@Override
public void apply(RequestTemplate requestTemplate) {
String traceId = TraceIdUtil.getTraceId();
// 传递请求头
if (StrUtil.isNotBlank(traceId)) {
requestTemplate.header(TraceIdUtil.TRACE_ID, traceId);
} else {
requestTemplate.header(TraceIdUtil.TRACE_ID, TraceIdUtil.generateTraceId());
}
}
}
4. 线程父子间传递
- 由于MDC的底层是ThreadLocal,所以会导致子线程拿不到主线程里的数据
public class ThreadMdcUtil {
public static void setTraceIdIfAbsent() {
if (MDC.get(TraceIdUtil.TRACE_ID) == null) {
MDC.put(TraceIdUtil.TRACE_ID, TraceIdUtil.generateTraceId());
}
}
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);
}
//设置traceId
setTraceIdIfAbsent();
try {
runnable.run();
} finally {
MDC.clear();
}
};
}
}
- 自定义线程池
public class ThreadPoolExecutorMdcWrapper extends ThreadPoolTaskExecutor {
private static final long serialVersionUID = 3940722618853093830L;
@Override
public void execute(Runnable task) {
super.execute(ThreadMdcUtil.wrap(task, MDC.getCopyOfContextMap()));
}
@Override
public <T> Future<T> submit(Callable<T> task) {
return super.submit(ThreadMdcUtil.wrap(task, MDC.getCopyOfContextMap()));
}
@Override
public Future<?> submit(Runnable task) {
return super.submit(ThreadMdcUtil.wrap(task, MDC.getCopyOfContextMap()));
}
}
@Configuration
public class ThreadPoolTaskExecutorConfig{
//最大可用的CPU核数
public static final int PROCESSORS = Runtime.getRuntime().availableProcessors();
@Bean
public ThreadPoolExecutorMdcWrapper getExecutor(){
ThreadPoolExecutorMdcWrapper executor =new ThreadPoolExecutorMdcWrapper();
executor.setCorePoolSize(PROCESSORS *2);
executor.setMaxPoolSize(PROCESSORS * 4);
executor.setQueueCapacity(50);
executor.setKeepAliveSeconds(60);
executor.setThreadNamePrefix("Task-A");
executor.setRejectedExecutionHandler(new ThreadPoolExecutor.AbortPolicy());
executor.initialize();
return executor;
}
}
- 单线程的做法(不建议)
public class MDCRunable implements Runnable {
private Map<String, String> copyOfContextMap;
private Runnable runnable;
public MDCRunable(Runnable runnable) {
this.copyOfContextMap = MDC.getCopyOfContextMap();
this.runnable = runnable;
}
@Override
public void run() {
if (!copyOfContextMap.isEmpty()) {
MDC.setContextMap(copyOfContextMap);
}
try {
runnable.run();
} finally {
if (!copyOfContextMap.isEmpty()) {
MDC.clear();
}
}
}
}
5. 测试结果
- 上游日志
2023-02-27 18:58:05 [http-nio-8099-exec-2] INFO c.s.c.controller.ConsumerController [65f8173c73f945d99ea5b0ab209164fd] - consumer-打印日志2
2023-02-27 18:58:05 [DefaultAsync-1] INFO c.s.c.controller.ConsumerController [65f8173c73f945d99ea5b0ab209164fd] - consumer-thread-01，测试线程
2023-02-27 18:58:05 [pool-9-thread-1] INFO c.s.c.controller.ConsumerController [65f8173c73f945d99ea5b0ab209164fd] - consumer-mdc-thread
- 下游日志
2023-02-27 18:58:05 [http-nio-8089-exec-1] INFO c.s.f.p.c.ProviderController [65f8173c73f945d99ea5b0ab209164fd] - provider-测试日志
2023-02-27 18:58:05 [DefaultAsync-1] INFO c.s.f.p.c.ProviderController [65f8173c73f945d99ea5b0ab209164fd] - provider-thread-02，测试线程