[
https://issues.apache.org/jira/browse/LOG4J2-529?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
]
Remko Popma updated LOG4J2-529:
-------------------------------
Description:
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...
was:
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 my solution 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...
> 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
>
> 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: log4j-dev-unsubscr...@logging.apache.org
For additional commands, e-mail: log4j-dev-h...@logging.apache.org
