当热部署SpringMVC应用到Tomcat7时出现OutOfMemoryError-可能与log4j2有关[英] OutOfMemoryError when hot-deploying SpringMVC app to Tomcat7 - possible relation to log4j2

问题描述

I am having trouble Hot Deploying a Spring-MVC 4.0 (not SpringBoot) Web Application. I am trying to go xml-less and just use JavaConfig. OutOfMemoryErrors result when I remove web.xml, or when I deploy an empty web.xml with nothing but an empty element. This does not happen every time the app is hot-deployed, and after a successful hot-deployment, the app does work correctly, but after three or four hot-deployments with this configuration the following error occurs:

Jul 03, 2015 10:49:43 AM org.springframework.web.context.ContextLoader initWebApplicationContext
    SEVERE: Context initialization failed
    java.lang.OutOfMemoryError: PermGen space
            at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.doCreateBean(AbstractAutowireCapableBeanFactory.java:547)
            at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.createBean(AbstractAutowireCapableBeanFactory.java:476)
            at org.springframework.beans.factory.support.AbstractBeanFactory$1.getObject(AbstractBeanFactory.java:303)
            at org.springframework.beans.factory.support.DefaultSingletonBeanRegistry.getSingleton(DefaultSingletonBeanRegistry.java:230)
            at org.springframework.beans.factory.support.AbstractBeanFactory.doGetBean(AbstractBeanFactory.java:299)
            at org.springframework.beans.factory.support.AbstractBeanFactory.getBean(AbstractBeanFactory.java:199)
            at org.springframework.context.support.PostProcessorRegistrationDelegate.registerBeanPostProcessors(PostProcessorRegistrationDelegate.java:220)
            at org.springframework.context.support.AbstractApplicationContext.registerBeanPostProcessors(AbstractApplicationContext.java:615)
            at org.springframework.context.support.AbstractApplicationContext.refresh(AbstractApplicationContext.java:465)
            at org.springframework.web.context.ContextLoader.configureAndRefreshWebApplicationContext(ContextLoader.java:403)
            at org.springframework.web.context.ContextLoader.initWebApplicationContext(ContextLoader.java:306)
            at org.springframework.web.context.ContextLoaderListener.contextInitialized(ContextLoaderListener.java:106)
            at org.apache.catalina.core.StandardContext.listenerStart(StandardContext.java:5014)
            at org.apache.catalina.core.StandardContext.startInternal(StandardContext.java:5524)
            at org.apache.catalina.util.LifecycleBase.start(LifecycleBase.java:150)
            at org.apache.catalina.core.ContainerBase.addChildInternal(ContainerBase.java:901)
            at org.apache.catalina.core.ContainerBase.addChild(ContainerBase.java:877)
            at org.apache.catalina.core.StandardHost.addChild(StandardHost.java:649)
            at org.apache.catalina.startup.HostConfig.deployWAR(HostConfig.java:1081)
            at org.apache.catalina.startup.HostConfig$DeployWar.run(HostConfig.java:1877)
            at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
            at java.util.concurrent.FutureTask.run(FutureTask.java:262)
            at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
            at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
            at java.lang.Thread.run(Thread.java:745)

    Jul 03, 2015 10:49:44 AM org.apache.catalina.core.ContainerBase$ContainerBackgroundProcessor run
    SEVERE: Unexpected death of background thread ContainerBackgroundProcessor[StandardEngine[Catalina]]
    java.lang.OutOfMemoryError: PermGen space
            at java.util.concurrent.FutureTask.report(FutureTask.java:122)
            at java.util.concurrent.FutureTask.get(FutureTask.java:188)
            at org.apache.catalina.startup.HostConfig.deployWARs(HostConfig.java:816)
            at org.apache.catalina.startup.HostConfig.deployApps(HostConfig.java:488)
            at org.apache.catalina.startup.HostConfig.check(HostConfig.java:1655)
            at org.apache.catalina.startup.HostConfig.lifecycleEvent(HostConfig.java:328)
            at org.apache.catalina.util.LifecycleSupport.fireLifecycleEvent(LifecycleSupport.java:117)
            at org.apache.catalina.util.LifecycleBase.fireLifecycleEvent(LifecycleBase.java:90)
            at org.apache.catalina.core.ContainerBase.backgroundProcess(ContainerBase.java:1374)
            at org.apache.catalina.core.ContainerBase$ContainerBackgroundProcessor.processChildren(ContainerBase.java:1546)
            at org.apache.catalina.core.ContainerBase$ContainerBackgroundProcessor.processChildren(ContainerBase.java:1556)
            at org.apache.catalina.core.ContainerBase$ContainerBackgroundProcessor.run(ContainerBase.java:1524)
            at java.lang.Thread.run(Thread.java:745)

    Exception in thread "ContainerBackgroundProcessor[StandardEngine[Catalina]]" java.lang.OutOfMemoryError: PermGen space
            at java.util.concurrent.FutureTask.report(FutureTask.java:122)
            at java.util.concurrent.FutureTask.get(FutureTask.java:188)
            at org.apache.catalina.startup.HostConfig.deployWARs(HostConfig.java:816)
            at org.apache.catalina.startup.HostConfig.deployApps(HostConfig.java:488)
            at org.apache.catalina.startup.HostConfig.check(HostConfig.java:1655)
            at org.apache.catalina.startup.HostConfig.lifecycleEvent(HostConfig.java:328)
            at org.apache.catalina.util.LifecycleSupport.fireLifecycleEvent(LifecycleSupport.java:117)
            at org.apache.catalina.util.LifecycleBase.fireLifecycleEvent(LifecycleBase.java:90)
            at org.apache.catalina.core.ContainerBase.backgroundProcess(ContainerBase.java:1374)
            at org.apache.catalina.core.ContainerBase$ContainerBackgroundProcessor.processChildren(ContainerBase.java:1546)
            at org.apache.catalina.core.ContainerBase$ContainerBackgroundProcessor.processChildren(ContainerBase.java:1556)
            at org.apache.catalina.core.ContainerBase$ContainerBackgroundProcessor.run(ContainerBase.java:1524)
            at java.lang.Thread.run(Thread.java:745)

