log4j2 LoggerFactory.getLogger的背后

时间: 2016-02-28 标签: java, log4j2, slf4j

1. 引子

我们在java代码中使用Log4j2打印日志时，通常使用Logger LOGGER = LoggerFactory.getLogger(XX.class)这个语句来得到org.slf4j.Logger，这句代码背后包含了一系列的内容的，这里通过阅读源码，以异步Log4j2为例，大致了解下这句代码背后的来龙去脉。

2. 准备

使用到的一些jar包的版本如下pom文件中所示，这里简单列出几个主要的版本：

<dependency>
<groupId>org.slf4j</groupId>
<artifactId>slf4j-api</artifactId>
<version>1.7.12</version>
</dependency>
<dependency>
<groupId>org.apache.logging.log4j</groupId>
<artifactId>log4j-slf4j-impl</artifactId>
<version>2.3</version>
</dependency>
<!--
<dependency>
<groupId>org.slf4j</groupId>
<artifactId>slf4j-simple</artifactId>
<version>1.7.16</version>
</dependency>
-->
<dependency>
<groupId>org.apache.logging.log4j</groupId>
<artifactId>log4j-api</artifactId>
<version>2.3</version>
</dependency>
<dependency>
<groupId>org.apache.logging.log4j</groupId>
<artifactId>log4j-core</artifactId>
<version>2.3</version>
</dependency>

3. slf4j和Log4j2的桥接

Logger LOGGER = LoggerFactory.getLogger(XX.class)这句话中的Logger和LoggerFactory都是slf4j包中的，我们知道java支持的日志打印方式挺多的，slf4j只是相当于一个门面，背后的实际实现方式挺多，比如log4j, log4j2, logback，JDK 1.4 logging等。以log4j2为例，slf4j和log4j2是如何联系起来的呢，这里的关键点就是StaticLoggerBinder类。三个包的对应关系如下图所示，log4j-slf4j-impl就是起到桥接作用的。

slf4j-api <---> log4j-slf4j-impl <---> log4j-api

实现桥接的原理最简单来说是通过在加载类的路径下查找StaticLoggerBinder的实现来完成的。相关代码在LoggerFactory类中，如下：

private static String STATIC_LOGGER_BINDER_PATH = "org/slf4j/impl/StaticLoggerBinder.class";

private static Set<URL> findPossibleStaticLoggerBinderPathSet() {
// use Set instead of list in order to deal with bug #138
// LinkedHashSet appropriate here because it preserves insertion order during iteration
Set<URL> staticLoggerBinderPathSet = new LinkedHashSet<URL>();
try {
ClassLoader loggerFactoryClassLoader = LoggerFactory.class.getClassLoader();
Enumeration<URL> paths;
if (loggerFactoryClassLoader == null) {
paths = ClassLoader.getSystemResources(STATIC_LOGGER_BINDER_PATH);
} else {
paths = loggerFactoryClassLoader.getResources(STATIC_LOGGER_BINDER_PATH);
}
while (paths.hasMoreElements()) {
URL path = (URL) paths.nextElement();
staticLoggerBinderPathSet.add(path);
}
} catch (IOException ioe) {
Util.report("Error getting resources from path", ioe);
}
return staticLoggerBinderPathSet;
}

如果没有找到任何实现，则会提示下面的错误信息，然后默认使用NOPLoggerFactory(一个不做操作的实现)

SLF4J: Failed to load class "org.slf4j.impl.StaticLoggerBinder".
SLF4J: Defaulting to no-operation (NOP) logger implementation
SLF4J: See http://www.slf4j.org/codes.html#StaticLoggerBinder for further details.

如果找到多个实现，会打印warning信息，列出所有的实现。然后选择一个作为实现，具体选择哪个和JVM有关系。比如在pom配置文件中添加一个slf4j-simple实现的jar包，会打印出下面的信息，从下面信息中可以看出SLF4J选择了org.apache.logging.slf4j.Log4jLoggerFactory

SLF4J: Class path contains multiple SLF4J bindings.
SLF4J: Found binding in [jar:file:/Users/yindongyang/.m2/repository/org/apache/logging/log4j/log4j-slf4j-impl/2.3/log4j-slf4j-impl-2.3.jar!/org/slf4j/impl/StaticLoggerBinder.class]
SLF4J: Found binding in [jar:file:/Users/yindongyang/.m2/repository/org/slf4j/slf4j-simple/1.7.16/slf4j-simple-1.7.16.jar!/org/slf4j/impl/StaticLoggerBinder.class]
SLF4J: See http://www.slf4j.org/codes.html#multiple_bindings for an explanation.
SLF4J: Actual binding is of type [org.apache.logging.slf4j.Log4jLoggerFactory]

