背景

最近在排查问题查问日志的的时候，有个很困扰的问题就是多线程调用的状况下，没方法查问一次调用的全链路调用日志，比方在应用elk查问日志的时候，我想看某个日志的前后调用的残缺的日志，如果不做解决的话是不太好查问的，所以我通过查问材料发现的确有很多形式解决这种问题，以下是我集体认为比拟好的解决形式，即通过MDC解决.

MDC介绍

MDC（Mapped Diagnostic Context，映射调试上下文）是 log4j 、logback及log4j2 提供的一种不便在多线程条件下记录日志的性能。MDC 能够看成是一个与以后线程绑定的哈希表，能够往其中增加键值对。MDC 中蕴含的内容能够被同一线程中执行的代码所拜访。以后线程的子线程会继承其父线程中的 MDC 的内容。当须要记录日志时，只须要从 MDC 中获取所需的信息即可。MDC 的内容则由程序在适当的时候保留进去。对于一个 Web 利用来说，通常是在申请被解决的最开始保留这些数据

API阐明：

  • clear() => 移除所有MDC
  • get (String key) => 获取以后线程MDC中指定key的值
  • getContext() => 获取以后线程MDC的MDC
  • put(String key, Object o) => 往以后线程的MDC中存入指定的键值对
  • remove(String key) => 删除以后线程MDC中指定的键值对

实现（基于spring boot）

一，创立EnvironmentPostProcessor实现类，配置日志格式化全局环境配置，如："%1p [%X{X-B3-TraceId:-}]"

public class TraceEnvironmentPostProcessor implements EnvironmentPostProcessor {    private static final String PROPERTY_SOURCE_NAME = "defaultProperties";    private static final String LEVEL_STR_PARENT = "%1p [%X{X-B3-TraceId:-}]";    private static final String LOG_PATTERN_LEVEL = "logging.pattern.level";    @Override    public void postProcessEnvironment(ConfigurableEnvironment environment, SpringApplication application) {        Map<String, Object> map = new HashMap<>(1);        map.put(LOG_PATTERN_LEVEL, LEVEL_STR_PARENT);        MutablePropertySources propertySources = environment.getPropertySources();        MapPropertySource target = null;        if (propertySources.contains(PROPERTY_SOURCE_NAME)) {            PropertySource<?> source = propertySources.get(PROPERTY_SOURCE_NAME);            if (source instanceof MapPropertySource) {                target = (MapPropertySource) source;                for (String key : map.keySet()) {                    if (!target.containsProperty(key)) {                        target.getSource().put(key, map.get(key));                    }                }            }        }        if (target == null) {            target = new MapPropertySource(PROPERTY_SOURCE_NAME, map);        }        if (!propertySources.contains(PROPERTY_SOURCE_NAME)) {            propertySources.addLast(target);        }    }}

二，应用filter拦挡每次申请，通过MDC为以后线程增加惟一traceId

@Componentpublic class TraceFilter implements Filter {    @Override    public void doFilter(ServletRequest servletRequest, ServletResponse servletResponse, FilterChain chain) throws IOException, ServletException {        //String LEGACY_TRACE_ID_NAME = "X-B3-TraceId";        HttpServletRequest request = ((HttpServletRequest) servletRequest);        String traceId = request.getParameter(LogConstant.LEGACY_TRACE_ID_NAME);        // 如果为空，则示意第一次拜访，即上游服务端的申请        if (StringUtils.isEmpty(traceId)) {            //应用工具类生成uuid            MDC.put(LogConstant.LEGACY_TRACE_ID_NAME, TraceIdUtil.traceId());        } else {            MDC.put(LogConstant.LEGACY_TRACE_ID_NAME, traceId);        }        chain.doFilter(servletRequest, servletResponse);        MDC.clear();    }}

三，在META-INF目录下增加spring.factories文件，增加咱们创立的processor类，在我的项目启动的时候通过spring boot主动扫描，通过spring调用postProcessEnvironment发放初始化配置

# Environment Post Processororg.springframework.boot.env.EnvironmentPostProcessor=\com.example.log.trace.processor.TraceEnvironmentPostProcessor

四，应用简略的controller测试日志

@Slf4j@RestControllerpublic class TraceLogController {    @GetMapping(value = "/trace")    public Object trace() {        log.info("---------trace log 1--------");        log.info("---------trace log 2--------");        log.info("---------trace log 3--------");        log.info("---------trace log 4--------");        return Boolean.TRUE;    }}

发现打印的日志曾经有咱们增加的惟一的 traceId,并且屡次打印的都是同一个traceId，这样咱们在elk中想要查问一次调用的全链路调用日志就很不便了，只有通过traceId查问就很容易查问全链路的日志

2020-08-29 16:48:37.412 INFO [36d47a716d6d4891a264f050ff710d38] 20856 --- [nio-8080-exec-3] c.e.l.t.controller.TraceLogController    : ---------trace log 1--------2020-08-29 16:52:11.284 INFO [36d47a716d6d4891a264f050ff710d38] 20856 --- [nio-8080-exec-3] c.e.l.t.controller.TraceLogController    : ---------trace log 2--------2020-08-29 16:53:38.189 INFO [36d47a716d6d4891a264f050ff710d38] 20856 --- [nio-8080-exec-3] c.e.l.t.controller.TraceLogController    : ---------trace log 3--------2020-08-29 17:23:37.527 INFO [36d47a716d6d4891a264f050ff710d38] 20856 --- [nio-8080-exec-3] c.e.l.t.controller.TraceLogController    : ---------trace log 4--------

原理剖析

猜测

实现原理必定是log-back(spring boot默认日志框架)通过拼接的形式打印日志，咱们在全局增加了对应的key-value的匹配准则，在通过log打印日志的时候应用mdc通过key替换咱们在增加的uuid,因而很简略的实现了全链路日志

源码剖析

通过debug跟踪log链路，其调用链路还是很长的（如下图），咱们只须要关怀要害的逻辑就能够了，
其中打印日志拼接是通过ch.qos.logback.core.pattern.PatternLayoutBase#writeLoopOnConverters 进行解决的。


writeLoopOnConverters通过遍历调用converter的write办法拼接所须要打印的日志，如下流程：

DateConverter       -----工夫---- 2020-08-29 17:45:22.318LiteralConverter    -----空格---- 2020-08-29 17:45:22.318 有空格CompositeConverter ----自定义---- 2020-08-29 17:45:22.318 INFO [1a3801d149bb4b5e99698ab53481e263]......剩下的还有线程号,执行类等咱们只关怀自定义的规定解决.....

再看看CompositeConverter具体解决逻辑，发现其中还存在一层遍历解决如下图，
拼接了咱们自定义的[traceId]的日志，其中外围的解决类就是MDCConverter的解决，替换咱们定义的key


MDCConverter外围解决办法如下，通过key：X-B3-TraceId从 mdcPropertyMap中获取traceId，自此证实了咱们的猜测，通过key拿到value进行日志拼接，全链路日志原理简略剖析到此为止！

@Overridepublic String convert(ILoggingEvent event) {    //X-B3-TraceId -> 1a3801d149bb4b5e99698ab53481e263    Map<String, String> mdcPropertyMap = event.getMDCPropertyMap();    if (mdcPropertyMap == null) {        return defaultValue;    }    if (key == null) {        return outputMDCForAllKeys(mdcPropertyMap);    } else {        //X-B3-TraceId        String value = mdcPropertyMap.get(key);        if (value != null) {            return value;        } else {            return defaultValue;        }    }}