slf4j绑定log4j2日志系统的过程（源码分析）

一、环境及介绍

slf4j和log4j2的介绍在文章http://blog.csdn.net/honghailiang888/article/details/52681777进行过介绍，源码分析版本log4j-api-2.2.jar、log4j-core-2.2.jar、log4j-slf4j-impl-2.2.jar、slf4j-api-1.7.21.jar

二、从使用入手

/**
 * @author HHL
 * 
 * @date 2016年9月27日
 * 
 *       日志工具类类，采用slf4j方式
 */
public class LogUtil {
	// test日志
	public static Logger testLog = LoggerFactory.getLogger("test_logger");
	
	public static boolean isPrintStackTrace = true;
	
	// 记录test错误日志信息
	public static void testLogError(String errorMessage, Exception ex) {
		if (testLog != null) {
			testLog.error(errorMessage);
		}

		if (isPrintStackTrace && ex != null && testLog != null) {
			testLog.error(ex.getMessage(), ex);
		}
	}

	public static void printInfoLog(Class<?> cla, String message) {
		LoggerFactory.getLogger(cla).info(message);
	}
}

配置文件内容log4j2.xml

 

<?xml version="1.0" encoding="UTF-8"?>
<Configuration status="WARN">
  <Appenders>
    <Console name="Console" target="SYSTEM_OUT">
      <PatternLayout pattern="%d{YYYY-MM-dd HH:mm:ss.SSS} [%t] %-5level %l %msg%n"/>
    </Console>
    
    <RollingFile name="test_logger" filename="${sys:catalina.home}/logs/test_logger.log"
      filepattern="${sys:catalina.home}/logs/test_logger.%d{yyyy-MM-dd-HH}.log">
  	<PatternLayout pattern="%d{YYYY-MM-dd HH:mm:ss.SSS} %5p [%t] %c(%F:%L) - %msg%n" />
      <Policies>
      	<!-- 文件大小配置 -->
        <SizeBasedTriggeringPolicy size="100 KB"/>
      </Policies>	
       <!-- 共存log文件数量 -->
       <DefaultRolloverStrategy max="20"/>
    </RollingFile>
    
  </Appenders>
  
  <Loggers>
    <Root level="info">
      <AppenderRef ref="Console"/>
    </Root>
    <!-- springMVC log配置 -->
    <Logger name="org.springframework.web" level="info" additivity="false">
      <AppenderRef ref="Console"/>
    </Logger>
    <!-- mybatis log配置 -->
    <Logger name="com.mango.mapper" level="trace" additivity="false">
      <AppenderRef ref="Console"/>
    </Logger>
    <!-- log文件配置 -->
    <Logger name="test_logger" level="info" additivity="true">
      <AppenderRef ref="test_logger"/>
    </Logger>
  </Loggers>
</Configuration>

 

 

 

 

 

 

三、源码分析

1.从第一句入手

 

public static Logger testLog = LoggerFactory.getLogger("test_logger");

 

 

 

 

 

 

 /**
     * Return a logger named according to the name parameter using the
     * statically bound {@link ILoggerFactory} instance.
     * 
     * @param name
     *            The name of the logger.
     * @return logger
     */
    public static Logger getLogger(String name) {
        ILoggerFactory iLoggerFactory = getILoggerFactory();
        return iLoggerFactory.getLogger(name);
    }

 

