從原始碼分析 SpringBoot 的 LoggingSystem → 它是如何繫結日誌元件的

青石路發表於2024-08-22

原始碼Spring Boot元件

開心一刻

今天心情不好，想約哥們喝點

我：心情不好，給你女朋友說一聲，來我家，過來喝點

哥們：行！我給她說一聲

我：你想吃啥？我點外賣

哥們：你倆定吧，我已經讓她過去了

我：？？？我踏馬讓你過來！和她說一聲

哥們：哈哈哈，我踏馬尋思讓她過去呢

前情回顧

SpringBoot2.7 霸王硬上弓 Logback1.3 → 不甜但解渴實現了 spring-boot 2.x.x 與 logback 1.3.x 的整合，分兩步

關閉 Spring Boot 的 LoggingSystem

配置檔案用 logback.xml

從示例看，整合是成功的；但有些問題是沒有分析的，比如

System.setProperty("org.springframework.boot.logging.LoggingSystem", "none") 是如何生效的

Spring Boot 的 LoggingSystem 是如何與日誌元件繫結的

Spring Boot 預設依賴 3 個日誌元件：logback、log4j、jul，為什麼預設啟用的是 logback，而非其它兩個？

基於如上 3 個問題，我們一起去翻一翻 Spring Boot 的原始碼；在看原始碼之前，我先帶大家回顧一些內容，方便下文的原始碼分析

設計模式之觀察者模式 → 事件機制的底層原理

講了觀察者模式的實現，以及在 JDK 中的應用（JDK 事件模型）、Spring 中的應用（事件機制）；大家可以重點看下 Spring 的那個案例，使用非常簡單，總結一句就是

SpringBoot 啟動過程中傳送的事件，所有 ApplicationListener 都會收到（即 onApplicationEvent 方法會被呼叫）
spring-boot-2.0.3啟動原始碼篇一 - SpringApplication構造方法

大家不要通篇去讀，重點看 getSpringFactoriesInstances，與本文息息相關的歸納成一句

查詢類路徑下全部的 META-INF/spring.factories 的檔案路徑，並載入所有 spring.factories 中的內容到 SpringFactoriesLoader 的 cache 中，然後從快取中獲取 ApplicationListener 型別的類並進行例項化

下文是基於 Spring Boot 預設情況下的原始碼分析，而非整合 logback 1.3.x 的原始碼分析，大家注意下

整合 logback 1.3.x 需要關閉 Spring Boot 的 LoggingSystem，那還分析個毛

原始碼分析

問題來了，從哪開始跟？我就不繞圈子了，從 LoggingApplicationListener 開始跟，首先它在 META-INF/spring.factories 中

spring.factories_LoggingApplicationListener

其次它實現了 ApplicationListener

那麼 Spring Boot 在啟動過程中會例項化 LoggingApplicationListener，Spring Boot 啟動過程中傳送的事件都會來到 LoggingApplicationListener 的 onApplicationEvent 方法

@Override
public void onApplicationEvent(ApplicationEvent event) {
	if (event instanceof ApplicationStartingEvent) {
		onApplicationStartingEvent((ApplicationStartingEvent) event);
	}
	else if (event instanceof ApplicationEnvironmentPreparedEvent) {
		onApplicationEnvironmentPreparedEvent((ApplicationEnvironmentPreparedEvent) event);
	}
	else if (event instanceof ApplicationPreparedEvent) {
		onApplicationPreparedEvent((ApplicationPreparedEvent) event);
	}
	else if (event instanceof ContextClosedEvent) {
		onContextClosedEvent((ContextClosedEvent) event);
	}
	else if (event instanceof ApplicationFailedEvent) {
		onApplicationFailedEvent();
	}
}

Spring Boot 啟動過程分不同的階段，在每個階段都會傳送對應階段的事件，LoggingApplicationListener 針對這些事件會有不同的處理，我們暫且只需要關注以下事件

ApplicationStartingEvent，對應的處理方法：onApplicationStartingEvent

