1. 概述

本文将探讨如何使用 映射诊断上下文 (MDC) 来增强应用程序的日志功能。

MDC 提供了一种机制,允许我们在日志消息中添加额外上下文信息。这些信息可能在日志记录点不可直接访问,但对于追踪程序执行流程至关重要。

2. 为什么需要 MDC

假设我们要开发一个转账系统。首先定义 Transfer 类表示交易基本信息:

public class Transfer {
    private String transactionId;
    private String sender;
    private Long amount;
    
    public Transfer(String transactionId, String sender, long amount) {
        this.transactionId = transactionId;
        this.sender = sender;
        this.amount = amount;
    }
    
    public String getSender() {
        return sender;
    }

    public String getTransactionId() {
        return transactionId;
    }

    public Long getAmount() {
        return amount;
    }
}

通过抽象服务类 TransferService 执行转账:

public abstract class TransferService {

    public boolean transfer(long amount) {
        // 连接远程服务实际执行转账
    }

    abstract protected void beforeTransfer(long amount);

    abstract protected void afterTransfer(long amount, boolean outcome);
}

我们重写 beforeTransfer()afterTransfer() 方法记录日志:

import org.apache.log4j.Logger;
import com.baeldung.mdc.TransferService;

public class Log4JTransferService extends TransferService {
    private Logger logger = Logger.getLogger(Log4JTransferService.class);

    @Override
    protected void beforeTransfer(long amount) {
        logger.info("Preparing to transfer " + amount + "$.");
    }

    @Override
    protected void afterTransfer(long amount, boolean outcome) {
        logger.info(
          "Has transfer of " + amount + "$ completed successfully ? " + outcome + ".");
    }
}

⚠️ 核心问题:日志记录时无法访问 Transfer 对象,只能记录金额,导致无法关联交易ID和发送方信息。

配置 log4j.properties 输出到控制台:

log4j.appender.consoleAppender=org.apache.log4j.ConsoleAppender
log4j.appender.consoleAppender.layout=org.apache.log4j.PatternLayout
log4j.appender.consoleAppender.layout.ConversionPattern=%-4r [%t] %5p %c %x - %m%n
log4j.rootLogger = TRACE, consoleAppender

使用线程池模拟并发转账:

public class TransferDemo {

    public static void main(String[] args) {
        ExecutorService executor = Executors.newFixedThreadPool(3);
        TransactionFactory transactionFactory = new TransactionFactory();
        for (int i = 0; i < 10; i++) {
            Transfer tx = transactionFactory.newInstance();
            Runnable task = new Log4JRunnable(tx);            
            executor.submit(task);
        }
        executor.shutdown();
    }
}

适配器类 Log4JRunnable

public class Log4JRunnable implements Runnable {
    private Transfer tx;
    
    public Log4JRunnable(Transfer tx) {
        this.tx = tx;
    }
    
    public void run() {
        log4jBusinessService.transfer(tx.getAmount());
    }
}

运行后日志混乱不堪,无法追踪具体交易:

...
519  [pool-1-thread-3]  INFO Log4JBusinessService 
  - Preparing to transfer 1393$.
911  [pool-1-thread-2]  INFO Log4JBusinessService 
  - Has transfer of 1065$ completed successfully ? true.
911  [pool-1-thread-2]  INFO Log4JBusinessService 
  - Preparing to transfer 1189$.
989  [pool-1-thread-1]  INFO Log4JBusinessService 
  - Has transfer of 1350$ completed successfully ? true.
989  [pool-1-thread-1]  INFO Log4JBusinessService 
  - Preparing to transfer 1178$.
1245 [pool-1-thread-3]  INFO Log4JBusinessService 
  - Has transfer of 1393$ completed successfully ? true.
1246 [pool-1-thread-3]  INFO Log4JBusinessService 
  - Preparing to transfer 1133$.
1507 [pool-1-thread-2]  INFO Log4JBusinessService 
  - Has transfer of 1189$ completed successfully ? true.
1508 [pool-1-thread-2]  INFO Log4JBusinessService 
  - Preparing to transfer 1907$.
1639 [pool-1-thread-1]  INFO Log4JBusinessService 
  - Has transfer of 1178$ completed successfully ? true.
1640 [pool-1-thread-1]  INFO Log4JBusinessService 
  - Preparing to transfer 674$.
...

MDC 就是解决这个问题的利器!

3. Log4j 中的 MDC

Log4j 的 MDC 允许我们向类 Map 结构填充数据,这些数据在日志写入时可供 Appender 访问。MDC 内部通过 ThreadLocal 绑定到执行线程。

使用流程:

  1. 向 MDC 填充需要记录的上下文信息
  2. 记录日志
  3. 清理 MDC

修改 Log4JRunnable

import org.apache.log4j.MDC;

public class Log4JRunnable implements Runnable {
    private Transfer tx;
    private static Log4JTransferService log4jBusinessService = new Log4JTransferService();

    public Log4JRunnable(Transfer tx) {
        this.tx = tx;
    }

