最近在学习使用同事开发的日志框架，感觉对于logback除了基本的使用并没有很深刻的了解，遂对debug过程做大概记录以备忘,debug所用demo如下：https://gitee.com/eshin/logbackDemo

一、Logfactory初始化

LogFactory在初次getLogger的时候完成初始化，之后的每次调用都是从缓存中读取
eg:private static final Log logger = LogFactory.getLog(SpringApplication.class); springboot 在main方法没有getlogger的情况下在org.springframework.boot.SpringApplication初次调用org.apache.commons.logging.LogFactory.getLog(Class)：默认初始化的Factory为org.apache.commons.logging.impl.SLF4JLogFactory.SLF4JLogFactory()-------------》org.apache.commons.logging.impl.SLF4JLogFactory.getInstance(String)

image.png

------------------》org.slf4j.LoggerFactory.getLogger(String)（可直接调用此处获取logger）---------------------》org.slf4j.LoggerFactory.getILoggerFactory()

image.png

--------------》org.slf4j.LoggerFactory.performInitialization()------》org.slf4j.LoggerFactory.bind()

image.png

完成StaticLoggerBinder的初始化后，将标志位INITIALLZATION_STATE置为3，在下次调用是直接获取单例不用再进行初始化操作，INITIALLZATION_STATE为volatile修饰的静态变量，保证了多线程环境的可见性，但无法保证binder的单例只有一次加载，binder的单例由StaticLoggerBinder设计完成。

StaticLoggerBinder的初始化

image.png

1、LoggerContext defaultLoggerContext = new LoggerContext();

image.png

2、org.slf4j.impl.StaticLoggerBinder.init()

• 2.1 new ContextInitializer(defaultLoggerContext).autoConfig();
  image.png
  ch.qos.logback.classic.util.ContextInitializer.findURLOfDefaultConfigurationFile(boolean)在类路径下查找logback.groovy ，logback.xml ，logback-test.xml查找这三个文件，若能找到这三个文件，则通过这三个配置文件生成Configurator，否则生成默认的ch.qos.logback.classic.BasicConfigurator。

• 2.2 contextSelectorBinder.init(defaultLoggerContext, KEY);
  image.png

  至此，LogFactory初始化完成、org.slf4j.LoggerFactory.getLogger(String)便可获取logger。

二、springboot与logback整合

spring-boot.x.x.x.jar的spring.factories文件中

image.png

org.springframework.boot.logging.LoggingApplicationListener.onApplicationEnvironmentPreparedEvent(ApplicationEnvironmentPreparedEvent)------------》org.springframework.boot.logging.LoggingApplicationListener.initialize(ConfigurableEnvironment, ClassLoader)在监听到ApplicationEnvironmentPreparedEvent事件后进入initialize方法。-------------》org.springframework.boot.logging.LoggingApplicationListener.initializeSystem(ConfigurableEnvironment, LoggingSystem, LogFile)

image.png

----------------------》org.springframework.boot.logging.logback.LogbackLoggingSystem.initialize(LoggingInitializationContext, String, LogFile) ** 此时configLocation为空 **

image.png

---------------------》由于configLocation为空 -----------》org.springframework.boot.logging.AbstractLoggingSystem.initialize(LoggingInitializationContext, String, LogFile)------------》org.springframework.boot.logging.AbstractLoggingSystem.initializeWithConventions(LoggingInitializationContext, LogFile)-----------》

image.png

• 1、加载配置文件 -----------》org.springframework.boot.logging.logback.LogbackLoggingSystem.loadConfiguration(LoggingInitializationContext, String, LogFile)-----------》
  image.png

• 1.1、根据logback配置文件加载context（logback-spring.xml）
  

  org.springframework.boot.logging.logback.LogbackLoggingSystem.configureByResourceUrl(LoggingInitializationContext, LoggerContext, URL)-------------->ch.qos.logback.core.joran.GenericConfigurator.doConfigure(URL)-------------->ch.qos.logback.core.joran.GenericConfigurator.doConfigure(InputStream, String)--------->ch.qos.logback.core.joran.GenericConfigurator.doConfigure(InputSource)这个过程将配置文件解析成recorder.recordEvents(inputSource) recordEvents是xml的每个标签，分startEvent、bodyEvent和endEvent对应标签头，内容标签，和标签尾
  image.png
  image.png
