java 如何实现日志追踪MDC

时间：2021-12-19 07:02:49

java 日志追踪MDC

MDC ( Mapped Diagnostic Contexts ) 有了日志之后，我们就可以追踪各种线上问题。

但是，在分布式系统中，各种无关日志穿行其中，导致我们可能无法直接定位整个操作流程。

因此，我们可能需要对一个用户的操作流程进行归类标记，比如使用线程+时间戳，或者用户身份标识等；如此，我们可以从大量日志信息中grep出某个用户的操作流程，或者某个时间的流转记录。其目的是为了便于我们诊断线上问题而出现的方法工具类。

虽然，Slf4j 是用来适配其他的日志具体实现包的，但是针对 MDC功能，目前只有logback 以及 log4j 支持。 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
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
54
55
56
57
58
59
60
61
62
63
64
65
66
67
68
69
70
71
72
73
74
75
76
77
78
79
80
81
82
83
84
85
86
87
88
89
90
91
92
93
94
95
96
97
98
99
100
101
102
103
104
105
package org.slf4j;
import java.io.Closeable;
import java.util.Map;
import org.slf4j.helpers.NOPMDCAdapter;
import org.slf4j.helpers.BasicMDCAdapter;
import org.slf4j.helpers.Util;
import org.slf4j.impl.StaticMDCBinder;
import org.slf4j.spi.MDCAdapter;
public class MDC {
    static final String NULL_MDCA_URL = "http://www.slf4j.org/codes.html#null_MDCA";
    static final String NO_STATIC_MDC_BINDER_URL = "http://www.slf4j.org/codes.html#no_static_mdc_binder";
    static MDCAdapter mdcAdapter;
 
    public static class MDCCloseable implements Closeable {
        private final String key;
        private MDCCloseable(String key) {
            this.key = key;
        }
        public void close() {
            MDC.remove(this.key);
        }
    }
    private MDC() {
    }
 
    static {
        try {
            mdcAdapter = StaticMDCBinder.SINGLETON.getMDCA();
        } catch (NoClassDefFoundError ncde) {
            mdcAdapter = new NOPMDCAdapter();
            String msg = ncde.getMessage();
            if (msg != null && msg.indexOf("StaticMDCBinder") != -1) {
                Util.report("Failed to load class \"org.slf4j.impl.StaticMDCBinder\".");
                Util.report("Defaulting to no-operation MDCAdapter implementation.");
                Util.report("See " + NO_STATIC_MDC_BINDER_URL + " for further details.");
            } else {
                throw ncde;
            }
        } catch (Exception e) {
            // we should never get here
            Util.report("MDC binding unsuccessful.", e);
        }
    }
 
    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);
    }
 
    public static MDCCloseable putCloseable(String key, String val) throws IllegalArgumentException {
        put(key, val);
        return new MDCCloseable(key);
    }
 
    public static String get(String key) 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);
        }
        return mdcAdapter.get(key);
    }
 
    public static void remove(String key) 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.remove(key);
    }
 
    public static void clear() {
        if (mdcAdapter == null) {
            throw new IllegalStateException("MDCAdapter cannot be null. See also " + NULL_MDCA_URL);
        }
        mdcAdapter.clear();
    }
 
    public static Map<String, String> getCopyOfContextMap() {
        if (mdcAdapter == null) {
            throw new IllegalStateException("MDCAdapter cannot be null. See also " + NULL_MDCA_URL);
        }
        return mdcAdapter.getCopyOfContextMap();
    }
 
    public static void setContextMap(Map<String, String> contextMap) {
        if (mdcAdapter == null) {
            throw new IllegalStateException("MDCAdapter cannot be null. See also " + NULL_MDCA_URL);
        }
        mdcAdapter.setContextMap(contextMap);
    }
    public static MDCAdapter getMDCAdapter() {
        return mdcAdapter;
    }
}

简单的demo

