关于log4j2:日志log4j2基于AsyncLogger的异步日志打印

前言

在日志-log4j2基于AsyncAppender的异步日志打印一文中，剖析了Log4j2如何基于AsyncAppender来实现异步日志打印，本篇文章将剖析Log4j2如何基于AsyncLogger来实现异步日志打印。

本篇文章会波及局部Disruptor队列的相干概念，如果不相熟Disruptor队列，能够先浏览多线程学习-Disruptor队列理解相干概念。

Log4j2版本：2.17.1

注释

首先搭建示例工程。引入依赖如下所示。

<dependencies>
    <dependency>
        <groupId>org.apache.logging.log4j</groupId>
        <artifactId>log4j-slf4j-impl</artifactId>
        <version>2.17.1</version>
    </dependency>
    <dependency>
        <groupId>org.apache.logging.log4j</groupId>
        <artifactId>log4j-core</artifactId>
        <version>2.17.1</version>
    </dependency>
    <dependency>
        <groupId>org.apache.logging.log4j</groupId>
        <artifactId>log4j-api</artifactId>
        <version>2.17.1</version>
    </dependency>

    <dependency>
        <groupId>com.lmax</groupId>
        <artifactId>disruptor</artifactId>
        <version>3.4.0</version>
    </dependency>
</dependencies>

打印日志的测试类如下所示。

public class LearnLog4j2Async {

    private static final Logger logger = LoggerFactory
            .getLogger(LearnLog4j2Async.class);

    public static void main(String[] args) {
        logger.info("{} be happy every day.", "Lee");
    }

}

要应用AysncLogger，须要在Log4j2的配置文件中应用<AsyncLogger>标签配置一个异步Logger，并为这个异步Logger配置非异步Appender。配置如下所示。

<?xml version="1.0" encoding="UTF-8"?>

<Configuration status="INFO">
    <Appenders>
        <!-- 配置两个非异步Appender -->
        <Console name="MyConsole" target="SYSTEM_OUT">
            <ThresholdFilter level="INFO" onMatch="ACCEPT" onMismatch="DENY"/>
            <PatternLayout pattern="%msg%n"/>
        </Console>
        <RollingFile name="MyFile" fileName="mylog.log"
                     filePattern="mylog.log.%i">
            <ThresholdFilter level="INFO" onMatch="ACCEPT" onMismatch="DENY" />
            <PatternLayout pattern="%msg%n"/>
            <SizeBasedTriggeringPolicy size="20M"/>
        </RollingFile>
    </Appenders>

    <Loggers>
        <!-- 为根Logger配置非异步Appender -->
        <Root level="INFO">
            <Appender-ref ref="MyConsole"/>
            <Appender-ref ref="MyFile"/>
        </Root>
        <!-- 定义一个异步Logger并为其配置非异步Appender -->
        <AsyncLogger name="com.lee.learn.log4j2.asynclogger.LearnLog4j2Async" level="INFO" additivity="false">
            <appender-ref ref="MyConsole"/>
        </AsyncLogger>
    </Loggers>
</Configuration>

已知Log4j2框架在首次获取Logger时，会初始化LoggerContext，而初始化LoggerContext时有一个步骤就是将Log4j2配置对象XmlConfiguration设置给LoggerContext并启动XmlConfiguration，这里看一下XmlConfiguration的start()办法，如下所示。

public void start() {
    if (getState().equals(State.INITIALIZING)) {
        initialize();
    }
    LOGGER.debug("Starting configuration {}", this);
    this.setStarting();
    if (watchManager.getIntervalSeconds() >= 0) {
        watchManager.start();
    }
    //判断是否配置了AsyncLogger
    if (hasAsyncLoggers()) {
        //调用asyncLoggerConfigDisruptor来启动AsyncLogger
        asyncLoggerConfigDisruptor.start();
    }
    final Set<LoggerConfig> alreadyStarted = new HashSet<>();
    for (final LoggerConfig logger : loggerConfigs.values()) {
        logger.start();
        alreadyStarted.add(logger);
    }
    for (final Appender appender : appenders.values()) {
        appender.start();
    }
    if (!alreadyStarted.contains(root)) {
        root.start();
    }
    super.start();
    LOGGER.debug("Started configuration {} OK.", this);
}

