Spring5 的日志学习

我们在使用 Spring5 的过程中会出现这样的现像，就是 Spring5 内部代码打印的日志和我们自己的业务代码打印日志使用的不是统一日志实现，尤其是在项目启动的时候，Spring5 的内部日志使用的是 log4j2，但是业务代码打印使用的可能是 logback ，log4j1 或者 其他日志实现

一、Spring4 采用日志是 commons-logging

二、Spring5 内部日志

1.Spring5 内部日志原理

Spring5 自己在 commons-logging 基础上进行修改，将修改完的代码单独封装为一个 jar 包，Spring5 内部就使用这个jar，我们可以注意一下当我们导入 Spring5 的相关 jar 包的时候，maven会为我们自动依赖一个 spring-jcl 的jar包，这就是那个jar包。

 

 

 可以看出这这两 jar 包的包名都起的一模一样，只是LogFactory的实现是Spring5自己实现的。

2. Spring5 日志关键源码分析

org.apache.commons.logging.LogFactory#getLog(java.lang.String)

	/**
	 * Convenience method to return a named logger.
	 * @param name logical name of the <code>Log</code> instance to be returned
	 */
	public static Log getLog(String name) {
		return LogAdapter.createLog(name);
	}

org.apache.commons.logging.LogAdapter#createLog

    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 {
//LOG4J_SPI = "org.apache.logging.log4j.spi.ExtendedLogger"在Log4j2包log4j-api中
//LOG4J_SLF4J_PROVIDER = 
//     "org.apache.logging.slf4j.SLF4JProvider"在Log4j2桥接器包log4j-to-slf4j中
//SLF4J_SPI = "org.slf4j.spi.LocationAwareLogger" 在slf4j包 slf4j-api 中
//SLF4J_API = "org.slf4j.Logger" 在slf4j包 slf4j-api 中

        
        //判断是否导入了 log4j2包 log4j-api
		if (isPresent(LOG4J_SPI)) {
			if (
             //判断是否导入了 Log4j2 桥接器包log4j-to-slf4j
             isPresent(LOG4J_SLF4J_PROVIDER) &&
             //判断是否导入了 slf4j包 slf4j-api
             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;
		}
	}


// LOG4J  采用 log4j2的 日志实现

// SLF4J_LAL 采用 slf4j  Slf4jLocationAwareLog Full SLF4J SPI 
//including location awareness support

// SLF4J 采用 slf4j  Slf4jLog  Minimal SLF4J API without 
//location awareness support

private enum LogApi {LOG4J, SLF4J_LAL, SLF4J, JUL}


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);
		}
}

 1.验证 不导入 log4j2 jar包 log4j-api 的情况

Spring5 内部日志的选择逻辑简单描述，如果没有导入log4j2的jar包 log4j-api，优先考虑 slf4j，如果没有导入 slf4j 相关依赖，就选择 jul。

        1.复现 不导入log4j2 和 slf4j Spring5 内部日志 按照jul

public static void main(String[] args) throws 
                                    InterruptedException {

        AnnotationConfigApplicationContext context = 
                new AnnotationConfigApplicationContext(SpringLogService.class);

        SpringLogService springLogService = 
                                    context.getBean(SpringLogService.class);

        System.out.println(springLogService);

}

运行结果:

com.fll.springlog.SpringLogService@3e58a80e

这里没打印Spring5启动的日志，因为Spring5容器正常启动打印的日志都是debug级别的，
我通过logging.properties 来修改 jul 的日志级别，但是没有修改成功

.level=debug

handlers=java.util.logging.ConsoleHandler

java.util.logging.ConsoleHandler.level=debug
java.util.logging.ConsoleHandler.formatter=java.util.logging.SimpleFormatter

可以通过debug的方式，查看Spring5容器实例化的 logger 对象是哪个日志实现

 

 

 

 成功在控制台使用Spring5的 logger 打印日志，证明容器的logger确实使用的 jul

        2.复现 不导入log4j2 ，但是导入slf4j  Spring5 内部日志按照slf4j 并且绑定 log4j1

<!-- log4j1 1.7.30 绑定器 -->
<dependency>
    <groupId>org.slf4j</groupId>
    <artifactId>slf4j-log4j12</artifactId>
    <version>1.7.30</version>
