logback的MDC机制

logback的MDC机制

1. MDC 介绍:

​ MDC(Mapped Diagnostic Context,映射调试上下文),即将一些运行时的上下文数据通过logback打印出来,是 一种方便在多线程条件下记录日志的功能。和SiftingAppender一起,可以实现根据运行时的上下文数据,将日志保存到不同的文件中。

2. demo:

2.1 logback配置文件:logback.xml

<?xml version="1.0" encoding="UTF-8"?>
<configuration>
    <appender name="console" class="ch.qos.logback.core.ConsoleAppender">
        <encoder charset="UTF-8">
            <pattern>%d{yyyy-MM-dd HH:mm:ss} %-5level [%class:%line] -  %X{logFileName} %X{logSign} %msg%n</pattern>
        </encoder>
    </appender>

    <appender name="FILE-INSERT" class="ch.qos.logback.classic.sift.SiftingAppender">
        <discriminator>
            <key>logFileName</key>
            <defaultValue>defName</defaultValue>
        </discriminator>
        <sift>
            <appender name="FILE-${logFileName}" class="ch.qos.logback.core.rolling.RollingFileAppender">
                <File>
                    D:/temp/downloadLogs/${logFileName}/gps.log
                </File>
                <layout class="ch.qos.logback.classic.PatternLayout">
                    <pattern>%msg%n</pattern>
                </layout>
                <append>true</append>
                <rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">
                    <fileNamePattern>
                        D:/temp/downloadLogs/${logFileName}/gps-%d{yyyyMMdd}.log
                    </fileNamePattern>
                    <maxHistory>2</maxHistory>
                </rollingPolicy>
            </appender>
        </sift>
    </appender>

    <logger name="com.chelaile.log.insert" level = "INFO">
        <appender-ref ref="FILE-INSERT"/>
        <appender-ref ref="console"/>
    </logger>

</configuration>

2.2 写文件的线程:

package com.chelaile.log.insert;

import org.slf4j.MDC;

import java.util.Map;

public abstract class MdcRunnable implements Runnable {

    /**
     * 为了线程池中的线程在复用的时候也能获得父线程的MDC中的信息,
     * 子线程第一次初始化的时候没事,因为通过ThreadLocal
     * 已经可以获得MDC中的内容了
     */
    private final Map mdcContext = MDC.getCopyOfContextMap();
    //ExecutorService.execute(new Runnable())的时候,在Runnable构造的时候,用这个方法得到一个Map,保存起来,这时的context是父线程的。
    //然后在执行run方法的时候,放到MDC中去——子线程的context map中去

    @Override
    public final void run() {
        // 线程重用的时候,把父线程中的context map内容带入当前线程的context map中,
        // 因为线程已经初始化过了,不会像初始化时那样通过拷贝父线程ThreadLocal到子线程
        // 的ThreadLocal操作来完成线程间context map的传递。
        // 真正执行到这个run方法的时候,已经到了子线程中了,所以要在初始化的时候用
        // MDC.getCopyOfContextMap()来获得父线程contest map,那时候还在父线程域中
        if (mdcContext != null) {
            MDC.setContextMap(mdcContext);//有了这一步其实不用MDC.clear,因为这一步会将子线程中的context map重置为父线程的context map
//            //源代码:
//            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);
//            }
        }
        try {
            runWithMdc();
        } finally {
//            MDC.clear();//如果都是用new Thread方法建立的线程可以不用加,因为之后线程会消亡。
            //如果用ThreadPool线程池的话,线程是可以重用的,如果之前的线程的MDC内容没有清除掉的话,
            // 再次重线程池中获取到这个线程,会取出之前的数据(脏数据),会导致一些不可预期的错误,
            // 所以当前线程结束后一定要清掉。
        }
    }

    protected abstract void runWithMdc();
}
package com.chelaile.log.insert;

import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
import org.slf4j.MDC;
import java.util.concurrent.LinkedBlockingQueue;
import java.util.concurrent.TimeUnit;

public class LogRunnable extends MdcRunnable {

    private volatile boolean flag = true;

    private static final Logger log = LoggerFactory.getLogger(LogRunnable.class);

    private String code;

    // 阻塞队列
    private LinkedBlockingQueue<String> queue = new LinkedBlockingQueue<>();