/**
     * Return the {@link ILoggerFactory} instance in use.
     * <p/>
     * <p/>
     * ILoggerFactory instance is bound with this class at compile time.
     * 
     * @return the ILoggerFactory instance in use
     */
    public static ILoggerFactory getILoggerFactory() {
        if (INITIALIZATION_STATE == UNINITIALIZED) {
            synchronized (LoggerFactory.class) {
                if (INITIALIZATION_STATE == UNINITIALIZED) {
                    INITIALIZATION_STATE = ONGOING_INITIALIZATION;
                    performInitialization();
                }
            }
        }
        switch (INITIALIZATION_STATE) {
        case SUCCESSFUL_INITIALIZATION:
            return StaticLoggerBinder.getSingleton().getLoggerFactory();
        case NOP_FALLBACK_INITIALIZATION:
            return NOP_FALLBACK_FACTORY;
        case FAILED_INITIALIZATION:
            throw new IllegalStateException(UNSUCCESSFUL_INIT_MSG);
        case ONGOING_INITIALIZATION:
            // support re-entrant behavior.
            // See also http://jira.qos.ch/browse/SLF4J-97
            return SUBST_FACTORY;
        }
        throw new IllegalStateException("Unreachable code");
    }

其中初次bind的日志系统就在上述performInitialization()中

private final static void performInitialization() {
        bind();
        if (INITIALIZATION_STATE == SUCCESSFUL_INITIALIZATION) {
            versionSanityCheck();
        }
    }

直接看bind()函数：

private final static void bind() {
        try {
            Set<URL> staticLoggerBinderPathSet = null;
            // skip check under android, see also
            // http://jira.qos.ch/browse/SLF4J-328
            if (!isAndroid()) {
                staticLoggerBinderPathSet = findPossibleStaticLoggerBinderPathSet();
                reportMultipleBindingAmbiguity(staticLoggerBinderPathSet);
            }
            // the next line does the binding
            StaticLoggerBinder.getSingleton();
            INITIALIZATION_STATE = SUCCESSFUL_INITIALIZATION;
            reportActualBinding(staticLoggerBinderPathSet);
            fixSubstituteLoggers();
            replayEvents();
            // release all resources in SUBST_FACTORY
            SUBST_FACTORY.clear();
        } catch (NoClassDefFoundError ncde) {
            String msg = ncde.getMessage();
            if (messageContainsOrgSlf4jImplStaticLoggerBinder(msg)) {
                INITIALIZATION_STATE = NOP_FALLBACK_INITIALIZATION;
                Util.report("Failed to load class \"org.slf4j.impl.StaticLoggerBinder\".");
                Util.report("Defaulting to no-operation (NOP) logger implementation");
                Util.report("See " + NO_STATICLOGGERBINDER_URL + " for further details.");
            } else {
                failedBinding(ncde);
                throw ncde;
            }
        } catch (java.lang.NoSuchMethodError nsme) {
            String msg = nsme.getMessage();
            if (msg != null && msg.contains("org.slf4j.impl.StaticLoggerBinder.getSingleton()")) {
                INITIALIZATION_STATE = FAILED_INITIALIZATION;
                Util.report("slf4j-api 1.6.x (or later) is incompatible with this binding.");
                Util.report("Your binding is version 1.5.5 or earlier.");
                Util.report("Upgrade your binding to version 1.6.x.");
            }
            throw nsme;
        } catch (Exception e) {
            failedBinding(e);
            throw new IllegalStateException("Unexpected initialization failure", e);
        }
    }

findPossibleStaticLoggerBinderPathSet()发现可能的binder路径，从类路径中寻找org/slf4j/impl/StaticLoggerBinder.class类：LoggerFactory.java

// We need to use the name of the StaticLoggerBinder class, but we can't
    // reference
    // the class itself.
    private static String STATIC_LOGGER_BINDER_PATH = "org/slf4j/impl/StaticLoggerBinder.class";

    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 = paths.nextElement();
                staticLoggerBinderPathSet.add(path);
            }
        } catch (IOException ioe) {
            Util.report("Error getting resources from path", ioe);
        }
        return staticLoggerBinderPathSet;
    }

其中获取到的path为jar:file:/D:/software/Server/Tomcat/apache-tomcat-7.0.30/webapps/ETeam/WEB-INF/lib/log4j-slf4j-impl-2.2.jar!/org/slf4j/impl/StaticLoggerBinder.class，如果为多个（会记录会发出警告 reportMultipleBindingAmbiguity(staticLoggerBinderPathSet);），则会随机（

