Logback源码分析
前言
logback是slf4j的实现，里面有三大组件功能：logger, marker, MDC ，这里只分析logger功能。分析源码不是目的只是手段，最终我们是要从中学习经验纳入自己体系当中，建议不要跳过前面几步，尽管前面几步很简单，非要跳过可以从 源码分析 开始看
maven依赖版本
<dependency>
<groupId>ch.qos.logback</groupId>
<artifactId>logback-classic</artifactId>
<version>1.2.11</version>
</dependency>
logback.xml主要元素组件
logback.xml是logback的配置文件，位于项目的classpath下，其主要元素有三个：root至多一个，appender 0到多个, logger 0到多个
使用者角度logback元素关系
从使用者即开发者层次来说，我把它分为四部分：
- 输入操作
- logger
- appender
- 输出操作
我们以以下logback.xml实例来说：
<configuration>
<appender name="FILE" class="ch.qos.logback.core.FileAppender">
<file>myApp.log</file>
<encoder>
<pattern>%date %level [%thread] %logger{10} [%file:%line] %msg%n</pattern>
</encoder>
</appender>
<appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">
<encoder>
<pattern>%date %level [%thread] %logger{10} [%file:%line] %msg%n</pattern>
</encoder>
</appender>
<logger name="com.logback.test1" level="debug">
<appender-ref ref="STDOUT" />
</logger>
<logger name="com.logback.test2">
<appender-ref ref="FILE" />
</logger>
<root level="debug">
<appender-ref ref="STDOUT" />
<appender-ref ref="FILE" />
</root>
</configuration>
其关系图如下：
可以看出如下几点：
- logger和appender是多对多关系，一个logger下可以关联多个appender，一个appender可以归属于多个logger
- 输入操作可以同时触发多个logger，也就可能有多个输出，调用logger.info/debug等方法时触发
- 输入操作是以全类名来筛选合适的logger，会依次往父类包查找，级别以自己为准，没有就继承父类级别，依次类推找到为止
实例说明
项目文件如下：
com.logback
|
------test1
| |
| ---Test1.java
------test2
| |
| ---Test2.java
------Tests.java
logback.xml和上面配置一样：
<configuration>
<appender name="FILE" class="ch.qos.logback.core.FileAppender">
<file>myApp.log</file>
<encoder>
<pattern>%date %level [%thread] %logger{10} [%file:%line] %msg%n</pattern>
</encoder>
</appender>
<appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">
<encoder>
<pattern>%date %level [%thread] %logger{10} [%file:%line] %msg%n</pattern>
</encoder>
</appender>
<logger name="com.logback.test1" level="debug">
<appender-ref ref="STDOUT" />
</logger>
<logger name="com.logback.test2">
<appender-ref ref="FILE" />
</logger>
<root level="debug">
<appender-ref ref="STDOUT" />
<appender-ref ref="FILE" />
</root>
</configuration>
Tests.java代码如下：
package com.logback;
import com.logback.test1.Test1;
import com.logback.test2.Test2;
import org.junit.Test;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
public class Tests {
@Test
public void test() {
Logger logger = LoggerFactory.getLogger(Tests.class);
Logger logger1 = LoggerFactory.getLogger(Test1.class);
Logger logger2 = LoggerFactory.getLogger(Test2.class);
logger.info("Tests");
logger1.info("Test1");
logger2.info("Test2");
}
}
我们看下控制台结果：
2022-09-15 15:08:06,273 INFO [main] c.l.Tests [Tests.java:27] Tests
2022-09-15 15:08:06,275 INFO [main] c.l.t.Test1 [Tests.java:28] Test1
2022-09-15 15:08:06,275 INFO [main] c.l.t.Test1 [Tests.java:28] Test1
2022-09-15 15:08:06,275 INFO [main] c.l.t.Test2 [Tests.java:29] Test2
文件输出结果：
2022-09-15 15:08:06,273 INFO [main] c.l.Tests [Tests.java:27] Tests
2022-09-15 15:08:06,275 INFO [main] c.l.t.Test1 [Tests.java:28] Test1
2022-09-15 15:08:06,275 INFO [main] c.l.t.Test2 [Tests.java:29] Test2
2022-09-15 15:08:06,275 INFO [main] c.l.t.Test2 [Tests.java:29] Test2
我们来具体分析一下结果：
logger.info("Tests")
logger其来自于Tests.class，它的全类名为com.logback.Tests
依照筛选规则只有logger:root满足
logger:root下关联了两个appender，配置的debug级别，操作是info级别，满足条件，因此控制台和文件下都有输出
logger1.info("Test1")
logger1其来自于Test1.class，它的全类名为com.logback.test1.Test1
依照筛选规则logger:com.logback.test1, logger:root 两个满足
logger:com.logback.test1下关联了控制台,配置的debug级别，操作是info级别，满足条件，因此控制台有输出
logger:root下关联了两个appender，配置的debug级别，操作是info级别，满足条件，因此控制台和文件下都有输出
合计控制台输出两次，文件输出一次
logger2.info("Test2")
logger2其来自于Test2.class，它的全类名为com.logback.test2.Test2
依照筛选规则logger:com.logback.test2, logger:root 两个满足
logger:com.logback.test2下关联了文件appender,没有配置级别取其父级别即root的级别为debug，操作是info级别，满足条件，因此文件有输出
logger:root下关联了两个appender，配置的debug级别，操作是info级别，满足条件，因此控制台和文件下都有输出
合计控制台输出一次，文件输出两次
思考
上面只是说了主要功能，更多的是像一个需求，如果我们自己来实现上述功能，该怎么实现呢？
实现需要考虑几个问题：
- logback.xml怎么解析
- 解析后的数据怎么组织
- 输入操作触发时怎么从组织的数据中获取想要的logger及整体输出流程
其中第二点启承上启下的作用，我们来分析一下logger的层次结果，根据上面说明的筛选规则我们很容易第一时间就想到了树结构，全类名用点隔离，每个点之间包名就是一个节点，那就相当于LoggerFactory中持有一个logger:root 对象，它是树形结构包含了所有logger，而每个logger里面又持有多个关联的appender对象，我只要从LoggerFactory中找到对应的logger,从下往上访问到root，最终调用appender的方法输出，顺利成章的一下子就解决了第二，第三的问题。
再来看看第一个问题，root ,logger,appender 他们存在依赖关系，但都是单方向的，不存在循环依赖，最好的步骤应该类似这样：
parseAppender(configuration.getElement("appender"))
parseRoot(configuration.getElement("root"))
parseLogger(configuration.getElement("logger"))
对应应该有三个解析器：
ConfigurationParser, RootAndLoggerParser, AppenderParser
后两者应该在初始化时注册到了前者中，或者说前者持有后两者，如果解析器比较多就在一个地方统一注册处理，这里没有固定，至于具体怎么解析我们先不讨论，先搭框架。
所有问题都解决了，那么logback源码实现跟我们想的一致吗？
源码分析
先来说下自己分析实现和源码实现的结果对比：logback.xml解析完全不同，数据组织对了部分也少了部分，整体流程大致一致。
我们不怕不同，就怕相同，有不同说明有进步空间。
简单介绍slf4j
在分析logback之前，我们都知道它是slf4j的实现，我们不关心其它就关心两点：
- slf4j中调用logback的入口在哪
- Loggerfactory是外观模式，在logback中它的具体实现是谁，其必然实现了ILoggerFactory接口
直接说结果：
slf4j 1.8版本以前会在实现中找org.slf4j.impl.StaticLoggerBinder类，并调用StaticLoggerBinder.getSingleton().getLoggerFactory()方法获取
1.8及其以后采用java api机制，这里不做说明。我这分析的是1.8以前的版本。
特殊说明
本文目的主要研究三点，也是主要流程，不涉及其它细节，所有代码都已简化，其三点目的为：
- logback.xml解析
- 解析后的数据怎么组织
- 输入操作触发时怎么从组织的数据中获取想要的logger及整体输出流程
step1-入口及核心类
在logback中找到StaticLoggerBinder类，查看如下：
public class StaticLoggerBinder implements LoggerFactoryBinder {
public static String REQUESTED_API_VERSION = "1.7.16"; // !final
final static String NULL_CS_URL = CoreConstants.CODES_URL + "#null_CS";
/**
* The unique instance of this class.
*/
private static StaticLoggerBinder SINGLETON = new StaticLoggerBinder();
private static Object KEY = new Object();
static {
SINGLETON.init();
}
private boolean initialized = false;
private LoggerContext defaultLoggerContext = new LoggerContext();
private final ContextSelectorStaticBinder contextSelectorBinder = ContextSelectorStaticBinder.getSingleton();
public static StaticLoggerBinder getSingleton() {
return SINGLETON;
}
/**
* Package access for testing purposes.
*/
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);
}
}
public ILoggerFactory getLoggerFactory() {
if (!initialized) {
return defaultLoggerContext;
}
if (contextSelectorBinder.getContextSelector() == null) {
throw new IllegalStateException("contextSelector cannot be null. See also " + NULL_CS_URL);
}
return contextSelectorBinder.getContextSelector().getLoggerContext();
}
}
这里最重要的组件为LoggerContext, 也就是源码中defaultLoggerContext，它是整个的核心是真正的slf4j中LoggerFactory门面的实现，必然实现了Slf4j的ILoggerFactory 接口。
里面的两个方法很重要：
- init 涉及logback.xml解析及数据组织
- getLoggerFactory涉及用户获取Logger 进而触发整个日志记录流程
step2-LoggerContext初始化
StaticLoggerBinder类中init方法中有下面一段代码：
new ContextInitializer(defaultLoggerContext).autoConfig();
ContextInitializer从名字语义可以看出它是初始化器，它包含了logback.xml解析及数据组织初始化。按照语义及经验判断它不可能是懒加载，为什么？因为如果是懒加载，xml解析及初始化必定分开，名字理应叫ConfigurationParser，而不叫ContextInitializer，事实证明确实如此。
step2.1-ContextInitializer
public class ContextInitializer {
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";
final LoggerContext loggerContext;
public ContextInitializer(LoggerContext loggerContext) {
this.loggerContext = loggerContext;
}
public 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("xml")) {
JoranConfigurator configurator = new JoranConfigurator();
configurator.setContext(loggerContext);
configurator.doConfigure(url);
} else {
......
}
}
public void autoConfig() throws JoranException {
StatusListenerConfigHelper.installIfAsked(loggerContext);
URL url = findURLOfDefaultConfigurationFile(true);
if (url != null) {
configureByResource(url);
} else {
......
}
}
......
}
这里分析一下autoConfig方法，里面有两个方法需要注意：
- findURLOfDefaultConfigurationFile 这里查找配置文件，不是本文重点，不做介绍可以理解为查找logback.xml文件
- configureByResource
configureByResource方法可以看出ContextInitializer是老司机，当了甩手掌柜，丢给了JoranConfigurator去处理。它把查找配置文件的职责揽在了自己身上（至于是不是又找人代理查找谁知道呢，感兴趣可以自己去分析），并安慰JoranConfigurator就不要查找了，安心解析及初始化。
说明：这里这么做就是框架的老套路，当一个人承担的职责比较多时，就要分化职责，最后组织起来完成目的。
step2.2-JoranConfigurator
我们先看看这个类的继承关系：
JoranConfigurator->JoranConfiguratorBase->GenericConfigurator...
看到这我眼前闪过JoranConfigurator也是个老司机。继承关系中都包含Configurator这个词我就感觉不简单，又是一个套路。我们先不看源码，先猜猜是什么套路。
对外套路：凡是这种情况，说明必然还有其它Configurator，外面调用它可能会涉及（if else/switch）, map , 策略模式，状态模式
对内套路：几乎都是包含模板模式。
JoranConfigurator外就是if else, 对内就是模板模式。JoranConfigurator表示套路次次有，每次不能缺。这里不介绍各个模式，不属于本文重点。
JoranConfigurator.doConfigure方法调用给了GenericConfigurator
public abstract class GenericConfigurator extends ContextAwareBase {
private BeanDescriptionCache beanDescriptionCache;
protected Interpreter interpreter;
public final void doConfigure(URL url) throws JoranException {
InputStream in = null;
try {
......
doConfigure(in, url.toExternalForm());
} catch (IOException ioe) {
......
} finally {
......
}
}
public final void doConfigure(InputStream inputStream, String systemId) throws JoranException {
InputSource inputSource = new InputSource(inputStream);
inputSource.setSystemId(systemId);
doConfigure(inputSource);
}
public final void doConfigure(final InputSource inputSource) throws JoranException {
long threshold = System.currentTimeMillis();
SaxEventRecorder recorder = new SaxEventRecorder(context);
recorder.recordEvents(inputSource);
doConfigure(recorder.saxEventList);
......
}
public void doConfigure(final List<SaxEvent> eventList) throws JoranException {
buildInterpreter();
// disallow simultaneous configurations of the same context
synchronized (context.getConfigurationLock()) {
interpreter.getEventPlayer().play(eventList);
}
}
}
GenericConfigurator表示你们这些老板就知道欺负人，整天不干正事，殊不知自己也不干正事。它把解析xml的职责转给了SaxEventRecorder, 把初始化及组织数据的职责转给了Interpreter。真是应了那句话：自古套路得人心，一直套路一直爽。
step2.3-SaxEventRecorder
表示我已经是底层员工了，不能在派给下面人干活了，很是苦恼。不过毕竟大风大浪走过来，还是有几把刷子的。灵机一动把解析xml功能外包给了sax去解析，想了想怕被上面发现，在外面还包装了一层，最后还在心里默默夸自己是个天才。
public class SaxEventRecorder extends DefaultHandler implements ContextAware {
......
public List<SaxEvent> saxEventList = new ArrayList<SaxEvent>();
......
final public void recordEvents(InputStream inputStream) throws JoranException {
recordEvents(new InputSource(inputStream));
}
public List<SaxEvent> recordEvents(InputSource inputSource) throws JoranException {
SAXParser saxParser = buildSaxParser();
try {
saxParser.parse(inputSource, this);
return saxEventList;
} catch (IOException ie) {
handleError("I/O error occurred while parsing xml file", ie);
} catch (SAXException se) {
// Exception added into StatusManager via Sax error handling. No need to add it again
throw new JoranException("Problem parsing XML document. See previously reported errors.", se);
} catch (Exception ex) {
handleError("Unexpected exception while parsing XML document.", ex);
}
throw new IllegalStateException("This point can never be reached");
}
private SAXParser buildSaxParser() throws JoranException {
try {
SAXParserFactory spf = SAXParserFactory.newInstance();
spf.setValidating(false);
//spf.setFeature("http://apache.org/xml/features/disallow-doctype-decl", true);
spf.setFeature("http://xml.org/sax/features/external-general-entities", false);
spf.setFeature("http://xml.org/sax/features/external-parameter-entities", false);
spf.setNamespaceAware(true);
return spf.newSAXParser();
} catch (Exception pce) {
String errMsg = "Parser configuration error occurred";
addError(errMsg, pce);
throw new JoranException(errMsg, pce);
}
}
public void startElement(String namespaceURI, String localName, String qName, Attributes atts) {
......
saxEventList.add(new StartEvent(current, namespaceURI, localName, qName, atts, getLocator()));
}
public void characters(char[] ch, int start, int length) {
......
saxEventList.add(new BodyEvent(bodyStr, getLocator()));
......
}
public void endElement(String namespaceURI, String localName, String qName) {
saxEventList.add(new EndEvent(namespaceURI, localName, qName, getLocator()));
......
}
......
}
SaxEventRecorder它实现了sax中DefaultHandler的接口，当调用saxParser.parse(inputSource, this)时，会触发DefaultHandler中的方法，SaxEventRecorder倒也光棍复写了startElement, characters, endElement三个方法，并将其封装成三个事件StartEvent，BodyEvent，EndEvent，最终放入saxEventList集合中。类似于下面，我只写了部分：
<configuration> //StartEvent:configuration
<appender name="FILE" class="ch.qos.logback.core.FileAppender"> //StartEvent:appender
<file> //StartEvent:file
myApp.log //BodyEvent:(myApp.log)
</file> //EndEvent:file
<encoder> //StartEvent:encoder
<pattern>%date %level [%thread] %logger{10} [%file:%line] %msg%n</pattern>
</encoder>
</appender> //EndEvent:appender
<appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">
<encoder>
<pattern>%date %level [%thread] %logger{10} [%file:%line] %msg%n</pattern>
</encoder>
</appender>
<logger name="com.logback.test1" level="debug">
<appender-ref ref="STDOUT" />
</logger>
<logger name="com.logback.test2">
<appender-ref ref="FILE" />
</logger>
<root level="debug">
<appender-ref ref="STDOUT" />
<appender-ref ref="FILE" />
</root>
</configuration> //EndEvent:configuration
step2.4-Interpreter
Interpreter是一个实干家，接受到任务后表示一定完成任务，并喊着口号：我勤劳，我光荣。实则心里的苦只有自己知道。
我们先回到step2.2中的下面方法：
public void doConfigure(final List<SaxEvent> eventList) throws JoranException {
buildInterpreter();
// disallow simultaneous configurations of the same context
synchronized (context.getConfigurationLock()) {
interpreter.getEventPlayer().play(eventList);
}
}
先看看buildInterpreter方法：
protected 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());
}
看到这很多同学立马心里打鼓，为什么？因为看不明白。有经验的同学立马就能从Interpreter结构入手,因为凡是build方法肯定与其结构有关。我们先看看Interpreter结构，有删减：
public class Interpreter {
final private RuleStore ruleStore;
final private InterpretationContext interpretationContext;
final private ArrayList<ImplicitAction> implicitActions;
private ElementPath elementPath;
EventPlayer eventPlayer;
Stack<List<Action>> actionListStack;
......//删了一些
}
InterpretationContext这个就不必说，老生常谈，肯定上下文有关，我们先不关注它里面有哪些变量细节，知道大致语义即可。
ruleStore：规则存储
implicitActions：隐藏action
elementPath: 元素路径，大胆猜测是xml元素的路径比如appender 可能是configuration/appender
eventPlayer: 事件播放器，大胆猜测是处理StartEvent, BodyEvent, EndEvent
actionListStack: action集合堆栈
以上都是根据语义猜测，我们有待验证，做到心中有数就行了。回过头来再来看看上面方法，我把上面方法改变一下，大家就很熟悉了：
protected void buildInterpreter() {
this.interpreter = new Interpreter(context,initialElementPath());
interpreter.addRuleStore(buildRuleStore());
interpreter.addImplicitAction(buildImplicitAction());
interpreter.addDefaultNestedComponentRegistryRules(new RegistryRules {
public void registry(DefaultNestedComponentRegistry registry) {
addDefaultNestedComponentRegistryRules(registry);
}
});
}
protected RuleStore buildRuleStore() {
RuleStore rs = new SimpleRuleStore(context);
addInstanceRules(rs);
return rs;
}
protected ImplicitAction buildImplicitAction() {
List<ImplicitAction> implicitActions = new ArrayList<ImplicitAction>();
addImplicitRules(implicitActions);
return implicitActions;
}
---------------------------------------------------
// interpreter里面的方法当然也要做相应变动，这里只是举例就不多说
---------------------------------------------------
上面分了四部分：
- Interpreter构造
- addInstanceRules(rs);
- addImplicitRules(interpreter);
- addDefaultNestedComponentRegistryRules(interpretationContext.getDefaultNestedComponentRegistry());
我们先看看Interpreter构造函数，传入里面的context其实就是loggerContext它是整个的核心，解析后的最终树形logger数据就是要放入它中，因此InterpretationContext 中含有context很合理，然后持有Interpreter也很合理，毕竟它就是为了解决Interpreter功能而派生出来的。这里还需注意的是EventPlayer，它里面也含有Interpreter，为什么要含有它，后面再来说明。
public Interpreter(Context context, RuleStore rs, ElementPath initialElementPath) {
this.cai = new CAI_WithLocatorSupport(context, this);
ruleStore = rs;
interpretationContext = new InterpretationContext(context, this);
implicitActions = new ArrayList<ImplicitAction>(3);
this.elementPath = initialElementPath;
actionListStack = new Stack<List<Action>>();
eventPlayer = new EventPlayer(this);
}
我们在来看看addInstanceRules(rs);
public class JoranConfigurator extends JoranConfiguratorBase<ILoggingEvent> {
@Override
public 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());
}
.......
}
// 其中super.addInstanceRules(rs);
abstract public class JoranConfiguratorBase<E> extends GenericConfigurator {
@Override
protected void addInstanceRules(RuleStore rs) {
// is "configuration/variable" referenced in the docs?
rs.addRule(new ElementSelector("configuration/variable"), new PropertyAction());
rs.addRule(new ElementSelector("configuration/property"), new PropertyAction());
rs.addRule(new ElementSelector("configuration/substitutionProperty"), new PropertyAction());
rs.addRule(new ElementSelector("configuration/timestamp"), new TimestampAction());
rs.addRule(new ElementSelector("configuration/shutdownHook"), new ShutdownHookAction());
rs.addRule(new ElementSelector("configuration/define"), new DefinePropertyAction());
// the contextProperty pattern is deprecated. It is undocumented
// and will be dropped in future versions of logback
rs.addRule(new ElementSelector("configuration/contextProperty"), new ContextPropertyAction());
rs.addRule(new ElementSelector("configuration/conversionRule"), new ConversionRuleAction());
rs.addRule(new ElementSelector("configuration/statusListener"), new StatusListenerAction());
rs.addRule(new ElementSelector("configuration/appender"), new AppenderAction<E>());
rs.addRule(new ElementSelector("configuration/appender/appender-ref"), new AppenderRefAction<E>());
rs.addRule(new ElementSelector("configuration/newRule"), new NewRuleAction());
rs.addRule(new ElementSelector("*/param"), new ParamAction(getBeanDescriptionCache()));
}
......
}
看到这立马就知道RuleStore干什么的了：处理xml元素，我们重点关注：
- ConfigurationAction
- AppenderAction
- LoggerAction
- RootLoggerAction
说明：这种就是典型策略模式加模板模式，一般含有Action，Handler，Strategy,往往含有dispatch,反射，xml文件，properties文件，注解等等，这个套路太常见了。这里比较简单，因为是静态的，不存在自己查找，不存在动态添加，变更，合并，反射，资源加载。
不过这里也学到了一个新词store, 一般叫RuleRegister, RuleManage, RuleMapping,更有甚者是RuleSupport,RuleProvider(这里两者语义不合适，前者调用它往往要提供support方法表示不同大的类别支持，后者往往伴随资源加载如xml，properties，反射，涉及类加载器)
再来看看addImplicitRules(interpreter)：
protected void addImplicitRules(Interpreter interpreter) {
// The following line adds the capability to parse nested components
NestedComplexPropertyIA nestedComplexPropertyIA = new NestedComplexPropertyIA(getBeanDescriptionCache());
nestedComplexPropertyIA.setContext(context);
interpreter.addImplicitAction(nestedComplexPropertyIA);
NestedBasicPropertyIA nestedBasicIA = new NestedBasicPropertyIA(getBeanDescriptionCache());
nestedBasicIA.setContext(context);
interpreter.addImplicitAction(nestedBasicIA);
}
这里就加了两个组件：
- NestedComplexPropertyIA
- NestedBasicPropertyIA
相当于xml里面元素中没有找到对应Action处理就在这两个中找，它们的区别类似于java中的基础类型和非基础类型。我这里全文只研究骨架不关注细节，这里不做介绍。
这里不介绍表示不重要，相反它很重要，其本质就是设置对象的值。有setter方法就用setter，没有就用反射。
这里记住一点它的职责就行了：狭义理解为没有找到对应Action处理就在这两个中找。
最后看看addDefaultNestedComponentRegistryRules(interpretationContext.getDefaultNestedComponentRegistry())：
protected void addDefaultNestedComponentRegistryRules(DefaultNestedComponentRegistry registry) {
DefaultNestedComponentRules.addDefaultNestedComponentRegistryRules(registry);
}
----------------------------------------------------
static public void addDefaultNestedComponentRegistryRules(DefaultNestedComponentRegistry registry) {
registry.add(AppenderBase.class, "layout", PatternLayout.class);
registry.add(UnsynchronizedAppenderBase.class, "layout", PatternLayout.class);
registry.add(AppenderBase.class, "encoder", PatternLayoutEncoder.class);
registry.add(UnsynchronizedAppenderBase.class, "encoder", PatternLayoutEncoder.class);
registry.add(EvaluatorFilter.class, "evaluator", JaninoEventEvaluator.class);
SSLNestedComponentRegistryRules.addDefaultNestedComponentRegistryRules(registry);
}
这个是干什么的？我这里不准备详细介绍，简单说一下,拿PatternLayoutEncoder来说：
<appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">
<encoder>
<pattern>%date %level [%thread] %logger{10} [%file:%line] %msg%n</pattern>
</encoder>
</appender>
它就是来解析
%date %level [%thread] %logger{10} [%file:%line] %msg%n
将其分为Token，在转换成一个convert集合，最终就是将模板转换为真实数据做准备。说白了就是有些特殊功能处理。不过它是基于类（组件）来找到处理器，而前面我们都是基于xml元素来找处理器Action的。这个命名语义非常好，嵌入式组件注册器，用了registry这个词，很符合常见套路。
step2.5-EventPlayer
public void doConfigure(final List<SaxEvent> eventList) throws JoranException {
buildInterpreter();
// disallow simultaneous configurations of the same context
synchronized (context.getConfigurationLock()) {
interpreter.getEventPlayer().play(eventList);
}
}
这里为什么要加锁，我们把这个疑问留着，接着往下看EventPlayer：
public class EventPlayer {
final Interpreter interpreter;
List<SaxEvent> eventList;
int currentIndex;
public EventPlayer(Interpreter interpreter) {
this.interpreter = interpreter;
}
public List<SaxEvent> getCopyOfPlayerEventList() {
return new ArrayList<SaxEvent>(eventList);
}
public 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);
}
}
}
public void addEventsDynamically(List<SaxEvent> eventList, int offset) {
this.eventList.addAll(currentIndex + offset, eventList);
}
}
从上可以看出EventPlayer做了事件分发及事件动态添加操作，最后将已解析的xml元素对象翻译成我们需要的对象还是给了Interpreter。为什么要这么做？这个套路我模糊记得很多框架都用过。
我们来想一想，没有EventPlayer我们会怎么做？那么EventPlayer的成员变量和play方法都要挪动到Interpreter中，这会造成什么后果？
对于功能实现而言不会产生什么后果，但是会产生代码坏味道，不偏于理解及扩展。我们从两个方面来介绍：
- 从语义上Interpreter是翻译的意思，翻译就是xml的事件对象翻译成我们需要的对象。EventPlayer的语义是事件播放器，它只处理事件相关。如果两者合在一起，会造成后来者难以理解。
- 从功能上来说不便于扩展。就拿这个来说EventPlayer里面有个addEventsDynamically动态添加事件。扩展很方便，我不需要考虑Interpreter功能及结构。
里面有一个interpreter.getInterpretationContext().fireInPlay(se)方法，这个在本文中不是重点,删除它不影响主体骨架分析，可以略过。但这里我觉得有点争议，就来说一说。
我们知道一旦有fire这个词，一般就有Listener了，它两是一对好基友。查看了一下InterpretationContext 数据结构：
public class InterpretationContext extends ContextAwareBase implements PropertyContainer {
Stack<Object> objectStack;
Map<String, Object> objectMap;
Map<String, String> propertiesMap;
Interpreter joranInterpreter;
final List<InPlayListener> listenerList = new ArrayList<InPlayListener>();
DefaultNestedComponentRegistry defaultNestedComponentRegistry = new DefaultNestedComponentRegistry();
......
void fireInPlay(SaxEvent event) {
for (InPlayListener ipl : listenerList) {
ipl.inPlay(event);
}
}
}
objectStack和objectMap这两个非常重要，我们后面在说。不出所料有一个InPlayListener集合，争议点在哪呢？如果将List listenerList这个挪到EventPlayer里面会不会更合适一点。
InterpretationContext中如果要有Listener，那也是InterpretationContextListener,或者成员变量的监听器如：objectMapListener。表示它的上下文数据发生变化就触发。里面的fireInPlay方法中既没有对event的封装，也没有如setInterpretationContext操作，这就说明InPlayListener和它没有必要的耦合度。相反InPlayListener的名字中含有play，输入的参数含有event，和EventPlayer耦合度就比较高了。
step2.6-Action
在介绍之前我们先来捋一捋前面的涉及的组件：
- Interpreter
- EventPlayer
- InterpretationContext
- Action(如ConfigurationAction,AppenderAction,LoggerAction,RootLoggerAction)
它们什么关系？
- Configurator将eventList给EventPlayer去处理(GenericConfigurator.doConfigure)
- EventPlayer根据事件类型做了分发处理，又还给了Interpreter做具体处理(EventPlayer.play)
- Interpreter找到具体的Action去处理，并将InterpretationContext作为参数传入。（Interpreter.startElement, Interpreter.characters, Interpreter.endElement）
整个流程中涉及到四个非常重要的变量：
- Interpreter中的Stack<List> actionListStack;
- InterpretationContext中的Stack objectStack;
- InterpretationContext中的Map<String, Object> objectMap;
- InterpretationContext父类ContextAwareBase中的Context context;
- actionListStack就是存储上面的action，startEvent时add，endEvent时就pop。
- 同样的objectStack就是action在startEvent时产生的处理结果就add，endEvent时就pop，并将其完全处理好的数据放入objectMap或context中。objectStack相当于临时存储，因为它包含的还未解析完全的数据，只有endEvent时才算解析完全。它存储的是过程数据。
- objectMap狭义的理解就是appender对象的存储，广义理解就是解析完全的数据存放处。
- context就是loggerContext，里面含有一个成员变量Logger root,解析后的所有logger都存放在此处。还有一个变量Map<String, Logger> loggerCache 也非常重要。我们后面分析。
- loggerContext.getLogger(loggerName)
- LoggerFactory.getLogger
- 全文只介绍了整体骨架，不涉及细节，感兴趣的可以结合这篇文章对照源码调试一下。
- 看完这篇文章，感兴趣的可以自己实现一个简易版的日志框架。看的再多不如写一遍。
- 原文是用sax解析xml的，自己实现时如果改用dom解析,该如何实现。
- 如果要你来改写logback，需要它屏蔽xml解析，让用户自己选择采用sax还是dom或者其它，我们该如何设计。
- 如果要logback不止支持xml配置，也支持java config配置，注解配置，我们该如何设计。
前两者涉及怎么处理，后两者涉及处理的数据放在哪。
我们知道sax是基于事件机制的，它的事件是由外到内，在由内到外，富有层次的。外在表现形式就是先进后出，这简直就是Stack数据结构。举个例子：
ConfigurationAction(StartEvent)->AppenderAction(StartEvent)->...->AppenderAction(EndEvent)->ConfigurationAction(EndEvent)
前三个数据理论上来说就是衍生品，最终目的就是将得到的数据放入loggerContext中。我们知道Logger root是一个树形结构，里面包含了很多子logger，而每个子logger都关联了自己的appender。因此拥有了root本质上就拥有了整个框架数据。
这里也解释了下面的代码为什么要加锁，如果stack里面的顺序一旦错乱，后果不堪设想。
synchronized (context.getConfigurationLock()) {
interpreter.getEventPlayer().play(eventList);
}
我们回过神来再看看Interpreter怎么调用action的方法的:
public class Interpreter {
......
public void startElement(StartEvent se) {
......
startElement(se.namespaceURI, se.localName, se.qName, se.attributes);
}
private void startElement(String namespaceURI, String localName, String qName, Attributes atts) {
......
// 获取Action
List<Action> applicableActionList = getApplicableActionList(elementPath, atts);
if (applicableActionList != null) {
actionListStack.add(applicableActionList);
callBeginAction(applicableActionList, tagName, atts);
} else {
......
}
}
void 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();
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);
}
}
}
public void characters(BodyEvent be) {
......
List<Action> applicableActionList = actionListStack.peek();
if (body != null) {
body = body.trim();
if (body.length() > 0) {
// System.out.println("calling body method with ["+body+ "]");
callBodyAction(applicableActionList, body);
}
}
}
private void callBodyAction(List<Action> applicableActionList, String body) {
if (applicableActionList == null) {
return;
}
Iterator<Action> i = applicableActionList.iterator();
while (i.hasNext()) {
Action action = i.next();
try {
action.body(interpretationContext, body);
} catch (ActionException ae) {
cai.addError("Exception in end() methd for action [" + action + "]", ae);
}
}
}
public void endElement(EndEvent endEvent) {
......
endElement(endEvent.namespaceURI, endEvent.localName, endEvent.qName);
}
private void endElement(String namespaceURI, String localName, String qName) {
// given that an action list is always pushed for every startElement, we
// need
// to always pop for every endElement
List<Action> applicableActionList = (List<Action>) actionListStack.pop();
if (skip != null) {
if (skip.equals(elementPath)) {
skip = null;
}
} else if (applicableActionList != EMPTY_LIST) {
callEndAction(applicableActionList, getTagName(localName, qName));
}
// given that we always push, we must also pop the pattern
elementPath.pop();
}
private void callEndAction(List<Action> applicableActionList, String tagName) {
if (applicableActionList == null) {
return;
}
// logger.debug("About to call end actions on node: [" + localName + "]");
Iterator<Action> i = applicableActionList.iterator();
while (i.hasNext()) {
Action action = i.next();
try {
action.end(interpretationContext, tagName);
} catch (ActionException ae) {
cai.addError("ActionException in Action for tag [" + tagName + "]", ae);
} catch (RuntimeException e) {
// no point in setting skip
cai.addError("RuntimeException in Action for tag [" + tagName + "]", e);
}
}
}
}
再来看看Action：
public abstract class Action extends ContextAwareBase {
......
public abstract void begin(InterpretationContext ic, String name, Attributes attributes) throws ActionException;
public void body(InterpretationContext ic, String body) throws ActionException {
// NOP
}
public abstract void end(InterpretationContext ic, String name) throws ActionException;
}
其本质就是查找到Action后调用相应方法
step2.6.1-LoggerAction
我们只分析一下LoggerAction，其它action请自己分析。因为这个是核心的核心。我们对照一下xml
<logger name="com.logback.test1" level="debug">
<appender-ref ref="STDOUT" />
</logger>
public class LoggerAction extends Action {
public static final String LEVEL_ATTRIBUTE = "level";
boolean inError = false;
Logger logger;
public void begin(InterpretationContext ec, String name, Attributes attributes) {
// loggerContext其本质就是LoggerFactory
LoggerContext loggerContext = (LoggerContext) this.context;
......
// 根据全类名查找，如果没有就创建，这个方法非常重要，后面具体分析
logger = loggerContext.getLogger(loggerName);
......
// 将logger推入objectStack中
ec.pushObject(logger);
}
public void end(InterpretationContext ec, String e) {
......
//移除
ec.popObject();
......
}
public void finish(InterpretationContext ec) {
}
}
此时logger已经实例化了，属性也设置了，但是子元素还没有设置。
我们来看看AppenderRefAction怎么处理的。
step2.6.2-AppenderRefAction
public class AppenderRefAction<E> extends Action {
boolean inError = false;
@SuppressWarnings("unchecked")
public void begin(InterpretationContext ec, String tagName, Attributes attributes) {
......
// 此时的o就是上一步的logger实例对象
Object o = ec.peekObject();
......
// Logger 类实现了AppenderAttachable这个接口
AppenderAttachable<E> appenderAttachable = (AppenderAttachable<E>) o;
// 查找appender
String appenderName = ec.subst(attributes.getValue(ActionConst.REF_ATTRIBUTE));
HashMap<String, Appender<E>> appenderBag = (HashMap<String, Appender<E>>) ec.getObjectMap().get(ActionConst.APPENDER_BAG);
Appender<E> appender = (Appender<E>) appenderBag.get(appenderName);
......
// logger 关联解析好的appender
appenderAttachable.addAppender(appender);
}
public void end(InterpretationContext ec, String n) {
}
}
step2.7-LoggerContext.getLogger/LoggerFactory.getLogger
在step2.6.1中有一个loggerContext.getLogger(loggerName)方法，在用户调用LoggerFactory.getLogger时也有一个方法，两者是等同的：
public class LoggerContext extends ContextBase implements ILoggerFactory, LifeCycle {
......
final Logger root;
private Map<String, Logger> loggerCache;
private int size;
......
// 当调用LoggerFactory.getLogger就是调用它
public final Logger getLogger(final Class<?> clazz) {
return getLogger(clazz.getName());
}
@Override
public 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) {
//这里就是将全类名用点好分割成类似Token
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;
}
}
}
private void incSize() {
size++;
}
int size() {
return size;
}
}
看到这大家就很明白了，最终就是获取解析后的logger实例。这里为什么要加缓存？
如果不加缓存那么查找起来就非常吃力了，因为它是树形结构，我们写代码遍历查找就比较麻烦了，这个在java中rt.jar包中很多都用了这种方法，值得我们深思学习。相当于存了两份数据结构，一份是树形，一份是map。map用来定位查找，树形用来迭代和添加。如果我想访问logger实例的父元素只需要logger.parent
这里又有争议点了：
这两个方法分开调用会不会更好，为什么？
前者是解析xml配置中的logger实例，logger没有查找到就一定要创建，这个没有问题。后者调用相同方法就有问题了，查不到就是查不到，不要在创建了，当然创建了也没关系因为没有关联的Appender，最终不会有输出,LoggerFactory.getLogger应该这样：
public final Logger getLogger(final Class<?> clazz) {
Logger childLogger = (Logger) loggerCache.get(clazz.getName());
if (childLogger != null) {
return childLogger;
}
return root;
}
step2.8-Logger
Logger logger = LoggerFactory.getLogger(Tests.class);
logger.info("test");
当调用info时触发整体流程：
public final class Logger implements org.slf4j.Logger, LocationAwareLogger, AppenderAttachable<ILoggingEvent>, Serializable {
......
transient private AppenderAttachableImpl<ILoggingEvent> aai;
......
public void info(String msg) {
filterAndLog_0_Or3Plus(FQCN, null, Level.INFO, msg, null, null);
}
private void filterAndLog_0_Or3Plus(final String localFQCN, final Marker marker, final Level level, final String msg, final Object[] params,
final Throwable t) {
final FilterReply decision = loggerContext.getTurboFilterChainDecision_0_3OrMore(marker, this, level, msg, params, t);
if (decision == FilterReply.NEUTRAL) {
if (effectiveLevelInt > level.levelInt) {
return;
}
} else if (decision == FilterReply.DENY) {
return;
}
buildLoggingEventAndAppend(localFQCN, marker, level, msg, params, t);
}
private void buildLoggingEventAndAppend(final String localFQCN, final Marker marker, final Level level, final String msg, final Object[] params,
final Throwable t) {
LoggingEvent le = new LoggingEvent(localFQCN, this, level, msg, t, params);
le.setMarker(marker);
callAppenders(le);
}
public void callAppenders(ILoggingEvent event) {
int writes = 0;
for (Logger l = this; l != null; l = l.parent) {
writes += l.appendLoopOnAppenders(event);
if (!l.additive) {
break;
}
}
// No appenders in hierarchy
if (writes == 0) {
loggerContext.noAppenderDefinedWarning(this);
}
}
private int appendLoopOnAppenders(ILoggingEvent event) {
if (aai != null) {
return aai.appendLoopOnAppenders(event);
} else {
return 0;
}
}
}
我们忽略其它细节，只关注callAppenders(ILoggingEvent event)，可以看出将参数封装成了一个事件，从自己logger实例向父类迭代，触发多个logger配置的实例，直到Logger root为止。其中aai为logger与appender关联关系对象，里面关联了appender:
public class AppenderAttachableImpl<E> implements AppenderAttachable<E> {
......
public int appendLoopOnAppenders(E e) {
int size = 0;
final Appender<E>[] appenderArray = appenderList.asTypedArray();
final int len = appenderArray.length;
for (int i = 0; i < len; i++) {
appenderArray[i].doAppend(e);
size++;
}
return size;
}
......
}
最终调用了Appender.doAppend方法，至此整个骨架流程结束。
我们知道常见的Appender有FileAppender，ConsoleAppender，可以想象一个肯定是输出到流文件，一个是控制台。按照骨架流程，我们可以自定义输出到email,mysql,oracle,ES等等，事实上logback也内置了很多Appender，例如发送邮箱。之所以拿出来说一下是我们了解了整体流程后不要在局限在原有思想上，logback可以做更多事。
Zipkin 就是利用的日志框架实现的，不过里面还涉及到了日志的MDC功能。
后记
\
