logger(三)log4j2簡介及其實現原理

一、log4j2簡介

log4j2是log4j 1.x和logback的改進版，據說采用了一些新技術（無鎖異步、等等），使得日志的吞吐量、性能比log4j 1.x提高10倍，並解決了一些死鎖的bug，而且配置更加簡單靈活

maven配置

<!--log4j2核心包-->
<dependency>
    <groupId>org.apache.logging.log4j</groupId>
    <artifactId>log4j-api</artifactId>
    <version>2.9.1</version>
</dependency>
<dependency>
    <groupId>org.apache.logging.log4j</groupId>
    <artifactId>log4j-core</artifactId>
    <version>2.9.1</version>
</dependency>
<!-- Web項目需添加 -->
<dependency>
    <groupId>org.apache.logging.log4j</groupId>
    <artifactId>log4j-web</artifactId>
    <version>2.9.1</version>
</dependency>
<!--用於與slf4j保持橋接-->
<dependency>
    <groupId>org.apache.logging.log4j</groupId>
    <artifactId>log4j-slf4j-impl</artifactId>
    <version>2.9.1</version>
</dependency>
<!-- slf4j核心包-->
<dependency>
    <groupId>org.slf4j</groupId>
    <artifactId>slf4j-api</artifactId>
    <version>1.7.25</version>

也可以配置starter

<dependency>
    <groupId>org.springframework.boot</groupId>
    <artifactId>spring-boot-starter-log4j2</artifactId>
</dependency>

二、log4j2.xml配置

實現類在log4j2.xml配置文件中的標簽名。

<?xml version="1.0" encoding="UTF-8"?>
<!--日志級別以及優先級排序: OFF > FATAL > ERROR > WARN > INFO > DEBUG > TRACE > ALL -->
<!--Configuration后面的status，這個用於設置log4j2自身內部的信息輸出，可以不設置，當設置成trace時，你會看到log4j2內部各種詳細輸出-->
<!--monitorInterval：Log4j能夠自動檢測修改配置文件和重新配置本身，設置間隔秒數-->
<configuration status="WARN" monitorInterval="30">
    <properties>
        <property name="server.port"></property>
    </properties>

    <!--先定義所有的appender-->
    <appenders>
        <!--這個輸出控制台的配置-->
        <console name="Console" target="SYSTEM_OUT">
            <!--輸出日志的格式-->
            <PatternLayout pattern="%d{yyyy-MM-dd HH:mm:ss,SSS} [%thread] %p %m%n"/>
        </console>
        <!-- 這個會打印出所有的info及以下級別的信息 -->
        <RollingFile name="RollingFile" filePattern="/data/log/tomcat${sys:server.port}/catalina.%d{yyyy-MM-dd}.log">
            <!--控制台只輸出level及以上級別的信息（onMatch），其他的直接拒絕（onMismatch）-->
            <ThresholdFilter level="info" onMatch="ACCEPT" onMismatch="DENY"/>
            <PatternLayout pattern="%d{yyyy-MM-dd HH:mm:ss,SSS} [%thread] %p %m%n"/>
            <Policies>
                <TimeBasedTriggeringPolicy interval="1" modulate="true"/>
            </Policies>
            <DirectWriteRolloverStrategy/>
        </RollingFile>
    </appenders>
    <!--然后定義logger，只有定義了logger並引入的appender，appender才會生效-->
    <loggers>
        <!--過濾掉spring和mybatis的一些無用的DEBUG信息-->
        <logger name="org.springframework" level="INFO"></logger>
        <logger name="org.mybatis" level="INFO"></logger>
        <root level="INFO">
            <appender-ref ref="Console"/>
            <appender-ref ref="RollingFile"/>
        </root>
    </loggers>
</configuration>

簡單說Appender就是一個管道，定義了日志內容的去向(保存位置)。

配置一個或者多個Filter進行過濾


配置Layout來控制日志信息的輸出格式。

配置Policies以控制日志何時(When)進行滾動。

配置Strategy以控制日志如何(How)進行滾動。

簡單說了下配置項，具體可參考博客：https://www.imooc.com/article/78966

https://www.cnblogs.com/hafiz/p/6170702.html

三、log4j2其實現原理

首先介紹下log4j2中的幾個重要的概念

LoggerContext

 LoggerContext在Logging System中扮演了錨點的角色。根據情況的不同，一個應用可能同時存在於多個有效的LoggerContext中。在同一LoggerContext下，log system是互通的。如：Standalone Application、Web Applications、Java EE Applications、”Shared” Web Applications 和REST Service Containers，就是不同廣度范圍的log上下文環境。