ApplicationEnvironmentPreparedEvent，對應的處理方法：onApplicationEnvironmentPreparedEvent

ApplicationPreparedEvent，對應的處理方法：onApplicationPreparedEvent

onApplicationStartingEvent

private void onApplicationStartingEvent(ApplicationStartingEvent event) {
	this.loggingSystem = LoggingSystem.get(event.getSpringApplication().getClassLoader());
	this.loggingSystem.beforeInitialize();
}

方法很簡單，獲取日誌系統，然後呼叫其 beforeInitialize 方法，我們跟進 LoggingSystem.get

public static LoggingSystem get(ClassLoader classLoader) {
	String loggingSystemClassName = System.getProperty(SYSTEM_PROPERTY);
	if (StringUtils.hasLength(loggingSystemClassName)) {
		if (NONE.equals(loggingSystemClassName)) {
			return new NoOpLoggingSystem();
		}
		return get(classLoader, loggingSystemClassName);
	}
	LoggingSystem loggingSystem = SYSTEM_FACTORY.getLoggingSystem(classLoader);
	Assert.state(loggingSystem != null, "No suitable logging system located");
	return loggingSystem;
}

打個斷點除錯下，你們就會發現 SYSTEM_PROPERTY 的值是 org.springframework.boot.logging.LoggingSystem

從系統屬性中獲取 org.springframework.boot.logging.LoggingSystem ，是不是和

System.setProperty("org.springframework.boot.logging.LoggingSystem", "none") 是如何生效的

對應上了？如果獲取的值是 none，直接返回 NoOpLoggingSystem 例項

/**
 * {@link LoggingSystem} that does nothing.
 */
static class NoOpLoggingSystem extends LoggingSystem {

	@Override
	public void beforeInitialize() {

	}

	@Override
	public void setLogLevel(String loggerName, LogLevel level) {

	}

	@Override
	public List<LoggerConfiguration> getLoggerConfigurations() {
		return Collections.emptyList();
	}

	@Override
	public LoggerConfiguration getLoggerConfiguration(String loggerName) {
		return null;
	}

}

全是空實現，相當於關閉了 Spring Boot 的 LoggingSystem；org.springframework.boot.logging.LoggingSystem 還可以設定成其他值，但需要有對應的實現。預設情況下 loggingSystemClassName 的值是 null ，會跳過 if 來到 SYSTEM_FACTORY.getLoggingSystem(classLoader);

@Override
public LoggingSystem getLoggingSystem(ClassLoader classLoader) {
	List<LoggingSystemFactory> delegates = (this.delegates != null) ? this.delegates.apply(classLoader) : null;
	if (delegates != null) {
		for (LoggingSystemFactory delegate : delegates) {
			LoggingSystem loggingSystem = delegate.getLoggingSystem(classLoader);
			if (loggingSystem != null) {
				return loggingSystem;
			}
		}
	}
	return null;
}

這裡推薦用斷點除錯去跟原始碼，按 F7 之後會來到 LoggingSystemFactory#fromSpringFactories

/**
 * Return a {@link LoggingSystemFactory} backed by {@code spring.factories}.
 * @return a {@link LoggingSystemFactory} instance
 */
static LoggingSystemFactory fromSpringFactories() {
	return new DelegatingLoggingSystemFactory(
			(classLoader) -> SpringFactoriesLoader.loadFactories(LoggingSystemFactory.class, classLoader));
}

SpringFactoriesLoader.loadFactories 是不是很眼熟？（不眼熟的去看：spring-boot-2.0.3啟動原始碼篇一 - SpringApplication構造方法）此時它會做三件事

從 SpringFactoriesLoader#cache 中獲取 LoggingSystemFactory 型別的工廠類的類名列表

之前已經載入到 SpringFactoriesLoader#cache 中，所以此時從快取中獲取；注意看三個實現類的順序，LogbackLoggingSystem.Factory 在最前面
例項化這些工廠類
對這些工廠類例項按 @Order 升序排序

