MDC+Logback+TTL的化学反应

前言

以下代码为我们产品线目前在使用的日志方案。
由于不是本人的劳动成果,所以会屏蔽部分技术细节。

正文

上下文传递

在一次服务中,也叫一次事务即常说的TransectionID,是被上下文传递的。直到下一次事务才被更新。在漫长的上下文传递过程中这个值就十分容易丢,而且我们要记录的字段也远不止这一项,而且使用传参的方式做也太过于麻烦了。
因此MDC为“Mapped Diagnostic Context”(映射诊断上下文)就被提出来了。

其基本原理大概是:
MDC包含一个MDCAdapter接口其基本实现类是BasicMDCAdapter,BasicMDCAdapter使用了inheritableThreadLocal。而inheritableThreadLocal又由ThreadLocal改造而来。

那么ThreadLocal是什么呢?
详见://www.greatytc.com/p/1af4f7582b80
简单来说:
ThreadLocal是为每一个线程创建一个单独的变量副本,每个线程都可以独立地改变自己所拥有的变量副本,而不会影响其他线程所对应的副本。
而inheritableThreadLocal在线程切换时(父线程-->子线程),会自动地把这个副本传递下去。
这个时候你直接使用MDC.get("key");就像在使用一个普通的Map一样容易。
因此在日志配置里logback.xml可以配成

<configuration scan="true" scanPeriod="30 seconds" debug="false">
    <appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">
        <encoder>
            <pattern>%d{HH:mm:ss.SSS}-[%X{TransectionID}] [%t] %-5level %logger{36} - %msg%n</pattern>
        </encoder>
    </appender>
<root level="INFO" additivity="false" name="cn.itcast.product">
    <appender-ref ref="STDOUT"/>
</root>>
</configuration>

[%X{TransectionID}]代表打印日志时自动打印TransectionID。

但是在多线程实现的时候情况就大有不同了。

多线程情况下使用inheritableThreadLocal的MDC

由于线程池是由IOC容器管理的,一般来说线程池一旦创建就不再销毁。那么复用线程池的情况就总是存在。由于不再进行初始化,inheritableThreadLocal就无法同步父线程的值。
因此会存在MDC错乱的现象。
为此阿里巴巴提供了一套解决方案---TransmittableThreadLocal。

TransmittableThreadLocal

详见://www.greatytc.com/p/e0774f965aa3
TransmittableThreadLocal简称TTL。
其原理就是在MDC中替换inheritableThreadLocal为TransmittableThreadLocal从而解决以上问题。
他提供了一个修饰线程池的工具:TtlExecutors.getTtlExecutor(executor)。
具体用法如下:

/**
 * @author AUTO_BEAR
 */
@Configuration
@EnableAsync
public class Threadpool {
    @Bean
    public Executor testExecutor(ThreadPoolConfig config)
    {
        ThreadPoolTaskExecutor executor = new ThreadPoolTaskExecutor();
        executor.setCorePoolSize(1);
        executor.setMaxPoolSize(10);
        executor.setQueueCapacity(10);
        executor.setKeepAliveSeconds(5000);
        executor.setThreadNamePrefix("MydearThread-");
        executor.setRejectedExecutionHandler(new ThreadPoolExecutor.CallerRunsPolicy());
        executor.initialize();
        return TtlExecutors.getTtlExecutor(executor);
    }
}

实现BeanPostProcessor 接口后,便可以在Bean初始化的时候对线程池自动进行修饰:

@Configuration
public class NewBeanPostProcessor implements BeanPostProcessor {
    private static final Logger logger=LoggerFactory.getLogger(NewBeanPostProcessor.class);
    @Override
    public Object postProcessAfterInitialization(Object bean, String beanName) throws BeansException {
        if(bean instanceof Executor)
        {
            Executor executor=(Executor)bean;
            if (TtlExecutors.isTtlWrapper(executor))
            {
                logger.info("Executor[{}] is already wrapped by TTLExecutors",executor);
                return executor;
            }
            logger.info("Executor[{}] will be wrapped by TTLExecutors",executor);
            return TtlExecutors.getTtlExecutor(executor);
        }
        return bean;
    }
}

至此问题就基本得到解决了,但是还是会出现一个比较隐蔽的问题,使用TTL+MDC进行上下文传递时应该关注。

问题复现

以下代码隐式使用了ForkJoinPool

  list.parallelStream().forEach(x->map.put(x,printit(x)));