Configuration

 每一個LoggerContext都有一個有效的Configuration。Configuration包含了所有的Appenders、上下文范圍內的過濾器、LoggerConfigs以及StrSubstitutor.的引用。在重配置期間，新與舊的Configuration將同時存在。當所有的Logger對象都被重定向到新的Configuration對象后，舊的Configuration對象將被停用和丟棄。

 Logger

Loggers 是通過調用LogManager.getLogger方法獲得的。Logger對象本身並不實行任何實際的動作。它只是擁有一個name 以及與一個LoggerConfig相關聯。它繼承了AbstractLogger類並實現了所需的方法。當Configuration改變時，Logger將會與另外的LoggerConfig相關聯，從而改變這個Logger的行為。

LoggerConfig

每個LoggerConfig和logger是對應的，獲取到一個logger，寫日志時其實是通過LoggerConfig來記日志的

1、獲取LoggerFactory

和logback一樣，slf4j委托具體實現框架的StaticLoggerBinder來返回一個ILoggerFactory，從而對接到具體實現框架上，我們看下這個類(省略了部分代碼)

public final class StaticLoggerBinder implements LoggerFactoryBinder {

    private static final StaticLoggerBinder SINGLETON = new StaticLoggerBinder();
    private final ILoggerFactory loggerFactory;

    /**
     * Private constructor to prevent instantiation
     */
    private StaticLoggerBinder() {
        loggerFactory = new Log4jLoggerFactory();
    }

    /**
     * Returns the singleton of this class.
     *
     * @return the StaticLoggerBinder singleton
     */
    public static StaticLoggerBinder getSingleton() {
        return SINGLETON;
    }

    /**
     * Returns the factory.
     * @return the factor.
     */
    @Override
    public ILoggerFactory getLoggerFactory() {
        return loggerFactory;
    }
}

可以看到

• 1、通過getSingleton()獲取該類的單例
• 2、通過構造函數新建了Log4jLoggerFactory實例，
• 3、通過getLoggerFactory()方法返回該實例

2、獲取logger

進入Log4jLoggerFactory類中查看getLogger()方法，發現是在AbstractLoggerAdapter類中

@Override
    public L getLogger(final String name) {
        final LoggerContext context = getContext();
        final ConcurrentMap<String, L> loggers = getLoggersInContext(context);
        final L logger = loggers.get(name);
        if (logger != null) {
            return logger;
        }
        loggers.putIfAbsent(name, newLogger(name, context));
        return loggers.get(name);
    }

1、通過getContext()得到LoggerContext實例

2、在context中查找是否已經有該logger，有就返回

3、如果沒有則調用newLogger(name, context)方法新建logger

Log4jLoggerFactory只有兩個方法，就是上面說的getContext()和newLogger(name, context)。下面分兩節分別講下這兩個方法

public class Log4jLoggerFactory extends AbstractLoggerAdapter<Logger> implements ILoggerFactory {

    private static final String FQCN = Log4jLoggerFactory.class.getName();
    private static final String PACKAGE = "org.slf4j";

    @Override
    protected Logger newLogger(final String name, final LoggerContext context) {
        final String key = Logger.ROOT_LOGGER_NAME.equals(name) ? LogManager.ROOT_LOGGER_NAME : name;
        return new Log4jLogger(context.getLogger(key), name);
    }

    @Override
    protected LoggerContext getContext() {
        final Class<?> anchor = StackLocatorUtil.getCallerClass(FQCN, PACKAGE);
        return anchor == null ? LogManager.getContext() : getContext(StackLocatorUtil.getCallerClass(anchor));
    }

}

2.1  getContext()

getContext()方法就是返回合適的loggerContext，進入LogManager.getContext()方法

public static LoggerContext getContext() {
        try {
            return factory.getContext(FQCN, null, null, true);
        } catch (final IllegalStateException ex) {
            LOGGER.warn(ex.getMessage() + " Using SimpleLogger");
            return new SimpleLoggerContextFactory().getContext(FQCN, null, null, true);
        }
    }

factory實在LoggerContext靜態代碼塊中初始化的，繼續進入factory.getContext(FQCN, null, null, true)方法中，進入實現類Log4jContextFactory中