這三個工廠類的 @Order 值是一樣的，都是 @Order(Ordered.LOWEST_PRECEDENCE)，所以順序不變，LogbackLoggingSystem.Factory 仍在最前面

回到 DelegatingLoggingSystemFactory#getLoggingSystem，對這些工廠類例項逐個遍歷，得到 LoggingSystem 立即返回，不再遍歷後面的工廠例項；第一個遍歷的的是 LogbackLoggingSystem.Factory，呼叫其 getLoggingSystem 方法

private static final boolean PRESENT = ClassUtils.isPresent("ch.qos.logback.classic.LoggerContext",
		Factory.class.getClassLoader());

@Override
public LoggingSystem getLoggingSystem(ClassLoader classLoader) {
	if (PRESENT) {
		return new LogbackLoggingSystem(classLoader);
	}
	return null;
}

ch.qos.logback.classic.LoggerContext 存在（即存在logback依賴），直接建立 LogbackLoggingSystem 例項並返回；至此 Spring Boot 的 LoggingSystem 確定將基於 logback，而非 log4j，也非 jul，問題

Spring Boot 的 LoggingSystem 是如何與日誌元件繫結的

Spring Boot 預設依賴 3 個日誌元件：logback、log4j、jul，為什麼預設啟用的是 logback，而非其它兩個？

是不是清楚了？LoggingSystem 確定為 LogbackLoggingSystem 後回到 LoggingApplicationListener#onApplicationStartingEvent 方法的第二行，即呼叫 LogbackLoggingSystem#beforeInitialize 方法

@Override
public void beforeInitialize() {
	LoggerContext loggerContext = getLoggerContext();
	if (isAlreadyInitialized(loggerContext)) {
		return;
	}
	super.beforeInitialize();
	loggerContext.getTurboFilterList().add(FILTER);
}

主要初始化 LoggerContext，跟進 getLoggerContext()

private LoggerContext getLoggerContext() {
	ILoggerFactory factory = StaticLoggerBinder.getSingleton().getLoggerFactory();
	Assert.isInstanceOf(LoggerContext.class, factory,
			() -> String.format(
					"LoggerFactory is not a Logback LoggerContext but Logback is on "
							+ "the classpath. Either remove Logback or the competing "
							+ "implementation (%s loaded from %s). If you are using "
							+ "WebLogic you will need to add 'org.slf4j' to "
							+ "prefer-application-packages in WEB-INF/weblogic.xml",
					factory.getClass(), getLocation(factory)));
	return (LoggerContext) factory;
}

StaticLoggerBinder 有沒有很熟悉？看下它的全類名：org.slf4j.impl.StaticLoggerBinder，在 logback-classic-1.2.12.jar 下，而 logback 1.3.x 沒有這個類

所以 spring-boot 2.x.x 預設不支援 logback 1.3.x

總結下，onApplicationStartingEvent 方法確定了日誌系統是 LogbackLoggingSystem

onApplicationEnvironmentPreparedEvent

private void onApplicationEnvironmentPreparedEvent(ApplicationEnvironmentPreparedEvent event) {
	SpringApplication springApplication = event.getSpringApplication();
	if (this.loggingSystem == null) {
		this.loggingSystem = LoggingSystem.get(springApplication.getClassLoader());
	}
	initialize(event.getEnvironment(), springApplication.getClassLoader());
}

很顯然 loggingSystem 不為 null，我們直接跟 initialize 方法

protected void initialize(ConfigurableEnvironment environment, ClassLoader classLoader) {
	getLoggingSystemProperties(environment).apply();
	this.logFile = LogFile.get(environment);
	if (this.logFile != null) {
		this.logFile.applyToSystemProperties();
	}
	// 日誌分組，暫不關注
	this.loggerGroups = new LoggerGroups(DEFAULT_GROUP_LOGGERS);
	// 設定早期日誌級別，主要debug和trace之間的抉擇
	initializeEarlyLoggingLevel(environment);
	// 初始化日誌系統
	initializeSystem(environment, this.loggingSystem, this.logFile);
	// 設定最終日誌級別
	initializeFinalLoggingLevels(environment, this.loggingSystem);
	registerShutdownHookIfNecessary(environment, this.loggingSystem);
}