</dependency>

public static void main(String[] args) throws InterruptedException {

        AnnotationConfigApplicationContext context = 
            new AnnotationConfigApplicationContext(SpringLogService.class);

        SpringLogService springLogService = 
                                context.getBean(SpringLogService.class);

        Logger logger = LoggerFactory.getLogger( "slf4jLogger");

        logger.info("这里是业务日志:" + springLogService.getClass().toString());


    }

运行结果：

[log4j_1] 2024-08-05 17:32:32,368 DEBUG [org.springframework.context.annotation.AnnotationConfigApplicationContext] - Refreshing org.springframework.context.annotation.AnnotationConfigApplicationContext@48a242ce
[log4j_1] 2024-08-05 17:32:32,381 DEBUG [org.springframework.beans.factory.support.DefaultListableBeanFactory] - Creating shared instance of singleton bean 'org.springframework.context.annotation.internalConfigurationAnnotationProcessor'
[log4j_1] 2024-08-05 17:32:32,409 DEBUG [org.springframework.beans.factory.support.DefaultListableBeanFactory] - Creating shared instance of singleton bean 'org.springframework.context.event.internalEventListenerProcessor'
[log4j_1] 2024-08-05 17:32:32,410 DEBUG [org.springframework.beans.factory.support.DefaultListableBeanFactory] - Creating shared instance of singleton bean 'org.springframework.context.event.internalEventListenerFactory'
[log4j_1] 2024-08-05 17:32:32,412 DEBUG [org.springframework.beans.factory.support.DefaultListableBeanFactory] - Creating shared instance of singleton bean 'org.springframework.context.annotation.internalAutowiredAnnotationProcessor'
[log4j_1] 2024-08-05 17:32:32,415 DEBUG [org.springframework.beans.factory.support.DefaultListableBeanFactory] - Creating shared instance of singleton bean 'springLogService'
[log4j_1] 2024-08-05 17:32:32,428 INFO [slf4jLogger] - 这里是业务日志:class com.fll.springlog.SpringLogService


可以看到Spring5 容器启动日志采用slf4j绑定的是log4j1 , 业务也是采用slf4j绑定的是log4j1

        3.复现 不导入log4j2 ，但是导入slf4j  Spring5 内部日志按照slf4j 并且绑定 logback

[logback] 2024-08-06 09:04:25 [main] DEBUG o.s.c.a.AnnotationConfigApplicationContext - Refreshing org.springframework.context.annotation.AnnotationConfigApplicationContext@708f5957
[logback] 2024-08-06 09:04:25 [main] DEBUG o.s.b.f.s.DefaultListableBeanFactory - Creating shared instance of singleton bean 'org.springframework.context.annotation.internalConfigurationAnnotationProcessor'
[logback] 2024-08-06 09:04:25 [main] DEBUG o.s.b.f.s.DefaultListableBeanFactory - Creating shared instance of singleton bean 'org.springframework.context.event.internalEventListenerProcessor'
[logback] 2024-08-06 09:04:25 [main] DEBUG o.s.b.f.s.DefaultListableBeanFactory - Creating shared instance of singleton bean 'org.springframework.context.event.internalEventListenerFactory'
[logback] 2024-08-06 09:04:25 [main] DEBUG o.s.b.f.s.DefaultListableBeanFactory - Creating shared instance of singleton bean 'org.springframework.context.annotation.internalAutowiredAnnotationProcessor'
[logback] 2024-08-06 09:04:25 [main] DEBUG o.s.b.f.s.DefaultListableBeanFactory - Creating shared instance of singleton bean 'springLogService'
[logback] 2024-08-06 09:04:25 [main] INFO  slf4jLogger - 这里是业务日志:class com.fll.springlog.SpringLogService


可以看到Spring5 容器启动日志采用slf4j绑定的是logback , 业务也是采用slf4j绑定的是logback

2.验证 导入 log4j2 jar包 log4j-api 的情况
 

