slf4j MDC使用

slf4j MDC使用

最近也是在项目代码里发现一个地方有个MDC.put()，忍不住好奇点了进去，于是知道了MDC这个东西，细研究一下，发现还真是个好东西。

MDC解决了什么问题

MDC全名Mapped Diagnostic Contexts，是slf4j提供的一个API，主要功能就是在多线程环境下进行日志调用链路的跟踪，比如在一次事务处理中，会经过多个处理的流程，为了定位问题方便，在每个流程中免不了打印一些日志信息。在线上环境中，最后打出来的日志是很多的，如何定位哪些信息是在同一个线程中打印的呢？MDC很优雅地解决了这个问题。其他的日志框架有没有这个功能我暂时没去研究，对于slf4j（现在应该都会优先用这个吧？），实现了MDC的有logback和log4j，这里暂时以logback为例，更详细的文档见这里

MDC的使用

MDC使用起来还是相当简单的，一个例子就搞定了。
首先配置日志配置文件logback.xml

<span style="color:#333333"><code><span style="color:#0000ff"><<span style="color:#0000ff">configuration</span>></span>
    <span style="color:#0000ff"><<span style="color:#0000ff">appender</span> <span style="color:#ff0000">name</span>=<span style="color:#a31515">"STDOUT"</span> <span style="color:#ff0000">class</span>=<span style="color:#a31515">"ch.qos.logback.core.ConsoleAppender"</span>></span>
        <span style="color:#0000ff"><<span style="color:#0000ff">encoder</span>></span>
            <span style="color:#0000ff"><<span style="color:#0000ff">pattern</span>></span>%d{HH:mm:ss.SSS} [%thread] %-5level %logger{36} %X{txId} - %msg%n<span style="color:#0000ff"></<span style="color:#0000ff">pattern</span>></span>
        <span style="color:#0000ff"></<span style="color:#0000ff">encoder</span>></span>
    <span style="color:#0000ff"></<span style="color:#0000ff">appender</span>></span>

    <span style="color:#0000ff"><<span style="color:#0000ff">root</span> <span style="color:#ff0000">level</span>=<span style="color:#a31515">"debug"</span>></span>
        <span style="color:#0000ff"><<span style="color:#0000ff">appender-ref</span> <span style="color:#ff0000">ref</span>=<span style="color:#a31515">"STDOUT"</span>/></span>
    <span style="color:#0000ff"></<span style="color:#0000ff">root</span>></span>
<span style="color:#0000ff"></<span style="color:#0000ff">configuration</span>></span></code></span>

为了输出很简单的一个配置注意有个占位符txId，这就是我们每次事务处理的id。现在我们模拟多个线程同时处理事务。定义了一次事务处理的流程。

<span style="color:#333333"><code><span style="color:#0000ff">public</span> <span style="color:#0000ff">class</span> <span style="color:#a31515">TxFlow</span> {
    <span style="color:#0000ff">private</span> <span style="color:#0000ff">static</span> <span style="color:#0000ff">final</span> Logger LOGGER = LoggerFactory.getLogger(TxFlow.class);

    <span style="color:#0000ff">private</span> <span style="color:#0000ff">void</span> <span style="color:#a31515">prepare</span>() {
        LOGGER.info(<span style="color:#a31515">"prepare tx"</span>);
    }

    <span style="color:#0000ff">private</span> <span style="color:#0000ff">void</span> <span style="color:#a31515">handle</span>() {
        LOGGER.info(<span style="color:#a31515">"handle tx"</span>);
        <span style="color:#0000ff">try</span> {
            Thread.sleep(<span style="color:#0000ff">new</span> Random().nextInt(4) * 1000);
        } <span style="color:#0000ff">catch</span> (InterruptedException ignored) {
        }
    }

    <span style="color:#0000ff">private</span> <span style="color:#0000ff">void</span> <span style="color:#a31515">submit</span>() {
        LOGGER.info(<span style="color:#a31515">"submit tx"</span>);
    }

    <span style="color:#0000ff">public</span> <span style="color:#0000ff">void</span> <span style="color:#a31515">run</span>() {
        prepare();
        handle();
        submit();
    }
}</code></span>

对每一次事务处理，我们生成一个事务ID，并put到MDC中去。

