Springboot log4j2过滤器appender级别

springboot log4j2过滤器总介绍

为log4j2配置appender级别的过滤器，这是log4j2日志打印中，顺序执行的最后一条过滤器，过滤器执行后，将进入appender，完成日志打印

源码分析

以输出一条debug日志为例

log.debug("this is a debug log.");

程序将调用org.apache.logging.log4j.spi.AbstractLogger#debug(java.lang.String)方法, 该方法会顺序调用以下方法

    @Override
    public void debug(final String message, final Object... params) {
        logIfEnabled(FQCN, Level.DEBUG, null, message, params);
    }

    @Override
    public void debug(final String message, final Object... params) {
        logIfEnabled(FQCN, Level.DEBUG, null, message, params);
    }

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

    //org.apache.logging.log4j.spi.AbstractLogger#logMessage(java.lang.String, org.apache.logging.log4j.Level, org.apache.logging.log4j.Marker, java.lang.String, java.lang.Object...)
    protected void logMessage(final String fqcn, final Level level, final Marker marker, final String message,
            final Object... params) {
        final Message msg = messageFactory.newMessage(message, params);
        logMessageSafely(fqcn, level, marker, msg, msg.getThrowable());
    }  

    @PerformanceSensitive
    // NOTE: This is a hot method. Current implementation compiles to 30 bytes of byte code.
    // This is within the 35 byte MaxInlineSize threshold. Modify with care!
    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);
        }
    }

    @PerformanceSensitive
    // NOTE: This is a hot method. Current implementation compiles to 29 bytes of byte code.
    // This is within the 35 byte MaxInlineSize threshold. Modify with care!
    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();
        }
    }

    @PerformanceSensitive
    // NOTE: This is a hot method. Current implementation compiles to 26 bytes of byte code.
    // This is within the 35 byte MaxInlineSize threshold. Modify with care!
    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);
        }
    }

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

    // org.apache.logging.log4j.core.config.AwaitCompletionReliabilityStrategy#log(org.apache.logging.log4j.util.Supplier<org.apache.logging.log4j.core.config.LoggerConfig>, java.lang.String, java.lang.String, org.apache.logging.log4j.Marker, org.apache.logging.log4j.Level, org.apache.logging.log4j.message.Message, java.lang.Throwable)
    @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();
        }
    }

    //org.apache.logging.log4j.core.config.LoggerConfig#log(java.lang.String, java.lang.String, org.apache.logging.log4j.Marker, org.apache.logging.log4j.Level, org.apache.logging.log4j.message.Message, java.lang.Throwable)
    @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);
        }
    }

    public void log(final LogEvent event) {
        if (!isFiltered(event)) {
            processLogEvent(event);
        }
    }

    private void processLogEvent(final LogEvent event) {
        event.setIncludeLocation(isIncludeLocation());
        callAppenders(event);
        logParent(event);
    }

    @PerformanceSensitive("allocation")
    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);
        }
    }

    public void callAppender(final LogEvent event) {
        if (shouldSkip(event)) {
            return;
        }
        callAppenderPreventRecursion(event);
    }

    private void callAppenderPreventRecursion(final LogEvent event) {
        try {
            recursive.set(this);
            callAppender0(event);
        } finally {
            recursive.set(null);
        }
    }

    private void callAppender0(final LogEvent event) {
        ensureAppenderStarted();
        if (!isFilteredByAppender(event)) {
            tryCallAppender(event);
        }
    }

    private boolean isFilteredByAppender(final LogEvent event) {
        return appender instanceof Filterable && ((Filterable) appender).isFiltered(event);
    }

    // org.apache.logging.log4j.core.filter.AbstractFilterable#isFiltered
    @Override
    public boolean isFiltered(final LogEvent event) {
        return filter != null && filter.filter(event) == Filter.Result.DENY;
    }

Appender级别过滤器配置

以下两种配置方式，最终效果等效，唯一区别就是生效时间不一致

配置文件方式

配置后，程序启动即生效

<?xml version="1.0" encoding="UTF-8"?>
<Configuration status="WARN">
    <Appenders>
        <Console name="Console" target="SYSTEM_OUT">
            <PatternLayout pattern="%d{HH:mm:ss.SSS} [%t] %-5level %logger{36} - %msg%n"/>
            <ThresholdFilter level="info" onMatch="ACCEPT" onMismatch="DENY"/>
        </Console>
    </Appenders>
    <Loggers>
        <Root level="debug">
            <AppenderRef ref="Console"/>
        </Root>
    </Loggers>
</Configuration>

在application.properties中添加

logging.config=classpath:log4j2.xml

代码配置方式

配置后，代码执行到该处时生效

    private Appender consoleAppender(@Qualifier("log4j-configuration") Configuration configuration) {
        final String name = "Console";
        configuration.getRootLogger().removeAppender(name); //程序已经有一个Console，所以先清除， 然后再添加含有过滤器的Appender
        Layout<String> layout = PatternLayout.newBuilder()
                .withPattern(layoutPattern).build();
        Filter filter = ThresholdFilter.createFilter(Level.INFO, Filter.Result.ACCEPT, Filter.Result.DENY);
        ConsoleAppender appender = ConsoleAppender.createAppender(layout, filter, ConsoleAppender.Target.SYSTEM_OUT, 
                name, false, false, true);
        appender.start();

        configuration.getRootLogger().addAppender(appender, null, null);
        return appender;
    }

    @Bean("log4j-configuration")
    public Configuration configuration() {
        final LoggerContext ctx = (LoggerContext) LogManager.getContext(false);
        Configuration configuration = ctx.getConfiguration();
        consoleAppender(configuration);
        return configuration;
    }

总结

除全局过滤器外，推荐使用该过滤器
在同步日志时，LoggerConfig级别过滤器、AppenderController级别过滤器以及Appender级别过滤器效率相差无几（多每个级别多八九行代码的区别）
在异步日志时，推荐使用全局过滤器配合Appender级别过滤器使用， 全局过滤器负责简单过滤，减少日志事件的生成，Appender过滤器会异步执行，可负责较为耗时的细致过滤工作