Log4j2最强的AsyncLogger！

众所周知，对于log4j2比较核心的高性能组件就是AsyncLogger以及Garbage-free Logging。

Garbage-free Logging可以使你在打日志的时候尽可能的避免因为日志框架引发的GC问题。

当然还是得说明一下：Logger和Appender是两个组件，大家不要混为一谈了。

因为AsyncAppender底层是一个阻塞队列，存在锁争用的问题。

所以一般建议还是使用本文介绍的AsyncLogger。

Asynchronous Loggers for Low-Latency Logging

---

AsyncLogger可以提高系统的性能，因为它可以在一个独立的线程里执行一个写磁盘的IO。Log4j2在这一块做了很多的优化。

Asynchronous Loggers其实是log4j2里面附加的一个新功能，他可以通过Logger.log()往系统里面异步打日志。当然你也可以很容易的去配置异步日志与同步日志混合执行。

在异步这块底层是通过LMAX Disruptor technology技术实现的，其实最核心的就是用了Disruptor，他是一个无锁化线程间的一个通讯库，你也可以认为他是一个高性能内存消息队列。

你可以用Disruptor实现两个线程间的通信，以至于它可以由更高的吞吐量以及更低的延迟。

注：Appender是使用阻塞队列

---

Asynchronous Loggers的优点：在高并发的场景下他的吞吐量是同步日志的6~68倍，对于拥有大量日志的系统，它可以帮助我们降低延迟，减少写日志的等待时间。如果你把queue size设置的很大的话，就会避免系统突然高峰的时候被磁盘IO给拖垮。所以就特别适合高并发场景。

Asynchronous Loggers的缺点：

1. 因为他是异步化的，那么我们无法捕获住异常反馈给系统。当然我们也可以去配置一个ExceptionHandler进行回调，但是这个也解决不了所有的问题。当我们的业务类似于审计的时候，无可避免你只能使用同步日志去记录。
2. 用异步日志去打印可能会打印一个不一致的对象，也可能会产生异常。例如 logger.debug("My object is {}", myObject)。
3. 系统如果在cpu资源非常紧张的环境下，比如一核cpu，性能不会太好。（官方的这个例子太离谱了。。。）

---

那么如果使我们的日志变为Asynchronous Loggers呢？

首先你的Log4j至少要是2.9以上的版本。

然后需要把disruptor的jar配置到classpath里面，还要设置一个系统属性：把log4j2.contextSelector设置为org.apache.logging.log4j.core.async.AsyncLoggerContextSelector 或者org.apache.logging.log4j.core.async.BasicAsyncLoggerContextSelector

如果我们用了AsyncLoggerContextSelector 把所有的log都变为异步的，在xml里就用常规的<root> 和 <logger>就行了。他的机制其实与<asyncRoot>和<asyncLogger>是不同的。

---

在回到文章开头我们聊到过他不会引起JVM GC的问题，这是为啥呢？

很多的日志框架包括老版本的log4j，都会对日志产生的char或者string分配一些临时的对象去打印。肯定会导致jvm的新生代被快速填满，加速youngGC的频率。

但是在最新的模式下log4j是运行在garbage-free里的，他不会对GC有很大的影响。因为这些对象被引用了所以不会被反复回收，而是会重用复用，频繁的使用老年的对象和buffer。这个模式就叫做garbage-free

如图：这是log4j 2.5，每秒会分配809MB，会导致141次youngGC

 log4j 2.6以后 就不会分配对象了。而是驻留在老年代里。

---

 源码 

当我们执行 logger.info("这是测试的info日志......") 时Debug跟入，由于链路非常长，这里也不会一一赘述，我们只聊关键部分。

随着代码往下走，我们发现了tryEnqueue方法存在一个让人眼前一亮的disruptor队列😀。此时代码执行到了AsyncLoggerConfigDisruptor里。logEvent就是我们打印的日志，是在这里入队的。之后在Disruptor触发了一个Event事件就会被下面的回调捕获住

    @Override
    public boolean tryEnqueue(final LogEvent event, final AsyncLoggerConfig asyncLoggerConfig) {
        final LogEvent logEvent = prepareEvent(event);
        return disruptor.getRingBuffer().tryPublishEvent(translator, logEvent, asyncLoggerConfig);
    }

那么在这个类中同样有一个内部类处理回调：Log4jEventWrapperHandler。如果收到了一条日志事件，再去使用当前的线程进行日志的记录。

    private static class Log4jEventWrapperHandler implements SequenceReportingEventHandler<Log4jEventWrapper> {
        private static final int NOTIFY_PROGRESS_THRESHOLD = 50;
        private Sequence sequenceCallback;
        private int counter;

        @Override
        public void setSequenceCallback(final Sequence sequenceCallback) {
            this.sequenceCallback = sequenceCallback;
        }

        @Override
        public void onEvent(final Log4jEventWrapper event, final long sequence, final boolean endOfBatch)
                throws Exception {
            event.event.setEndOfBatch(endOfBatch);
            event.loggerConfig.logToAsyncLoggerConfigsOnCurrentThread(event.event);
            event.clear();

            notifyIntermediateProgress(sequence);
        }

    // 初始化代码
    @Override
    public synchronized void start() {
        if (disruptor != null) {
            LOGGER.trace("AsyncLoggerConfigDisruptor not starting new disruptor for this configuration, "
                    + "using existing object.");
            return;
        }
        LOGGER.trace("AsyncLoggerConfigDisruptor creating new disruptor for this configuration.");
        // 我们在配置文件中配置的属性
        ringBufferSize = DisruptorUtil.calculateRingBufferSize("AsyncLoggerConfig.RingBufferSize");
        final WaitStrategy waitStrategy = DisruptorUtil.createWaitStrategy("AsyncLoggerConfig.WaitStrategy");
        // 线程工厂
        final ThreadFactory threadFactory = new Log4jThreadFactory("AsyncLoggerConfig", true, Thread.NORM_PRIORITY) {
            @Override
            public Thread newThread(final Runnable r) {
                final Thread result = super.newThread(r);
                backgroundThreadId = result.getId();
                return result;
            }
        };
        asyncQueueFullPolicy = AsyncQueueFullPolicyFactory.create();

        translator = mutable ? MUTABLE_TRANSLATOR : TRANSLATOR;
        factory = mutable ? MUTABLE_FACTORY : FACTORY;
        // 对disruptor进行一些配置
        disruptor = new Disruptor<>(factory, ringBufferSize, threadFactory, ProducerType.MULTI, waitStrategy);

        // 封装Handler 把他设置给disruptor
        final ExceptionHandler<Log4jEventWrapper> errorHandler = DisruptorUtil.getAsyncLoggerConfigExceptionHandler();
        disruptor.setDefaultExceptionHandler(errorHandler);

        final Log4jEventWrapperHandler[] handlers = {new Log4jEventWrapperHandler()};
        disruptor.handleEventsWith(handlers);

        LOGGER.debug("Starting AsyncLoggerConfig disruptor for this configuration with ringbufferSize={}, "
                + "waitStrategy={}, exceptionHandler={}...", disruptor.getRingBuffer().getBufferSize(), waitStrategy
                .getClass().getSimpleName(), errorHandler);
        disruptor.start();
        super.start();
    }

由此可见：我们一旦把日志交给了disruptor ，他背后的后台线程就会把数据结构中的log日志取出来回调给自己实现的handler。通过handler实现异步化的处理。