Introduction to MDC

In complex applications, a request needs to be processed in many ways. How can we quickly find all the logs of a request. In distributed systems, we can use link tracking, such as zipkin and skywalking, to quickly find logs to locate problems. In a complex monomer management system, we can use slf4j's MDC to achieve similar functions.

MDC (mapped diagnostic contexts) is a method tool class that appears to help us diagnose online problems. Implemented using ThreadLocal, each thread will have a separate copy of the variables in MDC, and multiple threads will not interfere with each other. MDC functions, logback and log4j provide support. In matrix web, logback and slf4j are used for logging.

MDC principle

MDC class is a static tool class, which provides an interface similar to Map:

public class MDC { 
   // Empty all entries in the map.
   public static void clear(); 
   // Return the corresponding object according to the key value
   public static object get(String key); 
   // Returns all key values 
   public static Enumeration getKeys(); 
   // Insert the key value and the associated object into the map
   public static void put(String key, Object val), 
   // Delete the object corresponding to the key
   public static  remove(String key) 
}

In order to understand the principle of MDC, let's follow the MDC source code, such as the put method, and finally hand it over to the mdcdadapter.

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);
   }

The tracking code mdcAdapter is initialized by the StaticMDCBinder, that is, the instance of LogbackMDCAdapter.

public class StaticMDCBinder {

    /**
     * The unique instance of this class.
     */
    public static final StaticMDCBinder SINGLETON = new StaticMDCBinder();

    private StaticMDCBinder() {
    }

    /**
     * Currently this method always returns an instance of 
     * {@link StaticMDCBinder}.
     */
    public MDCAdapter getMDCA() {
        return new LogbackMDCAdapter();
    }

The put method in LogbackMDCAdapter is finally handled by copyOnThreadLocal.

  public void put(String key, String val) throws IllegalArgumentException {
        if (key == null) {
            throw new IllegalArgumentException("key cannot be null");
        }

        Map<String, String> oldMap = copyOnThreadLocal.get();
        Integer lastOp = getAndSetLastOperation(WRITE_OPERATION);

        if (wasLastOpReadOrNull(lastOp) || oldMap == null) {
            Map<String, String> newMap = duplicateAndInsertNewMap(oldMap);
            newMap.put(key, val);
        } else {
            oldMap.put(key, val);
        }
    }

copyOnThreadLocal is a ThreadLocal.

final ThreadLocal<Map<String, String>> copyOnThreadLocal = new ThreadLocal<Map<String, String>>();

It can be seen that the key and value of MDC are stored and retrieved by ThreadLocal.

Using MDC in matrix Web

In the matrix web, Filter is used for MDC processing. Before the request enters the business request logic, the request generated by the front end is processed_ The ID is stored in the MDC. When the requested business logic is completed, the MDC is cleared.

public class LogFilter implements Filter {
  
    public static final String REQUEST_ID="REQUEST_ID";
  
    @Override
    public void doFilter(ServletRequest servletRequest, ServletResponse servletResponse, FilterChain filterChain) throws IOException, ServletException {
        HttpServletRequest httpServletRequest = (HttpServletRequest) servletRequest;
      
          //REQUEST_ The ID is generated by the front end,
           MDC.put(REQUEST_ID, getRequestId(httpServletRequest));
         
            
           filterChain.doFilter(servletRequest, servletResponse);
      
          
           MDC.clear();
        }

    }
}

In logback Configure print request in XML_ ID, use this to configure% X{REQUEST_ID}. The specific configuration is as follows:

    <appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">
        <encoder class="ch.qos.logback.classic.encoder.PatternLayoutEncoder">
            <!--Format output:%d Indicates the date,%thread Represents the thread name,%-5level: The level is displayed 5 characters wide from the left%msg: Log messages,%n Is a newline character-->
            <pattern>%d{yyyy-MM-dd HH:mm:ss.SSS} %X{REQUEST_ID} [%thread] %-5level %logger{50} - %msg%n</pattern>
        </encoder>
    </appender>
    <!-- Generate log files on a daily basis -->
    <appender name="FILE"  class="ch.qos.logback.core.rolling.RollingFileAppender">
        <rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">
            <!--The file name of the log file output-->
            <FileNamePattern>${LOG_HOME}/${APP_NAME}.log.%d{yyyy-MM-dd}.log</FileNamePattern>
            <!--Log file retention days-->
            <MaxHistory>30</MaxHistory>
        </rollingPolicy>
        <encoder class="ch.qos.logback.classic.encoder.PatternLayoutEncoder">
            <!--Format output:%d Indicates the date,%thread Represents the thread name,%-5level: The level is displayed 5 characters wide from the left%msg: Log messages,%n Is a newline character-->
            <pattern>%d{yyyy-MM-dd HH:mm:ss.SSS} %X{REQUEST_ID} [%thread] %-5level %logger{50} - %msg%n</pattern>
        </encoder>
        <!--Maximum size of log file-->
        <triggeringPolicy class="ch.qos.logback.core.rolling.SizeBasedTriggeringPolicy">
            <MaxFileSize>10MB</MaxFileSize>
        </triggeringPolicy>
    </appender>

Define a RespDTO, which is used by the Controller to uniformly return results. In this class, the requestId will be automatically assigned to this class and uniformly assigned to the front end, so that the front end page can also find the requestId from the request results.

public class RespDTO<T> implements Serializable {

    public int code = 0;
    public String message = "";
    public T data;
    public String requestId;

    public static RespDTO onSuc(Object data) {
        RespDTO resp = new RespDTO();
        String requestId = MDC.get(REQUEST_ID);
        if (!StringUtils.isEmpty(requestId)) {
            resp.requestId = requestId;
        }
        resp.message="sucess";
        resp.data = data;
        return resp;
    }

    @Override
    public String toString() {
        return "RespDTO{" +
                "code=" + code +
                ", error='" + message + '\'' +
                ", data=" + data +
                '}';
    }
}

Using MDC, the logs of all business processing logic of a request can be concatenated through a unique ID to facilitate log troubleshooting.