log4j2打印一行日志做了啥

1.是什么？

log4j已成为大型系统必不可少的一部分，log4j可以很方便的帮助我们在程序的任何位置输出所要打印的信息，便于我们对系统在调试阶段和正式运行阶段对问题分析和定位。

2.日志级别

1.日志级从低到高：debug,info,warn,error, 依次升高，性能越高；

2.影响输出性能条件：

输出到文件系统 > 控制台
SimpleLayout > PatternLayout，不带格式化的直接输出更快；
日志级别越高，内容输出越少，应用受日志打印影响越少，性能越高；

根据不同场景选择不同的日志级别，一般按环境划分（开发，测试，生产），开发需要足够的调试日志信息，线上只需要一些关键的warn/更高级别的日志，避免日志过多或影响性能。

3.日志门面

Simple Logging Facade for Java（SLF4J）用作各种日志框架（例如 java.util.logging，logback，log4j）的简单外观或抽象，允许最终用户在部署时插入所需的日志框架;

总的来说，slf4j就是众多日志接口的集合（接口定义），不负责具体的日志实现，只在编译时寻找合适的日志系统进行绑定；

4.外观模式应用

外观模式：外部与一个子系统的通信必须通过一个统一的外观对象进行，为子系统中的一组接口提供一个一致的界面；

SLF4j的logger需要直接或间接指向实际依赖的日志系统的logger，通过实现LoggerFactoryBinder接口完成日志实现的绑定；

5.使用规范

【强制】应用中不可直接使用日志系统（Log4j、Logback）中的 API，而应依赖使用日志框架 SLF4J 中的 API，使用门面模式的日志框架，有利于维护和各个类的日志处理方式统一。

import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
private static final Logger logger = LoggerFactory.getLogger(Abc.class);

保证不会创建多个日志系统的logger，会选择绑定其中一个（根据配置文件,无配置文件则根据pom引入顺序）

lombok slf4j

6.log.info做了什么

1.找到log.info()

@Override
public void info(final Marker marker, final String s, final Object o, final Object o1) {
        logger.logIfEnabled(FQCN, Level.INFO, getMarker(marker), s, o, o1);
    }

2.进一步查看：

private void logMessageSafely(final String fqcn, final Level level, final Marker marker, final Message msg,
            final Throwable throwable) {
        try {
            logMessage(fqcn, level, marker, msg, throwable);
        } finally {
            // LOG4J2-1583 prevent scrambled logs when logging calls are nested (logging in toString())
            ReusableMessageFactory.release(msg);
        }
    }

3.从日志中读取要输出到appender的策略（从log4j2.xml中解析），执行log操作：

@Override
public void logMessage(final String fqcn, final Level level, final Marker marker, final Message message,
            final Throwable t) {
        final Message msg = message == null ? new SimpleMessage(Strings.EMPTY) : message;
        final ReliabilityStrategy strategy = privateConfig.loggerConfig.getReliabilityStrategy();
        strategy.log(this, getName(), fqcn, marker, level, msg, t);
    }

4.这时会发现打印日志却是由config去执行的(黑人问号脸❓)：

@Override
public void log(final Supplier<LoggerConfig> reconfigured, final String loggerName, final String fqcn,
            final Marker marker, final Level level, final Message data, final Throwable t) {

        final LoggerConfig config = getActiveLoggerConfig(reconfigured);
        try {
            config.log(loggerName, fqcn, marker, level, data, t);
        } finally {
            config.getReliabilityStrategy().afterLogEvent();
        }
    }

5.查看具体实现：

若值包含需要解析才能被替换的属性，则使用该属性；
否则则使用log.info时初始化的配置；
做完logEvent的初始化工作，接下来的log(logEvent)才是真正的log操作;

@PerformanceSensitive("allocation")
public void log(final String loggerName, final String fqcn, final Marker marker, final Level level,
            final Message data, final Throwable t) {
        List<Property> props = null;
        if (!propertiesRequireLookup) {
            props = properties;
        } else {
            if (properties != null) {
                props = new ArrayList<>(properties.size());
                final LogEvent event = Log4jLogEvent.newBuilder()
                        .setMessage(data)
                        .setMarker(marker)
                        .setLevel(level)
                        .setLoggerName(loggerName)
                        .setLoggerFqcn(fqcn)
                        .setThrown(t)
                        .build();
                for (int i = 0; i < properties.size(); i++) {
                    final Property prop = properties.get(i);
                    final String value = prop.isValueNeedsLookup() // since LOG4J2-1575
                            ? config.getStrSubstitutor().replace(event, prop.getValue()) //
                            : prop.getValue();
                    props.add(Property.createProperty(prop.getName(), value));
                }
            }
        }
        final LogEvent logEvent = logEventFactory.createEvent(loggerName, marker, fqcn, level, data, props, t);
        try {
            log(logEvent);
        } finally {
            // LOG4J2-1583 prevent scrambled logs when logging calls are nested (logging in toString())
            ReusableLogEventFactory.release(logEvent);
        }
    }