• 1.1.1buildInterpreter();该方法主要完成设置RuleStore
  ch.qos.logback.core.joran.GenericConfigurator.buildInterpreter()-------------->
  主要的RuleStore在如下两个类中设置分别设置不同包下的action
  ch.qos.logback.classic.joran.JoranConfigurator（ch.qos.logback.classic.joran.action）
  ch.qos.logback.core.joran.JoranConfiguratorBase<E>（ch.qos.logback.core.joran.action）
  设置的rule供解析event对应的标签action使用
  image.png
  image.png

• 1.1.2----------------->ch.qos.logback.core.joran.spi.EventPlayer.play(List<SaxEvent>)
  image.png
  ---------------->ch.qos.logback.core.joran.spi.nterpreter.startElement(StartEvent)----------------->ch.qos.logback.core.joran.spi.Interpreter.startElement(String, String, String, Attributes)--------------------->
  image.png
  image.png
  
  主要的几个action的功能：
• ch.qos.logback.classic.joran.action.ConfigurationAction
  image.png
  当debug=true（默认）时创建OnConsoleStatusListener实例并启动，用于控制台打印status（logcontext中的BasicStatusManager中保存的ch.qos.logback.core.status.Status对象）启动之后，当有调用ch.qos.logback.core.BasicStatusManager.add(Status)时，控制台便打印当前add的status。-------------》ch.qos.logback.core.BasicStatusManager.fireStatusAddEvent(Status)此处遍历Listener，之中包括该Listener。

• ch.qos.logback.core.joran.action.IncludeAction

  image.png
  将logback-spring.xml中include标签指定的xml配置文件加载并加入WatchList，然后与logback-spring.xml文件一样处理成recordEvents，并加入到加载logback-spring.xml时生成的record（recorder.saxEventList）中。

• ch.qos.logback.core.joran.action.ConversionRuleAction

  image.png
  image.png
  用于初始化converter
  conversionWord的值就是配置pattern时需要匹配成对应值的key，如下
  image.png
  image.png
  当converter匹配到对应的key便转换成需要打印的日志内容，因此，可自定义converter及pattern关键字实现更灵活的日志打印

• ch.qos.logback.core.joran.action.PropertyAction

  image.png
  用于存储properties，默认scope为local，存在InterpretationContext中，当scope为context时，存在logContext中，为system时存为系统变量

• ch.qos.logback.core.joran.action.AppenderAction<E>

  image.png
  image.png
  完成appender的初始化，ch.qos.logback.core.rolling.RollingFileAppender<E>，该appender设置rollingPolicy，调用start()方法时会检测rollingPolicy是否生效以及需要的日志文件是否存在，若不存在便根据在rollingpolicy设置的pattern新建一个。
  在打印日志调用ch.qos.logback.core.rolling.RollingFileAppender.subAppend(E)时，会先调用判断是否需要分割文件（打印日志步骤）
  image.png
  当有子标签时需要其他的action完成配置和引用，如：ch.qos.logback.core.joran.action.NestedComplexPropertyIA完成对rollingPolicy，encoder，等的加载，当仍有子标签时，按同样的方式遍历event加载。bodyevent直接设置值。
  NestedComplexPropertyIA加载时，当有配置class则根据class加载实例（rollingPolicy），若没有配置class，则按标签名为规则去查找（encoder）在之前的步骤中，
  image.png
  配置了默认的encoder,layout,和evalator，因此也可以根据需要自定义需要的encoder等，并通过配置class的方式配置，
  通过NestedComplexPropertyIA加载的startEvent,其对应的endevent将进入ch.qos.logback.core.joran.action.NestedComplexPropertyIA.end(InterpretationContext, String)
  如rollingPolicy，调用ch.qos.logback.core.rolling.SizeAndTimeBasedRollingPolicy<E>.start()方法完成rollingPolicy的加载。
  完成对文件名pattern的设置解析。
  如encoder,主要是调用ch.qos.logback.classic.encoder.PatternLayoutEncoder.start()方法完成encoder的加载。
  image.png
  image.png

• 1、ch.qos.logback.core.pattern.PatternLayoutBase.getEffectiveConverterMap()
  image.png

  p.compile();方法会将与patter的关键字匹配的converter保留，其余的过滤掉