?
1
2
3
4
5
6
7
8
9
10
11
package com.alibaba.otter.canal.common;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
import org.slf4j.MDC;
public class LogTest {
    private static final Logger logger = LoggerFactory.getLogger(LogTest.class);
    public static void main(String[] args) {
        MDC.put("THREAD_ID", String.valueOf(Thread.currentThread().getId()));
        logger.info("纯字符串信息的info级别日志");
    }
}

logback.xml 配置

?
1
2
3
4
5
6
7
8
9
10
11
12
13
14
<configuration scan="true" scanPeriod=" 5 seconds">
 
    <jmxConfigurator />
    <appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">
        <encoder>
            <pattern>%d{yyyy-MM-dd HH:mm:ss.SSS} [%thread] %-5level %logger{56} %X{THREAD_ID} - %msg%n
            </pattern>
        </encoder>
    </appender>
    
    <root level="INFO">
        <appender-ref ref="STDOUT"/>
    </root>
</configuration

对应的输出日志 可以看到输出了THREAD_ID

2016-12-08 14:59:32.855 [main] INFO com.alibaba.otter.canal.common.LogTest THREAD_ID 1 - 纯字符串信息的info级别日志

slf4j只是起到适配的作用 故查看实现类LogbackMDCAdapter属性

final InheritableThreadLocal<Map<String, String>> copyOnInheritThreadLocal = new InheritableThreadLocal<Map<String, String>>();

InheritableThreadLocal 该类扩展了 ThreadLocal，为子线程提供从父线程那里继承的值：在创建子线程时，子线程会接收所有

可继承的线程局部变量的初始值，以获得父线程所具有的值。通常，子线程的值与父线程的值是一致的；但是，通过重写这个类中的 childValue 方法，子线程的值可以作为父线程值的一个任意函数。

当必须将变量（如用户 ID 和 事务 ID）中维护的每线程属性（per-thread-attribute）自动传送给创建的所有子线程时，应尽可能地采用可继承的线程局部变量，而不是采用普通的线程局部变量

验证一下

?
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
34
35
36
package com.alibaba.otter.canal.parse.driver.mysql;
import org.junit.Test;
public class TestInheritableThreadLocal {
    @Test
    public void testThreadLocal() {
        final ThreadLocal<String> local = new ThreadLocal<String>(); 
        work(local); 
    }
 
    @Test
    public void testInheritableThreadLocal() {
        final ThreadLocal<String> local = new InheritableThreadLocal<String>(); 
        work(local);
    }
    private void work(final ThreadLocal<String> local) { 
        local.set("a"); 
        System.out.println(Thread.currentThread() + "," + local.get()); 
        Thread t = new Thread(new Runnable() { 
              
            @Override
            public void run() { 
                System.out.println(Thread.currentThread() + "," + local.get()); 
                local.set("b"); 
                System.out.println(Thread.currentThread() + "," + local.get()); 
            } 
        }); 
          
        t.start(); 
        try { 
            t.join(); 
        } catch (InterruptedException e) { 
            e.printStackTrace(); 
        }           
        System.out.println(Thread.currentThread() + "," + local.get()); 
    } 
}

分别运行得到的输出结果

ThreadLocal 存贮输出结果
Thread[main,5,main],a
Thread[Thread-0,5,main],null
Thread[Thread-0,5,main],b
Thread[main,5,main],a
InheritableThreadLocal存贮输出结果
Thread[main,5,main],a
Thread[Thread-0,5,main],a
Thread[Thread-0,5,main],b
Thread[main,5,main],a

输出结果说明一切 对于参数传递十分有用 我知道 canal的源码中用到了MDC

在 CanalServerWithEmbedded 中的 start 和stop等方法中都有用到

?
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
public void start(final String destination) {
    final CanalInstance canalInstance = canalInstances.get(destination);
    if (!canalInstance.isStart()) {
        try {
            MDC.put("destination", destination);
            canalInstance.start();
            logger.info("start CanalInstances[{}] successfully", destination);
        } finally {
            MDC.remove("destination");
        }
    }
}
 