我們暫時只關注 initializeSystem 方法

繼續往下跟，來到 LogbackLoggingSystem#initialize

繼續往下跟，來到 AbstractLoggingSystem#initialize

繼續往下跟，來到 AbstractLoggingSystem#initializeWithConventions

private void initializeWithConventions(LoggingInitializationContext initializationContext, LogFile logFile) {
	String config = getSelfInitializationConfig();
	if (config != null && logFile == null) {
		// self initialization has occurred, reinitialize in case of property changes
		reinitialize(initializationContext);
		return;
	}
	if (config == null) {
		config = getSpringInitializationConfig();
	}
	if (config != null) {
		loadConfiguration(initializationContext, config, logFile);
		return;
	}
	loadDefaults(initializationContext, logFile);
}

其中 getSelfInitializationConfig() 就是從 classpath 下逐個尋找

logback-test.groovy, logback-test.xml, logback.groovy, logback.xml

這四個檔案，一旦找到則直接返回；因為找到了 logback.xml，所以來到第一個 if

繼續跟進，來到 LogbackLoggingSystem#reinitialize

將logback.xml 中的配置進行載入；至此，Spring Boot 的 LoggingSystem 與 Logback 的繫結就完成了，你們清楚了嗎？

我們重新回到 AbstractLoggingSystem#initializeWithConventions ，如果 classpath 下

logback-test.groovy, logback-test.xml, logback.groovy, logback.xml

這四個檔案都沒有，會來到 config = getSpringInitializationConfig();，逐步跟下去會來到 AbstractLoggingSystem#getSpringConfigLocations

protected String[] getSpringConfigLocations() {
	String[] locations = getStandardConfigLocations();
	for (int i = 0; i < locations.length; i++) {
		String extension = StringUtils.getFilenameExtension(locations[i]);
		locations[i] = locations[i].substring(0, locations[i].length() - extension.length() - 1) + "-spring."
				+ extension;
	}
	return locations;
}

這個方法大家都能看懂吧，locations 的值

logback-test.groovy, logback-test.xml, logback.groovy, logback.xml

逐個遍歷，然後進行拼接，最終得到

logback-test-spring.groovy, logback-test-spring.xml, logback-spring.groovy, logback-spring.xml

同樣從 classpath 下逐個尋找，一旦找到直接返回；這也是為什麼我們的日誌配置檔案是 logback-spring.xml 也能生效的原因。我們可以給 Spring Boot 的日誌配置檔案排個優先順序

logback-test.groovy > logback-test.xml > logback.groovy > logback.xml > logback-test-spring.groovy > logback-test-spring.xml > logback-spring.groovy > logback-spring.xml

總結下，onApplicationEnvironmentPreparedEvent 完成了日誌系統的初始化（日誌配置檔案的載入）

onApplicationPreparedEvent

private void onApplicationPreparedEvent(ApplicationPreparedEvent event) {
	ConfigurableApplicationContext applicationContext = event.getApplicationContext();
	ConfigurableListableBeanFactory beanFactory = applicationContext.getBeanFactory();
	if (!beanFactory.containsBean(LOGGING_SYSTEM_BEAN_NAME)) {
		beanFactory.registerSingleton(LOGGING_SYSTEM_BEAN_NAME, this.loggingSystem);
	}
	if (this.logFile != null && !beanFactory.containsBean(LOG_FILE_BEAN_NAME)) {
		beanFactory.registerSingleton(LOG_FILE_BEAN_NAME, this.logFile);
	}
	if (this.loggerGroups != null && !beanFactory.containsBean(LOGGER_GROUPS_BEAN_NAME)) {
		beanFactory.registerSingleton(LOGGER_GROUPS_BEAN_NAME, this.loggerGroups);
	}
	if (!beanFactory.containsBean(LOGGING_LIFECYCLE_BEAN_NAME) && applicationContext.getParent() == null) {
		beanFactory.registerSingleton(LOGGING_LIFECYCLE_BEAN_NAME, new Lifecycle());
	}
}