• 2、start方法主要完成converter的一些初始化工作，设置context，key,以便调用convert方法的时候进行内容转换。
  image.png
  当appender的类型是AsyncAppender时，在ch.qos.logback.core.joran.action.AppenderAction.end(InterpretationContext, String)时，ch.qos.logback.core.AsyncAppenderBase.start()会启动一个异步worker，对日志event进行异步打印处理。
  image.png

• ch.qos.logback.classic.joran.action.LoggerAction

  image.png
  为指定的包和类定义logger对象，并设置日志级别当logger带有appender-ref子标签时，继续startEvent并执行到ch.qos.logback.core.joran.action.AppenderRefAction<E>完成appender的引用

• org.springframework.boot.logging.logback.SpringPropertyAction

  image.png
  配置需要的变量，当spring配置文件中有对应的值时取spring中配置文件的内容，否则使用defaultValue的值
  （application.properties的加载在加载logback-spring.xml之前，其实在LogFactory初始化的时候有过一次对logback配置文件的加载（如果存在的话，只不过在加载logback-spring.xml时重置了））

• ch.qos.logback.core.joran.action.NewRuleAction
  自定义标签，需要通过改action解析自定义标签对应action的class。因此，该标签的配置，需要在使用该自定义标签之前配置。

  image.png
  查找action时，key是拼接上所有的父节点如[configuration][myrule]、[configuration][appender][encorder]
  因此自定义action时，需要用“/”将父节点分隔开，向rulestore存储action时会将pattern configuration/myrule 解析成[configuration][myrule]
  image.png
  还有其他action由于尚未使用，未曾了解。
  当所有的event执行完之后，便完成了对logback配置文件的加载

三、logger的执行与日志的打印

在完成LogFactory的加载后，就可以通过factory获取logger，当logger执行info(),debug(),warn(),error(),方法，将会执行到
ch.qos.logback.classic.Logger.filterAndLog_1(String, Marker, Level, String, Object, Throwable)或者
ch.qos.logback.classic.Logger.filterAndLog_2(String, Marker, Level, String, Object, Object, Throwable)或者
ch.qos.logback.classic.Logger.filterAndLog_0_Or3Plus(String, Marker, Level, String, Object[], Throwable)
三者的不同之处在于通过“{}”占位符可填充的参数个数不同。三者最终调用的都是
ch.qos.logback.classic.Logger.buildLoggingEventAndAppend(String, Marker, Level, String, Object[], Throwable)

------------------->ch.qos.logback.classic.Logger.callAppenders(ILoggingEvent)

image.png

image.png

------------------>ch.qos.logback.core.spi.AppenderAttachableImpl.appendLoopOnAppenders(E)

image.png

AsyncAppender主要完成将日志event放入ch.qos.logback.core.AsyncAppenderBase<E>的blockingQueue中，供二中开启的worker消费。

image.png

ConsoleAppender主要完成将日志event在控制台输出
RollingAppender的实例在进入ch.qos.logback.core.UnsynchronizedAppenderBase.doAppend(E)之后调用this.append(eventObject);------------》ch.qos.logback.core.OutputStreamAppender.append(E)-------------》ch.qos.logback.core.rolling.RollingFileAppender.subAppend(E)此时调用rollingPOlicy----》ch.qos.logback.core.rolling.SizeAndTimeBasedFNATP.isTriggeringEvent(File, E)

image.png

最终，这三个appender调用的super.subAppend(event)都指向----------------》ch.qos.logback.core.OutputStreamAppender.subAppend(E)--------------》ch.qos.logback.core.OutputStreamAppender.writeOut(E)-------------》调用ch.qos.logback.classic.encoder.PatternLayoutEncoder的doEncode方法，实际调用---》ch.qos.logback.core.encoder.LayoutWrappingEncoder.doEncode(E)

image.png

• 1、layout.doLayout(event);-------------》ch.qos.logback.classic.PatternLayout.doLayout(ILoggingEvent)-----------》ch.qos.logback.core.pattern.PatternLayoutBase.writeLoopOnConverters(E)
  image.png
  如：ch.qos.logback.classic.pattern.MDCConverter
  image.png

总的来说，logback提供了相当大的自定义空间，很容易进行拓展

demo地址：https://gitee.com/eshin/logbackDemo

更多文字性描述和用法，推荐参考：

https://logback.qos.ch/manual/

https://www.cnblogs.com/lixuwu/p/5804793.html （系列）