在XmlConfiguration的start()办法中，须要关注的就是调用了asyncLoggerConfigDisruptor的start()办法来启动AsyncLogger，asyncLoggerConfigDisruptor是一个AsyncLoggerConfigDisruptor对象，其在首次初始化AsyncLoggerConfig时被创立，如下所示。

protected AsyncLoggerConfig(final String name,
        final List<AppenderRef> appenders, final Filter filter,
        final Level level, final boolean additive,
        final Property[] properties, final Configuration config,
        final boolean includeLocation) {
    super(name, appenders, filter, level, additive, properties, config,
            includeLocation);
    //在这里调用XmlConfiguration的getAsyncLoggerConfigDelegate()办法来创立AsyncLoggerConfigDisruptor
    delegate = config.getAsyncLoggerConfigDelegate();
    delegate.setLogEventFactory(getLogEventFactory());
}

AsyncLoggerConfigDisruptor的start()办法中次要逻辑就是创立Disruptor高性能队列，实现如下所示。

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.");
    //计算Disruptor队列大小，默认是4096
    ringBufferSize = DisruptorUtil.calculateRingBufferSize("AsyncLoggerConfig.RingBufferSize");
    //创立期待策略，默认是TimeoutBlockingWaitStrategy
    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;
        }
    };
    //创立队列满时的策略类，这里和AsyncAppender里的策略类是一样的
    asyncQueueFullPolicy = AsyncQueueFullPolicyFactory.create();

    translator = mutable ? MUTABLE_TRANSLATOR : TRANSLATOR;
    //创立填充RingBuffer的EventFactory
    //Disruptor队列在初始化时会应用这个EventFactory来生成事件对象来填充斥RingBuffer
    factory = mutable ? MUTABLE_FACTORY : FACTORY;
    //创立Disruptor队列，指定生产者模式为MULTI，示意这是多生产者场景，一个AsyncLogger就是一个生产者
    disruptor = new Disruptor<>(factory, ringBufferSize, threadFactory, ProducerType.MULTI, waitStrategy);

    final ExceptionHandler<Log4jEventWrapper> errorHandler = DisruptorUtil.getAsyncLoggerConfigExceptionHandler();
    disruptor.setDefaultExceptionHandler(errorHandler);

    //创立只有一个Log4jEventWrapperHandler的数组
    //Log4jEventWrapperHandler实现了EventHandler接口
    //所以Log4j2外面应用的Disruptor队列只有单消费者生产
    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队列
    disruptor.start();
    super.start();
}

在AsyncLoggerConfigDisruptor的start()办法中次要就是在进行Disruptor队列的创立和启动，所以如果应用了AsyncLogger，那么存储日志音讯元素的Disruptor队列在初始化LoggerContext时就会被创立并启动。

当初看一下每一个AsyncLogger是如何向Disruptor队列增加日志音讯的。首先察看一下一个AsyncLogger的具体内容。

那么每一个AsyncLogger都持有一个AsyncLoggerConfig，所以可知AsyncLogger打印日志会通过AsyncLoggerConfig来打印，上面看一下AsyncLogger的log()办法，如下所示。