    public LogRunnable(String code) {
        this.code = code;
    }

    @Override
    protected void runWithMdc() {
        String str;
        System.out.println("code=" + code + ",启动,logFileName=" + MDC.get("logFileName"));
        while (flag || queue.size() > 0) {
            try {
                str = queue.poll(5, TimeUnit.SECONDS);
                if (str == null || "null".equals(str) || "".equals(str)) {
                    continue;
                }
            } catch (InterruptedException e) {
                e.printStackTrace();
                continue;
            }
            log.info(str);
            MDC.put("logFileName",code);
        }
        System.out.println("code=" + code + ",结束,logFileName=" + MDC.get("logFileName"));
    }

    public void close() {
        this.flag = false;
    }

    public void setQueue(String str) {
        queue.add(str);
    }

    public String getCode() {
        return code;
    }
}

2.3 测试代码:

package com.chelaile.test;

import com.chelaile.SpringStart;
import com.chelaile.log.insert.LogRunnable;
import org.junit.Test;
import org.junit.runner.RunWith;
import org.slf4j.MDC;
import org.springframework.boot.test.context.SpringBootTest;
import org.springframework.test.context.junit4.SpringJUnit4ClassRunner;

import java.util.HashMap;
import java.util.Map;
import java.util.concurrent.*;

@RunWith(SpringJUnit4ClassRunner.class)
@SpringBootTest(classes = SpringStart.class)
public class LogRunnableTest {

    private Map<Integer, LogRunnable> logRunnableMap = new HashMap<>();

    @Test
    public void testLog() {
        ExecutorService logExecService = Executors.newFixedThreadPool(1);
        MDC.put("logFileName","默认");
        MDC.put("logSign","标记");

        for (int i = 0; i < 5; i++) {
            LogRunnable logRunnable = new LogRunnable("test" + i);
            logExecService.execute(logRunnable);
            logRunnableMap.put(i,logRunnable);
        }
        for (int i = 0; i < 5; i++) {
            LogRunnable logRunnable = logRunnableMap.get(i);
            logRunnable.setQueue("测试数据" + i);
            logRunnable.setQueue("我是测试" + i);
            logRunnable.setQueue("测试测试" + i);
            logRunnable.close();
        }
        while(true){} //测试的时候,不加  while(true){}  的话,由于主线程结束,日志没有写入文件线程就终止了
    }

}

2.4输出:

2.4.1控制台输出:
code=test0,启动,logFileName=默认
2018-07-19 15:44:12 INFO  [com.chelaile.log.insert.LogRunnable:38] -  默认 标记 测试数据0
2018-07-19 15:44:12 INFO  [com.chelaile.log.insert.LogRunnable:38] -  test0 标记 我是测试0
2018-07-19 15:44:12 INFO  [com.chelaile.log.insert.LogRunnable:38] -  test0 标记 测试测试0
code=test0,结束,logFileName=test0
code=test1,启动,logFileName=默认
2018-07-19 15:44:12 INFO  [com.chelaile.log.insert.LogRunnable:38] -  默认 标记 测试数据1
2018-07-19 15:44:12 INFO  [com.chelaile.log.insert.LogRunnable:38] -  test1 标记 我是测试1
2018-07-19 15:44:12 INFO  [com.chelaile.log.insert.LogRunnable:38] -  test1 标记 测试测试1
code=test1,结束,logFileName=test1
code=test2,启动,logFileName=默认
2018-07-19 15:44:12 INFO  [com.chelaile.log.insert.LogRunnable:38] -  默认 标记 测试数据2
2018-07-19 15:44:12 INFO  [com.chelaile.log.insert.LogRunnable:38] -  test2 标记 我是测试2
2018-07-19 15:44:12 INFO  [com.chelaile.log.insert.LogRunnable:38] -  test2 标记 测试测试2
code=test2,结束,logFileName=test2
code=test3,启动,logFileName=默认
2018-07-19 15:44:12 INFO  [com.chelaile.log.insert.LogRunnable:38] -  默认 标记 测试数据3
2018-07-19 15:44:12 INFO  [com.chelaile.log.insert.LogRunnable:38] -  test3 标记 我是测试3
2018-07-19 15:44:12 INFO  [com.chelaile.log.insert.LogRunnable:38] -  test3 标记 测试测试3
code=test3,结束,logFileName=test3
code=test4,启动,logFileName=默认
2018-07-19 15:44:12 INFO  [com.chelaile.log.insert.LogRunnable:38] -  默认 标记 测试数据4
2018-07-19 15:44:12 INFO  [com.chelaile.log.insert.LogRunnable:38] -  test4 标记 我是测试4
2018-07-19 15:44:12 INFO  [com.chelaile.log.insert.LogRunnable:38] -  test4 标记 测试测试4
code=test4,结束,logFileName=test4
2.4.2生成的日志目录结构:
日志目录结构