@Override
    public LoggerContext getContext(final String fqcn, final ClassLoader loader, final Object externalContext,
                                    final boolean currentContext) {
        final LoggerContext ctx = selector.getContext(fqcn, loader, currentContext);
        if (externalContext != null && ctx.getExternalContext() == null) {
            ctx.setExternalContext(externalContext);
        }
        if (ctx.getState() == LifeCycle.State.INITIALIZED) {
            ctx.start();
        }
        return ctx;
    }

LoggerContext是從selector.getContext(fqcn, loader, currentContext)中獲取的，此時判斷ctx.getState()是否等於LifeCycle.State.INITIALIZED，第一次調用getlogger()時，會進入此方法，我們看下ctx.start();

public void start() {
        LOGGER.debug("Starting LoggerContext[name={}, {}]...", getName(), this);
        if (PropertiesUtil.getProperties().getBooleanProperty("log4j.LoggerContext.stacktrace.on.start", false)) {
            LOGGER.debug("Stack trace to locate invoker",
                    new Exception("Not a real error, showing stack trace to locate invoker"));
        }
        if (configLock.tryLock()) {
            try {
                if (this.isInitialized() || this.isStopped()) {
                    this.setStarting();
                    reconfigure(); if (this.configuration.isShutdownHookEnabled()) {
                        setUpShutdownHook();
                    }
                    this.setStarted();
                }
            } finally {
                configLock.unlock();
            }
        }
        LOGGER.debug("LoggerContext[name={}, {}] started OK.", getName(), this);
    }

進入reconfigure()方法

private void reconfigure(final URI configURI) {
        final ClassLoader cl = ClassLoader.class.isInstance(externalContext) ? (ClassLoader) externalContext : null;
        LOGGER.debug("Reconfiguration started for context[name={}] at URI {} ({}) with optional ClassLoader: {}",
                contextName, configURI, this, cl);
        final Configuration instance = ConfigurationFactory.getInstance().getConfiguration(this, contextName, configURI, cl);
        if (instance == null) {
            LOGGER.error("Reconfiguration failed: No configuration found for '{}' at '{}' in '{}'", contextName, configURI, cl);
        } else {
            setConfiguration(instance);
            /*
             * instance.start(); Configuration old = setConfiguration(instance); updateLoggers(); if (old != null) {
             * old.stop(); }
             */
            final String location = configuration == null ? "?" : String.valueOf(configuration.getConfigurationSource());
            LOGGER.debug("Reconfiguration complete for context[name={}] at URI {} ({}) with optional ClassLoader: {}",
                    contextName, location, this, cl);
        }
    }

我們的配置文件log4j2.xml就是該函數中實現的，ConfigurationFactory.getInstance().getConfiguration(this, contextName, configURI, cl)得到了配置文件，並解析成Configuration。進入setConfiguration(instance)方法，啟動當前的configuration，並啟動該配置下的所有appender，logger和root。

public Configuration setConfiguration(final Configuration config) {
        if (config == null) {
            LOGGER.error("No configuration found for context '{}'.", contextName);
            // No change, return the current configuration.
            return this.configuration;
        }
        configLock.lock();
        try {
            final Configuration prev = this.configuration;
            config.addListener(this);
            final ConcurrentMap<String, String> map = config.getComponent(Configuration.CONTEXT_PROPERTIES);
            try { // LOG4J2-719 network access may throw android.os.NetworkOnMainThreadException
                map.putIfAbsent("hostName", NetUtils.getLocalHostname());
            } catch (final Exception ex) {
                LOGGER.debug("Ignoring {}, setting hostName to 'unknown'", ex.toString());
                map.putIfAbsent("hostName", "unknown");
            }
            map.putIfAbsent("contextName", contextName);
            config.start(); this.configuration = config;
            updateLoggers();
            if (prev != null) {
                prev.removeListener(this);
                prev.stop();
            }
            firePropertyChangeEvent(new PropertyChangeEvent(this, PROPERTY_CONFIG, prev, config));
            try {
                Server.reregisterMBeansAfterReconfigure();
            } catch (final LinkageError | Exception e) {
                // LOG4J2-716: Android has no java.lang.management
                LOGGER.error("Could not reconfigure JMX", e);
            }
            // AsyncLoggers update their nanoClock when the configuration changes
            Log4jLogEvent.setNanoClock(configuration.getNanoClock());

            return prev;
        } finally {
            configLock.unlock();
        }
    }

2.2 newLogger(name, context)

protected Logger newLogger(final String name, final LoggerContext context) {
        final String key = Logger.ROOT_LOGGER_NAME.equals(name) ? LogManager.ROOT_LOGGER_NAME : name;
        return new Log4jLogger(context.getLogger(key), name);
    }