    public void run() {
        MDC.put("transaction.id", tx.getTransactionId());
        MDC.put("transaction.owner", tx.getSender());
        log4jBusinessService.transfer(tx.getAmount());
        MDC.clear();
    }
}

更新 log4j.properties 打印 MDC 内容(使用 %X{key} 占位符):

log4j.appender.consoleAppender.layout.ConversionPattern=
  %-4r [%t] %5p %c{1} %x - %m - tx.id=%X{transaction.id} tx.owner=%X{transaction.owner}%n

现在日志清晰可追踪:

638  [pool-1-thread-2]  INFO Log4JBusinessService 
  - Has transfer of 1104$ completed successfully ? true. - tx.id=2 tx.owner=Marc
638  [pool-1-thread-2]  INFO Log4JBusinessService 
  - Preparing to transfer 1685$. - tx.id=4 tx.owner=John
666  [pool-1-thread-1]  INFO Log4JBusinessService 
  - Has transfer of 1985$ completed successfully ? true. - tx.id=1 tx.owner=Marc
666  [pool-1-thread-1]  INFO Log4JBusinessService 
  - Preparing to transfer 958$. - tx.id=5 tx.owner=Susan
739  [pool-1-thread-3]  INFO Log4JBusinessService 
  - Has transfer of 783$ completed successfully ? true. - tx.id=3 tx.owner=Samantha
739  [pool-1-thread-3]  INFO Log4JBusinessService 
  - Preparing to transfer 1024$. - tx.id=6 tx.owner=John
1259 [pool-1-thread-2]  INFO Log4JBusinessService 
  - Has transfer of 1685$ completed successfully ? false. - tx.id=4 tx.owner=John
1260 [pool-1-thread-2]  INFO Log4JBusinessService 
  - Preparing to transfer 1667$. - tx.id=7 tx.owner=Marc

4. Log4j2 中的 MDC

Log4j2 中对应功能称为 ThreadContext,使用方式类似:

import org.apache.logging.log4j.LogManager;
import org.apache.logging.log4j.Logger;

public class Log4J2TransferService extends TransferService {
    private static final Logger logger = LogManager.getLogger();

    @Override
    protected void beforeTransfer(long amount) {
        logger.info("Preparing to transfer {}$.", amount);
    }

    @Override
    protected void afterTransfer(long amount, boolean outcome) {
        logger.info("Has transfer of {}$ completed successfully ? {}.", amount, outcome);
    }
}

修改 Log4J2Runnable

import org.apache.logging.log4j.ThreadContext;

public class Log4J2Runnable implements Runnable {
    private final Transaction tx;
    private Log4J2BusinessService log4j2BusinessService = new Log4J2BusinessService();

    public Log4J2Runnable(Transaction tx) {
        this.tx = tx;
    }

    public void run() {
        ThreadContext.put("transaction.id", tx.getTransactionId());
        ThreadContext.put("transaction.owner", tx.getOwner());
        log4j2BusinessService.transfer(tx.getAmount());
        ThreadContext.clearAll();
    }
}

配置 log4j2.xml(语法与 Log4j 相同):

<Configuration status="INFO">
    <Appenders>
        <Console name="stdout" target="SYSTEM_OUT">
            <PatternLayout
              pattern="%-4r [%t] %5p %c{1} - %m - tx.id=%X{transaction.id} tx.owner=%X{transaction.owner}%n" />
        </Console>
    </Appenders>
    <Loggers>
        <Logger name="com.baeldung.log4j2" level="TRACE" />
        <AsyncRoot level="DEBUG">
            <AppenderRef ref="stdout" />
        </AsyncRoot>
    </Loggers>
</Configuration>

日志输出效果一致:

1119 [pool-1-thread-3]  INFO Log4J2BusinessService 
  - Has transfer of 1198$ completed successfully ? true. - tx.id=3 tx.owner=Samantha
1120 [pool-1-thread-3]  INFO Log4J2BusinessService 
  - Preparing to transfer 1723$. - tx.id=5 tx.owner=Samantha
1170 [pool-1-thread-2]  INFO Log4J2BusinessService 
  - Has transfer of 701$ completed successfully ? true. - tx.id=2 tx.owner=Susan
1171 [pool-1-thread-2]  INFO Log4J2BusinessService 
  - Preparing to transfer 1108$. - tx.id=6 tx.owner=Susan
1794 [pool-1-thread-1]  INFO Log4J2BusinessService 
  - Has transfer of 645$ completed successfully ? true. - tx.id=4 tx.owner=Susan

5. SLF4J/Logback 中的 MDC

SLF4J 的 MDC 依赖底层实现(Logback/Log4j),标准配置下开箱即用:

import org.slf4j.Logger;
import org.slf4j.LoggerFactory;

final class Slf4TransferService extends TransferService {
    private static final Logger logger = LoggerFactory.getLogger(Slf4TransferService.class);

    @Override
    protected void beforeTransfer(long amount) {
        logger.info("Preparing to transfer {}$.", amount);
    }

