MDC：更好的日志记录方式

概述

MDC（Mapped Diagnostic Context）是一种用于在日志记录过程中传递上下文信息的机制。它允许将自定义的键值对与日志记录相关联，并在日志输出时自动将这些键值对添加到日志消息中

为什么使用MDC

一般的公司，中小型项目比较多，然后服务器资源也是比较紧俏，所以我们一般也不会去使用EFK等日志框架来为我们的开发和运维来提供支撑。但是在项目过程中，比如我要追踪整个请求的链路日志，但是这些日志并不会连续的打在一起，中间会穿插着其他的日志，甚至还会隔开很远。

LOGGER.info(“UserId:”+userId+” Session Id:”+sessionId+” Requestid:”+requestId+ "Handling request for service 1" );
1

所以我们在开发的时候可能会给我们自己的log.info添加一些固定的标识，比如：请求名称、固定字符串、用户标识等，然后在日志链路追踪的时候使用grep来检索。这样确实也能满足我们的要求，但是实际开发过程中，由于开发水平不一致，其他的一些同事比较随意的一些日志记录会让后续的同事排查起来非常辛苦。

使用MDC（Mapped Diagnostic Context）的主要目的是在日志记录过程中携带和传递上下文信息。以下是一些使用MDC的好处和原因：

1. 跟踪和调试：MDC允许将关键的上下文信息与每条日志消息相关联。例如，请求ID、用户信息、会话ID等。这样，当日志中出现问题或需要进行故障排除时，可以更轻松地跟踪和调试，因为您可以查看包含相关上下文信息的日志消息。

2. 上下文感知日志记录：MDC使日志记录更加上下文感知。通过将关键信息添加到MDC上下文中，这些信息将自动出现在日志消息中，而无需手动编写并在每个日志语句中添加。这样可以避免代码中的重复工作，提高代码的可读性和可维护性。

3. 安全审计：对于安全审计和合规性方面的需求，MDC可以用于记录关键的安全信息，例如用户身份、操作类型、时间戳等。这些信息可以用于后续的审计和监控，以确保系统的安全性和合规性。

4. 多线程环境支持：MDC在多线程环境中是线程安全的。它为每个线程维护独立的MDC上下文，因此线程之间的上下文信息不会相互干扰。这对于并发和多线程应用程序非常重要。

5. 日志聚合和分析：MDC的上下文信息可以用于日志聚合和分析。通过将相同请求或操作的日志消息关联到相同的上下文，可以更轻松地对日志进行分组、过滤和分析，以获得更全面的视图和洞察力。

logback/sl4j MDC使用

首先我给出logback.xml中的配置，在logback/log4j基本配置和标签详解的文章中，作者有详细的介绍，如果有不清楚的可以跳过去看看。

    <appender name="INFO" class="ch.qos.logback.core.rolling.RollingFileAppender">
        <file>${LOG_FILE_ROOT}/web-info.logfile>
        <filter class="ch.qos.logback.classic.filter.LevelFilter">
            <level>INFOlevel>
            <onMatch>ACCEPTonMatch>
            <onMismatch>DENYonMismatch>
        filter>
        <rollingPolicy class="ch.qos.logback.core.rolling.SizeAndTimeBasedRollingPolicy">
            <fileNamePattern>${LOG_FILE_ROOT}/web-info-%d{yyyy-MM-dd}.%i.log.gzfileNamePattern>
            <maxFileSize>100MBmaxFileSize>
            <maxHistory>20maxHistory>
            <cleanHistoryOnStart>truecleanHistoryOnStart>
        rollingPolicy>
        <encoder>
            <pattern>%date{yyyy-MM-dd HH:mm:ss.SSS}[%level][%thread][%logger.java:%line] - %msg%npattern>
        encoder>
    appender>
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18

上面这个appender中的pattern是之前的，后续我们需要对其进行修改，因为我们这边需要添加MDC。

step1： 添加HandlerInterceptor，我使用了一个工具类来生成随机的id最为追踪id，如果你的系统是分布式的集群部署的建议换个雪花算法啥的，我这边只是单纯的演示功能。

import org.slf4j.MDC;

@Component
public class LoggerAdapterHandler implements HandlerInterceptor {

    private final static String TRACE_ID = "TRACEID";
    @Override
     public boolean preHandle(HttpServletRequest request, HttpServletResponse response, Object handler) throws Exception { {
        MDC.put(TRACE_ID, IdUtil.randomUUID());
        return true;
    }
}
1
2
3
4
5
6
7
8
9
10
11
12

step2: 优化logback.xml文件，将所有的pattern加上%X{TRACEID}，这里面的类容自己定义具体位置。

<encoder>
            <pattern>%date{yyyy-MM-dd HH:mm:ss.SSS}[%level][%thread][%logger.java:%line][tx.id=%X{TRACEID}] - %msg%npattern>
        encoder>
1
2
3

step3: 我们在查询日志的根据生成的traceId来grep,就可以把整个链路打印出来了

tail -100f web-info.log |grep ‘43471a4b-43e3-4767-b16a-ecf8e2cc10b7’

如果我在代码中加了线程池进行并行操作，线程池中的traceid会有吗？