如果导入了log4j2的jar包，也导入了log4j2的桥接包和slf4j，容器就选择slf4j（个人理解，如果导入了log4j2的桥接包和slf4j，说明使用者想将 log4j2 桥接到slf4j，所以直接就选择slf4j，和桥接到slf4j的效果一样）。如果导入了log4j2的jar包，log4j2的桥接包和slf4j 这两个任意一个没导入，容器就选择log4j2

        1.复现导入log4j2 ，但是不导入slf4j 或者 log4j2桥接包log4j-to-slf4j Spring5 内部日志按照log4j2，业务代码采用slf4j绑定log4j1

 运行结果:

[log4j_2] line=594 22:46:41.041 [main]DEBUG - Refreshing org.springframework.context.annotation.AnnotationConfigApplicationContext@6cdba6dc
[log4j_2] line=213 22:46:41.041 [main]DEBUG - Creating shared instance of singleton bean 'org.springframework.context.annotation.internalConfigurationAnnotationProcessor'
[log4j_2] line=213 22:46:41.041 [main]DEBUG - Creating shared instance of singleton bean 'org.springframework.context.event.internalEventListenerProcessor'
[log4j_2] line=213 22:46:41.041 [main]DEBUG - Creating shared instance of singleton bean 'org.springframework.context.event.internalEventListenerFactory'
[log4j_2] line=213 22:46:41.041 [main]DEBUG - Creating shared instance of singleton bean 'org.springframework.context.annotation.internalAutowiredAnnotationProcessor'
[log4j_2] line=213 22:46:41.041 [main]DEBUG - Creating shared instance of singleton bean 'springLogService'
[log4j_1] 2024-08-05 22:46:41,655 INFO [slf4jLogger] - 这里是业务日志:class com.fll.springlog.SpringLogService


可以看到Spring5 容器启动日志采用的是log4j2 , 业务采用slf4j绑定log4j1

        2.复现导入log4j2 ，但是不导入slf4j 或者 log4j2桥接包log4j-to-slf4j Spring5 内部日志按照log4j2，业务代码采用slf4j绑定logback

运行结果:

[log4j_2] line=594 22:54:19.019 [main]DEBUG - Refreshing org.springframework.context.annotation.AnnotationConfigApplicationContext@7d3d101b
[log4j_2] line=213 22:54:19.019 [main]DEBUG - Creating shared instance of singleton bean 'org.springframework.context.annotation.internalConfigurationAnnotationProcessor'
[log4j_2] line=213 22:54:19.019 [main]DEBUG - Creating shared instance of singleton bean 'org.springframework.context.event.internalEventListenerProcessor'
[log4j_2] line=213 22:54:19.019 [main]DEBUG - Creating shared instance of singleton bean 'org.springframework.context.event.internalEventListenerFactory'
[log4j_2] line=213 22:54:19.019 [main]DEBUG - Creating shared instance of singleton bean 'org.springframework.context.annotation.internalAutowiredAnnotationProcessor'
[log4j_2] line=213 22:54:19.019 [main]DEBUG - Creating shared instance of singleton bean 'springLogService'
[logback] 2024-08-05 22:54:20 [main] INFO  slf4jLogger - 这里是业务日志:class com.fll.springlog.SpringLogService


可以看到Spring5 容器启动日志采用的是log4j2 , 业务采用slf4j绑定的logback

        3.复现导入log4j2 ，同时导入slf4j 和 log4j2桥接包log4j-to-slf4j Spring5 内部日志按照slf4j绑定log4j1，业务代码采用slf4j绑定log4j1

运行结果：

[log4j_1] 2024-08-06 09:16:34,984 DEBUG [org.springframework.context.annotation.AnnotationConfigApplicationContext] - Refreshing org.springframework.context.annotation.AnnotationConfigApplicationContext@6c9f5c0d
[log4j_1] 2024-08-06 09:16:35,000 DEBUG [org.springframework.beans.factory.support.DefaultListableBeanFactory] - Creating shared instance of singleton bean 'org.springframework.context.annotation.internalConfigurationAnnotationProcessor'
[log4j_1] 2024-08-06 09:16:35,031 DEBUG [org.springframework.beans.factory.support.DefaultListableBeanFactory] - Creating shared instance of singleton bean 'org.springframework.context.event.internalEventListenerProcessor'
[log4j_1] 2024-08-06 09:16:35,031 DEBUG [org.springframework.beans.factory.support.DefaultListableBeanFactory] - Creating shared instance of singleton bean 'org.springframework.context.event.internalEventListenerFactory'
[log4j_1] 2024-08-06 09:16:35,031 DEBUG [org.springframework.beans.factory.support.DefaultListableBeanFactory] - Creating shared instance of singleton bean 'org.springframework.context.annotation.internalAutowiredAnnotationProcessor'
[log4j_1] 2024-08-06 09:16:35,031 DEBUG [org.springframework.beans.factory.support.DefaultListableBeanFactory] - Creating shared instance of singleton bean 'springLogService'
[log4j_1] 2024-08-06 09:16:35,047 INFO [slf4jLogger] - 这里是业务日志:class com.fll.springlog.SpringLogService