正常情况下只会有一个StaticLoggerBinder实现，StaticLoggerBinder是一个单例，通过StaticLoggerBinder.getSingleton().getLoggerFactory()可以获取得到ILoggerFactory，可参考LoggerFactory的getILoggerFactory函数。对于Log4j2来说，得到的ILoggerFactory实现类是Log4jLoggerFactory，而Log4jLoggerFactory继承自log4j-api包下面的AbstractLoggerAdapter。至此，slf4j-api就和log4j-api通过log4j-slf4j-impl桥接了起来，并且得到了Log4j2包的Log4jLoggerFactory。

4. LoggerContextFactory的获得

得到LoggerFactory后然后就是如何通过Log4jLoggerFactory获取org.slf4j.Logger对象，下面主要从Log4j2的异步AsyncLogger来梳理下流程。首先看AbstractLoggerAdapter中的如下代码：

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

从上面代码中可见第一步是需要获取LoggerContext，LoggerContext从LoggerContextFactory工厂类获取，而LoggerContextFactory工厂类是在LogManager中静态代码块部分初始化的，LoggerContextFactory可以有三个来源： * 通过系统属性来设置比如-Dlog4j2.loggerContextFactory * 通过查找jar包中的配置文件 * 使用默认的SimpleLoggerContextFactory。

下面主要看下我们用到的第二种，从LoggerManager中获取到的相关代码如下：

if (ProviderUtil.hasProviders()) {
for (final Provider provider : ProviderUtil.getProviders()) {
final Class<? extends LoggerContextFactory> factoryClass = provider.loadLoggerContextFactory();
if (factoryClass != null) {
try {
factories.put(provider.getPriority(), factoryClass.newInstance());
} catch (final Exception e) {
LOGGER.error("Unable to create class {} specified in {}", factoryClass.getName(),
provider.getUrl().toString(), e);
}
}
}

if (factories.isEmpty()) {
LOGGER.error("Log4j2 could not find a logging implementation. Please add log4j-core to the classpath. Using SimpleLogger to log to the console...");
factory = new SimpleLoggerContextFactory();
} else {
final StringBuilder sb = new StringBuilder("Multiple logging implementations found: \n");
for (final Map.Entry<Integer, LoggerContextFactory> entry : factories.entrySet()) {
sb.append("Factory: ").append(entry.getValue().getClass().getName());
sb.append(", Weighting: ").append(entry.getKey()).append('\n');
}
factory = factories.get(factories.lastKey());
sb.append("Using factory: ").append(factory.getClass().getName());
LOGGER.warn(sb.toString());

}
} else {

ProviderUtil主要是读取所有jar包目录下的log4j-provider.properties文件，例如log4j-core-2.3.jar包中包含"META-INF/log4j-provider.properties"文件，其内容如下：

LoggerContextFactory = org.apache.logging.log4j.core.impl.Log4jContextFactory
Log4jAPIVersion = 2.1.0
FactoryPriority= 10

如果有多个log4j-provider.properties就根据FactoryPriority来决定选取优先级最高的，一般应该只有一个。从上面可以看出这里用的LoggerContextFactory类是org.apache.logging.log4j.core.impl.Log4jContextFactory。例化Log4jContextFactory，

5. LogContext的获取

LogContext的工厂类Log4jContextFactory已经获取了，下面是从Log4jContextFactory得到LogContext的主要函数：

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

上面代码中有个selector，其获取代码如下：

public static final String LOG4J_CONTEXT_SELECTOR = "Log4jContextSelector";

private static ContextSelector createContextSelector() {
final String sel = PropertiesUtil.getProperties().getStringProperty(Constants.LOG4J_CONTEXT_SELECTOR);
if (sel != null) {
try {
return Loader.newCheckedInstanceOf(sel, ContextSelector.class);
} catch (final Exception ex) {
LOGGER.error("Unable to create context {}", sel, ex);
}
}
return new ClassLoaderContextSelector();
}

如果要使用Log4j2的异步logger,就可以在java启动时传入定义一个全局的property如下：

-DLog4jContextSelector=org.apache.logging.log4j.core.async.AsyncLoggerContextSelector

这个property我们通常在boot.ini中定义。 AsyncLoggerContextSelector返回LoggerContext：

private static final AsyncLoggerContext CONTEXT = new AsyncLoggerContext("AsyncLoggerContext@"
+ AsyncLoggerContext.class.hashCode());

@Override
public LoggerContext getContext(final String fqcn, final ClassLoader loader, final boolean currentContext) {
return CONTEXT;
}

至此获取LoggerContext完毕，配置了异步Logger的全局property的话得到的就是一个AsyncLoggerContext实例。

6. Logger获取

已经有了LoggerContext,然后就是根据LoggerContext获取Logger，继续回到AbstractLoggerAdapter中，会首先从一个HashMap判断在这个LoggerContext下是否已经存在同名的Logger，如果存在就直接取出。注意这地方用了一个WeakHashMap，大概因为很多Logger用完就不再需要了？谁能告知下准确原因。

protected final Map<LoggerContext, ConcurrentMap<String, L>> registry =
new WeakHashMap<LoggerContext, ConcurrentMap<String, L>>();
public ConcurrentMap<String, L> getLoggersInContext(final LoggerContext context) {
synchronized (registry) {
ConcurrentMap<String, L> loggers = registry.get(context);
if (loggers == null) {
loggers = new ConcurrentHashMap<String, L>();
registry.put(context, loggers);
}
return loggers;
}
}

如果WeakHashMap中没有取到的话就需要通过Log4jLoggerFactory创建一个，

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)，这里context就是前面获得到的AsyncLoggerContext，最终会通过下面代码获取一个AsyncLogger,Log4jLogger只是对AsyncLogger进行简单的封装。

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