進入context.getLogger(key)方法

@Override
    public Logger getLogger(final String name) {
        return getLogger(name, null);
    }
@Override
public Logger getLogger(final String name, final MessageFactory messageFactory) {
        // Note: This is the only method where we add entries to the 'loggerRegistry' ivar.
        Logger logger = loggerRegistry.getLogger(name, messageFactory);
        if (logger != null) {
            AbstractLogger.checkMessageFactory(logger, messageFactory);
            return logger;
        }

        logger = newInstance(this, name, messageFactory);
        loggerRegistry.putIfAbsent(name, messageFactory, logger);
        return loggerRegistry.getLogger(name, messageFactory);
    }

進入newInstance(this, name, messageFactory)方法

protected Logger newInstance(final LoggerContext ctx, final String name, final MessageFactory messageFactory) {
        return new Logger(ctx, name, messageFactory);
    }

protected Logger(final LoggerContext context, final String name, final MessageFactory messageFactory) {
        super(name, messageFactory);
        this.context = context;
        privateConfig = new PrivateConfig(context.getConfiguration(), this);
    }

public PrivateConfig(final Configuration config, final Logger logger) {
            this.config = config;
            this.loggerConfig = config.getLoggerConfig(getName());
            this.loggerConfigLevel = this.loggerConfig.getLevel();
            this.intLevel = this.loggerConfigLevel.intLevel();
            this.logger = logger;
        }

public LoggerConfig getLoggerConfig(final String loggerName) {
        LoggerConfig loggerConfig = loggerConfigs.get(loggerName);
        if (loggerConfig != null) {
            return loggerConfig;
        }
        String substr = loggerName;
        while ((substr = NameUtil.getSubName(substr)) != null) {
            loggerConfig = loggerConfigs.get(substr);
            if (loggerConfig != null) {
                return loggerConfig;
            }
        }
        return root;
    }

可以看到首先從loggerConfigs也就是配置文件中配置的logger中獲取，如果獲取不到則循環遞歸name中"."之前的logger，如果還是獲取不到，則默認使用root的配置。

3、logger.info()

Log4jLogger.class

public void info(final String format) {
        logger.logIfEnabled(FQCN, Level.INFO, null, format);
    }

@Override
    public void logIfEnabled(final String fqcn, final Level level, final Marker marker, final String message) {
        if (isEnabled(level, marker, message)) {
            logMessage(fqcn, level, marker, message);
        }
    }

 public boolean isEnabled(final Level level, final Marker marker, final String message) {
        return privateConfig.filter(level, marker, message);
    }

protected void logMessage(final String fqcn, final Level level, final Marker marker, final String message) {
        final Message msg = messageFactory.newMessage(message);
        logMessageSafely(fqcn, level, marker, msg, msg.getThrowable());
    }

可以看到isEnabled()方法中用來通過配置的filter來判斷是否符合，如果符合則進入logMessage()方法

protected void logMessage(final String fqcn, final Level level, final Marker marker, final String message) {
        final Message msg = messageFactory.newMessage(message);
        logMessageSafely(fqcn, level, marker, msg, msg.getThrowable());
    }

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

private void logMessageTrackRecursion(final String fqcn,
                                          final Level level,
                                          final Marker marker,
                                          final Message msg,
                                          final Throwable throwable) {
        try {
            incrementRecursionDepth(); // LOG4J2-1518, LOG4J2-2031
 tryLogMessage(fqcn, level, marker, msg, throwable);
        } finally {
            decrementRecursionDepth();
        }
    }

private void tryLogMessage(final String fqcn,
                               final Level level,
                               final Marker marker,
                               final Message msg,
                               final Throwable throwable) {
        try {
            logMessage(fqcn, level, marker, msg, throwable);
        } catch (final Exception e) {
            // LOG4J2-1990 Log4j2 suppresses all exceptions that occur once application called the logger
            handleLogMessageException(e, fqcn, msg);
        }
    }

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);
    }

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) {
        loggerConfig.log(loggerName, fqcn, marker, level, data, t);
    }

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, LoggerConfigPredicate.ALL);
        } finally {
            // LOG4J2-1583 prevent scrambled logs when logging calls are nested (logging in toString())
            ReusableLogEventFactory.release(logEvent);
        }
    }

protected void log(final LogEvent event, final LoggerConfigPredicate predicate) {
        if (!isFiltered(event)) {
            processLogEvent(event, predicate);
        }
    }