可以看到这里Spring5 容器启动日志是 slf4j绑定 log4j1，业务日志也是slf4j绑定 log4j1

         4.复现导入log4j2 ，同时导入slf4j 和 log4j2桥接包log4j-to-slf4j Spring5 内部日志按照slf4j绑定logback，业务代码采用slf4j绑定logback

[logback] 2024-08-06 09:25:56 [main] DEBUG o.s.c.a.AnnotationConfigApplicationContext - Refreshing org.springframework.context.annotation.AnnotationConfigApplicationContext@20ce78ec
[logback] 2024-08-06 09:25:56 [main] DEBUG o.s.b.f.s.DefaultListableBeanFactory - Creating shared instance of singleton bean 'org.springframework.context.annotation.internalConfigurationAnnotationProcessor'
[logback] 2024-08-06 09:25:56 [main] DEBUG o.s.b.f.s.DefaultListableBeanFactory - Creating shared instance of singleton bean 'org.springframework.context.event.internalEventListenerProcessor'
[logback] 2024-08-06 09:25:56 [main] DEBUG o.s.b.f.s.DefaultListableBeanFactory - Creating shared instance of singleton bean 'org.springframework.context.event.internalEventListenerFactory'
[logback] 2024-08-06 09:25:56 [main] DEBUG o.s.b.f.s.DefaultListableBeanFactory - Creating shared instance of singleton bean 'org.springframework.context.annotation.internalAutowiredAnnotationProcessor'
[logback] 2024-08-06 09:25:56 [main] DEBUG o.s.b.f.s.DefaultListableBeanFactory - Creating shared instance of singleton bean 'springLogService'
[logback] 2024-08-06 09:25:56 [main] INFO  slf4jLogger - 这里是业务日志:class com.fll.springlog.SpringLogService


可以看到这里Spring5 容器启动日志是 slf4j绑定 logback，业务日志也是slf4j绑定 logback

3.测试总结

以上几个例子总结：如果导入了log4j2的jar包，但是没有导入log4j2的桥接包或slf4j，容器就选择log4j2，就会出现这样一种现像:
        假如之前导入了slf4j的jar包，没有导入log4j2的jar包log4j-api 和 log4j2的桥接包 log4j-to-slf4j，那么容器就会使用 slf4j ，绑定的可以是log4j1 或者 logback，我们的业务系统也使用 slf4j ，这样容器和业务系统的日志就统一了。但是导入第三方jar的时候由于maven的传递依赖，不小心导入了log4j2的jar包log4j-api，但是由于没有 log4j2的桥接包，就会导致 Spring5 的内部日志变成 log4j2 ，和我们的业务系统使用的日志不一致了，我个人想到的解决办法就是不管用不用先导入log4j2的桥接包 log4j-to-slf4j，这样就算不小心导入log4j-api，容器还是使用 slf4j。

4.main方法 和  org.junit.Test 测试方法，容器的启动日志不一样

在B站上看到，有的同学在使用Spring5调试学习的时候发现，同样的代码，同样的gradle依赖，但是容器的启动日志不一样

因为使用org.junit.Test时环境中有 log4j2的jar包，所以会导致 使用org.junit.Test 容器启动日志会采用log4j2. 使用main方法的时候没有 log4j2的jar包，所以会采用 slf4j，所以可能会不同

原因是：

 我们平时使用Spring的时候都是通过依赖jar的方式，在打jar包的时候是不会打包有关测试类的东西，所以我们平时是不会发现这个问题，只有在使用Spring5 源码的时候才会遇到