Ralph Goers (JIRA | 19 May 2013 09:35
Picon
Favicon

[jira] [Commented] (LOG4J2-223) IllegalStateException thrown during Tomcat shutdown


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

Ralph Goers commented on LOG4J2-223:
------------------------------------

Log4jContextListener is documented at http://logging.apache.org/log4j/2.x/log4j-web/index.html
but could use an example.  You can find one at
https://svn.apache.org/repos/asf/logging/log4j/log4j2/trunk/samples/flume-remote/src/main/webapp/WEB-INF/web.xml.
How to use the BasicContextSelector is documented on the page you reference. See item 1 under "Using
Context Selectors".

> IllegalStateException thrown during Tomcat shutdown
> ---------------------------------------------------
>
>                 Key: LOG4J2-223
>                 URL: https://issues.apache.org/jira/browse/LOG4J2-223
>             Project: Log4j 2
>          Issue Type: Bug
>          Components: Core
>    Affects Versions: 2.0-beta5
>            Reporter: Ralph Goers
>            Priority: Critical
>             Fix For: 2.0-beta7
>
>         Attachments: log4j-223.war
>
>
(Continue reading)

Remko Popma (JIRA | 19 May 2013 09:29
Picon
Favicon

[jira] [Commented] (LOG4J2-223) IllegalStateException thrown during Tomcat shutdown


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

Remko Popma commented on LOG4J2-223:
------------------------------------

Sounds like one for the FAQ page.
I'd like to try this. How do I do register the Log4jContextListener? 

Also, does https://logging.apache.org/log4j/2.x/manual/logsep.html need to be updated after this?
I'd like to try the simple approach mentioned on that page first and configure the BasicContextSelector,
but how do I do that?

> IllegalStateException thrown during Tomcat shutdown
> ---------------------------------------------------
>
>                 Key: LOG4J2-223
>                 URL: https://issues.apache.org/jira/browse/LOG4J2-223
>             Project: Log4j 2
>          Issue Type: Bug
>          Components: Core
>    Affects Versions: 2.0-beta5
>            Reporter: Ralph Goers
>            Priority: Critical
>             Fix For: 2.0-beta7
>
>         Attachments: log4j-223.war
>
(Continue reading)

bugzilla | 19 May 2013 09:15
Picon
Favicon

Bug report for Log4j [2013/05/19]

+---------------------------------------------------------------------------+
| Bugzilla Bug ID                                                           |
|     +---------------------------------------------------------------------+
|     | Status: UNC=Unconfirmed NEW=New         ASS=Assigned                |
|     |         OPN=Reopened    VER=Verified    (Skipped Closed/Resolved)   |
|     |   +-----------------------------------------------------------------+
|     |   | Severity: BLK=Blocker CRI=Critical  REG=Regression  MAJ=Major   |
|     |   |           MIN=Minor   NOR=Normal    ENH=Enhancement TRV=Trivial |
|     |   |   +-------------------------------------------------------------+
|     |   |   | Date Posted                                                 |
|     |   |   |          +--------------------------------------------------+
|     |   |   |          | Description                                      |
|     |   |   |          |                                                  |
| 4913|Opn|Min|2001-11-16|org.apache.log4j.helpers.FileWatchdog should allow|
|13099|Opn|Nor|2002-09-27|DOMConfigurator ignores category factory setting  |
|17887|Opn|Maj|2003-03-11|RollingFileAppender does not work for 10 threads  |
|20395|Inf|Enh|2003-06-01|PreparedStatementAppender Enhancement             |
|23329|New|Enh|2003-09-22|<logger> element in XML config should support reso|
|26084|Inf|Nor|2004-01-13|Log Event detail panel does not show special chara|
|27363|Inf|Enh|2004-03-02|JNI based SyslogAppender                          |
|27367|Inf|Enh|2004-03-02|NetSendAppender                                   |
|28059|Opn|Enh|2004-03-30|DOMConfigurator.configure(java.io.InputStream)    |
|29244|Inf|Nor|2004-05-27|Preserve XML content in log messages when using XM|
|29305|New|Nor|2004-05-30|Chainsaw doesn't see locationinfo from XMLSocketRe|
|30055|New|Nor|2004-07-12|Problem with registering Appenders with the same n|
|30888|Inf|Maj|2004-08-27|Chainsaw mixes files in same panel                |
|30892|New|Min|2004-08-27|Log files cannot be closed                        |
|31089|New|Nor|2004-09-07|Does not accept ISO8601 dates in focus field      |
|31178|Inf|Cri|2004-09-11|Exception using Chainsaw for simple debugging     |
|31179|Ass|Enh|2004-09-11|Implement Chainsaw as Eclipse stand-alone applicat|
(Continue reading)

Ralph Goers (JIRA | 19 May 2013 08:33
Picon
Favicon

[jira] [Commented] (LOG4J2-223) IllegalStateException thrown during Tomcat shutdown


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

Ralph Goers commented on LOG4J2-223:
------------------------------------

The web.xml in the sample application doesn't have the Log4jContextListener registered. If it did the
LoggerContext would have been unregistered when the webapp was undeployed, the shutdown hook would have
been removed, and the above error would not have occurred. 

It is hard to imagine what at line 170 could be causing the NPE, but I would guess that the
NullPointerException that Remko got above is because the webapp has already been undeployed and the
StatusLogger class isn't there any more.  If they had been deployed to the Tomcat class loader instead of
the webapp classloader then I suspect this error would not have occurred.

Removing the shutdown hook is not an appropriate solution. The configuration really needs to be shutdown
when the web app is undeployed or when the server is shutdown, depending on where the log4j jars are placed,
to clean up all the resources. 

> IllegalStateException thrown during Tomcat shutdown
> ---------------------------------------------------
>
>                 Key: LOG4J2-223
>                 URL: https://issues.apache.org/jira/browse/LOG4J2-223
>             Project: Log4j 2
>          Issue Type: Bug
>          Components: Core
>    Affects Versions: 2.0-beta5
(Continue reading)

Remko Popma (JIRA | 19 May 2013 07:03
Picon
Favicon

[jira] [Commented] (LOG4J2-223) IllegalStateException thrown during Tomcat shutdown


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

Remko Popma commented on LOG4J2-223:
------------------------------------

Would it be an idea for the LoggerContext to check if it is running in a web application and not register the
shutdown hook if that is the case? (Is there an official way to check if you are running inside a web container?)

> IllegalStateException thrown during Tomcat shutdown
> ---------------------------------------------------
>
>                 Key: LOG4J2-223
>                 URL: https://issues.apache.org/jira/browse/LOG4J2-223
>             Project: Log4j 2
>          Issue Type: Bug
>          Components: Core
>    Affects Versions: 2.0-beta5
>            Reporter: Ralph Goers
>            Priority: Critical
>             Fix For: 2.0-beta7
>
>         Attachments: log4j-223.war
>
>
> {noformat}Apr 25, 2013 3:03:33 PM org.apache.catalina.core.StandardServer await
> INFO: A valid shutdown command was received via the shutdown port. Stopping the Server instance.
> Apr 25, 2013 3:03:33 PM org.apache.coyote.AbstractProtocol pause
(Continue reading)

Nick Williams (JIRA | 19 May 2013 07:01
Picon
Favicon

[jira] [Commented] (LOG4J2-223) IllegalStateException thrown during Tomcat shutdown


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

Nick Williams commented on LOG4J2-223:
--------------------------------------

Note: I have asked on the Tomcat user's and developer's list for one of the people very knowledgeable about
class loaders and memory leaks to chime in on this bug.

> IllegalStateException thrown during Tomcat shutdown
> ---------------------------------------------------
>
>                 Key: LOG4J2-223
>                 URL: https://issues.apache.org/jira/browse/LOG4J2-223
>             Project: Log4j 2
>          Issue Type: Bug
>          Components: Core
>    Affects Versions: 2.0-beta5
>            Reporter: Ralph Goers
>            Priority: Critical
>             Fix For: 2.0-beta7
>
>         Attachments: log4j-223.war
>
>
> {noformat}Apr 25, 2013 3:03:33 PM org.apache.catalina.core.StandardServer await
> INFO: A valid shutdown command was received via the shutdown port. Stopping the Server instance.
> Apr 25, 2013 3:03:33 PM org.apache.coyote.AbstractProtocol pause
(Continue reading)

Remko Popma (JIRA | 19 May 2013 06:55
Picon
Favicon

[jira] [Comment Edited] (LOG4J2-223) IllegalStateException thrown during Tomcat shutdown


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

Remko Popma edited comment on LOG4J2-223 at 5/19/13 4:53 AM:
-------------------------------------------------------------

I also tried my fix in Tomcat 6.
Here, I don't get the 500 error.
The logging.jsp page shows the message "Messages have been logged.", and the output from the taglib logs is
correctly logged to the console and /logs/application.log file.
My hello-world page also shows the expected output.

Unloading the webapp does not give warnings, it just says "Undeploying web application at context path
/log4j-223" (in Japanese, the English may be slightly different).

Shutting down Tomcat-6 after that with Ctrl-C now gives this stack trace:
{code}
Exception in thread "Thread-40" java.lang.NullPointerException
        at org.apache.logging.log4j.status.StatusLogger.log(StatusLogger.java:170)
        at org.apache.logging.log4j.spi.AbstractLogger.debug(AbstractLogger.java:354)
        at org.apache.logging.log4j.core.appender.AbstractManager.release(AbstractManager.java:118)
        at org.apache.logging.log4j.core.appender.AbstractOutputStreamAppender.stop(AbstractOutputStreamAppender.java:97)
        at org.apache.logging.log4j.core.appender.RollingFileAppender.stop(RollingFileAppender.java:70)
        at org.apache.logging.log4j.core.config.BaseConfiguration.stop(BaseConfiguration.java:142)
        at org.apache.logging.log4j.core.config.XMLConfiguration.stop(XMLConfiguration.java:244)
        at org.apache.logging.log4j.core.LoggerContext.stop(LoggerContext.java:206)
        at org.apache.logging.log4j.core.LoggerContext$ShutdownThread.run(LoggerContext.java:430)
{code}
(Continue reading)

Remko Popma (JIRA | 19 May 2013 06:51
Picon
Favicon

[jira] [Comment Edited] (LOG4J2-223) IllegalStateException thrown during Tomcat shutdown


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

Remko Popma edited comment on LOG4J2-223 at 5/19/13 4:49 AM:
-------------------------------------------------------------

I also tried my fix in Tomcat 6.
Here, I don't get the 500 error.
The logging.jsp page shows the message "Messages have been logged.", and the output from the taglib logs is
correctly logged to the console and /logs/application.log file.
My hello-world page also shows the expected output.

Unloading the webapp does not give warnings, it just says "Undeploying web application at context path
/log4j-223" (in Japanese, the English may be slightly different).

Shutting down Tomcat-6 after that with Ctrl-C now gives this stack trace:
{code}
Exception in thread "Thread-40" java.lang.NullPointerException
        at org.apache.logging.log4j.status.StatusLogger.log(StatusLogger.java:170)
        at org.apache.logging.log4j.spi.AbstractLogger.debug(AbstractLogger.java:354)
        at org.apache.logging.log4j.core.appender.AbstractManager.release(AbstractManager.java:118)
        at org.apache.logging.log4j.core.appender.AbstractOutputStreamAppender.stop(AbstractOutputStreamAppender.java:97)
        at org.apache.logging.log4j.core.appender.RollingFileAppender.stop(RollingFileAppender.java:70)
        at org.apache.logging.log4j.core.config.BaseConfiguration.stop(BaseConfiguration.java:142)
        at org.apache.logging.log4j.core.config.XMLConfiguration.stop(XMLConfiguration.java:244)
        at org.apache.logging.log4j.core.LoggerContext.stop(LoggerContext.java:206)
        at org.apache.logging.log4j.core.LoggerContext$ShutdownThread.run(LoggerContext.java:430)
{code}
(Continue reading)

Remko Popma (JIRA | 19 May 2013 06:51
Picon
Favicon

[jira] [Commented] (LOG4J2-223) IllegalStateException thrown during Tomcat shutdown


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

Remko Popma commented on LOG4J2-223:
------------------------------------

Well, my son wants to go play in the park now. That gets priority. :-) I have seen more than enough Tomcat for
today... I hope the above helps with the investigation.

> IllegalStateException thrown during Tomcat shutdown
> ---------------------------------------------------
>
>                 Key: LOG4J2-223
>                 URL: https://issues.apache.org/jira/browse/LOG4J2-223
>             Project: Log4j 2
>          Issue Type: Bug
>          Components: Core
>    Affects Versions: 2.0-beta5
>            Reporter: Ralph Goers
>            Priority: Critical
>             Fix For: 2.0-beta7
>
>         Attachments: log4j-223.war
>
>
> {noformat}Apr 25, 2013 3:03:33 PM org.apache.catalina.core.StandardServer await
> INFO: A valid shutdown command was received via the shutdown port. Stopping the Server instance.
> Apr 25, 2013 3:03:33 PM org.apache.coyote.AbstractProtocol pause
(Continue reading)

Nick Williams (JIRA | 19 May 2013 06:49
Picon
Favicon

[jira] [Commented] (LOG4J2-223) IllegalStateException thrown during Tomcat shutdown


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

Nick Williams commented on LOG4J2-223:
--------------------------------------

Yes, the log4j*.jar exclusion doesn't exist in Tomcat 6 (only Tomcat 7+), and it is not surprising that the
error resulting from the class loader problem is slightly different in Tomcat 6 and Tomcat 7.

Make sure you see my comment above about the log4j*.jar exclusion in Tomcat 7+ and about questioning the
shutdown hook.

> IllegalStateException thrown during Tomcat shutdown
> ---------------------------------------------------
>
>                 Key: LOG4J2-223
>                 URL: https://issues.apache.org/jira/browse/LOG4J2-223
>             Project: Log4j 2
>          Issue Type: Bug
>          Components: Core
>    Affects Versions: 2.0-beta5
>            Reporter: Ralph Goers
>            Priority: Critical
>             Fix For: 2.0-beta7
>
>         Attachments: log4j-223.war
>
>
(Continue reading)

Remko Popma (JIRA | 19 May 2013 06:45
Picon
Favicon

[jira] [Commented] (LOG4J2-223) IllegalStateException thrown during Tomcat shutdown


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

Remko Popma commented on LOG4J2-223:
------------------------------------

I also tried my fix in Tomcat 6.
Here, I don't get the 500 error.
The logging.jsp page shows the message "Messages have been logged.", and the output from the taglib logs is
correctly logged to the console and /logs/application.log file.
My hello-world page also shows the expected output.

Unloading the webapp does not give warnings, it just says "Undeploying web application at context path
/log4j-223" (in Japanese, the English may be slightly different).

Shutting down Tomcat-6 after that with Ctrl-C now gives this stack trace:
{code}
Exception in thread "Thread-40" java.lang.NullPointerException
        at org.apache.logging.log4j.status.StatusLogger.log(StatusLogger.java:170)
        at org.apache.logging.log4j.spi.AbstractLogger.debug(AbstractLogger.java:354)
        at org.apache.logging.log4j.core.appender.AbstractManager.release(AbstractManager.java:118)
        at org.apache.logging.log4j.core.appender.AbstractOutputStreamAppender.stop(AbstractOutputStreamAppender.java:97)
        at org.apache.logging.log4j.core.appender.RollingFileAppender.stop(RollingFileAppender.java:70)
        at org.apache.logging.log4j.core.config.BaseConfiguration.stop(BaseConfiguration.java:142)
        at org.apache.logging.log4j.core.config.XMLConfiguration.stop(XMLConfiguration.java:244)
        at org.apache.logging.log4j.core.LoggerContext.stop(LoggerContext.java:206)
        at org.apache.logging.log4j.core.LoggerContext$ShutdownThread.run(LoggerContext.java:430)
{code}
(Continue reading)


Gmane