Evidently memory is leaking with this configuration somehow.

It may or may not be relevant that this web application uses Log4j2. An earlier Stack Overflow question explored this. If the web application uses just the following minimal web.xml

<?xml version="1.0"?>
<web-app 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-app_3_0.xsd"
          version="3.0">

    <context-param>
        <param-name>log4jConfiguration</param-name>
        <param-value>file:///path/to/log4j2.xml</param-value>
    </context-param> 

</web-app>

then the WebApp can be hot-deployed over and over without getting these errors.

Can anyone hazard a guess at what could be going on here?

Update: - See the discussion between @Makoton and myself below. It appears that there may well be a Garbage collection issue relating to loading log4j2 from the application (the Java Config way) vs loading it from web.xml (the traditional way). See this article which debunks the "classic" Stack Overflow suggestion for this problem (similar to that cited by Makoton).

This makes me think about SpringBoot, which, as I understand it, loads Tomcat as part of the application. This might be one solution to this problem.

推荐答案

I believe Luke is right that this issue may be caused by a bug in Log4j2.

The bug is that if the <display-name> element is not present in the web.xml, the Log4jServletContextListener class responsible for log4j resource management can only start, but not stop log4j.

This means that no cleanup happens when the web application is stopped or restarted. JMX MBeans are not unregistered, but also any threads are not stopped, and as a result Log4j classes are not unloaded. The leaked memory grows every time the web app is restarted, because each web app has its own classloader (so the VM sees them as different classes).

This bug is fixed in Git master now and the fix will be part of the log4j 2.5 release. Meanwhile, please use a <display-name> element in your web.xml.

其他推荐答案

I believe that this is a bug in Log4j2.

I've been looking into similar PermGen memory leaks in an application I work on. By using a profiler I could see that when Log4j2 was shutting down it was not deregistering all of the JMX management MBeans it had previously registered. Because these MBeans were left in the JVM's internal MBean registry, the undeployed web application's classes couldn't be entirely removed from memory because there were references to instances of these classes.

Like you in your previous question, I too was seeing Log4j2 generate the message

No Log4j context configuration provided. This is very unusual.

during startup. In my case, however, the fix was somewhat odd - the web app didn't have a <display-name> set in our web.xml, and giving it a display name made that message and the memory leak go away!

I suspect that there is a bug in Log4j2 in that it doesn't deregister MBeans it registered if it is started without the context it mentions. Passing a display name is one way to create enough of a context, adding a context param for the location of the configuration appears to be another. I will look at raising an issue for this if there isn't already one.There is currently an issue on the Log4j2 JIRA that mentions problems if the display-name is missing, I've now added a comment to this issue to mention that there is also a memory leak in this situation.

As far as I see it, you have three options.

1. Live with a web.xml file. It's possible that it would only need to have a <display-name>.

2. Disable JMX in Log4j2 by setting the system property log4j2.disable.jmx to true. (This is best done with a command-line argument -Dlog4j2.disable.jmx=true.) This option is mentioned in the Log4j2 JMX documentation.

3. Look into Mattias Jiderhamn's ClassLoaderLeakPreventor library. One of its functions during web application shutdown is to deregister any MBeans that a web application registered but didn't deregister. You wouldn't be able to use the library as a JAR file directly because it needs to be added to web.xml as a listener, presumably for the benefit of those still using older Servlets versions. However, there are some options to get around this.

   Firstly, there is only one .java file in this library, and you could perhaps include its source (or just the parts of its source that unregister MBeans) in your application if you also add a @WebListener annotation to the class. Secondly, you could extend the ClassLoaderLeakPreventor class and add the @WebListener annotation to your subclass.

其他推荐答案

Long time ago I have the same problem with tomcat7 hot deployment. When i start to using JAVA_OPTS with

-XX:+CMSClassUnloadingEnabled

solve my problem. I would like to explain, but i think that are better explanations.

What does JVM flag CMSClassUnloadingEnabled actually do?

http://frankkieviet.blogspot.ca/2006/10/classloader-leaks-dreaded-permgen-space.html