程式碼不復雜，就是註冊了幾個 Bean 到 Spring 容器，其中的 loggingSystem 是我們暫時比較關注的，預設情況下其型別是：LogbackLoggingSystem

日誌列印

Spring Boot 的 LoggingSystem 完成與 Logback 的繫結後，它是如何使用然後列印日誌的呢？是不是也像

這樣來使用的？那絕對不可能的！

這麼使用的話，跟 Spring Boot 的 LoggingSystem 有雞毛的關係？我們來看下 Spring Boot 中日誌的使用，SpringApplication 179 行就用到了

我們會發現 Log、LogFactory 在 spring-jcl-5.3.31.jar 包下

spring-jcl 類似 slf4j，也是一個日誌門面，本文不展開

跟進 LogFactory.getLog ，一路跟下去會來到 LogAdapter#createLog

public static Log createLog(String name) {
	switch (logApi) {
		case LOG4J:
			return Log4jAdapter.createLog(name);
		case SLF4J_LAL:
			return Slf4jAdapter.createLocationAwareLog(name);
		case SLF4J:
			return Slf4jAdapter.createLog(name);
		default:
			// Defensively use lazy-initializing adapter class here as well since the
			// java.logging module is not present by default on JDK 9. We are requiring
			// its presence if neither Log4j nor SLF4J is available; however, in the
			// case of Log4j or SLF4J, we are trying to prevent early initialization
			// of the JavaUtilLog adapter - e.g. by a JVM in debug mode - when eagerly
			// trying to parse the bytecode for all the cases of this switch clause.
			return JavaUtilAdapter.createLog(name);
	}
}

logApi 的值獲取如下

private static final String LOG4J_SPI = "org.apache.logging.log4j.spi.ExtendedLogger";

private static final String LOG4J_SLF4J_PROVIDER = "org.apache.logging.slf4j.SLF4JProvider";

private static final String SLF4J_SPI = "org.slf4j.spi.LocationAwareLogger";

private static final String SLF4J_API = "org.slf4j.Logger";

private static final LogApi logApi;

static {
	if (isPresent(LOG4J_SPI)) {
		if (isPresent(LOG4J_SLF4J_PROVIDER) && isPresent(SLF4J_SPI)) {
			// log4j-to-slf4j bridge -> we'll rather go with the SLF4J SPI;
			// however, we still prefer Log4j over the plain SLF4J API since
			// the latter does not have location awareness support.
			logApi = LogApi.SLF4J_LAL;
		}
		else {
			// Use Log4j 2.x directly, including location awareness support
			logApi = LogApi.LOG4J;
		}
	}
	else if (isPresent(SLF4J_SPI)) {
		// Full SLF4J SPI including location awareness support
		logApi = LogApi.SLF4J_LAL;
	}
	else if (isPresent(SLF4J_API)) {
		// Minimal SLF4J API without location awareness support
		logApi = LogApi.SLF4J;
	}
	else {
		// java.util.logging as default
		logApi = LogApi.JUL;
	}
}

根據優先順序逐個去類路徑下尋找類，找到了直接返回；Spring Boot 預設情況下用的是 SLF4J + Logback，所以 logApi 的值是 SLF4J_SPI，那麼 LogAdapter#createLog 的返回值的型別是 LogAdapter$Slf4jLocationAwareLog

相當於完成了 spring-jcl 到 slf4j 的適配；這麼說來，Spring Boot 日誌還是走的 SLF4J + Logback ？跟 Spring Boot 的 LoggingSystem 有什麼關係呢？敬請期待下篇

總結

onApplicationStartingEvent

確定日誌系統型別並建立對應的 LoggingSystem，預設情況下是 LogbackLoggingSystem
onApplicationEnvironmentPreparedEvent