SLF4J 会在编译时会绑定import org.slf4j.impl.StaticLoggerBinder; 该类里面实现对具体日志方案的绑定接入。任何一种基于slf4j 的实现都要有一个这个类。如：

org.slf4j.slf4j-log4j12-1.5.6: 提供对 log4j 的一种适配实现。

Org.slf4j.slf4j-simple-1.5.6: 是一种 simple 实现，会将 log 直接打到控制台。

……

那么这个地方就要注意了：如果有任意两个实现slf4j 的包同时出现，那就有可能酿就悲剧，你可能会发现日志不见了、或都打到控制台了。原因是这两个jar 包里都有各自的org.slf4j.impl.StaticLoggerBinder ，编译时候绑定的是哪个是不确定的（根据类加载原理，一般只会加载一个，且是顺序加载，因此执行的时候只会选择一个）。这个地方要特别注意！！出现过几次因为这个导致日志错乱的问题。

）选取一个bind（多个时会记录选择的哪个reportActualBinding(staticLoggerBinderPathSet);），但这里只有一个，因此只会选择一个。

总结，其实这里获取StaticLoggerBinder类的路径只是用来记录用，使用哪一个在编译时期就已经决定了(log4j-slf4j-impl-2.2.jar包起了桥接的作用)。这个时候就和log4j2关联上了。获得的loggerFactory就是

 

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

 

 

 

 

 

 

2、看Log4jLoggerFactory.java中的getLogger是继承的AbstractLoggerAdapter类中的

 

@Override
    public L getLogger(final String name) {
        final LoggerContext context = getContext();   //获取logger环境
        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);  根据名字获取logger
    }

 

 

 

 

 

 

看getContext()干了什么

 

@Override
    protected LoggerContext getContext() {
        final Class<?> anchor = ReflectionUtil.getCallerClass(FQCN, PACKAGE); 获取调用类
        return anchor == null ? LogManager.getContext() : getContext(ReflectionUtil.getCallerClass(anchor));
    }

 

 

 

 

 

 

最终调用到了LogManager.java中，彻底进入log4j2

/**
     * Gets the {@link LoggerContext} associated with the given caller class.
     *
     * @param callerClass the caller class
     * @return the LoggerContext for the calling class
     */
    protected LoggerContext getContext(final Class<?> callerClass) {
        ClassLoader cl = null;
        if (callerClass != null) {
            cl = callerClass.getClassLoader();
        }
        if (cl == null) {
            cl = LoaderUtil.getThreadContextClassLoader();
        }
        return LogManager.getContext(cl, false);
    }

 

public static LoggerContext getContext(final ClassLoader loader, final boolean currentContext) {
        return factory.getContext(FQCN, loader, null, currentContext);
    }

 

Log4jContextFactory.java

/**
     * Loads the LoggerContext using the ContextSelector.
     * @param fqcn The fully qualified class name of the caller.
     * @param loader The ClassLoader to use or null.
     * @param currentContext If true returns the current Context, if false returns the Context appropriate
     * for the caller if a more appropriate Context can be determined.
     * @param externalContext An external context (such as a ServletContext) to be associated with the LoggerContext.
     * @return The LoggerContext.
     */
    @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();           //初始获取，会解析配置文件log4j2.xml
        }
        return ctx;
    }

 

LoggerContext.java

@Override
    public void start() {
        LOGGER.debug("Starting LoggerContext[name={}, {}]...", getName(), this);
        if (configLock.tryLock()) {
            try {
                if (this.isInitialized() || this.isStopped()) {
                    this.setStarting();
                    reconfigure();       //解析配置文件
                    if (this.config.isShutdownHookEnabled()) {
                        setUpShutdownHook();
                    }
                    this.setStarted();
                }
            } finally {
                configLock.unlock();
            }
        }
        LOGGER.debug("LoggerContext[name={}, {}] started OK.", getName(), this);
    }

 

 

