Log4j 2
  1. Log4j 2
  2. LOG4J2-406

JMX MBeans are not being unregistered when a tomcat web application that uses log4j is undeployed, leading to a permgen memory leak.

    Details

    • Type: Bug Bug
    • Status: Resolved
    • Priority: Major Major
    • Resolution: Fixed
    • Affects Version/s: 2.0-beta9
    • Fix Version/s: 2.0-rc1, 2.0
    • Component/s: Core, JMX
    • Labels:
      None
    • Environment:

      Java 1.7.0_17-b02, tomcat 7.0.34.0, NetBeans 7.3, Windows 7 (64 bit)

      Description

      When the log4j2 library is being used with a tomcat web application (included in the web application's libraries, not in the container's libraries), tomcat correctly discovers and initializes the Log4jServletContainerInitializer and adds the Log4JServletContextListener as described in the manual (after removing "log4j*.jar" from the jarsToSkip property as described on that page). However, two MBeans that log4j registers (ContextSelector and StatusLogger) are never unregistered when the web application is undeployed. This prevents the entire web application from being garbage collected and leads to a permgen memory leak and causes an OutOfMemoryError after a few undeploy/redeploy cycles*.

      We could work around this by taking the following steps:

      1. Added a context parameter to the web.xml file specifying a value for the log4jContextName parameter. This seems to prevent java.lang.ApplicationShutdownHooks from keeping a refernce to the log4j LoggerContext, which was part of why the memory leak was occuring**.
      2. In addition, took one of the following measures:
        • Added the log4j2 libraries to tomcat's classpath. Regardless of whether or not the libraries were in the web application's classpath, this seemed to circumvent the entire issue.
        • Disabled jmx entirely, by adding -Dlog4j.disable.jmx=true to the JVM options for tomcat.
        • Added a custom ServletContextListener which manually unregisters all log4j MBeans upon the destruction of the context.

      Any of the steps from 2 worked equally well, but none of them worked unless we also took step 1.

      * We used jmap and jhat to confirm that the application was not being unloaded from memory after being undeployed, and were able to narrow the cause down to those MBeans by tracing a reference path from the StandardClassloader through them to the WebappClassLoader.
      ** We're unsure of what role ApplicationShutdownHooks plays in this scenario, but we observed in jhat that the reference path between log4j and ApplicationShutdownHooks disappeared after adding the log4jContextName parameter, and that this was necessary to stop the permgen memory leak.

      1. PermGen.zip
        743 kB
        Kerrigan Joseph

        Issue Links

          Activity

          Hide
          Nick Williams added a comment -

          The ServletContextListener correctly shuts down Log4j. The problem is that shutting down Log4j doesn't remove the MBeans. IMO, it should. Remko, can you take a look at that?

          The ApplicationShutdownHooks should be disabled in a web application environment. I'll look at that this weekend.

          Show
          Nick Williams added a comment - The ServletContextListener correctly shuts down Log4j. The problem is that shutting down Log4j doesn't remove the MBeans. IMO, it should. Remko, can you take a look at that? The ApplicationShutdownHooks should be disabled in a web application environment. I'll look at that this weekend.
          Hide
          Kerrigan Joseph added a comment - - edited

          I've attached a sample netbeans project illustrating the issue. If this project is deployed and undeployed, an examination of a jmap dump of the tomcat process using jhat should indicate that it is still loaded. The web.xml file has some commented out sections that demonstrate one of the workarounds.

          Show
          Kerrigan Joseph added a comment - - edited I've attached a sample netbeans project illustrating the issue. If this project is deployed and undeployed, an examination of a jmap dump of the tomcat process using jhat should indicate that it is still loaded. The web.xml file has some commented out sections that demonstrate one of the workarounds.
          Hide
          Remko Popma added a comment -

          Nick, I did't have much time to work on this but I've added a way to unregister all MBeans associated with a LoggerContext.
          org.apache.logging.log4j.core.jmx.Server#unregisterContext(String loggerContextName)

          Next step would be calling this method when a web application is undeployed.

          Show
          Remko Popma added a comment - Nick, I did't have much time to work on this but I've added a way to unregister all MBeans associated with a LoggerContext. org.apache.logging.log4j.core.jmx.Server#unregisterContext(String loggerContextName) Next step would be calling this method when a web application is undeployed.
          Hide
          Remko Popma added a comment - - edited

          Linked to LOG4J2-323: some more "cleaning-up-resources" work to do at undeploy time.

          (update)
          ... and unlinked as it turns out that the ThreadLocal memory leak can be taken care of internally in the async logging components.

          Show
          Remko Popma added a comment - - edited Linked to LOG4J2-323 : some more "cleaning-up-resources" work to do at undeploy time. (update) ... and unlinked as it turns out that the ThreadLocal memory leak can be taken care of internally in the async logging components.
          Hide
          Remko Popma added a comment -

          Changes:

          • MBeans are now re-registered every time the Configuration is modified (previously there were some code paths where MBeans were not registered).
          • All MBeans are now unregistered when the LoggerContext is stopped. This includes the MBeans for the StatusLogger and ContextSelector.
          • Cleaned up the o.a.l.l.c.jmx.Server class (mixing format changes with logic changes, sorry about that).

          This should solve the problem but when using jhat to view the heap after undeploying the example PermGen application I still see the log4j classes loaded. (Not sure that I did this right...) With another test program I've verified that MBeans are unregistered when the LoggerContext is stopped, though, so is it possible that the problem is caused by something other than the MBeans?

          Note also that this is a stopgap solution. It unregisters all MBeans, so unloading one webapp will unload the MBeans for all other webapps as well. This is clearly not ideal but seemed a lesser evil than causing the app server to crash with an OutOfMemoryError. I will create a separate Jira issue for the permanent solution.

          Fixed in revision 1557654.
          Please verify and close.

          Show
          Remko Popma added a comment - Changes: MBeans are now re-registered every time the Configuration is modified (previously there were some code paths where MBeans were not registered). All MBeans are now unregistered when the LoggerContext is stopped. This includes the MBeans for the StatusLogger and ContextSelector. Cleaned up the o.a.l.l.c.jmx.Server class (mixing format changes with logic changes, sorry about that). This should solve the problem but when using jhat to view the heap after undeploying the example PermGen application I still see the log4j classes loaded. (Not sure that I did this right...) With another test program I've verified that MBeans are unregistered when the LoggerContext is stopped, though, so is it possible that the problem is caused by something other than the MBeans? Note also that this is a stopgap solution. It unregisters all MBeans, so unloading one webapp will unload the MBeans for all other webapps as well. This is clearly not ideal but seemed a lesser evil than causing the app server to crash with an OutOfMemoryError. I will create a separate Jira issue for the permanent solution. Fixed in revision 1557654. Please verify and close.
          Hide
          Kerrigan Joseph added a comment -

          Thanks much! I'll try to poke it a bit and see if I can see why the log4j classes aren't unloading.

          Show
          Kerrigan Joseph added a comment - Thanks much! I'll try to poke it a bit and see if I can see why the log4j classes aren't unloading.
          Hide
          Remko Popma added a comment -

          Thank you! I am not confident that I did the jhat thing right...

          Show
          Remko Popma added a comment - Thank you! I am not confident that I did the jhat thing right...
          Hide
          Remko Popma added a comment -

          This ticket only mentions the stopgap solution. A more fine-grained solution was implemented with LOG4J2-500.

          Show
          Remko Popma added a comment - This ticket only mentions the stopgap solution. A more fine-grained solution was implemented with LOG4J2-500 .

            People

            • Assignee:
              Remko Popma
              Reporter:
              Kerrigan Joseph
            • Votes:
              0 Vote for this issue
              Watchers:
              3 Start watching this issue

              Dates

              • Created:
                Updated:
                Resolved:

                Development