完成日誌配置檔案的載入以及 LoggingSystem 的初始化
Spring Boot 的日誌列印貌似與 LoggingSystem 沒有關係？下篇分析

原始碼分析：vue和react元件事件繫結中的this
2018-10-23
原始碼VueReact元件事件
從MySQL原始碼看日誌命令失效的原因
2017-10-19
MySql原始碼
原始碼分析：Vue的雙向資料繫結
2017-09-23
原始碼Vue
Zookeeper原始碼分析（二） —– zookeeper日誌
2019-03-02
原始碼
Zookeeper原始碼分析（二） ----- zookeeper日誌
2018-04-30
原始碼
vue雙向繫結的原理及實現雙向繫結MVVM原始碼分析
2017-09-25
VueMVVM原始碼
SpringBoot 用的 spring-jcl 列印日誌，與 LoggingSystem 有雞毛關係？
2024-08-23
Spring Boot
mybaits原始碼分析--日誌模組（四）
2021-09-01
AI原始碼
【RocketMQ】Dledger日誌複製原始碼分析
2023-02-26
MQ原始碼
從原始碼角度看CPU相關日誌
2019-03-04
原始碼
SpringBoot | SpringBoot 是如何實現日誌的？
2019-03-24
Spring Boot
Node 進階：express 預設日誌元件 morgan 從入門使用到原始碼剖析
2016-12-12
Express元件原始碼
從Vue.js原始碼角度再看資料繫結
2019-02-26
Vue.js原始碼
【Android原始碼】Service的繫結過程
2017-12-23
Android原始碼
Spring原始碼系列(二)--bean元件的原始碼分析
2020-06-26
Spring原始碼Bean元件
Mybatis日誌原始碼探究
2021-03-29
MyBatis原始碼
SpringBoot原始碼分析
2024-09-17
Spring Boot原始碼
日誌分析-apache日誌分析
2024-04-28
Apache
日誌分析如何演變
2018-10-31
.NetCore中的日誌（1）日誌元件解析
2016-09-07
NetCore元件
vue資料繫結原始碼
2019-01-30
Vue原始碼
Netty原始碼分析--Channel註冊&繫結埠（下）（七）
2019-07-04
Netty原始碼
從原始碼分析Node的Cluster模組
2019-01-21
原始碼
Vue原始碼探究-資料繫結的實現
2018-11-04
Vue原始碼
如何寫一個拖拽日曆元件（附原始碼）
2018-04-03
元件原始碼
yii2-從behaviors()來研究元件繫結行為的原理
2017-08-21
元件
oracle日誌分析從列表中移去一個日誌檔案
2007-12-08
Oracle
從原始碼分析如何優雅的使用 Kafka 生產者
2018-10-11
原始碼Kafka
Java 原始碼刨析 - 執行緒的狀態有哪些？它是如何工作的？
2020-06-18
Java原始碼執行緒
PostgreSQL 原始碼解讀（22）- 查詢語句#7（PlannedStmt結構詳解-日誌分析）
2018-08-20
SQL原始碼
Vue 如何給元件繫結原生事件
2019-04-05
Vue元件事件
深入理解Logger日誌——框架繫結原理
2020-10-13
框架
一個完整的go 日誌元件
2018-12-29
Go元件
從原始碼分析 XtraBackup 的備份原理
2021-11-14
原始碼
如何利用NLog輸出結構化日誌，並在Kibana優雅分析日誌？
2020-08-06
從原始碼分析IntentService
2016-05-16
原始碼Intent
那些年我們用過的元件-結構化日誌元件 Serilog
2023-01-05
元件
MySQL的日誌總結
2020-09-27
MySql

從原始碼分析 SpringBoot 的 LoggingSystem → 它是如何繫結日誌元件的

開心一刻

前情回顧

原始碼分析

onApplicationStartingEvent

onApplicationEnvironmentPreparedEvent

onApplicationPreparedEvent

日誌列印

總結

相關文章