7. AsyncLogger的工作方式

最后再看看AsyncLogger是如何打印logger的。AsyncLogger的异步操作是利用com.lmax.disruptor包来实现的。无论是error还是info，warn级别的打印，都会通过AsyncLogger中的logMessage函数进行操作。logMessage中调用disruptor.publishEvent(info.translator);添加到RingBuffer中。disruptor的初始化代码如下：

private static volatile Disruptor<RingBufferLogEvent> disruptor;

private static final ExecutorService executor = Executors
.newSingleThreadExecutor(new DaemonThreadFactory("AsyncLogger-"));

static {
initInfoForExecutorThread();
LOGGER.debug("AsyncLogger.ThreadNameStrategy={}", THREAD_NAME_STRATEGY);
final int ringBufferSize = calculateRingBufferSize();

final WaitStrategy waitStrategy = createWaitStrategy();
disruptor = new Disruptor<RingBufferLogEvent>(RingBufferLogEvent.FACTORY, ringBufferSize, executor,
ProducerType.MULTI, waitStrategy);
disruptor.handleExceptionsWith(getExceptionHandler());
disruptor.handleEventsWith(new RingBufferLogEventHandler());

LOGGER.debug("Starting AsyncLogger disruptor with ringbuffer size {}...", disruptor.getRingBuffer()
.getBufferSize());
disruptor.start();
}

disruptor中通过一个Executors.newSingleThreadExecutor得到的DaemonThreadFactory线程，不停取RingBuffer中的info.translator事件，然后执行RingBufferLogEventHandler中的onEvent方法，这个方法最终会执行到AsyncLogger中的actualAsyncLog函数上：

/**
* This method is called by the EventHandler that processes the
* RingBufferLogEvent in a separate thread.
*
* @param event the event to log
*/
public void actualAsyncLog(final RingBufferLogEvent event) {
final Map<Property, Boolean> properties = config.loggerConfig.getProperties();
event.mergePropertiesIntoContextMap(properties, config.config.getStrSubstitutor());
config.logEvent(event);
}

因此最终的写日志操作是通过config.logEvent(event);完成的，config的初始化是在有Log4jContextFactory得到Log4jContext后执行start方法中的reconfigure()方法时按照一定的默认规则读取配置文件，这部分对Log4j2和Log4j1应该是一样的，有兴趣的可以阅读源码ConfigurationFactory.java或者参考文档https://logging.apache.org/log4j/2.x/manual/configuration.html。

8. 总结

java中的日志打印方式多种多样，其实slf4j配合log4j是比较流行的一种方式，log4j背后的实现知识也涉及到方方面面。上面内容大体上以Log4j2中的AsyncLogger为例梳理了一下流程，以期能够窥一豹而见全身，中间不免有疏漏错误之处，欢迎指正。