<span style="color:#333333"><code><span style="color:#0000ff">public</span> <span style="color:#0000ff">class</span> <span style="color:#a31515">TxMDC</span> {
    <span style="color:#0000ff">private</span> <span style="color:#0000ff">static</span> <span style="color:#0000ff">final</span> Logger LOGGER = LoggerFactory.getLogger(TxMDC.class);

    <span style="color:#0000ff">public</span> <span style="color:#0000ff">static</span> <span style="color:#0000ff">void</span> <span style="color:#a31515">main</span>(String[] args) {
        LOGGER.info(<span style="color:#a31515">"main thread start"</span>);
        <span style="color:#0000ff">for</span> (<span style="color:#0000ff">int</span> i = 0; i < 5; i++) {
            <span style="color:#0000ff">new</span> Thread(() -> {
                MDC.put(<span style="color:#a31515">"txId"</span>, UUID.randomUUID().toString());
                <span style="color:#0000ff">new</span> TxFlow().run();
            }).start();
        }
    }
}</code></span>

得到输出如下，这样就很容易根据事务ID将一次事务中各个流程中的日志信息串联起来，便于后期的处理（比如查到一次事务的txId后grep一下txId就把整个处理流程中的日志信息串联起来了）。

<span style="color:#333333"><code>13:20:21.581 [main] INFO  i.d.l.TxMDC txId=主线程ID - main thread start
13:20:22.050 [Thread-1] INFO  i.d.l.TxFlow txId=c4bd7356-b932-4571-bbad-d450e90de821 - prepare tx
13:20:22.050 [Thread-1] INFO  i.d.l.TxFlow txId=c4bd7356-b932-4571-bbad-d450e90de821 - handle tx
13:20:22.050 [Thread-2] INFO  i.d.l.TxFlow txId=9ee129de-0dfe-4086-9267-e6868e1478b0 - prepare tx
13:20:22.050 [Thread-2] INFO  i.d.l.TxFlow txId=9ee129de-0dfe-4086-9267-e6868e1478b0 - handle tx
13:20:22.052 [Thread-3] INFO  i.d.l.TxFlow txId=7971563a-2807-4e1f-bbd9-639a090b5689 - prepare tx
13:20:22.053 [Thread-3] INFO  i.d.l.TxFlow txId=7971563a-2807-4e1f-bbd9-639a090b5689 - handle tx
13:20:22.053 [Thread-4] INFO  i.d.l.TxFlow txId=5c5656c4-bc7a-4277-be25-2269aee0b54e - prepare tx
13:20:22.053 [Thread-4] INFO  i.d.l.TxFlow txId=5c5656c4-bc7a-4277-be25-2269aee0b54e - handle tx
13:20:22.054 [Thread-0] INFO  i.d.l.TxFlow txId=ebaa0082-1a19-450d-ba71-679510a2fa92 - prepare tx
13:20:22.054 [Thread-0] INFO  i.d.l.TxFlow txId=ebaa0082-1a19-450d-ba71-679510a2fa92 - handle tx
13:20:22.082 [Thread-1] INFO  i.d.l.TxFlow txId=c4bd7356-b932-4571-bbad-d450e90de821 - submit tx
13:20:23.055 [Thread-0] INFO  i.d.l.TxFlow txId=ebaa0082-1a19-450d-ba71-679510a2fa92 - submit tx
13:20:24.050 [Thread-2] INFO  i.d.l.TxFlow txId=9ee129de-0dfe-4086-9267-e6868e1478b0 - submit tx
13:20:25.054 [Thread-3] INFO  i.d.l.TxFlow txId=7971563a-2807-4e1f-bbd9-639a090b5689 - submit tx
13:20:25.055 [Thread-4] INFO  i.d.l.TxFlow txId=5c5656c4-bc7a-4277-be25-2269aee0b54e - submit tx</code></span>

MDC的实现原理

slf4j只提供了一个接口，具体的实现在logback和log4j中。不过从上面功能中，我们已经知道MDC记录了是线程上下文，聪明的你肯定已经想到了实现是基于ThreadLocal，事实也如此，有兴趣继续研究代码我就不多说了。

---

 

许多年前 你有一双清澈的双眼

奔跑起来 像是一道春天的闪电

 

想看遍这世界 去最遥远的远方

 

感觉有双翅膀 能飞越高山和海洋