• Slf4j MDC机制


    转自:  https://www.liangzl.com/get-article-detail-572.html

    MDC 简介

    MDC ( Mapped Diagnostic Contexts ),它是一个线程安全的存放诊断日志的容器。

    Logback设计的一个目标之一是对分布式应用系统的审计和调试。在现在的分布式系统中,需要同时处理很多的请求。如何来很好的区分日志到底是那个请求输出的呢?我们可以为每一个请求生一个logger,但是这样子最产生大量的资源浪费,并且随着请求的增多这种方式会将服务器资源消耗殆尽,所以这种方式并不推荐。

    一种更加轻量级的实现是使用MDC机制,在处理请求前将请求的唯一标示放到MDC容器中如sessionId,这个唯一标示会随着日志一起输出,以此来区分该条日志是属于那个请求的。并在请求处理完成之后清除MDC容器。

    下面是MDC对外提供的方法,也可以通过MDC javadocs查看所有方法。

    package org.slf4j;
    
    public class MDC {
      // 将一个K-V的键值对放到容器,其实是放到当前线程的ThreadLocalMap中
      public static void put(String key, String val);
    
      // 根据key在当前线程的MDC容器中获取对应的值
      public static String get(String key);
    
      // 根据key移除容器中的值
      public static void remove(String key);
    
      // 清空当前线程的MDC容器
      public static void clear();
    }

    简单的例子

    Example 7.1: Basic MDC usage ( logback-examples/src/main/java/chapters/mdc/SimpleMDC.java)

    package com.xiaolyuh;
    
    import org.slf4j.Logger;
    import org.slf4j.LoggerFactory;
    import org.slf4j.MDC;
    
    public class SimpleMDC {
        public static void main(String[] args) throws Exception {
    
            // You can put values in the MDC at any time. Before anything else
            // we put the first name
            MDC.put("first", "Dorothy");
    
            Logger logger = LoggerFactory.getLogger(SimpleMDC.class);
            // We now put the last name
            MDC.put("last", "Parker");
    
            // The most beautiful two words in the English language according
            // to Dorothy Parker:
            logger.info("Check enclosed.");
            logger.debug("The most beautiful two words in English.");
    
            MDC.put("first", "Richard");
            MDC.put("last", "Nixon");
            logger.info("I am not a crook.");
            logger.info("Attributed to the former US president. 17 Nov 1973.");
        }
    
    }

    Logback配置:

    <appender name="CONSOLE" class="ch.qos.logback.core.ConsoleAppender"> 
      <layout>
        <Pattern>%X{first} %X{last} - %m%n</Pattern>
      </layout> 
    </appender>

    输出日志:

    Dorothy Parker - Check enclosed.
    Dorothy Parker - The most beautiful two words in English.
    Richard Nixon - I am not a crook.
    Richard Nixon - Attributed to the former US president. 17 Nov 1973.
    1. 在日志模板logback.xml 中,使用 %X{ }来占位,替换到对应的 MDC 中 key 的值。同样,logback.xml配置文件支持了多种格式的日志输出,比如%highlight、%d等等,这些标志,在PatternLayout.java中维护。
    2. MDC的容器中的key可以多次赋值,最后一次的赋值会覆盖上一次的值。

    PatternLayout :

    public class PatternLayout extends PatternLayoutBase<ILoggingEvent> {
    
        public static final Map<String, String> defaultConverterMap = new HashMap<String, String>();
        public static final String HEADER_PREFIX = "#logback.classic pattern: ";
    
        static {
            defaultConverterMap.putAll(Parser.DEFAULT_COMPOSITE_CONVERTER_MAP);
            // 按照{}配置输出时间
            defaultConverterMap.put("d", DateConverter.class.getName());
            defaultConverterMap.put("date", DateConverter.class.getName());
            // 输出应用启动到日志时间触发时候的毫秒数
            defaultConverterMap.put("r", RelativeTimeConverter.class.getName());
            defaultConverterMap.put("relative", RelativeTimeConverter.class.getName());
            // 输出日志级别的信息
            defaultConverterMap.put("level", LevelConverter.class.getName());
            defaultConverterMap.put("le", LevelConverter.class.getName());
            defaultConverterMap.put("p", LevelConverter.class.getName());
            // 输出产生日志事件的线程名
            defaultConverterMap.put("t", ThreadConverter.class.getName());
            defaultConverterMap.put("thread", ThreadConverter.class.getName());
            // 输出产生log事件的原点的日志名=我们创建logger的时候设置的
            defaultConverterMap.put("lo", LoggerConverter.class.getName());
            defaultConverterMap.put("logger", LoggerConverter.class.getName());
            defaultConverterMap.put("c", LoggerConverter.class.getName());
            // 输出 提供日志事件的对应的应用信息
            defaultConverterMap.put("m", MessageConverter.class.getName());
            defaultConverterMap.put("msg", MessageConverter.class.getName());
            defaultConverterMap.put("message", MessageConverter.class.getName());
            // 输出调用方发布日志事件的完整类名
            defaultConverterMap.put("C", ClassOfCallerConverter.class.getName());
            defaultConverterMap.put("class", ClassOfCallerConverter.class.getName());
            // 输出发布日志请求的方法名
            defaultConverterMap.put("M", MethodOfCallerConverter.class.getName());
            defaultConverterMap.put("method", MethodOfCallerConverter.class.getName());
            // 输出log请求的行数
            defaultConverterMap.put("L", LineOfCallerConverter.class.getName());
            defaultConverterMap.put("line", LineOfCallerConverter.class.getName());
            // 输出发布日志请求的java源码的文件名
            defaultConverterMap.put("F", FileOfCallerConverter.class.getName());
            defaultConverterMap.put("file", FileOfCallerConverter.class.getName());
            // 输出和发布日志事件关联的线程的MDC
            defaultConverterMap.put("X", MDCConverter.class.getName());
            defaultConverterMap.put("mdc", MDCConverter.class.getName());
            // 输出和日志事件关联的异常的堆栈信息
            defaultConverterMap.put("ex", ThrowableProxyConverter.class.getName());
            defaultConverterMap.put("exception", ThrowableProxyConverter.class
                    .getName());
            defaultConverterMap.put("rEx", RootCauseFirstThrowableProxyConverter.class.getName());
            defaultConverterMap.put("rootException", RootCauseFirstThrowableProxyConverter.class
                    .getName());
            defaultConverterMap.put("throwable", ThrowableProxyConverter.class
                    .getName());
            // 和上面一样,此外增加类的包信息
            defaultConverterMap.put("xEx", ExtendedThrowableProxyConverter.class.getName());
            defaultConverterMap.put("xException", ExtendedThrowableProxyConverter.class
                    .getName());
            defaultConverterMap.put("xThrowable", ExtendedThrowableProxyConverter.class
                    .getName());
            // 当我们想不输出异常信息时,使用这个。其假装处理异常,其实无任何输出
            defaultConverterMap.put("nopex", NopThrowableInformationConverter.class
                    .getName());
            defaultConverterMap.put("nopexception",
                    NopThrowableInformationConverter.class.getName());
            // 输出在类附加到日志上的上下文名字. 
            defaultConverterMap.put("cn", ContextNameConverter.class.getName());
            defaultConverterMap.put("contextName", ContextNameConverter.class.getName());
            // 输出产生日志事件的调用者的位置信息
            defaultConverterMap.put("caller", CallerDataConverter.class.getName());
            // 输出和日志请求关联的marker
            defaultConverterMap.put("marker", MarkerConverter.class.getName());
            // 输出属性对应的值,一般为System.properties中的属性
            defaultConverterMap.put("property", PropertyConverter.class.getName());
            // 输出依赖系统的行分隔符
            defaultConverterMap.put("n", LineSeparatorConverter.class.getName());
            // 相关的颜色格式设置
            defaultConverterMap.put("black", BlackCompositeConverter.class.getName());
            defaultConverterMap.put("red", RedCompositeConverter.class.getName());
            defaultConverterMap.put("green", GreenCompositeConverter.class.getName());
            defaultConverterMap.put("yellow", YellowCompositeConverter.class.getName());
            defaultConverterMap.put("blue", BlueCompositeConverter.class.getName());
            defaultConverterMap.put("magenta", MagentaCompositeConverter.class.getName());
            defaultConverterMap.put("cyan", CyanCompositeConverter.class.getName());
            defaultConverterMap.put("white", WhiteCompositeConverter.class.getName());
            defaultConverterMap.put("gray", GrayCompositeConverter.class.getName());
            defaultConverterMap.put("boldRed", BoldRedCompositeConverter.class.getName());
            defaultConverterMap.put("boldGreen", BoldGreenCompositeConverter.class.getName());
            defaultConverterMap.put("boldYellow", BoldYellowCompositeConverter.class.getName());
            defaultConverterMap.put("boldBlue", BoldBlueCompositeConverter.class.getName());
            defaultConverterMap.put("boldMagenta", BoldMagentaCompositeConverter.class.getName());
            defaultConverterMap.put("boldCyan", BoldCyanCompositeConverter.class.getName());
            defaultConverterMap.put("boldWhite", BoldWhiteCompositeConverter.class.getName());
            defaultConverterMap.put("highlight", HighlightingCompositeConverter.class.getName());
        }
    }

    Notes:日志模板配置,使用 %为前缀让解析器识别特殊输出模式,然后以{}后缀结尾,内部指定相应的参数设置。

    使用切面

    在处理请求前将请求的唯一标示放到MDC容器中如sessionId,这个唯一标示会随着日志一起输出,以此来区分该条日志是属于那个请求的。这个我们可以使用Advanced来实现,可以使用filter,interceptor等。

    Interceptor

    可以参考篇文章Logback 快速定位用户在一次请求中的所有日志

    MDCInsertingServletFilter

    这是Logback提供的一个filter,他会将一些请求信息放到MDC容器中,这个filter最好放到配置编码的filter之后。以下是详细的key:

    | MDC key | MDC value | --|-- | req.remoteHost | as returned by the getRemoteHost() method | | req.xForwardedFor | value of the "X-Forwarded-For" header | | req.method | as returned by getMethod() method | | req.requestURI | as returned by getRequestURI() method | | req.requestURL | as returned by getRequestURL() method | | req.queryString | as returned by getQueryString() method | | req.userAgent | value of the "User-Agent" header |

    使用配置:需要保证filter在需要使用的到该MDC的其他filter之前。

    <filter>
     <filter-name>MDCInsertingServletFilter</filter-name>
     <filter-class>
       ch.qos.logback.classic.helpers.MDCInsertingServletFilter
     </filter-class>
    </filter>
    <filter-mapping>
     <filter-name>MDCInsertingServletFilter</filter-name>
     <url-pattern>/*</url-pattern>
    </filter-mapping>

    应用key:

    %X{req.remoteHost} %X{req.requestURI}%n%d - %m%n

    管理每个线程的MDC容器

    我们在主线程上,新起一个子线程,并由 java.util.concurrent.Executors来执行它时,在早期的版本中子线程可以直接自动继承父线程的MDC容器中的内容,因为MDC在早期版本中使用的是InheritableThreadLocal来作为底层实现。但是由于性能问题被取消了,最后还是使用的是ThreadLocal来作为底层实现。这样子线程就不能直接继承父线程的MDC容器。

    所以,Logback官方建议我们在父线程新建子线程之前调用MDC.getCopyOfContextMap()方法将MDC内容取出来传给子线程,子线程在执行操作前先调用MDC.setContextMap()方法将父线程的MDC内容设置到子线程。

    Slf4j MDC实现原理

    Slf4j 的实现原则就是调用底层具体实现类,比如logback,logging等包;而不会去实现具体的输出打印等操作。这里使用了装饰者模式,看源码就能看出来,所有的方法都是在对mdcAdapter 这个属性进行操作。所以实现核心是MDCAdapter类。

    MDCAdapter

    MDCAdapter只是定义了一个接口,具体实现由子类完成,源码如下:

    public interface MDCAdapter {
        public void put(String key, String val);
    
        public String get(String key);
    
        public void remove(String key);
    
        public void clear();
    
        public Map<String, String> getCopyOfContextMap();
    
        public void setContextMap(Map<String, String> contextMap);
    }

    它有三个实现类,BasicMDCAdapter、LogbackMDCAdapter,NOPMDCAdapter。Logback使用的是LogbackMDCAdapter。

    LogbackMDCAdapter

    package ch.qos.logback.classic.util;
    
    import java.util.Collections;
    import java.util.HashMap;
    import java.util.Map;
    import java.util.Set;
    
    import org.slf4j.spi.MDCAdapter;
    
    public class LogbackMDCAdapter implements MDCAdapter {
    
        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>();
    
        private Integer getAndSetLastOperation(int op) {
            Integer lastOp = lastOperation.get();
            lastOperation.set(op);
            return lastOp;
        }
    
        private boolean wasLastOpReadOrNull(Integer lastOp) {
            return lastOp == null || lastOp.intValue() == MAP_COPY_OPERATION;
        }
    
        private Map<String, String> duplicateAndInsertNewMap(Map<String, String> oldMap) {
            Map<String, String> newMap = Collections.synchronizedMap(new HashMap<String, String>());
            if (oldMap != null) {
                // we don't want the parent thread modifying oldMap while we are
                // iterating over it
                synchronized (oldMap) {
                    newMap.putAll(oldMap);
                }
            }
    
            copyOnThreadLocal.set(newMap);
            return newMap;
        }
    
        /**
         * Put a context value (the <code>val</code> parameter) as identified with the
         * <code>key</code> parameter into the current thread's context map. Note that
         * contrary to log4j, the <code>val</code> parameter can be null.
         * <p/>
         * <p/>
         * If the current thread does not have a context map it is created as a side
         * effect of this call.
         *
         * @throws IllegalArgumentException in case the "key" parameter is null
         */
        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);
            }
        }
    
        /**
         * Remove the the context identified by the <code>key</code> parameter.
         * <p/>
         */
        public void remove(String key) {
            if (key == null) {
                return;
            }
            Map<String, String> oldMap = copyOnThreadLocal.get();
            if (oldMap == null)
                return;
    
            Integer lastOp = getAndSetLastOperation(WRITE_OPERATION);
    
            if (wasLastOpReadOrNull(lastOp)) {
                Map<String, String> newMap = duplicateAndInsertNewMap(oldMap);
                newMap.remove(key);
            } else {
                oldMap.remove(key);
            }
        }
    
        /**
         * Clear all entries in the MDC.
         */
        public void clear() {
            lastOperation.set(WRITE_OPERATION);
            copyOnThreadLocal.remove();
        }
    
        /**
         * Get the context identified by the <code>key</code> parameter.
         * <p/>
         */
        public String get(String key) {
            final Map<String, String> map = copyOnThreadLocal.get();
            if ((map != null) && (key != null)) {
                return map.get(key);
            } else {
                return null;
            }
        }
    
        /**
         * Get the current thread's MDC as a map. This method is intended to be used
         * internally.
         */
        public Map<String, String> getPropertyMap() {
            lastOperation.set(MAP_COPY_OPERATION);
            return copyOnThreadLocal.get();
        }
    
        /**
         * Returns the keys in the MDC as a {@link Set}. The returned value can be
         * null.
         */
        public Set<String> getKeys() {
            Map<String, String> map = getPropertyMap();
    
            if (map != null) {
                return map.keySet();
            } else {
                return null;
            }
        }
    
        /**
         * Return a copy of the current thread's context map. Returned value may be
         * null.
         */
        public Map<String, String> getCopyOfContextMap() {
            Map<String, String> hashMap = copyOnThreadLocal.get();
            if (hashMap == null) {
                return null;
            } else {
                return new HashMap<String, String>(hashMap);
            }
        }
    
        public void setContextMap(Map<String, String> contextMap) {
            lastOperation.set(WRITE_OPERATION);
    
            Map<String, String> newMap = Collections.synchronizedMap(new HashMap<String, String>());
            newMap.putAll(contextMap);
    
            // the newMap replaces the old one for serialisation's sake
            copyOnThreadLocal.set(newMap);
        }
    }
    final ThreadLocal<Integer> lastOperation = new ThreadLocal<Integer>();

    通过这段代码,我们可以看到底层最终是使用的是ThreadLocal来做实现。

  • 相关阅读:
    JavaScript:Number 对象
    JavaScript:Math 对象
    杂项:引用资源列表
    小团队管理与大团队管理
    技术转管理
    【翻译+整理】.NET Core的介绍
    自己开发给自己用的个人知识管理工具【脑细胞】,源码提供
    关于【自证清白】
    这篇博客能让你戒烟——用程序员的思维来戒烟!
    如果我是博客园的产品经理【下】
  • 原文地址:https://www.cnblogs.com/laj12347/p/14491248.html
Copyright © 2020-2023  润新知