java loggerlfactory,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文件中所示，这里简单列出几个主要的版本：

org.slf4j

slf4j-api

1.7.12

org.apache.logging.log4j

log4j-slf4j-impl

2.3

org.apache.logging.log4j

log4j-api

2.3

org.apache.logging.log4j

log4j-core

2.3

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 findPossibleStaticLoggerBinderPathSet() {

// use Set instead of list in order to deal with bug #138

// LinkedHashSet appropriate here because it preserves insertion order during iteration

Set staticLoggerBinderPathSet = new LinkedHashSet();

try {

ClassLoader loggerFactoryClassLoader = LoggerFactory.class.getClassLoader();

Enumeration 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 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 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> registry =

new WeakHashMap>();

public ConcurrentMap getLoggersInContext(final LoggerContext context) {

synchronized (registry) {

ConcurrentMap loggers = registry.get(context);

if (loggers == null) {

loggers = new ConcurrentHashMap();

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 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.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 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为例梳理了一下流程，以期能够窥一豹而见全身，中间不免有疏漏错误之处，欢迎指正。