ForkjoinPool是JDK1.8以后提出来的,其执行逻辑和其他线程池有点不同,他是窃格瓦拉式的拉风但是又是一个十恶不赦的工贼模式---在他空闲的时候他只喜欢偷别人的工作(不是工作成果)。因此这是一个很高效的方法。
我们可以使用原始的方法解决:

 Map<String, String> mdcmap = MDC.getCopyOfContextMap();
  list.parallelStream().forEach(x->map.put(x,printit(x,mdcmap)));
//在printit内添加这行代码
  MDC.setContextMap(mdcmap);

但是我不同意!!!于是我把代码改为,每次使用ForkJoinPool我就自己手动New一个出来,因此符合inheritableThreadLocal的逻辑,线程初始化时同步父线程的MDC值。
以下是茴香豆的“囬”的几种写法:

1.
ForkJoinPool pool = new ForkJoinPool();
        Map<String, String> mdcmap = MDC.getCopyOfContextMap();
        list.parallelStream().forEach(x->printit(x));
2.
 ForkJoinPool pool = new ForkJoinPool();
       try {
           pool.submit(() -> list.parallelStream().forEach(x -> {
                    this.printit(x);
           })).get();
        } catch (InterruptedException e) {
            e.printStackTrace();
        } catch (ExecutionException e) {
            e.printStackTrace();
        }
3.
        ForkJoinPool pool = new ForkJoinPool();
        try {
            for(String s:list){
                SendMessageTask task=new SendMessageTask(s);
                forkJoinPool.execute(task);
            }
            forkJoinPool.awaitTermination(2, TimeUnit.SECONDS);
            forkJoinPool.shutdown();
            if(!forkJoinPool.isShutdown()) {
                forkJoinPool.awaitTermination(5, TimeUnit.SECONDS);
                forkJoinPool.shutdownNow();
            }
        } catch (Exception e) {
            e.printStackTrace();
        }
    }
public class SendMessageTask extends RecursiveAction {
  String  s = null;
    public SendMessageTask(String s) {
        this.s = s;
    }
    @Override
    protected void compute() {
    Dosomething....
  }
}

但是这种写法有一个巨大的危害:我们平时都清楚要避免频繁创建线程池。为什么呢?https://blog.csdn.net/qq_33744693/article/details/88696584
他告诉我们CPU资源的宝贵,是如何被频繁创建销毁所浪费的。
虽然任务完成了,但是性能也下降了,至少我认为是不够保守的方法,因此:我不同意!!!

最终解决方案

我们可以看出TTL是管不到那些路边有事没事长出来的线程池的,因为毕竟BeanPostProcessor 这个接口是SpringIOC提供的,如果超出IOC的辖区,那么Executor是无法乖乖就范的。因此我们需要把线程池拿到IOC的户籍本里注册一下。

那么,答案就藏在了最开始,我们注册了一个ForkJoinPool的线程池,并供程序使用。

    @Bean
    public Executor myForkJoinPool()
    {
        Executor executor=new ForkJoinPool();
        ExecutorService executor = TtlExecutors.getTtlExecutorService(new ForkJoinPool());
        return executor;
    }

如此他就必然被TTL管理了。然后异步调用的时候也就可以心安理得地去使用它了:

    @Async("myForkJoinPool")
    public Map<String,String> CALL(List<String> list){
        Map<String ,String > map=new HashMap();
        for(String s:list){
           String rs=printit(s);
           map.put(s,rs);
        }
        return map;
    }

我们不但解决了问题,还把讨厌的lambda表达式给跳过去了,至此本篇结束。

结尾

最近工作有点累,但是也有收获,在前辈的带领下也学了不少知识,希望能够在搬砖这条路上越走越好吧。

我慢慢地对这份工作有所感悟:
软件业有一点像运输业,都是服务业嘛没毛病。一开始你可能只是一个跑腿的能把货物送到就行,慢慢地你开起了车,一开始是开五菱宏光送货,但是随着业务量的增加你可能接到送几个老乡进城的需求,因此你要租一辆小轿车,这叫做用户体验。
如果让你运钞,你不但会选一辆装甲车、运钞车,你还会配备押送人员,你会去考虑存放钞票的箱子是否结实可靠,甚至你会躲避人流量多的时间去进行运钞。数据的可靠性、安全性是一个值得考虑的指标。一个大型的系统往往需要一些信息安全的专业人员。
有时候你会有感而发:飞机有飞机的优点、摩托车有摩托车的优点,时间就是生命!数据的时效性、系统的效率也是一个重要的指标。

因此任何一个线程池的选型,还有所结合的List和Map作为入参出参(容器)的选型都是值得学习深究的。
希望下班后别总是玩游戏,还是应该看看书,看看别人写的代码。

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