| [备忘]spring5.x版本，log4j2里${web:rootDir}不生效的原因 | ||
上一篇:[备忘]spring+quartz升级quartz版本后报错： There is no DataSource named ... |
||
| 添加日期：2025/9/16 12:03:55 | 快速返回 返回列表 | 阅读96次 |
<!--log4j2核心包--> <dependency> <groupId>org.apache.logging.log4j</groupId> <artifactId>log4j-api</artifactId> <version>2.17.2</version> </dependency> <dependency> <groupId>org.apache.logging.log4j</groupId> <artifactId>log4j-core</artifactId> <version>2.17.2</version> </dependency> <!-- Web项目需添加 --> <dependency> <groupId>org.apache.logging.log4j</groupId> <artifactId>log4j-web</artifactId> <version>2.17.2</version> </dependency> <!--用于与slf4j保持桥接--> <dependency> <groupId>org.apache.logging.log4j</groupId> <artifactId>log4j-slf4j-impl</artifactId> <version>2.17.2</version> </dependency> <!-- slf4j核心包--> <!--log4j-slf4j-impl should be used with SLF4J 1.7.x releases or older.--> <dependency> <groupId>org.slf4j</groupId> <artifactId>slf4j-api</artifactId> <version>1.7.36</version> </dependency> <dependency> <groupId>com.lmax</groupId> <artifactId>disruptor</artifactId> <version>3.4.4</version> </dependency> log4j2.xml <Configuration status="info" monitorInterval="120"> <Properties> <Property name="logPath">${web:rootDir}/../data/log</Property> </Properties> <Appenders> <Console name="CONSOLE" target="SYSTEM_OUT"> <PatternLayout pattern="[%d{yyyy-MM-dd HH:mm:ss}] [%t] %-5p %l %m%n"/> </Console> <RollingRandomAccessFile name="QueryOrderAppender" immediateFlush="false" fileName="${logPath}/QueryOrderAppender.log" filePattern="${logPath}/QueryOrderAppender-%d{yyyy-MM-dd}-%i.log"> <Filters><ThresholdFilter level="INFO" onMatch="ACCEPT" onMismatch="DENY"/></Filters> <PatternLayout charset="UTF-8" pattern="[%d{yyyy-MM-dd HH:mm:ss.SSS}][%X{log4jMDCNum}][%X{shopId}][%X{userId}][%p][%t][%l][%x] %n%m%n"/> <Policies> <TimeBasedTriggeringPolicy /> <SizeBasedTriggeringPolicy size="100 MB"/> </Policies> <DefaultRolloverStrategy max="10"/> </RollingRandomAccessFile> 报错信息： java.nio.file.InvalidPathException: Illegal char <:> at index 5: ${web:rootDir}..\data\log\QueryOrderAppender.log at sun.nio.fs.WindowsPathParser.normalize(WindowsPathParser.java:182) at sun.nio.fs.WindowsPathParser.parse(WindowsPathParser.java:153) at sun.nio.fs.WindowsPathParser.parse(WindowsPathParser.java:77) at sun.nio.fs.WindowsPath.parse(WindowsPath.java:94) at sun.nio.fs.WindowsFileSystem.getPath(WindowsFileSystem.java:255) at java.io.File.toPath(File.java:2273) at org.apache.logging.log4j.core.appender.rolling.AbstractRolloverStrategy.getEligibleFiles(AbstractRolloverStrategy.java:136) at org.apache.logging.log4j.core.appender.rolling.AbstractRolloverStrategy.getEligibleFiles(AbstractRolloverStrategy.java:96) at org.apache.logging.log4j.core.appender.rolling.AbstractRolloverStrategy.getEligibleFiles(AbstractRolloverStrategy.java:87) at org.apache.logging.log4j.core.appender.rolling.DefaultRolloverStrategy.purgeAscending(DefaultRolloverStrategy.java:415) at org.apache.logging.log4j.core.appender.rolling.DefaultRolloverStrategy.purge(DefaultRolloverStrategy.java:402) at org.apache.logging.log4j.core.appender.rolling.DefaultRolloverStrategy.rollover(DefaultRolloverStrategy.java:531) at org.apache.logging.log4j.core.appender.rolling.RollingFileManager.rollover(RollingFileManager.java:502) at org.apache.logging.log4j.core.appender.rolling.RollingFileManager.rollover(RollingFileManager.java:392) at org.apache.logging.log4j.core.appender.rolling.RollingFileManager.checkRollover(RollingFileManager.java:308) at org.apache.logging.log4j.core.appender.RollingRandomAccessFileAppender.append(RollingRandomAccessFileAppender.java:240) at org.apache.logging.log4j.core.config.AppenderControl.tryCallAppender(AppenderControl.java:161) at org.apache.logging.log4j.core.config.AppenderControl.callAppender0(AppenderControl.java:134) at org.apache.logging.log4j.core.config.AppenderControl.callAppenderPreventRecursion(AppenderControl.java:125) at org.apache.logging.log4j.core.config.AppenderControl.callAppender(AppenderControl.java:89) at org.apache.logging.log4j.core.config.LoggerConfig.callAppenders(LoggerConfig.java:675) at org.apache.logging.log4j.core.config.LoggerConfig.processLogEvent(LoggerConfig.java:633) at org.apache.logging.log4j.core.config.LoggerConfig.log(LoggerConfig.java:616) at org.apache.logging.log4j.core.config.LoggerConfig.log(LoggerConfig.java:604) at org.apache.logging.log4j.core.config.AwaitCompletionReliabilityStrategy.log(AwaitCompletionReliabilityStrategy.java:98) at org.apache.logging.log4j.core.async.AsyncLogger.actualAsyncLog(AsyncLogger.java:488) at org.apache.logging.log4j.core.async.RingBufferLogEvent.execute(RingBufferLogEvent.java:156) at org.apache.logging.log4j.core.async.RingBufferLogEventHandler.onEvent(RingBufferLogEventHandler.java:51) at org.apache.logging.log4j.core.async.RingBufferLogEventHandler.onEvent(RingBufferLogEventHandler.java:29) at com.lmax.disruptor.BatchEventProcessor.processEvents(BatchEventProcessor.java:168) at com.lmax.disruptor.BatchEventProcessor.run(BatchEventProcessor.java:125) at java.lang.Thread.run(Thread.java:750) 结果，日志输出在tomcat的bin/data/log下，而不是预想的程序目录的../data/log目录。 =============================================== 研究过程： log4j2是通过Log4jServletContainerInitializer自动配置的， public class Log4jServletContainerInitializer implements ServletContainerInitializer { 它启动很早，比spring都早 org.apache.logging.log4j.web.WebLookup.java提供了${web:rootDir}的替换功能。 大致过程就是Log4jServletContainerInitializer里初始化配置信息，替换${xx}，这些变量 ${xx}有很多写法，可以参考：https://logging.apache.org/log4j/2.x/manual/lookups.html ----------------- 研究了好几天。 搭建了一个最小化的工程，没有问题。 但我的大工程就是不行。 @Plugin(name = "RollingRandomAccessFile", category = Core.CATEGORY_NAME, elementType = Appender.ELEMENT_TYPE, printObject = true) public final class RollingRandomAccessFileAppender extends AbstractOutputStreamAppender<RollingRandomAccessFileManager> { public static class Builder<B extends Builder<B>> extends AbstractOutputStreamAppender.Builder<B> implements org.apache.logging.log4j.core.util.Builder<RollingRandomAccessFileAppender> { public Builder() { withBufferSize(RollingRandomAccessFileManager.DEFAULT_BUFFER_SIZE); setIgnoreExceptions(true); withImmediateFlush(true); } @PluginBuilderAttribute("fileName") private String fileName; @PluginBuilderAttribute("filePattern") private String filePattern; 这里的fileName等变量，是外面调用者通过反射注入的。 小工程下断点，发现这里都替换完毕了，没有问题 大工程下断点，发现没有替换。 在WebLookUp下断点，发现前面N次调用，ServletContext都是null，导致${web:rootDir}没有替换。 @Plugin(name = "web", category = "Lookup") public class WebLookup extends AbstractLookup { private static final String ATTR_PREFIX = "attr."; private static final String INIT_PARAM_PREFIX = "initParam."; @Override public String lookup(final LogEvent event, final String key) { final ServletContext ctx = WebLoggerContextUtils.getServletContext(); if (ctx == null) { return null; } 查看堆栈，发现是tomcat初始化websocket时调用的，堆栈如下： lookup:36, WebLookup (org.apache.logging.log4j.web) evaluate:119, StrLookup (org.apache.logging.log4j.core.lookup) evaluate:43, AbstractLookup (org.apache.logging.log4j.core.lookup) evaluate:190, Interpolator (org.apache.logging.log4j.core.lookup) resolveVariable:1183, StrSubstitutor (org.apache.logging.log4j.core.lookup) substitute:1098, StrSubstitutor (org.apache.logging.log4j.core.lookup) substitute:974, StrSubstitutor (org.apache.logging.log4j.core.lookup) replace:488, StrSubstitutor (org.apache.logging.log4j.core.lookup) visit:53, PluginValueVisitor (org.apache.logging.log4j.core.config.plugins.visitors) generateParameters:264, PluginBuilder (org.apache.logging.log4j.core.config.plugins.util) build:137, PluginBuilder (org.apache.logging.log4j.core.config.plugins.util) createPluginObject:1122, AbstractConfiguration (org.apache.logging.log4j.core.config) createConfiguration:1047, AbstractConfiguration (org.apache.logging.log4j.core.config) createConfiguration:1039, AbstractConfiguration (org.apache.logging.log4j.core.config) doConfigure:628, AbstractConfiguration (org.apache.logging.log4j.core.config) initialize:249, AbstractConfiguration (org.apache.logging.log4j.core.config) start:295, AbstractConfiguration (org.apache.logging.log4j.core.config) setConfiguration:621, LoggerContext (org.apache.logging.log4j.core) reconfigure:694, LoggerContext (org.apache.logging.log4j.core) reconfigure:711, LoggerContext (org.apache.logging.log4j.core) start:253, LoggerContext (org.apache.logging.log4j.core) start:76, AsyncLoggerContext (org.apache.logging.log4j.core.async) getContext:155, Log4jContextFactory (org.apache.logging.log4j.core.impl) getContext:47, Log4jContextFactory (org.apache.logging.log4j.core.impl) getContext:196, LogManager (org.apache.logging.log4j) <clinit>:155, LogAdapter$Log4jLog (org.apache.commons.logging) createLog:122, LogAdapter$Log4jAdapter (org.apache.commons.logging) createLog:89, LogAdapter (org.apache.commons.logging) getInstance:46, LogFactoryService (org.apache.commons.logging) getInstance:41, LogFactoryService (org.apache.commons.logging) getLog:351, LogFactory (org.apache.commons.logging) <clinit>:57, SpringConfigurator (org.springframework.web.socket.server.standard) newInstance0:-1, NativeConstructorAccessorImpl (sun.reflect) newInstance:62, NativeConstructorAccessorImpl (sun.reflect) newInstance:45, DelegatingConstructorAccessorImpl (sun.reflect) newInstance:423, Constructor (java.lang.reflect) addEndpoint:240, WsServerContainer (org.apache.tomcat.websocket.server) onStartup:116, WsSci (org.apache.tomcat.websocket.server) startInternal:4491, StandardContext (org.apache.catalina.core) start:164, LifecycleBase (org.apache.catalina.util) addChildInternal:599, ContainerBase (org.apache.catalina.core) addChild:571, ContainerBase (org.apache.catalina.core) addChild:603, StandardHost (org.apache.catalina.core) manageApp:1746, HostConfig (org.apache.catalina.startup) invoke0:-1, NativeMethodAccessorImpl (sun.reflect) invoke:62, NativeMethodAccessorImpl (sun.reflect) invoke:43, DelegatingMethodAccessorImpl (sun.reflect) invoke:498, Method (java.lang.reflect) invoke:252, BaseModelMBean (org.apache.tomcat.util.modeler) invoke:819, DefaultMBeanServerInterceptor (com.sun.jmx.interceptor) invoke:801, JmxMBeanServer (com.sun.jmx.mbeanserver) createStandardContext:449, MBeanFactory (org.apache.catalina.mbeans) createStandardContext:403, MBeanFactory (org.apache.catalina.mbeans) invoke0:-1, NativeMethodAccessorImpl (sun.reflect) invoke:62, NativeMethodAccessorImpl (sun.reflect) invoke:43, DelegatingMethodAccessorImpl (sun.reflect) invoke:498, Method (java.lang.reflect) invoke:252, BaseModelMBean (org.apache.tomcat.util.modeler) invoke:819, DefaultMBeanServerInterceptor (com.sun.jmx.interceptor) invoke:801, JmxMBeanServer (com.sun.jmx.mbeanserver) invoke:468, MBeanServerAccessController (com.sun.jmx.remote.security) doOperation:1468, RMIConnectionImpl (javax.management.remote.rmi) access$300:76, RMIConnectionImpl (javax.management.remote.rmi) run:1309, RMIConnectionImpl$PrivilegedOperation (javax.management.remote.rmi) doPrivileged:-1, AccessController (java.security) doPrivilegedOperation:1408, RMIConnectionImpl (javax.management.remote.rmi) invoke:829, RMIConnectionImpl (javax.management.remote.rmi) invoke0:-1, NativeMethodAccessorImpl (sun.reflect) invoke:62, NativeMethodAccessorImpl (sun.reflect) invoke:43, DelegatingMethodAccessorImpl (sun.reflect) invoke:498, Method (java.lang.reflect) dispatch:357, UnicastServerRef (sun.rmi.server) run:200, Transport$1 (sun.rmi.transport) run:197, Transport$1 (sun.rmi.transport) doPrivileged:-1, AccessController (java.security) serviceCall:196, Transport (sun.rmi.transport) handleMessages:573, TCPTransport (sun.rmi.transport.tcp) run0:834, TCPTransport$ConnectionHandler (sun.rmi.transport.tcp) lambda$run$0:688, TCPTransport$ConnectionHandler (sun.rmi.transport.tcp) run:-1, 610806165 (sun.rmi.transport.tcp.TCPTransport$ConnectionHandler$$Lambda$27) doPrivileged:-1, AccessController (java.security) run:687, TCPTransport$ConnectionHandler (sun.rmi.transport.tcp) runWorker:1149, ThreadPoolExecutor (java.util.concurrent) run:624, ThreadPoolExecutor$Worker (java.util.concurrent) run:750, Thread (java.lang) tomcat的WsSci也是一个ServletContainerInitializer，实际情况是它先执行了。 在它的onStartup()方法里会扫描注解@ServerEndpoint，然后创建configurator实例 @ServerEndpoint(value = "/websocket/xxx", configurator = SpringConfigurator.class) 这里是SpringConfigurator，大概意思是使用spring的变量注入吧。 而SpringConfigurator里有logger变量，导致log4j2提前初始化。 public class SpringConfigurator extends Configurator { private static final Log logger = LogFactory.getLog(SpringConfigurator.class); 然后，log4j2的Log4jServletContainerInitializer才执行初始化。 所以，根本原因是两个ServletContainerInitializer 执行顺序问题。 在log-web.jar/META-INF/web-fragment.xml里，有 <web-fragment xmlns="http://java.sun.com/xml/ns/javaee" xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance" xsi:schemaLocation="http://java.sun.com/xml/ns/javaee http://java.sun.com/xml/ns/javaee/web-fragment_3_0.xsd" version="3.0" metadata-complete="true"> <!-- The Log4j web fragment must be loaded before all other fragments. The configuration below should make this happen automatically. If you experience problems, try specifying an <absolute-ordering> in your web.xml deployment descriptor. --> <name>log4j</name> <distributable /> <ordering> <before> <others /> </before> </ordering> </web-fragment> 理论上，log4j应该先执行，不知道为啥后执行的。 具体怎么解决，还没想好。 试验了，把所有@ServerEndpoint注解都注释掉，就没问题了。 ======================================================= 继续研究，下载了tomcat源代码，远程调试下断点， 发现启动时，共有4个Initializer，顺序如下： ---- JasperInitializer WsSci Log4jServletContainerInitializer SpringServletContainerInitializer ---- 看来，这个顺序应该没有问题。 本次工程修改，是升级了一堆jar包版本，包括spring，log4j等版本。 spring从4.1.7升级到5.3.39版本 用旧工程，发现没有问题。 因为LogFactory.getLog()返回的是JDK14Logger，也就是没有发现高级logger， 降级到默认的commons.logger那个东西。 没有使用Log4j2，自然没进WebLookUp的断点，也自然没有影响log4j2。 （log4j2初始化时，会生成一堆logManager，里面会替换变量，只生成一次。 如果第一次没替换掉，后面也就那样了） 用新工程，发现走了spring-jcl的代码， org.apache.commons.logging.LogAdapter.java这个文件，包名还是apache的呢 它判断存在log4j2的类，就直接走log4j2的初始化了。 从Spring5开始，spring-core 模块的日志依赖已经从原生的 commons-logging 改为了自家的 spring-jcl。 看来，这是根本原因了！！！！ 升级到spring 5.x版本后，由于spring-jcl的判断方式，识别为log4j2， 在初始化websocket阶段，提前初始化了log4j2，导致log4j2的不正常。 在旧版本，没识别到log4j2，反倒没事。 ======================================================== 怎么解决呢？我也不知道！！ 先不用${web.rootDir}了。 ============================================================ 补记： 之前将spring版本换回4.1.7也不行，是因为没换干净。 [INFO] +- org.springframework.amqp:spring-amqp:jar:2.4.17:compile [INFO] | \- org.springframework:spring-core:jar:5.3.30:compile [INFO] | \- org.springframework:spring-jcl:jar:5.3.30:compile 这个amqp版本是新的，它引用了5.3.30的core.jar，里面引用了spring-jcl，导致不行。 把这个版本也退回去， mvn dependency:tree -Dincludes=org.springframework 用这个命令看看，确保没有spring-jcl， 在spring 4.1.7版本下，会使用JDK14Logger，没问题。 ============================================================ 至此，所有疑惑得到了解释！！！！！ ============================================================ 我提的工单，呵呵 https://github.com/apache/logging-log4j2/issues/3927 |
||
| 评论 COMMENTS | |
| 没有评论 No Comments. |