    @Override
    protected void afterTransfer(long amount, boolean outcome) {
        logger.info("Has transfer of {}$ completed successfully ? {}.", amount, outcome);
    }
}

修改 Slf4jRunnable

import org.slf4j.MDC;

public class Slf4jRunnable implements Runnable {
    private final Transaction tx;
    
    public Slf4jRunnable(Transaction tx) {
        this.tx = tx;
    }
    
    public void run() {
        MDC.put("transaction.id", tx.getTransactionId());
        MDC.put("transaction.owner", tx.getOwner());
        new Slf4TransferService().transfer(tx.getAmount());
        MDC.clear();
    }
}

配置 logback.xml

<configuration>
    <appender name="stdout" class="ch.qos.logback.core.ConsoleAppender">
        <encoder class="ch.qos.logback.classic.encoder.PatternLayoutEncoder">
            <pattern>%-4r [%t] %5p %c{1} - %m - tx.id=%X{transaction.id} tx.owner=%X{transaction.owner}%n</pattern>
    </encoder>
    </appender>
    <root level="TRACE">
        <appender-ref ref="stdout" />
    </root>
</configuration>

输出效果同样清晰:

1020 [pool-1-thread-3]  INFO c.b.m.s.Slf4jBusinessService 
  - Has transfer of 1869$ completed successfully ? true. - tx.id=3 tx.owner=John
1021 [pool-1-thread-3]  INFO c.b.m.s.Slf4jBusinessService 
  - Preparing to transfer 1303$. - tx.id=6 tx.owner=Samantha
1221 [pool-1-thread-1]  INFO c.b.m.s.Slf4jBusinessService 
  - Has transfer of 1498$ completed successfully ? true. - tx.id=4 tx.owner=Marc
1221 [pool-1-thread-1]  INFO c.b.m.s.Slf4jBusinessService 
  - Preparing to transfer 1528$. - tx.id=7 tx.owner=Samantha
1492 [pool-1-thread-2]  INFO c.b.m.s.Slf4jBusinessService 
  - Has transfer of 1110$ completed successfully ? true. - tx.id=5 tx.owner=Samantha
1493 [pool-1-thread-2]  INFO c.b.m.s.Slf4jBusinessService 
  - Preparing to transfer 644$. - tx.id=8 tx.owner=John

💡 如果底层日志框架不支持 MDC,相关调用会被静默忽略,不会产生副作用。

6. MDC 与线程池的坑

⚠️ **MDC 实现通常基于 ThreadLocal**,这在线程池中可能引发问题:

  1. 从线程池获取线程
  2. 通过 MDC.put() 存储上下文
  3. 记录日志后忘记清理 MDC
  4. 线程归还到线程池
  5. 应用再次获取该线程
  6. 线程仍残留上次执行的上下文数据

这会导致日志信息错乱!

解决方案

方案一:手动清理(不推荐)

@Override
public void run() {
    try {
        MDC.put("transaction.id", tx.getTransactionId());
        MDC.put("transaction.owner", tx.getSender());
        new Slf4TransferService().transfer(tx.getAmount());
    } finally {
        MDC.clear(); // 必须清理
    }
}

❌ 依赖人工记忆,容易遗漏

方案二:线程池钩子(推荐)

自定义 ThreadPoolExecutor,重写 afterExecute 钩子:

public class MdcAwareThreadPoolExecutor extends ThreadPoolExecutor {

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

    @Override
    protected void afterExecute(Runnable r, Throwable t) {
        System.out.println("Cleaning the MDC context");
        MDC.clear();
        org.apache.log4j.MDC.clear();
        ThreadContext.clearAll();
    }
}

✅ 自动清理,无需手动干预:

@Override
public void run() {
    MDC.put("transaction.id", tx.getTransactionId());
    MDC.put("transaction.owner", tx.getSender());
    new Slf4TransferService().transfer(tx.getAmount());
}

使用示例:

ExecutorService executor = new MdcAwareThreadPoolExecutor(3, 3, 0, MINUTES, 
  new LinkedBlockingQueue<>(), Thread::new, new AbortPolicy());
        
TransactionFactory transactionFactory = new TransactionFactory();

for (int i = 0; i < 10; i++) {
    Transfer tx = transactionFactory.newInstance();
    Runnable task = new Slf4jRunnable(tx);
    executor.submit(task);
}

executor.shutdown();

7. 总结

MDC 在多线程日志追踪中价值巨大,能有效解决日志交错导致的可读性问题。本文展示了在三大日志框架中的实现:

  • Log4j:直接使用 MDC
  • Log4j2:使用 ThreadContext
  • SLF4J:通过 MDC 接口适配

关键注意事项

  1. 线程池环境必须清理 MDC
  2. 推荐使用自定义线程池钩子自动清理
  3. 配置文件需添加 %X{key} 占位符

本文源码已托管至 GitHub,欢迎参考实践。


原始标题:Java Logging with Mapped Diagnostic Context (MDC)

« 上一篇: Java字符串转换