/**
     * Reconfigure the context.
     */
    public synchronized void reconfigure() {
        final ClassLoader cl = ClassLoader.class.isInstance(externalContext) ? (ClassLoader) externalContext : null;
        LOGGER.debug("Reconfiguration started for context[name={}] at {} ({}) with optional ClassLoader: {}", name,
            configLocation, this, cl);
        final Configuration instance = ConfigurationFactory.getInstance().getConfiguration(name, configLocation, cl);
        setConfiguration(instance);
        /*
         * instance.start(); Configuration old = setConfiguration(instance);
         * updateLoggers(); if (old != null) { old.stop(); }
         */

        LOGGER.debug("Reconfiguration complete for context[name={}] at {} ({}) with optional ClassLoader: {}", name,
            configLocation, this, cl);
    }

 

 

 

 

 

 

直接看最终的

 

private Configuration getConfiguration(final boolean isTest, final String name) {
            final boolean named = name != null && name.length() > 0;
            final ClassLoader loader = LoaderUtil.getThreadContextClassLoader();
            for (final ConfigurationFactory factory : factories) {
                String configName;
                final String prefix = isTest ? TEST_PREFIX : DEFAULT_PREFIX;
                final String [] types = factory.getSupportedTypes();
                if (types == null) {
                    continue;
                }

                for (final String suffix : types) {
                    if (suffix.equals("*")) {
                        continue;
                    }
                    configName = named ? prefix + name + suffix : prefix + suffix;

                    final ConfigurationSource source = getInputFromResource(configName, loader);
                    if (source != null) {
                        return factory.getConfiguration(source);
                    }
                }
            }
            return null;
        }

</pre><pre class="java" name="code" code_snippet_id="1933544" snippet_file_name="blog_20161017_19_6401194">/**
     * File name prefix for test configurations.
     */
    protected static final String TEST_PREFIX = "log4j2-test";

    /**
     * File name prefix for standard configurations.
     */
    protected static final String DEFAULT_PREFIX = "log4j2";

slf4j和log4j2的结合就此出现，log输出也是用的log4j2的。

 

 

 

 

 

 

 

 

四、没有配置的情况下，默认的配置为

/**
 * The default configuration writes all output to the Console using the default logging level. You configure default
 * logging level by setting the system property "org.apache.logging.log4j.level" to a level name. If you do not
 * specify the property, Log4j uses the ERROR Level. Log Events will be printed using the basic formatting provided
 * by each Message.
 */
public class DefaultConfiguration extends AbstractConfiguration {

    private static final long serialVersionUID = 1L;

    /**
     * The name of the default configuration.
     */
    public static final String DEFAULT_NAME = "Default";
    /**
     * The System Property used to specify the logging level.
     */
    public static final String DEFAULT_LEVEL = "org.apache.logging.log4j.level";
    /**
     * The default Pattern used for the default Layout.
     */
    public static final String DEFAULT_PATTERN = "%d{HH:mm:ss.SSS} [%thread] %-5level %logger{36} - %msg%n";

    /**
     * Constructor to create the default configuration.
     */
    public DefaultConfiguration() {
        super(ConfigurationSource.NULL_SOURCE);
        
        setName(DEFAULT_NAME);
        final Layout<? extends Serializable> layout = PatternLayout.newBuilder()
            .withPattern(DEFAULT_PATTERN)
            .withConfiguration(this)
            .build();
        final Appender appender = ConsoleAppender.createDefaultAppenderForLayout(layout);
        appender.start();
        addAppender(appender);
        final LoggerConfig root = getRootLogger();
        root.addAppender(appender, null, null);

        final String levelName = PropertiesUtil.getProperties().getStringProperty(DEFAULT_LEVEL);
        final Level level = levelName != null && Level.valueOf(levelName) != null ?
            Level.valueOf(levelName) : Level.ERROR;
        root.setLevel(level);
    }

    @Override
    protected void doConfigure() {
    }
}

 

输出到console中，默认级别为error级别，也可以通过system property "org.apache.logging.log4j.level"配置级别