public void stop(String destination) {
    CanalInstance canalInstance = canalInstances.remove(destination);
    if (canalInstance != null) {
        if (canalInstance.isStart()) {
            try {
                MDC.put("destination", destination);
                canalInstance.stop();
                logger.info("stop CanalInstances[{}] successfully", destination);
            } finally {
                MDC.remove("destination");
            }
        }
    }
}

MDC的介绍及使用

1、MDC是什么？

MDC是（Mapped Diagnostic Context，映射调试上下文）是 log4j 和 logback 支持的一种方便在多线程条件下记录追踪日志的功能。通常打印出的日志会有线程号等信息来标志当前日志属于哪个线程，然而由于线程是可以重复使用的，所以并不能很清晰的确认一个请求的日志范围。处理这种情况一般有两种处理方式：

1）手动生成一个唯一序列号打印在日志中；

2）使用日志控件提供的MDC功能，生成一个唯一序列标记一个线程的日志；

两种方法的区别在于：

方法一只能标记一条日志，线程内其他日志需要人肉去筛选；

方法二标记整个线程的所有日志，方便grep命令查询；

对比可见，使用MDC功能更好。

2、MDC的原理

MDC 可以看成是一个与当前线程绑定的哈希表，可以往其中添加键值对。MDC 中包含的内容可以被同一线程中执行的代码所访问。当前线程的子线程会继承其父线程中的 MDC 的内容。当需要记录日志时，只需要从 MDC 中获取所需的信息即可。MDC 的内容则由程序在适当的时候保存进去。对于一个 Web 应用来说，通常是在请求被处理的最开始保存这些数据。

?
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
@RunWith(SpringRunner.class)
@SpringBootTest(classes=CreditAppApplication.class)
publicclassMDCTest{
 
@Test
publicvoidmdcTest1(){
MDC.put("first","thefirst1");
 
Loggerlogger=LoggerFactory.getLogger(MDCTest.class);
MDC.put("last","thelast1");
 
logger.info("checkenclosed.");
logger.debug("themostbeautifultwowordsinenglish.");
 
MDC.put("first","thefirst2");
MDC.put("last","thelast2");
 
logger.info("iamnotacrook.");
logger.info("AttributedtotheformerUSpresident.17Nov1973.");
}
}

logback的配置：

java 如何实现日志追踪MDC

3、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
@Component
@Order(Ordered.HIGHEST_PRECEDENCE)
publicclassGlobalLogTagConfigextendsOncePerRequestFilter{
privatestaticfinalStringGLOBAL_LOG_TAG="GLOG_TAG";
privatestaticStringgenerateSeqNo(){
returnUUID.randomUUID().toString().replace("-","").substring(0,12);
}
 
@Override
protectedvoiddoFilterInternal(HttpServletRequesthttpServletRequest,HttpServletResponsehttpServletResponse,FilterChainfilterChain)throwsServletException,IOException{
try{
StringseqNo;
if(httpServletRequest!=null){
seqNo=httpServletRequest.getHeader(GLOBAL_LOG_TAG);
 
if(StringUtils.isEmpty(seqNo)){
seqNo=generateSeqNo();
}
}else{
seqNo=generateSeqNo();
}
MDC.put(GLOBAL_LOG_TAG,seqNo);
filterChain.doFilter(httpServletRequest,httpServletResponse);
}finally{
MDC.remove(GLOBAL_LOG_TAG);
}
}
}

注意：

OncePerRequestFilter的作用是为了让每个请求只经过这个过滤器一次（因为web container的不同，有些过滤器可能被多次执行）

logback配置：

java 如何实现日志追踪MDC

以上为个人经验，希望能给大家一个参考，也希望大家多多支持服务器之家。

原文链接：https://www.jianshu.com/p/06b1d35526c2

标签：

相关文章