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过滤器会异步执行，可负责较为耗时的细致过滤工作