protected void log(final LogEvent event, final LoggerConfigPredicate predicate) {
    //只有predicate为ALL，ASYNC_LOGGER_ENTERED为false以及以后AsyncLogger有Appender时才打印
    //predicate示意容许的日志打印类型，有ALL，ASYNCHRONOUS_ONLY和SYNCHRONOUS_ONLY三种
    //ASYNC_LOGGER_ENTERED是和线程绑定的原子布尔值，即同一线程只能串行的调用logToAsyncDelegate()办法向Disruptor队列增加日志音讯
    if (predicate == LoggerConfigPredicate.ALL &&
            ASYNC_LOGGER_ENTERED.get() == Boolean.FALSE && hasAppenders()) {
        ASYNC_LOGGER_ENTERED.set(Boolean.TRUE);
        try {
            super.log(event, LoggerConfigPredicate.SYNCHRONOUS_ONLY);
            //异步日志打印
            logToAsyncDelegate(event);
        } finally {
            ASYNC_LOGGER_ENTERED.set(Boolean.FALSE);
        }
    } else {
        super.log(event, predicate);
    }
}

在AsyncLogger的log()办法中，只有同时满足如下条件才执行异步日志打印。

以后打印动作是全类型打印，即predicate等于LoggerConfigPredicate.ALL。LoggerConfigPredicate一共有三种枚举值，LoggerConfigPredicate.ASYNCHRONOUS_ONLY示意仅异步打印，LoggerConfigPredicate.SYNCHRONOUS_ONLY示意仅同步打印，LoggerConfigPredicate.ALL示意同步异步都能够；
ASYNC_LOGGER_ENTERED的get()办法返回false。ASYNC_LOGGER_ENTERED是一个类型为ThreadLocal<Boolean>的变量，即同一线程只能串行的调用logToAsyncDelegate()办法向Disruptor队列增加日志音讯；
以后AsyncLogger有Appender。

满足上述三点条件后，就会调用logToAsyncDelegate()办法来将日志音讯增加到Disruptor队列中，看一下其实现。

private void logToAsyncDelegate(final LogEvent event) {
    if (!isFiltered(event)) {
        populateLazilyInitializedFields(event);
        //这里的delegate就是AsyncLoggerConfigDisruptor
        //通过AsyncLoggerConfigDisruptor将日志音讯放入Disruptor的RingBuffer中
        if (!delegate.tryEnqueue(event, this)) {
            //Disruptor容量满时执行策略类的逻辑，这里与AsyncAppender中的策略是统一的
            handleQueueFull(event);
        }
    }
}

上述办法会调用AsyncLoggerConfigDisruptor的tryEnqueue()办法将日志音讯增加到Disruptor队列中，如下所示。

public boolean tryEnqueue(final LogEvent event, final AsyncLoggerConfig asyncLoggerConfig) {
    final LogEvent logEvent = prepareEvent(event);
    //从Disruptor对象中取出RingBuffer，而后将日志音讯增加到RingBuffer中并公布
    return disruptor.getRingBuffer().tryPublishEvent(translator, logEvent, asyncLoggerConfig);
}

日志音讯增加到Disruptor队列理论就是将日志音讯LogEvent公布到Disruptor的RingBuffer中，后续消费者就可能从RingBuffer生产日志音讯并基于Appender打印日志。

当初最初剖析消费者线程的启动和生产逻辑。已知在初始化Log4j2的LoggerContext时会实现Disruptor队列的创立和启动，理论就是在Disruptor启动也就是Disruptor的start()办法执行时，会将消费者线程运行起来，这里的消费者是BatchEventProcessor，其本质是一个Runnable，所以最终会调用到BatchEventProcessor的run()办法，在run()办法中会循环的从Disruptor对象的RingBuffer中获取音讯元素并将音讯元素交由EventHandler解决，整个这一块儿逻辑是属于Disruptor队列的逻辑，这里不再赘述，然而解决音讯的EventHandler是由Log4j2提供的Log4jEventWrapperHandler，这个在后面的剖析中曾经晓得，所以看一下Log4jEventWrapperHandler的onEvent()办法。

public void onEvent(final Log4jEventWrapper event, final long sequence, final boolean endOfBatch)
        throws Exception {
    event.event.setEndOfBatch(endOfBatch);
    //从Log4jEventWrapper中将AsyncLoggerConfig获取进去并在以后线程中实现日志打印
    event.loggerConfig.logToAsyncLoggerConfigsOnCurrentThread(event.event);
    event.clear();

    notifyIntermediateProgress(sequence);
}