 ThreadPoolExecutor threadPoolExecutor = new ThreadPoolExecutor(2, 2, 2, TimeUnit.MILLISECONDS, new LinkedBlockingQueue<>(3));
        for (int i = 0; i < 2; i++) {
            threadPoolExecutor.execute(()->{
                log.info("我主要看下线程");
            });

        }
1
2
3
4
5
6
7

我看从日志中看到tx.id= 空的，那我们在log.info里面加MDC.put方法是否可以加上呢

ThreadPoolExecutor threadPoolExecutor = new ThreadPoolExecutor(2, 2, 2, TimeUnit.MILLISECONDS, new LinkedBlockingQueue<>(3));
        for (int i = 0; i < 2; i++) {
            threadPoolExecutor.execute(()->{
                MDC.put("TRACEID", IdUtil.randomUUID());
                log.info("我主要看下线程");
            });

        }
1
2
3
4
5
6
7
8

确实可以，但是和外边的不一样，并且每个线程都不一样。

如果您想要线程池中的任务的TRACEID与外部一致，您可以将外部的TRACEID传递给线程池中的任务。这样，线程池中的任务就可以使用相同的TRACEID进行日志记录和跟踪。

以下是一种实现方法：

1. 在外部生成TRACEID：您可以在外部生成TRACEID，并将其存储在一个地方，以便在需要时访问。

2. 将TRACEID传递给线程池中的任务：在将任务提交给线程池之前，将TRACEID传递给任务。这可以通过构造函数、方法参数或通过自定义的任务包装器（Task Wrapper）来实现。

   public class MyTask implements Runnable {
       private final String traceId;
   
       public MyTask(String traceId) {
           this.traceId = traceId;
       }
   
       @Override
       public void run() {
           MDC.put(TRACE_ID, traceId);
           try {
               // 执行任务逻辑
               // 在日志语句中使用MDC上下文信息
               Logger logger = LoggerFactory.getLogger(MyTask.class);
               logger.info("Task execution with TRACEID: {}", MDC.get(TRACE_ID));
           } finally {
               MDC.remove(TRACE_ID);
           }
       }
   }
   
   public class MyTaskExecutor {
       @Autowired
       private ThreadPoolTaskExecutor taskExecutor;
   
       public void executeTask(String traceId) {
           taskExecutor.execute(new MyTask(traceId));
       }
   }
   ```
   
   在上述示例中，`MyTask`的构造函数接受TRACEID作为参数，并将其存储在任务中。在任务的`run`方法中，将该TRACEID设置到MDC上下文中，以便在日志语句中使用。
   
   1
   2
   3
   4
   5
   6
   7
   8
   9
   10
   11
   12
   13
   14
   15
   16
   17
   18
   19
   20
   21
   22
   23
   24
   25
   26
   27
   28
   29
   30
   31
   32
   33

3. 外部生成TRACEID并提交任务：在外部生成TRACEID后，通过调用executeTask(traceId)将任务提交给线程池。

   public class MainClass {
       @Autowired
       private MyTaskExecutor taskExecutor;
   
       public void mainMethod() {
           String traceId = generateTraceId(); // 外部生成TRACEID
           taskExecutor.executeTask(traceId); // 提交任务并传递TRACEID
       }
   }
   ```
   
   在上述示例中，`MainClass`调用
   
   1
   2
   3
   4
   5
   6
   7
   8
   9
   10
   11
   12
   13

MDC和线程池

MDC（Mapped Diagnostic Context）的实现通常使用ThreadLocal来存储上下文信息，这是一种实现线程安全的简单合理的方式。

然而，当在线程池中使用MDC时，我们需要小心。下面我们来看看ThreadLocal-based MDC和线程池结合使用可能存在的问题：

1. 从线程池获取一个线程。
2. 使用MDC.put()或ThreadContext.put()方法将一些上下文信息存储在MDC中。
3. 在某些日志中使用这些信息，但不小心忘记清除MDC上下文。
4. 归还的线程回到线程池。
5. 一段时间后，应用程序重新从线程池获取相同的线程。
6. 由于上次没有清除MDC，这个线程仍然持有来自先前执行的一些数据。
7. 这可能导致执行之间的一些意外不一致性。

为了避免这种情况，一种方法是始终记得在每次执行结束时清除MDC上下文。然而，这种方法通常需要严格的人工监督，因此容易出错。

另一种方法是使用ThreadPoolExecutor的钩子（hooks）并在每次执行后执行必要的清理操作。

为了实现这一点，我们可以扩展ThreadPoolExecutor类并重写afterExecute()钩子方法。

区别

log4j、SLF4J（Simple Logging Facade for Java）和Logback之间存在以下关系：

1. log4j：log4j是Java中最早的流行日志框架之一。它提供了强大的日志功能，包括日志级别、日志输出目的地（如控制台、文件等）、日志格式等。log4j有自己的API和配置方式。

2. SLF4J：SLF4J是一个抽象日志框架，旨在为Java应用程序提供一种统一的日志记录接口。它提供了一组接口和类，用于在应用程序代码中编写日志语句。SLF4J本身不提供任何实际的日志功能，而是作为一个门面（Facade）层，允许应用程序与底层的日志实现进行解耦。

3. Logback：Logback是由log4j的创始人Ceki Gülcü开发的日志框架，也是log4j的继任者。它是SLF4J的实现之一，提供了与SLF4J兼容的API。Logback具有与log4j类似的功能，包括日志级别、输出目的地、格式化等。它还提供了一些额外的功能，如异步日志记录和支持MDC（Mapped Diagnostic Context）。

由于SLF4J是一个抽象框架，它可以与不同的日志实现进行集成，包括log4j、Logback和其他一些日志库。因此，在项目中可以使用SLF4J作为日志门面接口，然后根据需要选择具体的日志实现。这样设计的好处是，您可以在不更改应用程序代码的情况下切换日志实现，只需要更改相关的依赖和配置。