日常在开发过程中方便排查文件，需要在日志中输出一些关键内容。
MDC
在茫茫日志中定位需要的信息很费时，MDC 全称是 Mapped Diagnostic Context.一个线程安全的存放诊断日志的容器。
演示代码
HTTP处理演示
代码
实际上代码不需要这么麻烦,只需要调用MDC.put 就能将数据写入，但是实际开发过程中。通过手动编码的方式添加太低效了，这里在spring mvc的场景下使用用拦截器来处理数据注入操作。
/**
* @author z201.coding@gmail.com
**/
@RestController
@Slf4j
public class AppApplicationController {
@RequestMapping(value = "")
public Object index() {
log.info("index");
Map<String, Object> data = new HashMap<>();
data.put("code", "200");
return data;
}
}
**
* @author z201.coding@gamil.com
*/
@Order(Ordered.HIGHEST_PRECEDENCE + 8)
@ConditionalOnClass(WebMvcConfigurer.class)
@Slf4j
@Component
public class MdcTraceContextFilter extends OncePerRequestFilter {
@Override
protected void doFilterInternal(HttpServletRequest request, HttpServletResponse response,
FilterChain filterChain) throws ServletException, IOException {
String appTraceId = request.getHeader(MdcApiConstant.HTTP_HEADER_TRACE_ID);
/**
* 没有设置就设置下,设置了就直接返回。注意这里必须提前在拦截器中设置好，不然会失效。
*/
if (StrUtil.isEmpty(appTraceId)) {
appTraceId = MDC.get(MdcApiConstant.HTTP_HEADER_TRACE_ID);
if (Strings.isEmpty(appTraceId)) {
appTraceId = MdcTool.getInstance().currentTraceId();
}
request.setAttribute(MdcApiConstant.HTTP_HEADER_TRACE_ID, appTraceId);
}
MDC.put(MdcApiConstant.HTTP_HEADER_TRACE_ID, appTraceId);
filterChain.doFilter(request, response);
}
}
/**
* @author z201.coding@gmail.com
**/
public class MdcTool {
private static class SingletonHolder {
private static final MdcTool INSTANCE = new MdcTool();
}
private MdcTool (){}
public static final MdcTool getInstance() {
return SingletonHolder.INSTANCE;
}
public synchronized String currentTraceId() {
ThreadLocalRandom random = ThreadLocalRandom.current();
UUID uuid = new UUID(random.nextInt(), random.nextInt());
StringBuilder st = new StringBuilder(uuid.toString().replace("-", "").toLowerCase());
st.append(Instant.now().toEpochMilli());
int i = 0;
while (i < 3) {
i++;
st.append(ThreadLocalRandom.current().nextInt(2));
}
return st.toString();
}
}
log配置文件
Log4j 或者 logback 在pattern表中修改表达式
%X{AppTraceId}这就是拦截去注入进去的数据key。
<pattern>[%t][%level][%file:%line][%X{AppTraceId}] %msg%n</pattern>
- Console
culr http://localhost:9007/mdc/
[AppApplicationController.java:19][00000000299baa76ffffffffbd27659b1641811416723011] index
异步调用的
- 在记录日志的时候，通常会使用MDC来存储每个线程的特有参数，以便更好的查询日志。
- 但是Logback在最新的版本中因为性能问题，不会自动的将MDC的内存传给子线程。所以Logback建议在执行异步线程前
- 先通过MDC.getCopyOfContextMap()方法将MDC内存获取出来，再传给线程。
- 并在子线程的执行的最开始调用MDC.setContextMap(context)方法将父线程的MDC内容传给子线程。
/**
* 这是{@link ThreadPoolTaskExecutor}简单的改良，可以在每个任务之前设置子线程的MDC数据。
* <p>
* https://logback.qos.ch/manual/mdc.html
*
* @author z201.coding@gamil.com
*/
public class MdcThreadPoolTaskExecutor extends ThreadPoolTaskExecutor {
/**
* Pool where task threads take MDC from the submitting thread.
*/
public static MdcThreadPoolTaskExecutor newWithInheritedMdc(int corePoolSize, int maximumPoolSize, long keepAliveTime,
TimeUnit unit, int queueCapacity, RejectedExecutionHandler rejectedExecutionHandler) {
return new MdcThreadPoolTaskExecutor(corePoolSize, maximumPoolSize, keepAliveTime, unit, queueCapacity, rejectedExecutionHandler);
}
private MdcThreadPoolTaskExecutor(int corePoolSize, int maximumPoolSize,
long keepAliveTime, TimeUnit unit, int queueCapacity, RejectedExecutionHandler rejectedExecutionHandler) {
setCorePoolSize(corePoolSize);
setMaxPoolSize(maximumPoolSize);
setKeepAliveSeconds((int) unit.toSeconds(keepAliveTime));
setQueueCapacity(queueCapacity);
setRejectedExecutionHandler(rejectedExecutionHandler);
}
private Map<String, String> initMdcContext() {
// 获取父线程MDC中的内容，必须在run方法之前，否则等异步线程执行的时候有可能MDC里面的值已经被清空了，这个时候就会返回null
Map<String, String> context = MDC.getCopyOfContextMap();
if (Validator.isNull(context)) {
context = new HashMap<>();
}
if (CollectionUtil.isEmpty(context)) {
// 防止线程没有链路信息,这里可以扩展
context.put(MdcApiConstant.HTTP_HEADER_TRACE_ID, MdcTool.getInstance().currentTraceId());
}
return context;
}
/**
* 所有线程都会委托给这个execute方法，在这个方法中我们把父线程的MDC内容赋值给子线程
* https://logback.qos.ch/manual/mdc.html#managedThreads
*
* @param runnable
*/
@Override
public void execute(@NonNull Runnable runnable) {
super.execute(() -> run(runnable, initMdcContext()));
}
/**
* 异步提交
*
* @param task
* @return
*/
@NonNull
@Override
public Future<?> submit(@NonNull Runnable task) {
return super.submit(() -> run(task, initMdcContext()));
}
/**
* 异步提交
*
* @param task
* @return
*/
@NonNull
@Override
public <T> Future<T> submit(@NonNull Callable<T> task) {
return super.submit(submit(task, initMdcContext()));
}
/**
* 子线程委托的执行方法s
*
* @param runnable {@link Runnable}
* @param context 父线程MDC内容
*/
private void run(Runnable runnable, Map<String, String> context) {
// 将父线程的MDC内容传给子线程
if (context != null) {
try {
MDC.setContextMap(context);
} catch (Exception e) {
logger.error(e.getMessage(), e);
}
}
try {
// 执行异步操作
runnable.run();
} finally {
// 清空MDC内容
MDC.clear();
}
}
private static <T> Callable<T> submit(final Callable<T> task, final Map<String, String> context) {
return () -> {
Map<String, String> previous = MDC.getCopyOfContextMap();
if (context == null) {
MDC.clear();
} else {
MDC.setContextMap(context);
}
try {
return task.call();
} finally {
if (previous == null) {
MDC.clear();
} else {
MDC.setContextMap(previous);
}
}
};
}
}
package cn.z201.mdc.log;
import java.util.concurrent.ThreadPoolExecutor;
import java.util.concurrent.TimeUnit;
/**
* @author z201.coding@gmail.com
**/
public class MdcThreadTaskUtils {
private static MdcThreadPoolTaskExecutor taskExecutor = null;
/**
* demo
* ThreadTaskUtils.run(() -> run());
* FutureTask<String> futureTask = new FutureTask<String>(() -> call());
* ThreadTaskUtils.run(futureTask);
*/
static {
/**
* 核心线程数 5
* 最大线程数 50
* 队列最大长度 1000
* 线程池维护线程所允许的空闲时间(单位秒) 120
* 线程池对拒绝任务(无线程可用)的处理策略 ThreadPoolExecutor.CallerRunsPolicy策略 ,调用者的线程会执行该任务,如果执行器已关闭,则丢弃. 120
*/
}
public static void run(Runnable runnable) {
if (null == taskExecutor) {
taskExecutor = MdcThreadPoolTaskExecutor.newWithInheritedMdc(5, 50, 1000, TimeUnit.SECONDS, 120, new ThreadPoolExecutor.AbortPolicy());
taskExecutor.initialize();
}
taskExecutor.execute(runnable);
}
}
线程次调用演示
package cn.z201.mdc.log;
import lombok.extern.slf4j.Slf4j;
import org.junit.jupiter.api.Disabled;
import org.junit.jupiter.api.MethodOrderer;
import org.junit.jupiter.api.Test;
import org.junit.jupiter.api.TestMethodOrder;
import org.junit.jupiter.api.extension.ExtendWith;
import org.springframework.boot.test.autoconfigure.web.servlet.AutoConfigureMockMvc;
import org.springframework.boot.test.context.SpringBootTest;
import org.springframework.test.context.junit.jupiter.SpringExtension;
import java.util.concurrent.CountDownLatch;
@Slf4j
@ExtendWith(SpringExtension.class)
@SpringBootTest(classes = AppApplication.class, webEnvironment = SpringBootTest.WebEnvironment.RANDOM_PORT)
@AutoConfigureMockMvc
// 指定单元测试方法顺序
@TestMethodOrder(MethodOrderer.OrderAnnotation.class)
public class AppApplicationTest {
@Test
@Disabled
public void testMdcTask(){
MdcThreadTaskUtils.run(()->{
log.info("");
});
int count = 10;
CountDownLatch countDownLatch = new CountDownLatch(count);
for (int i = 0; i < count; i++) {
MdcThreadTaskUtils.run(()->{
log.info("{}",Thread.currentThread().getId());
countDownLatch.countDown();
});
}
countDownLatch.countDown();
}
}
- Console
[MdcThreadPoolTaskExecutor-1][INFO][0000000044c1a93a000000000224a6b71641812254518111]
[MdcThreadPoolTaskExecutor-2][INFO][ffffffffd75119fd0000000030ef630d1641812254519101] 34
[MdcThreadPoolTaskExecutor-3][INFO][0000000066a8e5c8ffffffffd68aed601641812254519001] 35
[MdcThreadPoolTaskExecutor-4][INFO][0000000066ee68fdfffffffff577e4281641812254519111] 36
[MdcThreadPoolTaskExecutor-3][INFO][ffffffffa217a73300000000725bf6351641812254519000] 35
[MdcThreadPoolTaskExecutor-5][INFO][00000000320b6d0a000000003af12e701641812254519011] 37
[MdcThreadPoolTaskExecutor-3][INFO][000000006b4901b6ffffffffebbf10d91641812254519110] 35
[MdcThreadPoolTaskExecutor-1][INFO][000000002b61782800000000157d2c1e1641812254519100] 33
[MdcThreadPoolTaskExecutor-5][INFO][00000000586b86f7ffffffffc5581f661641812254520000] 37
[MdcThreadPoolTaskExecutor-1][INFO][ffffffff930e3437ffffffffa425c03b1641812254520011] 33
[MdcThreadPoolTaskExecutor-2][INFO][000000001a75d2e7fffffffff55857f91641812254520010] 34
- 成功防止异步操作丢失了log标记信息。
SpringAsync方法
@Bean
public AsyncTaskExecutor taskExecutor() {
ThreadPoolTaskExecutor executor =
MdcThreadPoolTaskExecutor.newWithInheritedMdc(8, 32, 2, TimeUnit.MINUTES, 1000, new ThreadPoolExecutor.AbortPolicy());
executor.setThreadNamePrefix("def-Executor ");
return executor;
}
@RestController
@Slf4j
public class AppApplicationController {
@Async
@RequestMapping(value = "")
public Object index() {
log.info("index");
Map<String, Object> data = new HashMap<>();
data.put("code", "200");
return data;
}
}
- Console
[def-Executor 1][INFO][ffffffffd62f558600000000385223a51641814195289011] index
- 还有其它场景的用法，比如内部服务调用的时候，就可以单独将数封住在请求中传递到下个服务，只需要在下一个服务中的拦截器中获取在设置到当前MDC中即可。
MDC源码
/**
* As of SLF4J version 1.7.14, StaticMDCBinder classes shipping in various bindings
* come with a getSingleton() method. Previously only a public field called SINGLETON
* was available.
*
* @return MDCAdapter
* @throws NoClassDefFoundError in case no binding is available
* @since 1.7.14
*/
private static MDCAdapter bwCompatibleGetMDCAdapterFromBinder() throws NoClassDefFoundError {
try {
return StaticMDCBinder.getSingleton().getMDCA();
} catch (NoSuchMethodError nsme) {
// binding is probably a version of SLF4J older than 1.7.14
return StaticMDCBinder.SINGLETON.getMDCA();
}
}
static {
try {
mdcAdapter = bwCompatibleGetMDCAdapterFromBinder();
} catch (NoClassDefFoundError ncde) {
mdcAdapter = new NOPMDCAdapter();
String msg = ncde.getMessage();
if (msg != null && msg.contains("StaticMDCBinder")) {
Util.report("Failed to load class \"org.slf4j.impl.StaticMDCBinder\".");
Util.report("Defaulting to no-operation MDCAdapter implementation.");
Util.report("See " + NO_STATIC_MDC_BINDER_URL + " for further details.");
} else {
throw ncde;
}
} catch (Exception e) {
// we should never get here
Util.report("MDC binding unsuccessful.", e);
}
}
/**
* Put a diagnostic context value (the <code>val</code> parameter) as identified with the
* <code>key</code> parameter into the current thread's diagnostic context map. The
* <code>key</code> parameter cannot be null. The <code>val</code> parameter
* can be null only if the underlying implementation supports it.
*
* <p>
* This method delegates all work to the MDC of the underlying logging system.
*
* @param key non-null key
* @param val value to put in the map
*
* @throws IllegalArgumentException
* in case the "key" parameter is null
*/
public static void put(String key, String val) throws IllegalArgumentException {
if (key == null) {
throw new IllegalArgumentException("key parameter cannot be null");
}
if (mdcAdapter == null) {
throw new IllegalStateException("MDCAdapter cannot be null. See also " + NULL_MDCA_URL);
}
mdcAdapter.put(key, val);
}
- 静态代码初始化mdcAdapter,mdcAdapter是个接口，可以理解为规范，会有不同的实现类。
- 项目中使用的是logback所以，实际使用的是LogbackMDCAdapter。
// The internal map is copied so as
// We wish to avoid unnecessarily copying of the map. To ensure
// efficient/timely copying, we have a variable keeping track of the last
// operation. A copy is necessary on 'put' or 'remove' but only if the last
// operation was a 'get'. Get operations never necessitate a copy nor
// successive 'put/remove' operations, only a get followed by a 'put/remove'
// requires copying the map.
// See http://jira.qos.ch/browse/LOGBACK-620 for the original discussion.
// We no longer use CopyOnInheritThreadLocal in order to solve LBCLASSIC-183
// Initially the contents of the thread local in parent and child threads
// reference the same map. However, as soon as a thread invokes the put()
// method, the maps diverge as they should.
final ThreadLocal<Map<String, String>> copyOnThreadLocal = new ThreadLocal<Map<String, String>>();
private static final int WRITE_OPERATION = 1;
private static final int MAP_COPY_OPERATION = 2;
// keeps track of the last operation performed
final ThreadLocal<Integer> lastOperation = new ThreadLocal<Integer>();
真想大白，实际上维护了一个
ThreadLocal这里需要注意有一个
NOPMDCAdapter，注意要是适配不支持上下文的日志系统。比如JDK14中的NOP。