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"配置級別