void logToAsyncLoggerConfigsOnCurrentThread(final LogEvent event) {
    //调用AsyncLoggerConfig的log()办法来打印日志
    //有两点须要留神：
    //1. 这里的log()办法和增加日志音讯到队列中的log()办法是同一个
    //2. 容许的打印行为被指定为LoggerConfigPredicate.ASYNCHRONOUS_ONLY，即同步打印
    log(event, LoggerConfigPredicate.ASYNCHRONOUS_ONLY);
}

protected void log(final LogEvent event, final LoggerConfigPredicate predicate) {
    if (predicate == LoggerConfigPredicate.ALL &&
            ASYNC_LOGGER_ENTERED.get() == Boolean.FALSE && hasAppenders()) {
        ASYNC_LOGGER_ENTERED.set(Boolean.TRUE);
        try {
            super.log(event, LoggerConfigPredicate.SYNCHRONOUS_ONLY);
            logToAsyncDelegate(event);
        } finally {
            ASYNC_LOGGER_ENTERED.set(Boolean.FALSE);
        }
    } else {
        //调用父对象也就是LoggerConfig来打印日志，后续就是同步日志打印流程了
        super.log(event, predicate);
    }
}

Log4jEventWrapperHandler的onEvent()办法中，会将生产到的日志音讯最终调用到和这条日志绑定的AsyncLoggerConfig的log()办法来打印日志，与生产音讯的时候调用到AsyncLoggerConfig#log办法不同，这时调用AsyncLoggerConfig#log办法传入的predicate为LoggerConfigPredicate.ASYNCHRONOUS_ONLY，所以会间接调用AsyncLoggerConfig的父对象LoggerConfig来打印日志，后续就是同步打印日志的流程，这里不再赘述。

总结

当应用AsyncLogger来实现异步日志打印时，存储日志元素的队列为Disruptor高性能队列，该队列相较于传统的阻塞队列，劣势如下。

应用RingBuffer环形数组存储元素，且在初始化队列时会将数组元素全副初始化进去，实现对象循环利用，防止频繁垃圾回收；
通过填充缓存行的形式防止了伪共享，充分利用缓存带来的效率晋升；
应用CAS操作代替加锁操作，防止加解锁带来的性能损耗。

应用Disruptor作为阻塞队列是Log4j2性能晋升的一大重要起因。

其次，所有AsyncLogger是共用同一个Disruptor队列的，每个AsyncLogger作为生产者能够并发的向Disruptor中增加日志元素，同时在消费者端存在一个消费者循环的从Disruptor中生产日志元素，每一条被生产的日志元素会被消费者调用到和这条日志绑定的LoggerConfig来实现打印，也就是能够了解为有多个生产者向Disruptor队列中生产日志元素，而后只有一个消费者从Disruptor队列生产日志元素并调用Appender实现日志打印，整个过程能够用下图进行示意和总结。

关于log4j2:日志log4j2基于AsyncLogger的异步日志打印

前言

注释

总结

评论

发表回复取消回复

更多文章

苹果iOS打包的ipa应用无法安装？一篇文章带你了解可能的原因及排查方法

图解Golang：从零开始实现简易版过期LRU缓存

深入解析：基于Delta的线性数据结构模型，打造高效富文本编辑器

轻松管理社交媒体：使用Automa插件实现一键拉黑功能

关于log4j2:日志log4j2基于AsyncLogger的异步日志打印

前言

注释

总结

评论

发表回复 取消回复

更多文章

苹果iOS打包的ipa应用无法安装？一篇文章带你了解可能的原因及排查方法

图解Golang：从零开始实现简易版过期LRU缓存

深入解析：基于Delta的线性数据结构模型，打造高效富文本编辑器

轻松管理社交媒体：使用Automa插件实现一键拉黑功能

发表回复取消回复