You are viewing a plain text version of this content. The canonical link for it is here.
Posted to log4j-dev@logging.apache.org by "Remko Popma (JIRA)" <ji...@apache.org> on 2014/02/07 05:37:19 UTC

[jira] [Comment Edited] (LOG4J2-529) Log4j2 does not auto-initialize on webapp deploy or auto-deinitialize on undeploy

    [ https://issues.apache.org/jira/browse/LOG4J2-529?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=13894189#comment-13894189 ] 

Remko Popma edited comment on LOG4J2-529 at 2/7/14 4:35 AM:
------------------------------------------------------------

Nick, I tried deploying in Tomcat 8.0.1 but I get the same result. MBeans are *not* registered when the webapp is deployed, only when I open {{log.jsp}} in a web browser. MBeans are not unregistered when undeploying the webapp.

Unfortunately I used the Windows installer for 8.0.1 so it does not have a console which makes it a bit harder to debug... 

Anyway, when redirecting standard error to a file I see this when deploying webapp1:
{code}
07-Feb-2014 13:17:05.422 INFO [http-nio-8080-exec-2] org.apache.catalina.startup.HostConfig.deployWAR Deploying web application archive D:\apps\Tomcat8.0\webapps\webapp1.war
07-Feb-2014 13:17:05.796 INFO [http-nio-8080-exec-2] org.apache.jasper.servlet.TldScanner.scanJars At least one JAR was scanned for TLDs yet contained no TLDs. Enable debug logging for this logger for a complete list of JARs that were scanned but no TLDs were found in them. Skipping unneeded JARs during scanning can improve startup time and JSP compilation time.
{code}

Not sure if this is relevant, but isn't Tomcat supposed to find your taglib stuff in the log4j-core jar? I tried to set the log level to debug in the Logging tab of the Configure Tomcat dialog but it did not change the output (no list of JARs)...

Here is the web.xml file I used:
{code}
<?xml version="1.0" encoding="ISO-8859-1"?>
<web-app xmlns="http://java.sun.com/xml/ns/j2ee"
    xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
    xsi:schemaLocation="http://java.sun.com/xml/ns/j2ee http://java.sun.com/xml/ns/j2ee/web-app_2_4.xsd"
    version="2.4">

    <display-name>Hello, World Application</display-name>
    <description>
	This is a simple web application with a source code organization
	based on the recommendations of the Application Developer's Guide.
    </description>
	
    <servlet>
        <servlet-name>HelloServlet</servlet-name>
        <servlet-class>mypackage.Hello</servlet-class>
    </servlet>

    <servlet-mapping>
        <servlet-name>HelloServlet</servlet-name>
        <url-pattern>/hello</url-pattern>
    </servlet-mapping>

</web-app>
{code}



was (Author: remkop@yahoo.com):
Nick, I tried deploying in Tomcat 8.0.1 but I get the same result. MBeans are *not* registered when the webapp is deployed, only when I open {{log.jsp}} in a web browser. MBeans are not unregistered when undeploying the webapp.

Unfortunately I used the Windows installer for 8.0.1 so it does not have a console which makes it a bit harder to debug... 

Anyway, when redirecting standard error to a file I see this when deploying webapp1:
{code}
07-Feb-2014 13:17:05.422 INFO [http-nio-8080-exec-2] org.apache.catalina.startup.HostConfig.deployWAR Deploying web application archive D:\apps\Tomcat8.0\webapps\webapp1.war
07-Feb-2014 13:17:05.796 INFO [http-nio-8080-exec-2] org.apache.jasper.servlet.TldScanner.scanJars At least one JAR was scanned for TLDs yet contained no TLDs. Enable debug logging for this logger for a complete list of JARs that were scanned but no TLDs were found in them. Skipping unneeded JARs during scanning can improve startup time and JSP compilation time.
{code}

Not sure what TLDs are, hope it is relevant. I tried to set the log level to debug in the Logging tab of the Configure Tomcat dialog but it did not change the output (no list of JARs)...

Here is the web.xml file I used:
{code}
<?xml version="1.0" encoding="ISO-8859-1"?>
<web-app xmlns="http://java.sun.com/xml/ns/j2ee"
    xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
    xsi:schemaLocation="http://java.sun.com/xml/ns/j2ee http://java.sun.com/xml/ns/j2ee/web-app_2_4.xsd"
    version="2.4">

    <display-name>Hello, World Application</display-name>
    <description>
	This is a simple web application with a source code organization
	based on the recommendations of the Application Developer's Guide.
    </description>
	
    <servlet>
        <servlet-name>HelloServlet</servlet-name>
        <servlet-class>mypackage.Hello</servlet-class>
    </servlet>

    <servlet-mapping>
        <servlet-name>HelloServlet</servlet-name>
        <url-pattern>/hello</url-pattern>
    </servlet-mapping>

</web-app>
{code}


> 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-unsubscribe@logging.apache.org
For additional commands, e-mail: log4j-dev-help@logging.apache.org