很多人解决这个问题的办法就是修改log4j源码,将文件重命名的代码改为文件复制的代码。
其实找到根本原因,就不需要修改源码了。
- 问题现象:
- 在控制台可以看到日志:log4j:ERROR Failed to rename
- DailyRollingFileAppender没有周期性的生成日志文件,只生成了一个日志文件。
- Tomcat启动慢并且占内存大(修改log4j源码是不能解决这个问题的)
- 问题发生的环境:
- Log4j使用DailyRollingFileAppender周期性生成日志
- 使用Tomcat服务器
- 在tomcat的默认的server.xml里面,错误的配置了Host或者Context标签
- 问题发生的直接原因:
当DailyRollingFileAppender对日志文件进行重命名时,因为其他程序占用了该日志文件,导致重命名失败而报错。
- 问题发生的根本原因:
在tomcat的默认的server.xml里面,错误的配置了Host或者Context标签,这导致了Tomcat多次加载Web工程,进而导致多个DailyRollingFileAppender对象持有相同日志文件。
- 问题的解决方案:
我们在配置域名访问的时候一般会在server.xml里配置新的host,以此为例,其中最关键的地方就是为Context配置name属性
对下面配置的说明:
- path=""时,可以直接用域名(www.xxx.com)来访问工程:web-sys
- path="/web-sys"时,只能通过域名+path(www.xxx.com/web-sys)来访问工程:web-sys
- mywebapps与webapps是同一目录的文件夹,在正确配置里,我们的工程web-sys是放在mywebapps里面的(webapps里面千万不能有web-sys)
- 到底有几个对象占用了文件,可以通过资源监视器来查看。
错误的配置1:这个配置会导致三个对象同时持有日志文件,可以直接用域名访问工程:web-sys
<Host name="www.xxx.com" appBase="webapps" autoDeploy="true" unpackWARs="true">
<Alias>www.xxx.cn</Alias>
<Alias>www.xxx.com.cn</Alias>
<Context docBase="web-sys" path=""/>
</Host>
错误的配置2:这个配置会导致二个对象同时持有日志文件,可以直接用域名访问工程:web-sys
<Host name="www.xxx.com" appBase="mywebapps" autoDeploy="true" unpackWARs="true">
<Alias>www.xxx.cn</Alias>
<Alias>www.xxx.com.cn</Alias>
<Context docBase="web-sys" path=""/>
</Host>
正确的配置1:只有一个对象持有日志文件,不能直接用域名访问工程:web-sys
<Host name="www.xxx.com" appBase="mywebapps" autoDeploy="true" unpackWARs="true">
<Alias>www.xxx.cn</Alias>
<Alias>www.xxx.com.cn</Alias>
<Context docBase="web-sys" path="/web-sys"/>
</Host>
正确的配置2:只有一个对象持有日志文件,可以直接用域名访问工程:web-sys
<Host name="www.xxx.com" appBase="mywebapps" autoDeploy="true" unpackWARs="true">
<Alias>www.xxx.cn</Alias>
<Alias>www.xxx.com.cn</Alias>
<Context docBase="web-sys" path="" name="/web-sys"/>
</Host>
- 关于server.xml配置的总结:
- 如果新增了Host,那Host/appBase的值是不能和其他Host/appBase的值一样的。比如appBase都是webapps,那么两个Host会导致webapps下面的工程被加载两遍。
- 如果配置了Context标签那么就一定要配置name属性值为:工程名(/web-sys),或者配置path值为工程名(/web-sys),否则就会引起重复加载工程的问题。
- <Alias>标签,允许我们把多个域名配置在一个Host下面,例如:xxx.com、xxx.cn、xxx.com.cn,都可以配置在一个Host下面
到这,问题已经解决。推荐使用上面的【正确的配置2】。
下面再分享一下我分析这个问题的过程,不想看的就可以跳过了。
——————————
- 分析过程
- 查看log4j源码,发现log4j:ERROR Failed to rename这个日志是在org.apache.log4j.DailyRollingFileAppender.rollOver()里面输出的
- 找到DailyRollingFileAppender输出日志文件的变量是父类:WriterAppender中的:QuietWriter qw。
- 找到设定qw的地方:org.apache.log4j.FileAppender.setQWForFiles(Writer)
- 在setQWForFiles里设置断点,发现有两个不同的Trace,他们都是用来初始化DispatcherServlet(Spring框架),不同点在Tomcat源码里
- 通过分析Tomcat源码,发现这两个Trace是由两个StandardContext对象:StandardContext[]和StandardContext[/web-sys])发起的。StandardContext[]来自于server.xml配置的Context;standardContext[/web-sys]是根据工程(web-sys),自动生成的。
- StandardContext[]和standardContext[/web-sys]其实代表的都是一个工程(web-sys),但是因为有两个对象,所以工程(web-sys)也被加载了两次。
- 分析StandardContext的生成及调用过程,发现StandardContext[]和StandardContext[/web-sys]最终都会被存储在StandardHost的属性children(HashMap)里,children的KEY是用StandardContext的name属性来标识的
- 分析StandardContext[/web-sys]的生成过程,其中有个判断:如果children里存在相同的StandardContext,就跳过该过程。
- 到这里我们发现了关键的地方,StandardContext[]和standardContext[/web-sys]他们的不同点就在于name属性。
- StandardContext[]的name属性值就来自于server.xml里的Context标签,standardContext[/web-sys]的name属性值来自于工程的名字(/web-sys)
- 如何才能改变StandardContext[]的name属性值呢?这就要从Context标签上面下功夫。
- 在Tomcat官方文档中,Context标签的说明里并没有提到name这个属性,而在StandardContext.setPath(String)里我们发现下面代码,就是说如果没有name,那就把name设定为path的值。
if (getName() == null) { setName(this.path); }
- 我以为只有Context标签的path属性才能改变StandardContext的name属性值。但是为了直接用域名访问工程,path只能为空。
- 分析StandardContext加载Context标签的过程,发现他是通过反射进行设值的。比如Context标签配置了path,它就调用了StandardContext.setPath。那如果Context标签配置了name,它是不是也会调用StandardContext.setName呢?
- 试着在Context标签里配置name属性值为工程名:"/web-sys",发现StandardContext[]的name值变了,而且standardContext[/web-sys]也没有被加载。
- 到此成功。