6.经过一系列标志位确认，过滤器确定是否输出appender日志，以AsyncAppender为例进行进一步实现分析，实际写日志的操作，执行步骤有：

生成logEvent事件；
将指定的日志logEvent放进BlockingQueue，如果失败（队列满或是没有接收者消费logEvent事件），则启用相应的策略，委托给事件路由去执行；
同时，这里需要一个异步事件去消费日志事件；

@Override
public void append(final LogEvent logEvent) {
        if (!isStarted()) {
            throw new IllegalStateException("AsyncAppender " + getName() + " is not active");
        }
        if (!Constants.FORMAT_MESSAGES_IN_BACKGROUND) { // LOG4J2-898: user may choose
            logEvent.getMessage().getFormattedMessage(); // LOG4J2-763: ask message to freeze parameters
        }
        final Log4jLogEvent memento = Log4jLogEvent.createMemento(logEvent, includeLocation);
        if (!transfer(memento)) {
            if (blocking) {
                // delegate to the event router (which may discard, enqueue and block, or log in current thread)
                final EventRoute route = asyncQueueFullPolicy.getRoute(thread.getId(), memento.getLevel());
                route.logMessage(this, memento);
            } else {
                error("Appender " + getName() + " is unable to write primary appenders. queue is full");
                logToErrorAppenderIfNecessary(false, memento);
            }
        }
    }

处处皆异步，还委托小三来干活。

7.执行线程实现日志异步输出：

从队列中获取logEvent事件;
callAppender调用已注册的日志事件；
线程退出前将对列中的元素都消费完再退出； org.apache.logging.log4j.core.appender.AsyncAppender.AsyncThread#run

        @Override
        public void run() {
            while (!shutdown) {
                LogEvent event;
                try {
                    event = queue.take();
                    if (event == SHUTDOWN) {
                        shutdown = true;
                        continue;
                    }
                } catch (final InterruptedException ex) {
                    break; // LOG4J2-830
                }
                event.setEndOfBatch(queue.isEmpty());
                final boolean success = callAppenders(event);
                if (!success && errorAppender != null) {
                    try {
                        errorAppender.callAppender(event);
                    } catch (final Exception ex) {
                        // Silently accept the error.
                    }
                }
            }
            // Process any remaining items in the queue.
            LOGGER.trace("AsyncAppender.AsyncThread shutting down. Processing remaining {} queue events.",
                queue.size());
            int count = 0;
            int ignored = 0;
            while (!queue.isEmpty()) {
                try {
                    final LogEvent event = queue.take();
                    if (event instanceof Log4jLogEvent) {
                        final Log4jLogEvent logEvent = (Log4jLogEvent) event;
                        logEvent.setEndOfBatch(queue.isEmpty());
                        callAppenders(logEvent);
                        count++;
                    } else {
                        ignored++;
                        LOGGER.trace("Ignoring event of class {}", event.getClass().getName());
                    }
                } catch (final InterruptedException ex) {
                    // May have been interrupted to shut down.
                    // Here we ignore interrupts and try to process all remaining events.
                }
            }
            LOGGER.trace("AsyncAppender.AsyncThread stopped. Queue has {} events remaining. "
                + "Processed {} and ignored {} events since shutdown started.", queue.size(), count, ignored);
        }

看到这些操作套路可能会有些熟悉，【添加任务到队列中（workers池子）->根据相应策略->由异步线程（thread）去执行】，与java线程池的设计较为相似；

AsyncAppender采用的是生产者消费者的模型,异步地将Logging Event送到对应的Appender中。

8.AsyncLogger的logMsessage方法，通过日志分发确定是否使用ThreadLocal对象，这里以org.apache.logging.log4j.core.async.AsyncLogger#logWithThreadLocalTranslator为例:

private void logWithThreadLocalTranslator(final String fqcn, final Level level, final Marker marker,
            final Message message, final Throwable thrown) {
        // Implementation note: this method is tuned for performance. MODIFY WITH CARE!

        final RingBufferLogEventTranslator translator = getCachedTranslator();
        initTranslator(translator, fqcn, level, marker, message, thrown);
        initTranslatorThreadValues(translator);
        publish(translator);
    }

10.同理，会有消费逻辑, 由disruptor执行;

log4j2的异步模式表现了绝对的性能优势，优势主要得益于Disruptor框架的使用 LMAX Disruptor technology. Asynchronous Loggers internally use the Disruptor, a lock-free inter-thread communication library, instead of queues, resulting in higher throughput and lower latency.

即一个无锁的线程间通信库代替了原来的队列

调用操作，当发布者将事件发送到RingBuffer时即调用最终调用：

7.log4j2 all async

1.不同日志组件的性能表现： 2.总结：

异步模式+Disruptor