[
https://issues.apache.org/jira/browse/LOG4J2-529?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=13894570#comment-13894570
]
Remko Popma edited comment on LOG4J2-529 at 2/7/14 2:49 PM:
------------------------------------------------------------
I've attached two webapps (webapp1.war and webapp2.war):
* webapp1.war has no listeners or filters in web.xml (servlet 3.0)
* webapp2.war has servlet 2.5 listeners and filters in web.xml
Apart from the listeners/filters in web.xml, the war files have identical
contents.
I have tested again in a different environment, Tomcat 7.0.40 on my laptop at
home. I can reliably reproduce the problem described above. (This in addition
to my PC at work where I tested with Tomcat 6.0.39, Tomcat 7.0.50 and Tomcat
8.0.1 - all with the same results.)
*Webapp1*
# Just deploying webapp1 *does not register the log4j2 MBeans*.
#* Confirmed no {{org.apache.logging.log4j2}} MBeans exist in JConsole
#* Confirmed no "DEBUG Registering MBean org.apache.logging.log4j2..." status
messages in the Tomcat console
# Opening URL http://localhost:8080/webapp1/log.jsp in a browser _will_ cause
the log4j MBeans to become registered
# Undeploying webapp1 *does not unregister the log4j2 MBeans*
#* JConsole still shows the {{org.apache.logging.log4j2}} MBeans
#* The Tomcat console only says "undeployed webapp1" but does not show status
messages "Unregistering MBean org.apache.logging...."
#* Find Leak button in Tomcat Manager gives a "not all classes unloaded" warning
*Webapp2*
(_Make sure to first undeploy webapp1 and shutdown and restart Tomcat before
testing webapp2._)
# Just deploying webapp2 causes the log4j2 MBeans to become registered. (No
need to open the log.jsp page in a web browser.)
#* JConsole shows {{org.apache.logging.log4j2}} MBeans
#* Tomcat console shows "DEBUG Registering MBean org.apache.logging.log4j2..."
status messages
# Undeploying webapp2 unregisters the log4j2 MBeans (again, checked in
JConsole, Tomcat console and Find Leaks button)
was (Author: [email protected]):
I've attached two webapps (webapp1.war and webapp2.war):
* webapp1.war has no listeners or filters in web.xml (servlet 3.0)
* webapp2.war has servlet 2.5 listeners and filters in web.xml
Apart from the listeners/filters in web.xml, the war files have identical
contents.
I have tested again in a different environment, Tomcat 7.0.40 on my laptop at
home. I can reliably reproduce the problem described above.
*Webapp1*
# Just deploying webapp1 *does not register the log4j2 MBeans*.
#* Confirmed no {{org.apache.logging.log4j2}} MBeans exist in JConsole
#* Confirmed no "DEBUG Registering MBean org.apache.logging.log4j2..." status
messages in the Tomcat console
# Opening URL http://localhost:8080/webapp1/log.jsp in a browser _will_ cause
the log4j MBeans to become registered
# Undeploying webapp1 *does not unregister the log4j2 MBeans*
#* JConsole still shows the {{org.apache.logging.log4j2}} MBeans
#* The Tomcat console only says "undeployed webapp1" but does not show status
messages "Unregistering MBean org.apache.logging...."
#* Find Leak button in Tomcat Manager gives a "not all classes unloaded" warning
*Webapp2*
(_Make sure to first undeploy webapp1 and shutdown and restart Tomcat before
testing webapp2._)
# Just deploying webapp2 causes the log4j2 MBeans to become registered. (No
need to open the log.jsp page in a web browser.)
#* JConsole shows {{org.apache.logging.log4j2}} MBeans
#* Tomcat console shows "DEBUG Registering MBean org.apache.logging.log4j2..."
status messages
# Undeploying webapp2 unregisters the log4j2 MBeans (again, checked in
JConsole, Tomcat console and Find Leaks button)
> Log4j2 does not auto-initialize on webapp deploy or auto-deinitialize on
> undeploy
> ---------------------------------------------------------------------------------
>
> Key: LOG4J2-529
> URL: https://issues.apache.org/jira/browse/LOG4J2-529
> Project: Log4j 2
> Issue Type: Bug
> Components: Configurators, Core, JMX
> Affects Versions: 2.0-beta9, 2.0-rc1
> Environment: Tomcat 7.0.50, Tomcat 8.0.1
> Reporter: Remko Popma
> Attachments: webapp1.war, webapp2.war
>
>
> The log4j2 manuals
> [says|http://logging.apache.org/log4j/2.0/manual/webapp.html#Servlet-3.0]
> that "Log4j 2 "just works" in Servlet 3.0 and newer web applications. It is
> capable of automatically starting when the application deploys and shutting
> down when the application undeploys."
> When testing for LOG4J2-500, I found that this does not seem to be the case,
> at least on Tomcat 7.0.50 and Tomcat 8.0.1.
> *Steps to reproduce the issue*
> # Enable JMX in Tomcat: create a file {{setup.bat}} in the {{bin}} directory
> with the following contents: {{set
> CATALINA_OPTS=-Dcom.sun.management.jmxremote
> -Dcom.sun.management.jmxremote.port=54321
> -Dcom.sun.management.jmxremote.ssl=false
> -Dcom.sun.management.jmxremote.authenticate=false}}
> # To test, I used the Tomcat [sample web
> app|http://tomcat.apache.org/tomcat-6.0-doc/appdev/sample/], with the
> following modifications:
> #* add log4j-api-2.0RC1-SNAPSHOT.jar to WEB-INF/lib
> #* add log4j-core-2.0RC1-SNAPSHOT.jar to WEB-INF/lib
> #* put log4j2.xml in WEB-INF/classes. Any valid config with
> {{status="trace"}} should be sufficient.
> #* copy hello.jsp to log.jsp and add these lines:
> {code}
> <% org.apache.logging.log4j.Logger logger =
> org.apache.logging.log4j.LogManager.getLogger(); %>
> <% logger.info("Logging from JSP"); %>
> <%= new String("Hello! LOGGED FROM JSP OK.") %>
> {code}
> # create {{webapp1.war}} from the above
> # deploy webapp1. Note that in the Tomcat console you will only see "INFO:
> Deploying web application archive
> D:\apps\apache-tomcat-7.0.50\webapps\webapp1.war", you will *not* see the
> Log4J initialization status messages (like "Generated plugins in 0.175750656
> seconds", or "Registering MBean org.apache.logging.log4j2:type=...")
> # Open JConsole, and connect to "localhost:54321". In the MBeans tab, you
> will *not* see MBeans for {{org.apache.logging.log4j2}}.
> # In a browser, open URL http://localhost:8080/webapp1/log.jsp
> #* In the Tomcat console you should now see "Generated plugins in 0.000016172
> seconds" and "Registering MBean org.apache.logging.log4j2"
> #* In JConsole you should now see MBeans for {{org.apache.logging.log4j2}}.
> The LoggerContext name looks something like
> {{"org.apache.jasper.servlet.JasperLoader@7da612aa"}}.
> # Now, _undeploy_ webapp1.
> #* *Bad sign #1:* in the Tomcat console I only see "INFO: Undeploying context
> /webapp1", I don't see any status messages for Log4J unloading. For example,
> I don't see any "Unregistering MBean ..." messages.
> #* *Bad sign #2:* in JConsole, the MBeans for {{org.apache.logging.log4j2}}
> are still displayed. Accessing their attributes may cause errors in the
> Tomcat console ("INFO: Illegal access: this web application instance has been
> stopped already. Could not load
> sun.reflect.SerializationConstructorAccessorImpl. The eventual following
> stack trace is caused by an error thrown for debugging purposes as well as to
> attempt to terminate the thread which caused the illegal access, and has no
> functional impact. java.lang.IllegalStateException...")
> #* *Bad sign #3:* In the Tomcat manager app, pressing the "Find Leaks" button
> shows this message: "The following web applications were stopped (reloaded,
> undeployed), but their classes from previous runs are still loaded in memory,
> thus causing a memory leak (use a profiler to confirm): /webapp1"
> So with the default setup, undeploying a webapp with log4j2 in its
> WEB-INF/lib folder does not automatically call {{LoggerContext.stop()}}.
> Things do seem to work better if I modify the {{web.xml}} file and add the
> listener, filter and filter-mapping [recommended for Servlet 2.5 web
> applications|http://logging.apache.org/log4j/2.0/manual/webapp.html#Servlet-2.5].
> # create webapp2.war with the modified {{web.xml}} file
> # shutdown and startup Tomcat/7.0.50
> # deploy webapp2.war. *_Do not open log.jsp in a browser yet._* In this case
> I immediately see Log4J initialization status messages like "Generated
> plugins in 0.000019904 seconds" and "Registering MBean
> org.apache.logging.log4j2..."
> # open JConsole, and connect to "localhost:54321". In the MBeans tab, I can
> see MBeans for {{org.apache.logging.log4j2}}.
> #* Interestingly, the LoggerContext name is very different now. It looks like
> this: "WebappClassLoader\n context: /webapp2\n delegate: false\n
> repositories:\n /WEB-INF/classes/\n----------> Parent
> Classloader:\norg.apache.catalina.loader.StandardClassLoader@1ebd2621\n"
> {code}
> WebappClassLoader
> context: /webapp2
> delegate: false
> repositories:
> /WEB-INF/classes/
> ----------> Parent Classloader:
> org.apache.catalina.loader.StandardClassLoader@1ebd2621{code}
> # undeploy webapp2
> #* In the Tomcat console, I can see Log4J status messages saying "Stopping
> LoggerContext WebappClassLoader...", and "Unregistering MBean
> org.apache.logging.log4j2..."
> #* In JConsole, the MBeans for {{org.apache.logging.log4j2}} are no longer
> displayed.
> #* Clicking the "Find Leaks" button in the Tomcat Manager app now shows
> message "No web applications appear to have triggered a memory leak on stop,
> reload or undeploy."
> So, it appears that automatic configuration does not work in Tomcat 7.0.50
> and that listener, filter and filter-mapping in web.xml are necessary for
> correct Log4J unloading...
--
This message was sent by Atlassian JIRA
(v6.1.5#6160)
---------------------------------------------------------------------
To unsubscribe, e-mail: [email protected]
For additional commands, e-mail: [email protected]