3.遇到的问题:

​ 第一次logback.xml文件没有配置layout,因为只想写入kafka中的数据,不想加多余的东西,导致测试内容没能写入文件,加上之后就OK了

<layout class="ch.qos.logback.classic.PatternLayout">
    <pattern>%msg%n</pattern>
</layout>

4. MDC分析 :

Slf4j MDC :

​ 对外接口,就是对参数进行校验,然后调用MDCAdapter的方法实现。

Logback MDC :

​ LogbackMDCAdapter类实现MDCAdapter接口,实现 put、get、remove等方法。

​ copyOnThreadLocal:存储每个线程的多个变量

​ 当在logback.xml中配置了%X{key} 或 SiftingAppender的<discriminator>的<key>,在需要输出日志的时候,从MDC中获取对应的key值,然后append到日志字符串中或生成文件路径,然后输出。

5. ThreadLocal 实现分析:

​ 在每个线程Thread内部有一个ThreadLocal.ThreadLocalMap类型的成员变量threadLocals,这个threadLocals就是用来存储实际的变量副本的,键值为当前ThreadLocal变量,value为变量副本(即T类型的变量)。

/* ThreadLocal values pertaining to this thread. This map is maintained
 * by the ThreadLocal class. */
ThreadLocal.ThreadLocalMap threadLocals = null;

​ 初始时,在Thread里面,threadLocals为空,当通过ThreadLocal变量调用get()方法或者set()方法,就会对Thread类中的threadLocals进行初始化,并且以当前ThreadLocal变量为键值,以ThreadLocal要保存的副本变量为value,存到threadLocals。

ThreadLocal类:

    ThreadLocalMap getMap(Thread t) {
        return t.threadLocals;
    }
    
    void createMap(Thread t, T firstValue) {
        t.threadLocals = new ThreadLocalMap(this, firstValue);
    }
    
    public void set(T value) {
        Thread t = Thread.currentThread();
        ThreadLocalMap map = getMap(t);
        if (map != null)
            map.set(this, value);//key用this,是因为同一个线程中如果有多个ThreadLocal,都会存储在该map中
        else
            createMap(t, value);
    }

    public T get() {
        Thread t = Thread.currentThread();
        ThreadLocalMap map = getMap(t);
        if (map != null) {
            ThreadLocalMap.Entry e = map.getEntry(this);
            if (e != null) {
                @SuppressWarnings("unchecked")
                T result = (T)e.value;
                return result;
            }
        }
        return setInitialValue();
    }

    private T setInitialValue() {
        T value = initialValue();
        Thread t = Thread.currentThread();
        ThreadLocalMap map = getMap(t);
        if (map != null)
            map.set(this, value);
        else
            createMap(t, value);
        return value;
    }
ThreadLocal总结:

1.实际的通过ThreadLocal创建的副本是存储在每个线程自己的threadLocals中的;

2.为何threadLocals的类型ThreadLocalMap的键值为ThreadLocal对象,因为每个线程中可有多个threadLocal变量