private void processLogEvent(final LogEvent event, final LoggerConfigPredicate predicate) {
        event.setIncludeLocation(isIncludeLocation());
        if (predicate.allow(this)) {
            callAppenders(event);
        }
        logParent(event, predicate);
    }

protected void callAppenders(final LogEvent event) {
        final AppenderControl[] controls = appenders.get();
        //noinspection ForLoopReplaceableByForEach
        for (int i = 0; i < controls.length; i++) {
            controls[i].callAppender(event);
        }
    }

這時候終於到了appender的處理了，直接定位到RollingFileAppender類中

public void append(final LogEvent event) {
        getManager().checkRollover(event);
        super.append(event);
    }

private void tryAppend(final LogEvent event) {
        if (Constants.ENABLE_DIRECT_ENCODERS) {
            directEncodeEvent(event);
        } else {
            writeByteArrayToManager(event);
        }
    }
protected void directEncodeEvent(final LogEvent event) {
        getLayout().encode(event, manager);
        if (this.immediateFlush || event.isEndOfBatch()) {
            manager.flush();
        }
    }

這時候可以看到layout和encode的使用了

public void encode(final StringBuilder source, final ByteBufferDestination destination) {
        try {
            final Object[] threadLocalState = getThreadLocalState();
            final CharsetEncoder charsetEncoder = (CharsetEncoder) threadLocalState[0];
            final CharBuffer charBuffer = (CharBuffer) threadLocalState[1];
            final ByteBuffer byteBuffer = (ByteBuffer) threadLocalState[2];
            TextEncoderHelper.encodeText(charsetEncoder, charBuffer, byteBuffer, source, destination);
        } catch (final Exception ex) {
            logEncodeTextException(ex, source, destination);
            TextEncoderHelper.encodeTextFallBack(charset, source, destination);
        }
    }

最后寫日志。

 

四、通過代碼動態生成logger對象

public class LoggerHolder {


    //加個前綴防止配置的name正好是我們某個類名，導致使用的日志路徑使用了類名的路徑
    private static final String PREFIX = "logger_";

    /**
     * 支持生成寫大數據文件的logger
     *
     * @param name logger name
     * @return Logger
     */
    public static Logger getLogger(String name) {
        String loggerName = PREFIX + name;
        Log4jLoggerFactory loggerFactory = (Log4jLoggerFactory) LoggerFactory.getILoggerFactory();
        LoggerContext context = (LoggerContext) LogManager.getContext();
        //如果未加載過該logger,則新建一個
        if (loggerFactory.getLoggersInContext(context).get(loggerName) == null) {
            buildLogger(name);
        }
        //
        return loggerFactory.getLogger(loggerName);
    }

    /**
     * 包裝了Loggerfactory，和LoggerFactory.getLogger(T.class)功能一致
     *
     * @param clazz
     * @return
     */
    public static Logger getLogger(Class<?> clazz) {
        Log4jLoggerFactory loggerFactory = (Log4jLoggerFactory) LoggerFactory.getILoggerFactory();
        return loggerFactory.getLogger(clazz.getName());
    }

    /**
     * @param name logger name
     */
    private static void buildLogger(String name) {
        String loggerName = PREFIX + name;
        LoggerContext context = (LoggerContext) LogManager.getContext();
        Configuration configuration = context.getConfiguration();
        //配置PatternLayout輸出格式
        PatternLayout layout = PatternLayout.newBuilder()
                .withCharset(UTF_8)
                .withPattern("%msg%n")
                .build();
        //配置基於時間的滾動策略
        TimeBasedTriggeringPolicy policy = TimeBasedTriggeringPolicy.newBuilder()
                .withInterval(24)
                .build();
        //配置同類型日志策略
        DirectWriteRolloverStrategy strategy = DirectWriteRolloverStrategy.newBuilder()
                .withConfig(configuration)
                .build();
        //配置appender
        RollingFileAppender appender = RollingFileAppender.newBuilder()
                .setName(loggerName)
                .withFilePattern("/data/bigdata/" + name + "/" + name + ".%d{yyyyMMdd}.log")
                .setLayout(layout)
                .withPolicy(policy)
                .withStrategy(strategy)
                .withAppend(true)
                .build();
        //改變appender狀態
        appender.start();
        //新建logger
        LoggerConfig loggerConfig = new LoggerConfig(loggerName, Level.INFO, false);
        loggerConfig.addAppender(appender, Level.INFO, null);
        configuration.addLogger(loggerName, loggerConfig);
        context.updateLoggers();
    }
}