聊一下 Java 的日志系列二
log 初始化过程，首先是在启动类里会获取 logger1
private static final Log logger = LogFactory.getLog(SpringApplication.class);
然后是1
2
3public static Log getLog(Class clazz) throws LogConfigurationException {
return getFactory().getInstance(clazz);
}
继续下去是org.apache.commons.logging.impl.SLF4JLogFactory#getInstance(java.lang.Class)1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20public Log getInstance(Class clazz) throws LogConfigurationException {
return this.getInstance(clazz.getName());
}
public Log getInstance(String name) throws LogConfigurationException {
Log instance = (Log)this.loggerMap.get(name);
if (instance != null) {
return instance;
} else {
Logger slf4jLogger = LoggerFactory.getLogger(name);
Object newInstance;
if (slf4jLogger instanceof LocationAwareLogger) {
newInstance = new SLF4JLocationAwareLog((LocationAwareLogger)slf4jLogger);
} else {
newInstance = new SLF4JLog(slf4jLogger);
}
Log oldInstance = (Log)this.loggerMap.putIfAbsent(name, newInstance);
return (Log)(oldInstance == null ? newInstance : oldInstance);
}
}
然后再往下处理就是 LoggerFactory.getLogger(name); 了，跟普通的获取 logger 一样1
2
3
4public static Logger getLogger(String name) {
ILoggerFactory iLoggerFactory = getILoggerFactory();
return iLoggerFactory.getLogger(name);
}
继续下去会先判断是否已初始化1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23public 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");
}
第一次调用的话就会走到 org.slf4j.LoggerFactory#performInitialization 里面是先调用绑定，这也是 slf4j 门面模式的特点1
2
3
4
5
6private final static void performInitialization() {
bind();
if (INITIALIZATION_STATE == SUCCESSFUL_INITIALIZATION) {
versionSanityCheck();
}
}1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42private 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);
}
}
非安卓环境会进入第一个 if 逻辑，先要去找static_logger_binder1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22static 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;
}
上面的 STATIC_LOGGER_BINDER_PATH
就是 org/slf4j/impl/StaticLoggerBinder.class 如果找不到在外层方法就会抛出 NoSuchMethodError 错误，然后就是通过 StaticLoggerBinder.getSingleton(); 获取 StaticLoggerBinder 实例了1
2
3
4public static StaticLoggerBinder getSingleton() {
return SINGLETON;
}
private static StaticLoggerBinder SINGLETON = new StaticLoggerBinder();
比较重要的是这里的 static 代码块还有一个逻辑，就是下面这个初始化逻辑1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20static {
SINGLETON.init();
}
void init() {
try {
try {
new ContextInitializer(defaultLoggerContext).autoConfig();
} catch (JoranException je) {
Util.report("Failed to auto configure default logger context", je);
}
// logback-292
if (!StatusUtil.contextHasStatusListener(defaultLoggerContext)) {
StatusPrinter.printInCaseOfErrorsOrWarnings(defaultLoggerContext);
}
contextSelectorBinder.init(defaultLoggerContext, KEY);
initialized = true;
} catch (Exception t) { // see LOGBACK-1159
Util.report("Failed to instantiate [" + LoggerContext.class.getName() + "]", t);
}
}
上面的 defaultLoggerContext 也是通过静态代码块处理的1
private LoggerContext defaultLoggerContext = new LoggerContext();
然后是调用 ch.qos.logback.classic.util.ContextInitializer#autoConfig 方法1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22public void autoConfig() throws JoranException {
StatusListenerConfigHelper.installIfAsked(loggerContext);
URL url = findURLOfDefaultConfigurationFile(true);
if (url != null) {
configureByResource(url);
} else {
Configurator c = EnvUtil.loadFromServiceLoader(Configurator.class);
if (c != null) {
try {
c.setContext(loggerContext);
c.configure(loggerContext);
} catch (Exception e) {
throw new LogbackException(String.format("Failed to initialize Configurator: %s using ServiceLoader", c != null ? c.getClass()
.getCanonicalName() : "null"), e);
}
} else {
BasicConfigurator basicConfigurator = new BasicConfigurator();
basicConfigurator.setContext(loggerContext);
basicConfigurator.configure(loggerContext);
}
}
}
前面会先查找配置文件路径URL url = findURLOfDefaultConfigurationFile(true); 还是调用这个类内的 ch.qos.logback.classic.util.ContextInitializer#findURLOfDefaultConfigurationFile 方法1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19public URL findURLOfDefaultConfigurationFile(boolean updateStatus) {
ClassLoader myClassLoader = Loader.getClassLoaderOfObject(this);
URL url = findConfigFileURLFromSystemProperties(myClassLoader, updateStatus);
if (url != null) {
return url;
}
url = getResource(TEST_AUTOCONFIG_FILE, myClassLoader, updateStatus);
if (url != null) {
return url;
}
url = getResource(GROOVY_AUTOCONFIG_FILE, myClassLoader, updateStatus);
if (url != null) {
return url;
}
return getResource(AUTOCONFIG_FILE, myClassLoader, updateStatus);
}
才发现原来这里也是硬编码了文件名1
2
3
4
5
6
7public class ContextInitializer {
final public static String GROOVY_AUTOCONFIG_FILE = "logback.groovy";
final public static String AUTOCONFIG_FILE = "logback.xml";
final public static String TEST_AUTOCONFIG_FILE = "logback-test.xml";
final public static String CONFIG_FILE_PROPERTY = "logback.configurationFile";
如果不为空就调用了ch.qos.logback.classic.util.ContextInitializer#configureByResource 这边是根据后缀判断处理方法1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22public void configureByResource(URL url) throws JoranException {
if (url == null) {
throw new IllegalArgumentException("URL argument cannot be null");
}
final String urlString = url.toString();
if (urlString.endsWith("groovy")) {
if (EnvUtil.isGroovyAvailable()) {
// avoid directly referring to GafferConfigurator so as to avoid
// loading groovy.lang.GroovyObject . See also http://jira.qos.ch/browse/LBCLASSIC-214
GafferUtil.runGafferConfiguratorOn(loggerContext, this, url);
} else {
StatusManager sm = loggerContext.getStatusManager();
sm.add(new ErrorStatus("Groovy classes are not available on the class path. ABORTING INITIALIZATION.", loggerContext));
}
} else if (urlString.endsWith("xml")) {
JoranConfigurator configurator = new JoranConfigurator();
configurator.setContext(loggerContext);
configurator.doConfigure(url);
} else {
throw new LogbackException("Unexpected filename extension of file [" + url.toString() + "]. Should be either .groovy or .xml");
}
}
因为我们找到的是 logback.xml，所以走的是ch.qos.logback.classic.joran.JoranConfigurator ，
然后调用了ch.qos.logback.core.joran.GenericConfigurator#doConfigure(java.net.URL)
这个 GenericConfigurator 是 JoranConfigurator 的父类1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27public final void doConfigure(URL url) throws JoranException {
InputStream in = null;
try {
informContextOfURLUsedForConfiguration(getContext(), url);
URLConnection urlConnection = url.openConnection();
// per http://jira.qos.ch/browse/LBCORE-105
// per http://jira.qos.ch/browse/LBCORE-127
urlConnection.setUseCaches(false);
in = urlConnection.getInputStream();
doConfigure(in, url.toExternalForm());
} catch (IOException ioe) {
String errMsg = "Could not open URL [" + url + "].";
addError(errMsg, ioe);
throw new JoranException(errMsg, ioe);
} finally {
if (in != null) {
try {
in.close();
} catch (IOException ioe) {
String errMsg = "Could not close input stream";
addError(errMsg, ioe);
throw new JoranException(errMsg, ioe);
}
}
}
}
然后继续调用ch.qos.logback.core.joran.GenericConfigurator#doConfigure(java.io.InputStream, java.lang.String) 处理具体的内容，前面处理了内容获取，因为如果是走的 url 文件就需要从网络获取文件流，1
2
3
4
5public final void doConfigure(InputStream inputStream, String systemId) throws JoranException {
InputSource inputSource = new InputSource(inputStream);
inputSource.setSystemId(systemId);
doConfigure(inputSource);
}
而实际的处理 xml 内容则是在ch.qos.logback.core.joran.GenericConfigurator#doConfigure(org.xml.sax.InputSource)1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16public final void doConfigure(final InputSource inputSource) throws JoranException {
long threshold = System.currentTimeMillis();
// if (!ConfigurationWatchListUtil.wasConfigurationWatchListReset(context)) {
// informContextOfURLUsedForConfiguration(getContext(), null);
// }
SaxEventRecorder recorder = new SaxEventRecorder(context);
recorder.recordEvents(inputSource);
doConfigure(recorder.saxEventList);
// no exceptions a this level
StatusUtil statusUtil = new StatusUtil(context);
if (statusUtil.noXMLParsingErrorsOccurred(threshold)) {
addInfo("Registering current configuration as safe fallback point");
registerSafeConfiguration(recorder.saxEventList);
}
}
需要解析 xml 了，先是调用 buildInterpreter 构建了 Interpreter1
2
3
4
5
6
7public void doConfigure(final List<SaxEvent> eventList) throws JoranException {
buildInterpreter();
// disallow simultaneous configurations of the same context
synchronized (context.getConfigurationLock()) {
interpreter.getEventPlayer().play(eventList);
}
}
build 里还有一些逻辑，就是匹配后面要处理的规则集，就是要确认那些标签要处理1
2
3
4
5
6
7
8
9protected void buildInterpreter() {
RuleStore rs = new SimpleRuleStore(context);
addInstanceRules(rs);
this.interpreter = new Interpreter(context, rs, initialElementPath());
InterpretationContext interpretationContext = interpreter.getInterpretationContext();
interpretationContext.setContext(context);
addImplicitRules(interpreter);
addDefaultNestedComponentRegistryRules(interpretationContext.getDefaultNestedComponentRegistry());
}
第一步就是先 new 一个 ch.qos.logback.core.joran.spi.SimpleRuleStore 然后调用了 ch.qos.logback.classic.joran.JoranConfigurator#addInstanceRules 来添加规则，就是下面的，可以看到对于 logger,appender 这些的配置，其中前面点的父类也又一些规则 ,ch.qos.logback.core.joran.JoranConfiguratorBase 逻辑类似就不展开了，这里的规则就对应了后面的各种 Action，就是对应的处理逻辑1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42public void addInstanceRules(RuleStore rs) {
// parent rules already added
super.addInstanceRules(rs);
rs.addRule(new ElementSelector("configuration"), new ConfigurationAction());
rs.addRule(new ElementSelector("configuration/contextName"), new ContextNameAction());
rs.addRule(new ElementSelector("configuration/contextListener"), new LoggerContextListenerAction());
rs.addRule(new ElementSelector("configuration/insertFromJNDI"), new InsertFromJNDIAction());
rs.addRule(new ElementSelector("configuration/evaluator"), new EvaluatorAction());
rs.addRule(new ElementSelector("configuration/appender/sift"), new SiftAction());
rs.addRule(new ElementSelector("configuration/appender/sift/*"), new NOPAction());
rs.addRule(new ElementSelector("configuration/logger"), new LoggerAction());
rs.addRule(new ElementSelector("configuration/logger/level"), new LevelAction());
rs.addRule(new ElementSelector("configuration/root"), new RootLoggerAction());
rs.addRule(new ElementSelector("configuration/root/level"), new LevelAction());
rs.addRule(new ElementSelector("configuration/logger/appender-ref"), new AppenderRefAction<ILoggingEvent>());
rs.addRule(new ElementSelector("configuration/root/appender-ref"), new AppenderRefAction<ILoggingEvent>());
// add if-then-else support
rs.addRule(new ElementSelector("*/if"), new IfAction());
rs.addRule(new ElementSelector("*/if/then"), new ThenAction());
rs.addRule(new ElementSelector("*/if/then/*"), new NOPAction());
rs.addRule(new ElementSelector("*/if/else"), new ElseAction());
rs.addRule(new ElementSelector("*/if/else/*"), new NOPAction());
// add jmxConfigurator only if we have JMX available.
// If running under JDK 1.4 (retrotranslateed logback) then we
// might not have JMX.
if (PlatformInfo.hasJMXObjectName()) {
rs.addRule(new ElementSelector("configuration/jmxConfigurator"), new JMXConfiguratorAction());
}
rs.addRule(new ElementSelector("configuration/include"), new IncludeAction());
rs.addRule(new ElementSelector("configuration/consolePlugin"), new ConsolePluginAction());
rs.addRule(new ElementSelector("configuration/receiver"), new ReceiverAction());
}
然后调用了 interpreter 的 eventPlayer 处理 xml 的各个标签1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24public void play(List<SaxEvent> aSaxEventList) {
eventList = aSaxEventList;
SaxEvent se;
for (currentIndex = 0; currentIndex < eventList.size(); currentIndex++) {
se = eventList.get(currentIndex);
if (se instanceof StartEvent) {
interpreter.startElement((StartEvent) se);
// invoke fireInPlay after startElement processing
interpreter.getInterpretationContext().fireInPlay(se);
}
if (se instanceof BodyEvent) {
// invoke fireInPlay before characters processing
interpreter.getInterpretationContext().fireInPlay(se);
interpreter.characters((BodyEvent) se);
}
if (se instanceof EndEvent) {
// invoke fireInPlay before endElement processing
interpreter.getInterpretationContext().fireInPlay(se);
interpreter.endElement((EndEvent) se);
}
}
}
接下去就在 startElement 中调用会先获取 getApplicableActionList 适配的 Action， callBeginAction1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22private void startElement(String namespaceURI, String localName, String qName, Attributes atts) {
String tagName = getTagName(localName, qName);
elementPath.push(tagName);
if (skip != null) {
// every startElement pushes an action list
pushEmptyActionList();
return;
}
List<Action> applicableActionList = getApplicableActionList(elementPath, atts);
if (applicableActionList != null) {
actionListStack.add(applicableActionList);
callBeginAction(applicableActionList, tagName, atts);
} else {
// every startElement pushes an action list
pushEmptyActionList();
String errMsg = "no applicable action for [" + tagName + "], current ElementPath is [" + elementPath + "]";
cai.addError(errMsg);
}
}
里面就是用了 ruleStore 来判断是否适配，并且取出对应的 Action1
2
3
4
5
6
7
8
9
10List<Action> getApplicableActionList(ElementPath elementPath, Attributes attributes) {
List<Action> applicableActionList = ruleStore.matchActions(elementPath);
// logger.debug("set of applicable patterns: " + applicableActionList);
if (applicableActionList == null) {
applicableActionList = lookupImplicitAction(elementPath, attributes, interpretationContext);
}
return applicableActionList;
}
比如我这边往下处理，通过规则匹配拿到了 LoggerAction, 然后调用 Action.begin 方法1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21void callBeginAction(List<Action> applicableActionList, String tagName, Attributes atts) {
if (applicableActionList == null) {
return;
}
Iterator<Action> i = applicableActionList.iterator();
while (i.hasNext()) {
Action action = (Action) i.next();
// now let us invoke the action. We catch and report any eventual
// exceptions
try {
action.begin(interpretationContext, tagName, atts);
} catch (ActionException e) {
skip = elementPath.duplicate();
cai.addError("ActionException in Action for tag [" + tagName + "]", e);
} catch (RuntimeException e) {
skip = elementPath.duplicate();
cai.addError("RuntimeException in Action for tag [" + tagName + "]", e);
}
}
}
就是下面这个1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40public void begin(InterpretationContext ec, String name, Attributes attributes) {
// Let us forget about previous errors (in this object)
inError = false;
logger = null;
LoggerContext loggerContext = (LoggerContext) this.context;
String loggerName = ec.subst(attributes.getValue(NAME_ATTRIBUTE));
if (OptionHelper.isEmpty(loggerName)) {
inError = true;
String aroundLine = getLineColStr(ec);
String errorMsg = "No 'name' attribute in element " + name + ", around " + aroundLine;
addError(errorMsg);
return;
}
logger = loggerContext.getLogger(loggerName);
String levelStr = ec.subst(attributes.getValue(LEVEL_ATTRIBUTE));
if (!OptionHelper.isEmpty(levelStr)) {
if (ActionConst.INHERITED.equalsIgnoreCase(levelStr) || ActionConst.NULL.equalsIgnoreCase(levelStr)) {
addInfo("Setting level of logger [" + loggerName + "] to null, i.e. INHERITED");
logger.setLevel(null);
} else {
Level level = Level.toLevel(levelStr);
addInfo("Setting level of logger [" + loggerName + "] to " + level);
logger.setLevel(level);
}
}
String additivityStr = ec.subst(attributes.getValue(ActionConst.ADDITIVITY_ATTRIBUTE));
if (!OptionHelper.isEmpty(additivityStr)) {
boolean additive = OptionHelper.toBoolean(additivityStr, true);
addInfo("Setting additivity of logger [" + loggerName + "] to " + additive);
logger.setAdditive(additive);
}
ec.pushObject(logger);
}
这里就会处理 logger 获取逻辑1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49public final Logger getLogger(final String name) {
if (name == null) {
throw new IllegalArgumentException("name argument cannot be null");
}
// if we are asking for the root logger, then let us return it without
// wasting time
if (Logger.ROOT_LOGGER_NAME.equalsIgnoreCase(name)) {
return root;
}
int i = 0;
Logger logger = root;
// check if the desired logger exists, if it does, return it
// without further ado.
Logger childLogger = (Logger) loggerCache.get(name);
// if we have the child, then let us return it without wasting time
if (childLogger != null) {
return childLogger;
}
// if the desired logger does not exist, them create all the loggers
// in between as well (if they don't already exist)
String childName;
while (true) {
int h = LoggerNameUtil.getSeparatorIndexOf(name, i);
if (h == -1) {
childName = name;
} else {
childName = name.substring(0, h);
}
// move i left of the last point
i = h + 1;
synchronized (logger) {
childLogger = logger.getChildByName(childName);
if (childLogger == null) {
childLogger = logger.createChildByName(childName);
loggerCache.put(childName, childLogger);
incSize();
}
}
logger = childLogger;
if (h == -1) {
return childLogger;
}
}
}
如果从 loggerCache 中能取到就直接获取，如果不能就会去创建