最后编辑于
©著作权归作者所有,转载或内容合作请联系作者
  • 序言:七十年代末,一起剥皮案震惊了整个滨河市,随后出现的几起案子,更是在滨河造成了极大的恐慌,老刑警刘岩,带你破解...
    沈念sama阅读 205,033评论 6 478
  • 序言:滨河连续发生了三起死亡事件,死亡现场离奇诡异,居然都是意外死亡,警方通过查阅死者的电脑和手机,发现死者居然都...
    沈念sama阅读 87,725评论 2 381
  • 文/潘晓璐 我一进店门,熙熙楼的掌柜王于贵愁眉苦脸地迎上来,“玉大人,你说我怎么就摊上这事。” “怎么了?”我有些...
    开封第一讲书人阅读 151,473评论 0 338
  • 文/不坏的土叔 我叫张陵,是天一观的道长。 经常有香客问我,道长,这世上最难降的妖魔是什么? 我笑而不...
    开封第一讲书人阅读 54,846评论 1 277
  • 正文 为了忘掉前任,我火速办了婚礼,结果婚礼上,老公的妹妹穿的比我还像新娘。我一直安慰自己,他们只是感情好,可当我...
    茶点故事阅读 63,848评论 5 368
  • 文/花漫 我一把揭开白布。 她就那样静静地躺着,像睡着了一般。 火红的嫁衣衬着肌肤如雪。 梳的纹丝不乱的头发上,一...
    开封第一讲书人阅读 48,691评论 1 282
  • 那天,我揣着相机与录音,去河边找鬼。 笑死,一个胖子当着我的面吹牛,可吹牛的内容都是我干的。 我是一名探鬼主播,决...
    沈念sama阅读 38,053评论 3 399
  • 文/苍兰香墨 我猛地睁开眼,长吁一口气:“原来是场噩梦啊……” “哼!你这毒妇竟也来了?” 一声冷哼从身侧响起,我...
    开封第一讲书人阅读 36,700评论 0 258
  • 序言:老挝万荣一对情侣失踪,失踪者是张志新(化名)和其女友刘颖,没想到半个月后,有当地人在树林里发现了一具尸体,经...
    沈念sama阅读 42,856评论 1 300
  • 正文 独居荒郊野岭守林人离奇死亡,尸身上长有42处带血的脓包…… 初始之章·张勋 以下内容为张勋视角 年9月15日...
    茶点故事阅读 35,676评论 2 323
  • 正文 我和宋清朗相恋三年,在试婚纱的时候发现自己被绿了。 大学时的朋友给我发了我未婚夫和他白月光在一起吃饭的照片。...
    茶点故事阅读 37,787评论 1 333
  • 序言:一个原本活蹦乱跳的男人离奇死亡,死状恐怖,灵堂内的尸体忽然破棺而出,到底是诈尸还是另有隐情,我是刑警宁泽,带...
    沈念sama阅读 33,430评论 4 321
  • 正文 年R本政府宣布,位于F岛的核电站,受9级特大地震影响,放射性物质发生泄漏。R本人自食恶果不足惜,却给世界环境...
    茶点故事阅读 39,034评论 3 307
  • 文/蒙蒙 一、第九天 我趴在偏房一处隐蔽的房顶上张望。 院中可真热闹,春花似锦、人声如沸。这庄子的主人今日做“春日...
    开封第一讲书人阅读 29,990评论 0 19
  • 文/苍兰香墨 我抬头看了看天上的太阳。三九已至,却和暖如春,着一层夹袄步出监牢的瞬间,已是汗流浃背。 一阵脚步声响...
    开封第一讲书人阅读 31,218评论 1 260
  • 我被黑心中介骗来泰国打工, 没想到刚下飞机就差点儿被人妖公主榨干…… 1. 我叫王不留,地道东北人。 一个月前我还...
    沈念sama阅读 45,174评论 2 352
  • 正文 我出身青楼,却偏偏与公主长得像,于是被迫代替她去往敌国和亲。 传闻我的和亲对象是个残疾皇子,可洞房花烛夜当晚...
    茶点故事阅读 42,526评论 2 343

推荐阅读更多精彩内容

  • Spring Cloud为开发人员提供了快速构建分布式系统中一些常见模式的工具(例如配置管理,服务发现,断路器,智...
    卡卡罗2017阅读 134,598评论 18 139
  • 原文地址为 https://github.com/logstash/logstash-logback-encode...
    飞来来阅读 18,252评论 1 10
  • 姓名:周小蓬 16019110037 转载自:http://blog.csdn.net/YChenFeng/art...
    aeytifiw阅读 34,703评论 13 425
  • 记得迷迷糊糊是凌晨后才睡着,可其实10点半我就在准备睡觉了…可现在才3点40已经被爸妈上厕所的噪音弄醒后再也睡不下...
    H2阅读 203评论 0 1