一、现象
最近在编写传统的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 {
@Autowired
ApplicationContext ctx;
private static Logger LOGGER = LoggerFactory.getLogger(MvcTest.class);
@Test
public 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 RunAfterTestMethodCallbacks
private 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 use
String 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 can
informUponSimilarName(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