一、现象
最近在编写传统的springmvc项目时,遇到了一个问题:虽然在项目的web.xml中指定了log4j的日志启动监听器Log4jServletContextListener,且开启了日志写入文件,但是日志文件中只记录业务代码中我们声明了日志记录器的日志,无法记录spring上下文启动的日志。
测试方法如下:
package com.vat;
import org.junit.Test;
import org.junit.runner.RunWith;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
import org.springframework.beans.factory.annotation.Autowired;
import org.springframework.context.ApplicationContext;
import org.springframework.test.context.ContextConfiguration;
import org.springframework.test.context.junit4.SpringJUnit4ClassRunner;/*** @author:whh* @date: 2024-02-01 21:02* <p></p>*/
@RunWith(SpringJUnit4ClassRunner.class)
@ContextConfiguration(locations = {"classpath:applicationcontext.xml"})
public class MvcTest {@AutowiredApplicationContext ctx;private static Logger LOGGER = LoggerFactory.getLogger(MvcTest.class);@Testpublic void fun(){LOGGER.debug("123");System.out.println(ctx);}
}
观察下面的运行结果截图,我们发现红色字体是spring上下文的启动日志而灰色字体是我们打印的日志,而且在日志文件中也只记录了我们打印的日志和druid数据源的关闭日志。实时上spring上下文的启动日志也非常重要,通常用于我们观察我们的应用是否启动正常,有没有一些bean没有被spring初始化到。但是从上面看其启动日志并未记录到日志文件中。
二、思考
遇到这个问题后,便使用debug模式追踪spring上下文的启动。
首先这个测试类有一个注解@RunWith(SpringJUnit4ClassRunner.class)
即我们可以猜测是通过SpringJUnit4ClassRunner来启动spring上下文的,接着我们看下这个类的源码。
public class SpringJUnit4ClassRunner extends BlockJUnit4ClassRunner {private static final Log logger = LogFactory.getLog(SpringJUnit4ClassRunner.class);private static final Method withRulesMethod;// Used by RunAfterTestClassCallbacks and RunAfterTestMethodCallbacksprivate static final String MULTIPLE_FAILURE_EXCEPTION_CLASS_NAME = "org.junit.runners.model.MultipleFailureException";static {boolean junit4dot9Present = ClassUtils.isPresent(MULTIPLE_FAILURE_EXCEPTION_CLASS_NAME,SpringJUnit4ClassRunner.class.getClassLoader());if (!junit4dot9Present) {throw new IllegalStateException(String.format("Failed to find class [%s]: SpringJUnit4ClassRunner requires JUnit 4.9 or higher.",MULTIPLE_FAILURE_EXCEPTION_CLASS_NAME));}
注意看第一行是使用静态常量初始化了一个logger对象并且这个Log的类型是org.apache.commons.logging.Log类型,学过类加载的我们都知道,静态常量是在编译器就会进行初始化。
接着进入getFactory方法,首先会获取一个类加载器,我们可以看出是
lanucherAppClassLoader。
接着往下走会往缓存中获取LogFactory,第一次肯定是null的。
接下来加载commons-logging.properties的配置文件,但是咱们没有配置,所以是空的。
最终创建了一个默认的LogFactoryImpl。
调用的LogFactoryImpl来创建Log
后面到discoverLogImplementation方法,确定具体的日志实现。
private Log discoverLogImplementation(String logCategory)throws LogConfigurationException {if (isDiagnosticsEnabled()) {logDiagnostic("Discovering a Log implementation...");}initConfiguration();Log result = null;// See if the user specified the Log implementation to useString specifiedLogClassName = findUserSpecifiedLogClassName();if (specifiedLogClassName != null) {if (isDiagnosticsEnabled()) {logDiagnostic("Attempting to load user-specified log class '" +specifiedLogClassName + "'...");}result = createLogFromClass(specifiedLogClassName,logCategory,true);if (result == null) {StringBuffer messageBuffer = new StringBuffer("User-specified log class '");messageBuffer.append(specifiedLogClassName);messageBuffer.append("' cannot be found or is not useable.");// Mistyping or misspelling names is a common fault.// Construct a good error message, if we caninformUponSimilarName(messageBuffer, specifiedLogClassName, LOGGING_IMPL_LOG4J_LOGGER);informUponSimilarName(messageBuffer, specifiedLogClassName, LOGGING_IMPL_JDK14_LOGGER);informUponSimilarName(messageBuffer, specifiedLogClassName, LOGGING_IMPL_LUMBERJACK_LOGGER);informUponSimilarName(messageBuffer, specifiedLogClassName, LOGGING_IMPL_SIMPLE_LOGGER);throw new LogConfigurationException(messageBuffer.toString());}return result;}
最终确定为jdk的日志实现。
由于spring也是使用的org.apache.commons.logging.Log作为日志适配器,,所以会使用缓存的日志工厂LogFactoryImpl,即其日志实现也是jdk的日志,,所以和咱们自己配置log4j实现根本无关也就造成了spring上下文的日志未写入文件。
三、问题解决
怎么解决这个问题呢?这边有两个方案。
方案1:刚刚我们在调试模式模式的时,实例化LogFatory时会加载一个commons-logging.properties然后在该配置文件中加入属性
org.apache.commons.logging.LogFactory=XXX,其中XXX是自定义的LogFactory,然后在该LogFactory中指定日志的实现,但是这种方式还是有些复杂的。
方案2:使用spring的jcl方案,其实这个jcl方案是我参考了springboot启动时的日志实现原理,所以咱们只要引入下面的依赖,版本可以看实际情况,本项目的spring版本为4.2.4。
<dependency><groupId>org.springframework</groupId><artifactId>spring-jcl</artifactId><version>5.3.5</version></dependency>
其原理是基于spi机制,通过LogAdapter进行检测具体的日志实现。
LogAdapter的static静态代码块会确定具体的日志实现。
四、结果
集成spring jcl后,咱么在启动测试类,观察结果返现控制台即文件输出日志都换成了咱们指定的log4j日志实现。
而且咱们使用jetty的maven插件,启动咱们的项目,也是有相同效果的。
五、最后
完整项目,大家可以到我的码云自行下载:
https://gitee.com/whhdev/vat/tree/master