Log4j 2
  1. Log4j 2
  2. LOG4J2-223

IllegalStateException thrown during Tomcat shutdown

    Details

    • Type: Bug Bug
    • Status: Closed
    • Priority: Critical Critical
    • Resolution: Fixed
    • Affects Version/s: 2.0-beta5
    • Fix Version/s: 2.0-beta7
    • Component/s: Core
    • Labels:
      None

      Description

      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
      INFO: Pausing ProtocolHandler ["http-nio-8080"]
      Apr 25, 2013 3:03:33 PM org.apache.coyote.AbstractProtocol pause
      INFO: Pausing ProtocolHandler ["ajp-nio-8009"]
      Apr 25, 2013 3:03:33 PM org.apache.catalina.core.StandardService stopInternal
      INFO: Stopping service Catalina
      Apr 25, 2013 3:03:33 PM org.apache.coyote.AbstractProtocol stop
      INFO: Stopping ProtocolHandler ["http-nio-8080"]
      Apr 25, 2013 3:03:33 PM org.apache.coyote.AbstractProtocol stop
      INFO: Stopping ProtocolHandler ["ajp-nio-8009"]
      Apr 25, 2013 3:03:33 PM org.apache.coyote.AbstractProtocol destroy
      INFO: Destroying ProtocolHandler ["http-nio-8080"]
      Apr 25, 2013 3:03:33 PM org.apache.coyote.AbstractProtocol destroy
      INFO: Destroying ProtocolHandler ["ajp-nio-8009"]
      Apr 25, 2013 3:03:33 PM org.apache.catalina.loader.WebappClassLoader loadClass
      INFO: Illegal access: this web application instance has been stopped already.  Could not load org.apache.logging.log4j.core.config.NullConfiguration.  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
      	at org.apache.catalina.loader.WebappClassLoader.loadClass(WebappClassLoader.java:1351)
      	at org.apache.catalina.loader.WebappClassLoader.loadClass(WebappClassLoader.java:1310)
      	at org.apache.logging.log4j.core.LoggerContext.stop(LoggerContext.java:171)
      	at org.apache.logging.log4j.core.LoggerContext$ShutdownThread.run(LoggerContext.java:389)
      
      Exception in thread "Thread-18" java.lang.NoClassDefFoundError: org/apache/logging/log4j/core/config/NullConfiguration
      	at org.apache.logging.log4j.core.LoggerContext.stop(LoggerContext.java:171)
      	at org.apache.logging.log4j.core.LoggerContext$ShutdownThread.run(LoggerContext.java:389)
      Caused by: java.lang.ClassNotFoundException: org.apache.logging.log4j.core.config.NullConfiguration
      	at org.apache.catalina.loader.WebappClassLoader.loadClass(WebappClassLoader.java:1465)
      	at org.apache.catalina.loader.WebappClassLoader.loadClass(WebappClassLoader.java:1310)
      	... 2 more
      1. log4j-223.war
        2.64 MB
        Nick Williams

        Issue Links

          Activity

          Ralph Goers created issue -
          Remko Popma made changes -
          Field Original Value New Value
          Link This issue relates to LOG4J2-222 [ LOG4J2-222 ]
          Hide
          Ralph Goers added a comment -

          Configurator was not stopping the LoggerContext but was just reconfiguring to a default configuration. It now stops the LoggerContext.

          Show
          Ralph Goers added a comment - Configurator was not stopping the LoggerContext but was just reconfiguring to a default configuration. It now stops the LoggerContext.
          Ralph Goers made changes -
          Status Open [ 1 ] Resolved [ 5 ]
          Fix Version/s 2.0-beta6 [ 12324340 ]
          Resolution Fixed [ 1 ]
          Hide
          Nick Williams added a comment -

          I guess you needed me to file a bug, huh?

          Do you still need me to provide a sample project? Say the word. I've got it zipped up and can attach it on request.

          By the way, misspelling in the bug title. IlliegalStateException should be IllegalStateException.

          Show
          Nick Williams added a comment - I guess you needed me to file a bug, huh? Do you still need me to provide a sample project? Say the word. I've got it zipped up and can attach it on request. By the way, misspelling in the bug title. IlliegalStateException should be IllegalStateException.
          Ralph Goers made changes -
          Status Resolved [ 5 ] Closed [ 6 ]
          Hide
          Remko Popma added a comment -

          Nick, this issue is closed so you cannot attach to it any more.
          However LOG4J2-222 looks similar and a sample project would be helpful when I double-check Ralph's solution. Could you attach your sample project to LOG4J2-222?
          Much appreciated! -Remko

          Show
          Remko Popma added a comment - Nick, this issue is closed so you cannot attach to it any more. However LOG4J2-222 looks similar and a sample project would be helpful when I double-check Ralph's solution. Could you attach your sample project to LOG4J2-222 ? Much appreciated! -Remko
          Hide
          Olivier Lamy (*$^¨%`£) added a comment -

          If you need a sample project, I have similar issue with archiva project.

          svn co https://svn.apache.org/repos/asf/archiva/trunk/ archiva-trunk
          cd archiva-trunk
          sh ./t7.sh

          when tomcat running just use ctrl+c

          Show
          Olivier Lamy (*$^¨%`£) added a comment - If you need a sample project, I have similar issue with archiva project. svn co https://svn.apache.org/repos/asf/archiva/trunk/ archiva-trunk cd archiva-trunk sh ./t7.sh when tomcat running just use ctrl+c
          Hide
          Remko Popma added a comment -

          Thanks Olivier! I'll take a look when I get home.

          Show
          Remko Popma added a comment - Thanks Olivier! I'll take a look when I get home.
          Hide
          Ralph Goers added a comment -

          The flume-remote sample web app had this problem and was used to debug and resolve it. Oliver, can you test the latest code and verify that it fixes the problem you are seeing?

          Show
          Ralph Goers added a comment - The flume-remote sample web app had this problem and was used to debug and resolve it. Oliver, can you test the latest code and verify that it fixes the problem you are seeing?
          Hide
          Olivier Lamy (*$^¨%`£) added a comment -

          Ralph Goers with r1477565 build locally I still have the issue.

          ^C2013-04-30 21:29:07,714 DEBUG Shutting down OutputStreamManager SYSTEM_OUT
          2013-04-30 21:29:07,714 DEBUG Shutting down FastRollingFileManager /Users/olamy/dev/tests/archiva-appserver-base-test/logs/archiva.log
          Exception in thread "Thread-6" java.lang.NullPointerException
          at org.apache.logging.log4j.core.async.AsyncLoggerConfigHelper.shutdown(AsyncLoggerConfigHelper.java:227)
          at org.apache.logging.log4j.core.async.AsyncLoggerConfig.stopFilter(AsyncLoggerConfig.java:137)
          at org.apache.logging.log4j.core.config.BaseConfiguration.stop(BaseConfiguration.java:148)
          at org.apache.logging.log4j.core.LoggerContext.stop(LoggerContext.java:201)
          at org.apache.logging.log4j.core.async.AsyncLoggerContext.stop(AsyncLoggerContext.java:57)
          at org.apache.logging.log4j.core.LoggerContext$ShutdownThread.run(LoggerContext.java:418)

          Show
          Olivier Lamy (*$^¨%`£) added a comment - Ralph Goers with r1477565 build locally I still have the issue. ^C2013-04-30 21:29:07,714 DEBUG Shutting down OutputStreamManager SYSTEM_OUT 2013-04-30 21:29:07,714 DEBUG Shutting down FastRollingFileManager /Users/olamy/dev/tests/archiva-appserver-base-test/logs/archiva.log Exception in thread "Thread-6" java.lang.NullPointerException at org.apache.logging.log4j.core.async.AsyncLoggerConfigHelper.shutdown(AsyncLoggerConfigHelper.java:227) at org.apache.logging.log4j.core.async.AsyncLoggerConfig.stopFilter(AsyncLoggerConfig.java:137) at org.apache.logging.log4j.core.config.BaseConfiguration.stop(BaseConfiguration.java:148) at org.apache.logging.log4j.core.LoggerContext.stop(LoggerContext.java:201) at org.apache.logging.log4j.core.async.AsyncLoggerContext.stop(AsyncLoggerContext.java:57) at org.apache.logging.log4j.core.LoggerContext$ShutdownThread.run(LoggerContext.java:418)
          Hide
          Remko Popma added a comment -

          Olivier, I tried running archiva.
          I could not get it to run (OutOfMemory on my 32bit PC at work), but I did see this:

          2013-05-01 19:56:22,300 DEBUG property AsyncLoggerConfig.WaitStrategy=null <--- (1) Mixed Async Logger <asyncRoot/asyncLogger>
          2013-05-01 19:56:22,300 DEBUG disruptor event handler uses SleepingWaitStrategy
          2013-05-01 19:56:22,331 DEBUG No AsyncLoggerConfig.ExceptionHandler specified
          2013-05-01 19:56:22,331 DEBUG Starting AsyncLoggerConfig disruptor with ringbuffer size 262144...
          2013-05-01 19:56:22,347 DEBUG Reconfiguration completed
          2013-05-01 19:56:22,347 DEBUG Using default SystemClock for timestamps
          2013-05-01 19:56:22,347 DEBUG property AsyncLogger.WaitStrategy=null <----(2) All Async Loggers (sysprop Log4jContextSelector)
          2013-05-01 19:56:22,347 DEBUG disruptor event handler uses SleepingWaitStrategy
          2013-05-01 19:56:22,394 DEBUG No AsyncLogger.ExceptionHandler specified
          2013-05-01 19:56:22,394 DEBUG Starting AsyncLogger disruptor with ringbuffer size 262144...

          Looks like you are using both Async Logger mechanisms together:
          1) the log4j2.xml config has <asyncLogger> and <asyncRoot> (and quite a few of them, good test case! )
          2) in addition, /archiva/archiva-modules/archiva-web/archiva-webapp/pom.xml has this line:
          <Log4jContextSelector>org.apache.logging.log4j.core.async.AsyncLoggerContextSelector</Log4jContextSelector>

          This means you end up with 2 disruptors. You only need one.
          The fix for LOG4J2-222 only works for (1). Can you try again after removing the AsyncLoggerContextSelector config from archiva-webapp/pom.xml ?

          Show
          Remko Popma added a comment - Olivier, I tried running archiva. I could not get it to run (OutOfMemory on my 32bit PC at work), but I did see this: 2013-05-01 19:56:22,300 DEBUG property AsyncLoggerConfig.WaitStrategy=null <--- (1) Mixed Async Logger <asyncRoot/asyncLogger> 2013-05-01 19:56:22,300 DEBUG disruptor event handler uses SleepingWaitStrategy 2013-05-01 19:56:22,331 DEBUG No AsyncLoggerConfig.ExceptionHandler specified 2013-05-01 19:56:22,331 DEBUG Starting AsyncLoggerConfig disruptor with ringbuffer size 262144... 2013-05-01 19:56:22,347 DEBUG Reconfiguration completed 2013-05-01 19:56:22,347 DEBUG Using default SystemClock for timestamps 2013-05-01 19:56:22,347 DEBUG property AsyncLogger.WaitStrategy=null <----(2) All Async Loggers (sysprop Log4jContextSelector) 2013-05-01 19:56:22,347 DEBUG disruptor event handler uses SleepingWaitStrategy 2013-05-01 19:56:22,394 DEBUG No AsyncLogger.ExceptionHandler specified 2013-05-01 19:56:22,394 DEBUG Starting AsyncLogger disruptor with ringbuffer size 262144... Looks like you are using both Async Logger mechanisms together: 1) the log4j2.xml config has <asyncLogger> and <asyncRoot> (and quite a few of them, good test case! ) 2) in addition, /archiva/archiva-modules/archiva-web/archiva-webapp/pom.xml has this line: <Log4jContextSelector>org.apache.logging.log4j.core.async.AsyncLoggerContextSelector</Log4jContextSelector> This means you end up with 2 disruptors. You only need one. The fix for LOG4J2-222 only works for (1). Can you try again after removing the AsyncLoggerContextSelector config from archiva-webapp/pom.xml ?
          Hide
          Olivier Lamy (*$^¨%`£) added a comment -

          To get it running I use MAVEN_OPTS=-Djava.awt.headless=true -Xmx768m -Xms768m -XX:MaxPermSize=256m -client -XX:+HeapDumpOnOutOfMemoryError.
          Oh Yes I removed <Log4jContextSelector>org.apache.logging.log4j.core.async.AsyncLoggerContextSelector</Log4jContextSelector> as it was for testing purpose.

          Show
          Olivier Lamy (*$^¨%`£) added a comment - To get it running I use MAVEN_OPTS=-Djava.awt.headless=true -Xmx768m -Xms768m -XX:MaxPermSize=256m -client -XX:+HeapDumpOnOutOfMemoryError. Oh Yes I removed <Log4jContextSelector>org.apache.logging.log4j.core.async.AsyncLoggerContextSelector</Log4jContextSelector> as it was for testing purpose.
          Hide
          Remko Popma added a comment -

          Thanks, that helped.
          I can now see one disruptor being started, followed by lots of archiva startup logs (cute banner btw)...

          When I press Ctrl-C, I get the same problem that Ralph fixed in LOG4J2-222.
          How do I make aptiva use my latest build of log4j2-XX-beta6-SNAPSHOT ?

          Show
          Remko Popma added a comment - Thanks, that helped. I can now see one disruptor being started, followed by lots of archiva startup logs (cute banner btw)... When I press Ctrl-C, I get the same problem that Ralph fixed in LOG4J2-222 . How do I make aptiva use my latest build of log4j2-XX-beta6-SNAPSHOT ?
          Hide
          Olivier Lamy (*$^¨%`£) added a comment -

          that's already the case
          mb-olamy:archiva olamy$ grep '<log4j.version' pom.xml
          <log4j.version>2.0-beta6-SNAPSHOT</log4j.version>
          You must install locally 2.0-beta6-SNAPSHOT (not sure snapshots for repository.a.o are deployed ?)

          Show
          Olivier Lamy (*$^¨%`£) added a comment - that's already the case mb-olamy:archiva olamy$ grep '<log4j.version' pom.xml <log4j.version>2.0-beta6-SNAPSHOT</log4j.version> You must install locally 2.0-beta6-SNAPSHOT (not sure snapshots for repository.a.o are deployed ?)
          Hide
          Remko Popma added a comment -

          That does not match what I'm seeing:

          Ctrl-C
          2013-05-01 20:57:08,487 DEBUG Generated plugins in 0.000010057 seconds
          2013-05-01 20:57:08,487 DEBUG Jansi is not installed
          2013-05-01 20:57:08,487 DEBUG Reconfiguration started for context Default <--- problem 2 caused by problem 1 below
          2013/05/01 20:57:08 org.apache.coyote.AbstractProtocol pause
          情報: Pausing ProtocolHandler ["http-bio-9091"]
          2013-05-01 20:57:08,519 DEBUG Generated plugins in 0.000008660 seconds
          ...
          2013-05-01 20:57:08,550 DEBUG Reconfiguration completed
          Exception in thread "Thread-3" java.lang.IllegalStateException: Shutdown in progress
          at java.lang.ApplicationShutdownHooks.add(ApplicationShutdownHooks.java:39)
          at java.lang.Runtime.addShutdownHook(Runtime.java:192)
          at org.apache.logging.log4j.core.LoggerContext.start(LoggerContext.java:150)
          at org.apache.logging.log4j.core.impl.Log4jContextFactory.getContext(Log4jContextFactory.java:84)
          at org.apache.logging.log4j.core.impl.Log4jContextFactory.getContext(Log4jContextFactory.java:34)
          at org.apache.logging.log4j.LogManager.getContext(LogManager.java:138) <------------ PROBLEM 1 ***********
          at org.apache.logging.log4j.core.async.AsyncLoggerConfig.stopFilter(AsyncLoggerConfig.java:132)
          at org.apache.logging.log4j.core.config.BaseConfiguration.stop(BaseConfiguration.java:136)
          at org.apache.logging.log4j.core.LoggerContext.stop(LoggerContext.java:172)
          at org.apache.logging.log4j.core.LoggerContext$ShutdownThread.run(LoggerContext.java:389)

          the line marked with PROBLEM 2 should not happen with the latest 2.0-beta6-SNAPSHOT:
          that call to LogManager.getContext was commented out...

          Show
          Remko Popma added a comment - That does not match what I'm seeing: Ctrl-C 2013-05-01 20:57:08,487 DEBUG Generated plugins in 0.000010057 seconds 2013-05-01 20:57:08,487 DEBUG Jansi is not installed 2013-05-01 20:57:08,487 DEBUG Reconfiguration started for context Default <--- problem 2 caused by problem 1 below 2013/05/01 20:57:08 org.apache.coyote.AbstractProtocol pause 情報: Pausing ProtocolHandler ["http-bio-9091"] 2013-05-01 20:57:08,519 DEBUG Generated plugins in 0.000008660 seconds ... 2013-05-01 20:57:08,550 DEBUG Reconfiguration completed Exception in thread "Thread-3" java.lang.IllegalStateException: Shutdown in progress at java.lang.ApplicationShutdownHooks.add(ApplicationShutdownHooks.java:39) at java.lang.Runtime.addShutdownHook(Runtime.java:192) at org.apache.logging.log4j.core.LoggerContext.start(LoggerContext.java:150) at org.apache.logging.log4j.core.impl.Log4jContextFactory.getContext(Log4jContextFactory.java:84) at org.apache.logging.log4j.core.impl.Log4jContextFactory.getContext(Log4jContextFactory.java:34) at org.apache.logging.log4j.LogManager.getContext(LogManager.java:138) <------------ PROBLEM 1 *********** at org.apache.logging.log4j.core.async.AsyncLoggerConfig.stopFilter(AsyncLoggerConfig.java:132) at org.apache.logging.log4j.core.config.BaseConfiguration.stop(BaseConfiguration.java:136) at org.apache.logging.log4j.core.LoggerContext.stop(LoggerContext.java:172) at org.apache.logging.log4j.core.LoggerContext$ShutdownThread.run(LoggerContext.java:389) the line marked with PROBLEM 2 should not happen with the latest 2.0-beta6-SNAPSHOT: that call to LogManager.getContext was commented out...
          Hide
          Remko Popma added a comment -

          ok I will try to replace the files in the local maven repo with my last build

          Show
          Remko Popma added a comment - ok I will try to replace the files in the local maven repo with my last build
          Hide
          Olivier Lamy (*$^¨%`£) added a comment -

          sure.
          mvn clean install (in log4j2 must do that )

          Show
          Olivier Lamy (*$^¨%`£) added a comment - sure. mvn clean install (in log4j2 must do that )
          Hide
          Remko Popma added a comment -

          Phew. I can now reproduce the problem (at least very similar):

          Ctrl-C
          2013-05-01 21:53:04,093 DEBUG Shutting down OutputStreamManager SYSTEM_OUT
          2013-05-01 21:53:04,093 DEBUG Shutting down FastRollingFileManager D:\data\workspace-4.2.1\archiva\archiva-modules\archi
          va-web\archiva-webapp\target/appserver-base/logs/archiva.log
          2013/05/01 21:53:04 org.apache.coyote.AbstractProtocol pause
          情報: Pausing ProtocolHandler ["http-bio-9091"]
          Exception in thread "Thread-3" java.lang.NullPointerException
          at org.apache.logging.log4j.core.async.AsyncLoggerConfigHelper.shutdown(AsyncLoggerConfigHelper.java:227)
          at org.apache.logging.log4j.core.async.AsyncLoggerConfig.stopFilter(AsyncLoggerConfig.java:137)
          at org.apache.logging.log4j.core.config.BaseConfiguration.stop(BaseConfiguration.java:148)
          at org.apache.logging.log4j.core.LoggerContext.stop(LoggerContext.java:201)
          at org.apache.logging.log4j.core.LoggerContext$ShutdownThread.run(LoggerContext.java:418)

          I suspect that the ShutdownThread runs after the Disruptor has already been shut down in the main application thread.
          The shutdown() code does not check if the static field holding the Disruptor has already been set to null.

          The fix is:
          AsyncLoggerConfigHelper.shutdown() line 222:
          CURRENT:
          Disruptor<Log4jEventWrapper> temp = disruptor;

          FIXED:
          Disruptor<Log4jEventWrapper> temp = disruptor;
          if (temp == null)

          { return; }
          Show
          Remko Popma added a comment - Phew. I can now reproduce the problem (at least very similar): Ctrl-C 2013-05-01 21:53:04,093 DEBUG Shutting down OutputStreamManager SYSTEM_OUT 2013-05-01 21:53:04,093 DEBUG Shutting down FastRollingFileManager D:\data\workspace-4.2.1\archiva\archiva-modules\archi va-web\archiva-webapp\target/appserver-base/logs/archiva.log 2013/05/01 21:53:04 org.apache.coyote.AbstractProtocol pause 情報: Pausing ProtocolHandler ["http-bio-9091"] Exception in thread "Thread-3" java.lang.NullPointerException at org.apache.logging.log4j.core.async.AsyncLoggerConfigHelper.shutdown(AsyncLoggerConfigHelper.java:227) at org.apache.logging.log4j.core.async.AsyncLoggerConfig.stopFilter(AsyncLoggerConfig.java:137) at org.apache.logging.log4j.core.config.BaseConfiguration.stop(BaseConfiguration.java:148) at org.apache.logging.log4j.core.LoggerContext.stop(LoggerContext.java:201) at org.apache.logging.log4j.core.LoggerContext$ShutdownThread.run(LoggerContext.java:418) I suspect that the ShutdownThread runs after the Disruptor has already been shut down in the main application thread. The shutdown() code does not check if the static field holding the Disruptor has already been set to null. The fix is: AsyncLoggerConfigHelper.shutdown() line 222: CURRENT: Disruptor<Log4jEventWrapper> temp = disruptor; FIXED: Disruptor<Log4jEventWrapper> temp = disruptor; if (temp == null) { return; }
          Hide
          Remko Popma added a comment -

          Fixed in revision 1478040.
          I'll re-test tomorrow. Olivier, could you also take a look if you have time?

          Show
          Remko Popma added a comment - Fixed in revision 1478040. I'll re-test tomorrow. Olivier, could you also take a look if you have time?
          Hide
          Remko Popma added a comment -

          Tested and looks good. Archiva/Tomcat now shuts down cleanly on Ctrl-C.

          ...
          情報: Starting ProtocolHandler ["http-bio-9091"]

          Ctrl-C

          2013-05-02 09:29:06,786 DEBUG Shutting down OutputStreamManager SYSTEM_OUT
          2013-05-02 09:29:06,786 DEBUG Shutting down FastRollingFileManager D:\data\workspace-4.2.1\archiva\archiva-modules\archi
          va-web\archiva-webapp\target/appserver-base/logs/archiva.log
          Terminate batch job (Y/N)? y

          D:\data\workspace-4.2.1\archiva>

          Show
          Remko Popma added a comment - Tested and looks good. Archiva/Tomcat now shuts down cleanly on Ctrl-C. ... 情報: Starting ProtocolHandler ["http-bio-9091"] Ctrl-C 2013-05-02 09:29:06,786 DEBUG Shutting down OutputStreamManager SYSTEM_OUT 2013-05-02 09:29:06,786 DEBUG Shutting down FastRollingFileManager D:\data\workspace-4.2.1\archiva\archiva-modules\archi va-web\archiva-webapp\target/appserver-base/logs/archiva.log Terminate batch job (Y/N)? y D:\data\workspace-4.2.1\archiva>
          Hide
          Olivier Lamy (*$^¨%`£) added a comment -

          Thanks Dude !

          Show
          Olivier Lamy (*$^¨%`£) added a comment - Thanks Dude !
          Hide
          Nick Williams added a comment -

          I still get this when shutting down Tomcat using Log4j2 beta6. This issue is not fixed.

          INFO: Illegal access: this web application instance has been stopped already. Could not load org.apache.logging.log4j.core.config.NullConfiguration. 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
          at org.apache.catalina.loader.WebappClassLoader.loadClass(WebappClassLoader.java:1351)
          at org.apache.catalina.loader.WebappClassLoader.loadClass(WebappClassLoader.java:1310)
          at org.apache.logging.log4j.core.LoggerContext.stop(LoggerContext.java:199)
          at org.apache.logging.log4j.core.LoggerContext$ShutdownThread.run(LoggerContext.java:418)

          Exception in thread "Thread-13" java.lang.NoClassDefFoundError: org/apache/logging/log4j/core/config/NullConfiguration
          at org.apache.logging.log4j.core.LoggerContext.stop(LoggerContext.java:199)
          at org.apache.logging.log4j.core.LoggerContext$ShutdownThread.run(LoggerContext.java:418)
          Caused by: java.lang.ClassNotFoundException: org.apache.logging.log4j.core.config.NullConfiguration
          at org.apache.catalina.loader.WebappClassLoader.loadClass(WebappClassLoader.java:1465)
          at org.apache.catalina.loader.WebappClassLoader.loadClass(WebappClassLoader.java:1310)
          ... 2 more

          Show
          Nick Williams added a comment - I still get this when shutting down Tomcat using Log4j2 beta6. This issue is not fixed. INFO: Illegal access: this web application instance has been stopped already. Could not load org.apache.logging.log4j.core.config.NullConfiguration. 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 at org.apache.catalina.loader.WebappClassLoader.loadClass(WebappClassLoader.java:1351) at org.apache.catalina.loader.WebappClassLoader.loadClass(WebappClassLoader.java:1310) at org.apache.logging.log4j.core.LoggerContext.stop(LoggerContext.java:199) at org.apache.logging.log4j.core.LoggerContext$ShutdownThread.run(LoggerContext.java:418) Exception in thread "Thread-13" java.lang.NoClassDefFoundError: org/apache/logging/log4j/core/config/NullConfiguration at org.apache.logging.log4j.core.LoggerContext.stop(LoggerContext.java:199) at org.apache.logging.log4j.core.LoggerContext$ShutdownThread.run(LoggerContext.java:418) Caused by: java.lang.ClassNotFoundException: org.apache.logging.log4j.core.config.NullConfiguration at org.apache.catalina.loader.WebappClassLoader.loadClass(WebappClassLoader.java:1465) at org.apache.catalina.loader.WebappClassLoader.loadClass(WebappClassLoader.java:1310) ... 2 more
          Hide
          Remko Popma added a comment -

          Darn! Hmm... I guess I need help to reproduce this issue. (It worked when Olivier and I tested.)
          Would it be possible to attach a small case that demonstrates the issue?

          Show
          Remko Popma added a comment - Darn! Hmm... I guess I need help to reproduce this issue. (It worked when Olivier and I tested.) Would it be possible to attach a small case that demonstrates the issue?
          Hide
          Nick Williams added a comment -

          Reopening since this is not fixed in beta6 and a test project needs to be attached.

          Show
          Nick Williams added a comment - Reopening since this is not fixed in beta6 and a test project needs to be attached.
          Nick Williams made changes -
          Resolution Fixed [ 1 ]
          Status Closed [ 6 ] Reopened [ 4 ]
          Assignee Ralph Goers [ ralph.goers@dslextreme.com ] Remko Popma [ remkop@yahoo.com ]
          Hide
          Nick Williams added a comment -

          Attached:
          Logging-Integration.zip - IntelliJ project with source code
          logging-integration-1.0.0.SNAPSHOT.war - WAR file that can be deployed directly in Tomcat

          You only need to go to http://localhost:8080/appcontext/ (replace appcontext with however you deploy it). The page will be blank but logging has taken place. That's enough to cause Log4j to start up. Then when you shut down Tomcat you'll see the errors. If you don't go to http://localhost:8080/appcontext/ to start up Log4j you won't see the errors.

          Show
          Nick Williams added a comment - Attached: Logging-Integration.zip - IntelliJ project with source code logging-integration-1.0.0.SNAPSHOT.war - WAR file that can be deployed directly in Tomcat You only need to go to http://localhost:8080/appcontext/ (replace appcontext with however you deploy it). The page will be blank but logging has taken place. That's enough to cause Log4j to start up. Then when you shut down Tomcat you'll see the errors. If you don't go to http://localhost:8080/appcontext/ to start up Log4j you won't see the errors.
          Nick Williams made changes -
          Attachment Logging-Integration.zip [ 12582455 ]
          Attachment logging-integration-1.0.0.SNAPSHOT.war [ 12582456 ]
          Remko Popma made changes -
          Priority Major [ 3 ] Critical [ 2 ]
          Hide
          Remko Popma added a comment -

          I have been unable to find the time to look at this and I don't expect this to change in the next few days. If anyone has the time and inclination to tackle this one, please go ahead.

          Show
          Remko Popma added a comment - I have been unable to find the time to look at this and I don't expect this to change in the next few days. If anyone has the time and inclination to tackle this one, please go ahead.
          Remko Popma made changes -
          Assignee Remko Popma [ remkop@yahoo.com ]
          Gary Gregory made changes -
          Fix Version/s 2.0-beta7 [ 12324400 ]
          Fix Version/s 2.0-beta6 [ 12324340 ]
          Hide
          Nick Williams added a comment - - edited

          In the latest 2.0-beta7-SNAPSHOT, this is still not fixed:

          INFO: Illegal access: this web application instance has been stopped already.  Could not load org.apache.logging.log4j.core.config.NullConfiguration.  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
          	at org.apache.catalina.loader.WebappClassLoader.loadClass(WebappClassLoader.java:1351)
          	at org.apache.catalina.loader.WebappClassLoader.loadClass(WebappClassLoader.java:1310)
          	at org.apache.logging.log4j.core.LoggerContext.stop(LoggerContext.java:201)
          	at org.apache.logging.log4j.core.LoggerContext$ShutdownThread.run(LoggerContext.java:427)
          
          Exception in thread "Thread-19" java.lang.NoClassDefFoundError: org/apache/logging/log4j/core/config/NullConfiguration
          	at org.apache.logging.log4j.core.LoggerContext.stop(LoggerContext.java:201)
          	at org.apache.logging.log4j.core.LoggerContext$ShutdownThread.run(LoggerContext.java:427)
          Caused by: java.lang.ClassNotFoundException: org.apache.logging.log4j.core.config.NullConfiguration
          	at org.apache.catalina.loader.WebappClassLoader.loadClass(WebappClassLoader.java:1465)
          	at org.apache.catalina.loader.WebappClassLoader.loadClass(WebappClassLoader.java:1310)
          	... 2 more

          I'd really like to see this issue fixed before beta7 is released. Are you able to replicate it in my sample application? Or have you still not been able to look at it? Is there anyone else that can look at it?

          I'd try to help with this, but now that Spring 4.0.0.M1 has been released (today), I have to get back to working on my book now. I'm about four weeks behind on chapters. Ooops.

          Show
          Nick Williams added a comment - - edited In the latest 2.0-beta7-SNAPSHOT, this is still not fixed: INFO: Illegal access: this web application instance has been stopped already. Could not load org.apache.logging.log4j.core.config.NullConfiguration. 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 at org.apache.catalina.loader.WebappClassLoader.loadClass(WebappClassLoader.java:1351) at org.apache.catalina.loader.WebappClassLoader.loadClass(WebappClassLoader.java:1310) at org.apache.logging.log4j.core.LoggerContext.stop(LoggerContext.java:201) at org.apache.logging.log4j.core.LoggerContext$ShutdownThread.run(LoggerContext.java:427) Exception in thread "Thread-19" java.lang.NoClassDefFoundError: org/apache/logging/log4j/core/config/NullConfiguration at org.apache.logging.log4j.core.LoggerContext.stop(LoggerContext.java:201) at org.apache.logging.log4j.core.LoggerContext$ShutdownThread.run(LoggerContext.java:427) Caused by: java.lang.ClassNotFoundException: org.apache.logging.log4j.core.config.NullConfiguration at org.apache.catalina.loader.WebappClassLoader.loadClass(WebappClassLoader.java:1465) at org.apache.catalina.loader.WebappClassLoader.loadClass(WebappClassLoader.java:1310) ... 2 more I'd really like to see this issue fixed before beta7 is released. Are you able to replicate it in my sample application? Or have you still not been able to look at it? Is there anyone else that can look at it? I'd try to help with this, but now that Spring 4.0.0.M1 has been released (today), I have to get back to working on my book now. I'm about four weeks behind on chapters. Ooops.
          Hide
          Remko Popma added a comment -

          Haven't had a chance. Have been making long hours at work.
          I don't think I'll be able to this weekend. I don't even have Tomcat set up yet...

          Btw, could you provide some more details on versions and stuff?
          Java version, Tomcat version? Any command line options?
          I'm not 100% sure but you are not using Async Loggers, are you?
          Are you using another ContextSelector? Also, not sure if relevant, but are you using the JSP TagLib?

          Show
          Remko Popma added a comment - Haven't had a chance. Have been making long hours at work. I don't think I'll be able to this weekend. I don't even have Tomcat set up yet... Btw, could you provide some more details on versions and stuff? Java version, Tomcat version? Any command line options? I'm not 100% sure but you are not using Async Loggers, are you? Are you using another ContextSelector? Also, not sure if relevant, but are you using the JSP TagLib?
          Hide
          Nick Williams added a comment -

          Java 1.8.0-ea-b88
          Tomcat 8.0-SNAPSHOT (r1478984)
          No special command-line options.
          I am not using Async Loggers.
          I am not using another ContextSelector.
          I /am/ using the Tag Library but I get this error even if I don't go to any JSPs, so I don't think that's it.

          I'd encourage you to try to duplicate this on Java 7 / Tomcat 7 before bothering trying to replicate my setup.

          Show
          Nick Williams added a comment - Java 1.8.0-ea-b88 Tomcat 8.0-SNAPSHOT (r1478984) No special command-line options. I am not using Async Loggers. I am not using another ContextSelector. I /am/ using the Tag Library but I get this error even if I don't go to any JSPs, so I don't think that's it. I'd encourage you to try to duplicate this on Java 7 / Tomcat 7 before bothering trying to replicate my setup.
          Hide
          Remko Popma added a comment -

          Thanks.
          Unexpected family circumstances just came up and I won't have access to a PC today, maybe this weekend. Only iPhone.
          Could you paste the output of StatusLogger debug output here?

          Show
          Remko Popma added a comment - Thanks. Unexpected family circumstances just came up and I won't have access to a PC today, maybe this weekend. Only iPhone. Could you paste the output of StatusLogger debug output here?
          Hide
          Nick Williams added a comment -

          With status="DEBUG":

          2013-05-18 10:10:54,533 DEBUG Generated plugins in 0.000028800 seconds
          2013-05-18 10:10:54,533 DEBUG Generated plugins in 0.000013200 seconds
          2013-05-18 10:10:54,534 DEBUG Generated plugins in 0.000012700 seconds
          2013-05-18 10:10:54,534 DEBUG Generated plugins in 0.000013100 seconds
          2013-05-18 10:10:54,535 DEBUG Generated plugins in 0.000013500 seconds
          2013-05-18 10:10:54,535 DEBUG Generated plugins in 0.000012700 seconds
          2013-05-18 10:10:54,536 DEBUG Generated plugins in 0.000012900 seconds
          2013-05-18 10:10:54,536 DEBUG Generated plugins in 0.000012400 seconds
          2013-05-18 10:10:54,536 DEBUG Generated plugins in 0.000012100 seconds
          2013-05-18 10:10:54,537 DEBUG Generated plugins in 0.000012600 seconds
          2013-05-18 10:10:54,537 DEBUG Generated plugins in 0.000012000 seconds
          2013-05-18 10:10:54,538 DEBUG Generated plugins in 0.000012300 seconds
          2013-05-18 10:10:54,538 DEBUG Generated plugins in 0.000015800 seconds
          2013-05-18 10:10:54,539 DEBUG Generated plugins in 0.000015800 seconds
          2013-05-18 10:10:54,539 DEBUG Generated plugins in 0.000012700 seconds
          2013-05-18 10:10:54,540 DEBUG Generated plugins in 0.000012800 seconds
          2013-05-18 10:10:54,548 DEBUG Calling createLayout on class org.apache.logging.log4j.core.layout.PatternLayout for element PatternLayout with params(pattern="%d{HH:mm:ss.SSS} [%t] %-5level %logger{36} - %msg%n", Configuration(C:\Users\Nicholas\Desktop\Logging-Integration\target\logging-integration-1.0.0.SNAPSHOT\WEB-INF\classes\log4j2.xml), null, charset="null", suppressExceptions="null")
          2013-05-18 10:10:54,549 DEBUG Generated plugins in 0.000019700 seconds
          2013-05-18 10:10:54,551 DEBUG Calling createAppender on class org.apache.logging.log4j.core.appender.ConsoleAppender for element Console with params(PatternLayout(%d{HH:mm:ss.SSS} [%t] %-5level %logger{36} - %msg%n), null, target="SYSTEM_OUT", name="Console", follow="null", suppressExceptions="null")
          2013-05-18 10:10:54,551 DEBUG Jansi is not installed
          2013-05-18 10:10:54,552 DEBUG Calling createLayout on class org.apache.logging.log4j.core.layout.PatternLayout for element PatternLayout with params(pattern="%d{HH:mm:ss.SSS} [%t] %X{id} %X{username} %-5level %c{36} %l: %msg%n", Configuration(C:\Users\Nicholas\Desktop\Logging-Integration\target\logging-integration-1.0.0.SNAPSHOT\WEB-INF\classes\log4j2.xml), null, charset="null", suppressExceptions="null")
          2013-05-18 10:10:54,553 DEBUG Calling createPolicy on class org.apache.logging.log4j.core.appender.rolling.SizeBasedTriggeringPolicy for element SizeBasedTriggeringPolicy with params(size="10 MB")
          2013-05-18 10:10:54,554 DEBUG Calling createPolicy on class org.apache.logging.log4j.core.appender.rolling.CompositeTriggeringPolicy for element Policies with params(policies={SizeBasedTriggeringPolicy(size=10485760)})
          2013-05-18 10:10:54,555 DEBUG Calling createStrategy on class org.apache.logging.log4j.core.appender.rolling.DefaultRolloverStrategy for element DefaultRolloverStrategy with params(max="4", min="1", fileIndex="null", Configuration(C:\Users\Nicholas\Desktop\Logging-Integration\target\logging-integration-1.0.0.SNAPSHOT\WEB-INF\classes\log4j2.xml))
          2013-05-18 10:10:54,557 DEBUG Calling createAppender on class org.apache.logging.log4j.core.appender.RollingFileAppender for element RollingFile with params(fileName="../logs/application.log", filePattern="../logs/application-%d{MM-dd-yyyy}-%i.log", append="null", name="WroxFileAppender", bufferedIO="null", immediateFlush="null", Policies(CompositeTriggeringPolicy{SizeBasedTriggeringPolicy(size=10485760)}), DefaultRolloverStrategy(DefaultRolloverStrategy(min=1, max=4)), PatternLayout(%d{HH:mm:ss.SSS} [%t] %X{id} %X{username} %-5level %c{36} %l: %msg%n), null, suppressExceptions="null", advertise="null", advertiseURI="null", Configuration(C:\Users\Nicholas\Desktop\Logging-Integration\target\logging-integration-1.0.0.SNAPSHOT\WEB-INF\classes\log4j2.xml))
          2013-05-18 10:10:54,561 DEBUG Starting RollingFileManager ../logs/application.log
          2013-05-18 10:10:54,563 DEBUG Generated plugins in 0.000018300 seconds
          2013-05-18 10:10:54,565 DEBUG Calling createAppenders on class org.apache.logging.log4j.core.config.plugins.AppendersPlugin for element appenders with params(appenders={Console, WroxFileAppender})
          2013-05-18 10:10:54,565 DEBUG Generated plugins in 0.000013300 seconds
          2013-05-18 10:10:54,566 DEBUG Calling createAppenderRef on class org.apache.logging.log4j.core.config.AppenderRef for element appender-ref with params(ref="Console", level="null", null)
          2013-05-18 10:10:54,567 DEBUG Calling createLogger on class org.apache.logging.log4j.core.config.LoggerConfig$RootLogger for element root with params(additivity="null", level="warn", includeLocation="null", appender-ref={org.apache.logging.log4j.core.config.AppenderRef@5445de97}, properties={}, Configuration(C:\Users\Nicholas\Desktop\Logging-Integration\target\logging-integration-1.0.0.SNAPSHOT\WEB-INF\classes\log4j2.xml), null)
          2013-05-18 10:10:54,568 DEBUG Calling createAppenderRef on class org.apache.logging.log4j.core.config.AppenderRef for element appender-ref with params(ref="WroxFileAppender", level="null", null)
          2013-05-18 10:10:54,569 DEBUG Calling createLogger on class org.apache.logging.log4j.core.config.LoggerConfig for element logger with params(additivity="false", level="info", name="com.wrox", includeLocation="null", appender-ref={org.apache.logging.log4j.core.config.AppenderRef@70970527}, properties={}, Configuration(C:\Users\Nicholas\Desktop\Logging-Integration\target\logging-integration-1.0.0.SNAPSHOT\WEB-INF\classes\log4j2.xml), null)
          2013-05-18 10:10:54,570 DEBUG Calling createAppenderRef on class org.apache.logging.log4j.core.config.AppenderRef for element appender-ref with params(ref="WroxFileAppender", level="null", null)
          2013-05-18 10:10:54,571 DEBUG Calling createLogger on class org.apache.logging.log4j.core.config.LoggerConfig for element logger with params(additivity="null", level="info", name="org.apache", includeLocation="null", appender-ref={org.apache.logging.log4j.core.config.AppenderRef@17238e67}, properties={}, Configuration(C:\Users\Nicholas\Desktop\Logging-Integration\target\logging-integration-1.0.0.SNAPSHOT\WEB-INF\classes\log4j2.xml), null)
          2013-05-18 10:10:54,572 DEBUG Calling createLoggers on class org.apache.logging.log4j.core.config.plugins.LoggersPlugin for element loggers with params(loggers={root, com.wrox, org.apache})
          2013-05-18 10:10:54,574 DEBUG Reconfiguration completed

          All of these messages happen when I go to the first page in the sample app. There are no debug messages that occur while Tomcat is shutting down / while the errors are occurring. I changed it to status="TRACE" and didn't get any extra output.

          Show
          Nick Williams added a comment - With status="DEBUG" : 2013-05-18 10:10:54,533 DEBUG Generated plugins in 0.000028800 seconds 2013-05-18 10:10:54,533 DEBUG Generated plugins in 0.000013200 seconds 2013-05-18 10:10:54,534 DEBUG Generated plugins in 0.000012700 seconds 2013-05-18 10:10:54,534 DEBUG Generated plugins in 0.000013100 seconds 2013-05-18 10:10:54,535 DEBUG Generated plugins in 0.000013500 seconds 2013-05-18 10:10:54,535 DEBUG Generated plugins in 0.000012700 seconds 2013-05-18 10:10:54,536 DEBUG Generated plugins in 0.000012900 seconds 2013-05-18 10:10:54,536 DEBUG Generated plugins in 0.000012400 seconds 2013-05-18 10:10:54,536 DEBUG Generated plugins in 0.000012100 seconds 2013-05-18 10:10:54,537 DEBUG Generated plugins in 0.000012600 seconds 2013-05-18 10:10:54,537 DEBUG Generated plugins in 0.000012000 seconds 2013-05-18 10:10:54,538 DEBUG Generated plugins in 0.000012300 seconds 2013-05-18 10:10:54,538 DEBUG Generated plugins in 0.000015800 seconds 2013-05-18 10:10:54,539 DEBUG Generated plugins in 0.000015800 seconds 2013-05-18 10:10:54,539 DEBUG Generated plugins in 0.000012700 seconds 2013-05-18 10:10:54,540 DEBUG Generated plugins in 0.000012800 seconds 2013-05-18 10:10:54,548 DEBUG Calling createLayout on class org.apache.logging.log4j.core.layout.PatternLayout for element PatternLayout with params(pattern="%d{HH:mm:ss.SSS} [%t] %-5level %logger{36} - %msg%n", Configuration(C:\Users\Nicholas\Desktop\Logging-Integration\target\logging-integration-1.0.0.SNAPSHOT\WEB-INF\classes\log4j2.xml), null, charset="null", suppressExceptions="null") 2013-05-18 10:10:54,549 DEBUG Generated plugins in 0.000019700 seconds 2013-05-18 10:10:54,551 DEBUG Calling createAppender on class org.apache.logging.log4j.core.appender.ConsoleAppender for element Console with params(PatternLayout(%d{HH:mm:ss.SSS} [%t] %-5level %logger{36} - %msg%n), null, target="SYSTEM_OUT", name="Console", follow="null", suppressExceptions="null") 2013-05-18 10:10:54,551 DEBUG Jansi is not installed 2013-05-18 10:10:54,552 DEBUG Calling createLayout on class org.apache.logging.log4j.core.layout.PatternLayout for element PatternLayout with params(pattern="%d{HH:mm:ss.SSS} [%t] %X{id} %X{username} %-5level %c{36} %l: %msg%n", Configuration(C:\Users\Nicholas\Desktop\Logging-Integration\target\logging-integration-1.0.0.SNAPSHOT\WEB-INF\classes\log4j2.xml), null, charset="null", suppressExceptions="null") 2013-05-18 10:10:54,553 DEBUG Calling createPolicy on class org.apache.logging.log4j.core.appender.rolling.SizeBasedTriggeringPolicy for element SizeBasedTriggeringPolicy with params(size="10 MB") 2013-05-18 10:10:54,554 DEBUG Calling createPolicy on class org.apache.logging.log4j.core.appender.rolling.CompositeTriggeringPolicy for element Policies with params(policies={SizeBasedTriggeringPolicy(size=10485760)}) 2013-05-18 10:10:54,555 DEBUG Calling createStrategy on class org.apache.logging.log4j.core.appender.rolling.DefaultRolloverStrategy for element DefaultRolloverStrategy with params(max="4", min="1", fileIndex="null", Configuration(C:\Users\Nicholas\Desktop\Logging-Integration\target\logging-integration-1.0.0.SNAPSHOT\WEB-INF\classes\log4j2.xml)) 2013-05-18 10:10:54,557 DEBUG Calling createAppender on class org.apache.logging.log4j.core.appender.RollingFileAppender for element RollingFile with params(fileName="../logs/application.log", filePattern="../logs/application-%d{MM-dd-yyyy}-%i.log", append="null", name="WroxFileAppender", bufferedIO="null", immediateFlush="null", Policies(CompositeTriggeringPolicy{SizeBasedTriggeringPolicy(size=10485760)}), DefaultRolloverStrategy(DefaultRolloverStrategy(min=1, max=4)), PatternLayout(%d{HH:mm:ss.SSS} [%t] %X{id} %X{username} %-5level %c{36} %l: %msg%n), null, suppressExceptions="null", advertise="null", advertiseURI="null", Configuration(C:\Users\Nicholas\Desktop\Logging-Integration\target\logging-integration-1.0.0.SNAPSHOT\WEB-INF\classes\log4j2.xml)) 2013-05-18 10:10:54,561 DEBUG Starting RollingFileManager ../logs/application.log 2013-05-18 10:10:54,563 DEBUG Generated plugins in 0.000018300 seconds 2013-05-18 10:10:54,565 DEBUG Calling createAppenders on class org.apache.logging.log4j.core.config.plugins.AppendersPlugin for element appenders with params(appenders={Console, WroxFileAppender}) 2013-05-18 10:10:54,565 DEBUG Generated plugins in 0.000013300 seconds 2013-05-18 10:10:54,566 DEBUG Calling createAppenderRef on class org.apache.logging.log4j.core.config.AppenderRef for element appender-ref with params(ref="Console", level="null", null) 2013-05-18 10:10:54,567 DEBUG Calling createLogger on class org.apache.logging.log4j.core.config.LoggerConfig$RootLogger for element root with params(additivity="null", level="warn", includeLocation="null", appender-ref={org.apache.logging.log4j.core.config.AppenderRef@5445de97}, properties={}, Configuration(C:\Users\Nicholas\Desktop\Logging-Integration\target\logging-integration-1.0.0.SNAPSHOT\WEB-INF\classes\log4j2.xml), null) 2013-05-18 10:10:54,568 DEBUG Calling createAppenderRef on class org.apache.logging.log4j.core.config.AppenderRef for element appender-ref with params(ref="WroxFileAppender", level="null", null) 2013-05-18 10:10:54,569 DEBUG Calling createLogger on class org.apache.logging.log4j.core.config.LoggerConfig for element logger with params(additivity="false", level="info", name="com.wrox", includeLocation="null", appender-ref={org.apache.logging.log4j.core.config.AppenderRef@70970527}, properties={}, Configuration(C:\Users\Nicholas\Desktop\Logging-Integration\target\logging-integration-1.0.0.SNAPSHOT\WEB-INF\classes\log4j2.xml), null) 2013-05-18 10:10:54,570 DEBUG Calling createAppenderRef on class org.apache.logging.log4j.core.config.AppenderRef for element appender-ref with params(ref="WroxFileAppender", level="null", null) 2013-05-18 10:10:54,571 DEBUG Calling createLogger on class org.apache.logging.log4j.core.config.LoggerConfig for element logger with params(additivity="null", level="info", name="org.apache", includeLocation="null", appender-ref={org.apache.logging.log4j.core.config.AppenderRef@17238e67}, properties={}, Configuration(C:\Users\Nicholas\Desktop\Logging-Integration\target\logging-integration-1.0.0.SNAPSHOT\WEB-INF\classes\log4j2.xml), null) 2013-05-18 10:10:54,572 DEBUG Calling createLoggers on class org.apache.logging.log4j.core.config.plugins.LoggersPlugin for element loggers with params(loggers={root, com.wrox, org.apache}) 2013-05-18 10:10:54,574 DEBUG Reconfiguration completed All of these messages happen when I go to the first page in the sample app. There are no debug messages that occur while Tomcat is shutting down / while the errors are occurring. I changed it to status="TRACE" and didn't get any extra output.
          Hide
          Remko Popma added a comment -

          I was unable to reproduce this issue on Apache Tomcat/7.0.40 or Apache Tomcat/6.0.36 (on Windows 7 (64b), Java 1.7.0_11 64bit).

          Steps to reproduce:

          1. install Tomcat
          2. cd to TOMCAT_HOME/bin
          3. run startup.bat
          4. drop attached file logging-integration-1.0.0.SNAPSHOT.war into TOMCAT_HOME/webapps
          5. (there seems to be an extra directory named "logging-integration-1.0.0.SNAPSHOT" inside the WAR file, so pull the contents of TOMCAT_HOME/webapps/logging-integration-1.0.0.SNAPSHOT/logging-integration-1.0.0.SNAPSHOT into TOMCAT_HOME/webapps/logging-integration-1.0.0.SNAPSHOT)
          6. open http://localhost:8080/logging-integration-1.0.0.SNAPSHOT/ in browser
            1. (result on Tomcat 6) 404 - /logging-integration-1.0.0.SNAPSHOT/files is not available
            2. (result on Tomcat 7) 404 - /logging-integration-1.0.0.SNAPSHOT/ is not available
          7. run shutdown.bat
          8. Tomcat stops without any issues

          Sorry Nick, I am giving up on this one.

          Show
          Remko Popma added a comment - I was unable to reproduce this issue on Apache Tomcat/7.0.40 or Apache Tomcat/6.0.36 (on Windows 7 (64b), Java 1.7.0_11 64bit). Steps to reproduce: install Tomcat cd to TOMCAT_HOME/bin run startup.bat drop attached file logging-integration-1.0.0.SNAPSHOT.war into TOMCAT_HOME/webapps (there seems to be an extra directory named "logging-integration-1.0.0.SNAPSHOT" inside the WAR file, so pull the contents of TOMCAT_HOME/webapps/logging-integration-1.0.0.SNAPSHOT/logging-integration-1.0.0.SNAPSHOT into TOMCAT_HOME/webapps/logging-integration-1.0.0.SNAPSHOT) open http://localhost:8080/logging-integration-1.0.0.SNAPSHOT/ in browser (result on Tomcat 6) 404 - /logging-integration-1.0.0.SNAPSHOT/files is not available (result on Tomcat 7) 404 - /logging-integration-1.0.0.SNAPSHOT/ is not available run shutdown.bat Tomcat stops without any issues Sorry Nick, I am giving up on this one.
          Nick Williams made changes -
          Attachment logging-integration-1.0.0.SNAPSHOT.war [ 12582456 ]
          Nick Williams made changes -
          Attachment Logging-Integration.zip [ 12582455 ]
          Hide
          Nick Williams added a comment -

          Remko,

          Waaaaiiit! Don't give up yet! My apologies. I did three things wrong here:

          1. I compiled the application using Java 8, so you won't be able to run it (that's why you're getting 404 errors most likely).
          2. I created the WAR file incorrectly.
          3. I hadn't narrowed down the exact conditions that must take place.

          I have compiled with Java 6 and created a proper WAR file. I was able to get the WAR file to duplicate the problem by following the following steps:

          1. Install Tomcat
          2. Open TOMCAT_HOME/conf and add a user to tomcat-users.xml with the manager-gui role (e.g., <user username="admin" password="admin" roles="manager-gui"/>).
          3. Copy log4j-223.war into TOMCAT_HOME/webapps
          4. cd into TOMCAT_HOME/bin
          5. Run catalina.bat run.
          6. Go to http://localhost:8080/log4j-223/files
          7. Go to http://localhost:8080/manager and enter proper credentials (admin/admin)
          8. Click the "Undeploy" button next to the log4j-223 application
          9. Return to command prompt and Ctrl+C to shut down Tomcat
          10. Error appears
          Show
          Nick Williams added a comment - Remko, Waaaaiiit! Don't give up yet! My apologies. I did three things wrong here: I compiled the application using Java 8, so you won't be able to run it (that's why you're getting 404 errors most likely). I created the WAR file incorrectly. I hadn't narrowed down the exact conditions that must take place. I have compiled with Java 6 and created a proper WAR file. I was able to get the WAR file to duplicate the problem by following the following steps: Install Tomcat Open TOMCAT_HOME/conf and add a user to tomcat-users.xml with the manager-gui role (e.g., <user username="admin" password="admin" roles="manager-gui"/> ). Copy log4j-223.war into TOMCAT_HOME/webapps cd into TOMCAT_HOME/bin Run catalina.bat run . Go to http://localhost:8080/log4j-223/files Go to http://localhost:8080/manager and enter proper credentials (admin/admin) Click the "Undeploy" button next to the log4j-223 application Return to command prompt and Ctrl+C to shut down Tomcat Error appears
          Nick Williams made changes -
          Attachment log4j-223.war [ 12583752 ]
          Hide
          Remko Popma added a comment -

          with the above steps I was able to reproduce the issue. (I only tried Tomcat 7, btw.)

          5 19, 2013 11:12:11 AM org.apache.catalina.loader.WebappClassLoader loadClass
          INFO: Illegal access: this web application instance has been stopped already. 
                Could not load org.apache.logging.log4j.core.config.NullConfiguration. 
                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
                  at org.apache.catalina.loader.WebappClassLoader.loadClass(WebappClassLoader.java:1600)
                  at org.apache.catalina.loader.WebappClassLoader.loadClass(WebappClassLoader.java:1559)
                  at org.apache.logging.log4j.core.LoggerContext.stop(LoggerContext.java:199)
                  at org.apache.logging.log4j.core.LoggerContext$ShutdownThread.run(LoggerContext.java:418)
          
          Exception in thread "Thread-36" java.lang.NoClassDefFoundError: org/apache/logging/log4j/core/config/NullConfiguration
                  at org.apache.logging.log4j.core.LoggerContext.stop(LoggerContext.java:199)
                  at org.apache.logging.log4j.core.LoggerContext$ShutdownThread.run(LoggerContext.java:418)
          Caused by: java.lang.ClassNotFoundException: org.apache.logging.log4j.core.config.NullConfiguration
                  at org.apache.catalina.loader.WebappClassLoader.loadClass(WebappClassLoader.java:1714)
                  at org.apache.catalina.loader.WebappClassLoader.loadClass(WebappClassLoader.java:1559)
                  ... 2 more
          5 19, 2013 11:12:11 AM org.apache.coyote.AbstractProtocol pause
          INFO: Pausing ProtocolHandler ["ajp-apr-8009"]
          5 19, 2013 11:12:11 AM org.apache.catalina.core.StandardService stopInternal
          

          Looks like Catalina's WebappClassLoader won't allow a web application to load new classes after it has been stopped.

          The problem seems to be the code here:

          public void stop() {
              configLock.lock();
              try {
                  if (status == Status.STOPPED) {
                      return;
                  }
                  status = Status.STOPPING;
                  if (shutdownThread != null) {
                      Runtime.getRuntime().removeShutdownHook(shutdownThread);
                      shutdownThread = null;
                  }
                  Configuration prev = config;
                  config = new NullConfiguration(); // <-- Tomcat won't let us do this
                  updateLoggers();
                  prev.stop();
                  externalContext = null;
                  status = Status.STOPPED;
              } finally {
                  configLock.unlock();
              }
          }
          

          Here is what I tried: at the top of LoggerContext, declare a static field holding an instance of NullConfiguration.

           // LOG4J2-223 cannot load new class during stop() in web apps, so load this up front
           private static final NullConfiguration NULL_CONFIGURATION = new NullConfiguration();
          

          Then, in the stop() method, instead of creating a new NullConfiguration, return the pre-loaded instance:

          status = Status.STOPPING;
          if (shutdownThread != null) {
              Runtime.getRuntime().removeShutdownHook(shutdownThread);
              shutdownThread = null;
          }
          Configuration prev = config;
          config = NULL_CONFIGURATION;
          updateLoggers();
          prev.stop();
          externalContext = null;
          status = Status.STOPPED;
          

          To test this, I unzipped the log4j-223.war file and replaced these files:
          log4j-api-2.0-beta6.jar
          log4j-core-2.0-beta6.jar
          log4j-jcl-2.0-beta6.jar
          log4j-slf4j-impl-2.0-beta6.jar
          log4j-taglib-2.0-beta6.jar

          with these freshly built files:
          log4j-api-2.0-beta7-SNAPSHOT.jar
          log4j-core-2.0-beta7-SNAPSHOT.jar
          log4j-jcl-2.0-beta7-SNAPSHOT.jar
          log4j-slf4j-impl-2.0-beta7-SNAPSHOT.jar
          log4j-taglib-2.0-beta7-SNAPSHOT.jar

          Then I followed the same steps as Nick described above to check the result.

          Opening http://localhost:8080/log4j-223a/ gave (I actually got a Japanese error message but this is my rough translation):
          500 - /index.jsp (line: 1, column: 1) absolute URI: http://logging.apache.org/log4j/tld/log cannot be resolved in web.xml or the deployed jar for this application

          I think this is related to the JSP Taglib, here is the stack trace for completeness:

          org.apache.jasper.JasperException: /index.jsp (line: 1, column: 1) absolute URI: 
                               http://logging.apache.org/log4j/tld/log cannot be resolved in(?) 
                               web.xml or the deployed jar for this application
          	org.apache.jasper.compiler.DefaultErrorHandler.jspError(DefaultErrorHandler.java:42)
          	org.apache.jasper.compiler.ErrorDispatcher.dispatch(ErrorDispatcher.java:443)
          	org.apache.jasper.compiler.ErrorDispatcher.jspError(ErrorDispatcher.java:89)
          	org.apache.jasper.compiler.Parser.processIncludeDirective(Parser.java:324)
          	org.apache.jasper.compiler.Parser.addInclude(Parser.java:375)
          	org.apache.jasper.compiler.Parser.parse(Parser.java:132)
          	org.apache.jasper.compiler.ParserController.doParse(ParserController.java:242)
          	org.apache.jasper.compiler.ParserController.parse(ParserController.java:102)
          	org.apache.jasper.compiler.Compiler.generateJava(Compiler.java:198)
          	org.apache.jasper.compiler.Compiler.compile(Compiler.java:373)
          	org.apache.jasper.compiler.Compiler.compile(Compiler.java:353)
          	org.apache.jasper.compiler.Compiler.compile(Compiler.java:340)
          	org.apache.jasper.JspCompilationContext.compile(JspCompilationContext.java:646)
          	org.apache.jasper.servlet.JspServletWrapper.service(JspServletWrapper.java:357)
          	org.apache.jasper.servlet.JspServlet.serviceJspFile(JspServlet.java:390)
          	org.apache.jasper.servlet.JspServlet.service(JspServlet.java:334)
          	javax.servlet.http.HttpServlet.service(HttpServlet.java:728)
          	com.wrox.LoggingFilter.doFilter(LoggingFilter.java:32)
          

          Undeploying the webapp in the Tomcat manager did not work cleanly:
          webapps\log4j-223a\WEB-INF\lib\log4j-core-2.0-beta7-SNAPSHOT.jar was not removed
          and Tomcat gave these warnings in the console:

          5 19, 2013 12:46:43 午後 org.apache.catalina.startup.ExpandWar deleteDir
          SEVERE: [C:\apps\apache-tomcat-7.0.40\webapps\log4j-223a\WEB-INF\lib] could not be completely deleted. The presence of the remaining files may cause p
          roblems
          5 19, 2013 12:46:43 午後 org.apache.catalina.startup.ExpandWar deleteDir
          SEVERE: [C:\apps\apache-tomcat-7.0.40\webapps\log4j-223a\WEB-INF] could not be completely deleted. The presence of the remaining files may cause problems
          5 19, 2013 12:46:43 午後 org.apache.catalina.startup.ExpandWar deleteDir
          SEVERE: [C:\apps\apache-tomcat-7.0.40\webapps\log4j-223a] could not be completely deleted. The presence of the remaining files may cause problems
          5 19, 2013 12:46:43 午後 org.apache.catalina.startup.ExpandWar delete
          SEVERE: [C:\apps\apache-tomcat-7.0.40\webapps\log4j-223a] could not be completely deleted. The presence of the remaining files may cause problems
          5 19, 2013 12:46:43 午後 org.apache.catalina.startup.HostConfig deployDirectory
          INFO: Web application directory  C:\apps\apache-tomcat-7.0.40\webapps\log4j-223a deploying
          

          After this, Ctrl-C in the command prompt does shut down Tomcat without errors.

          Show
          Remko Popma added a comment - with the above steps I was able to reproduce the issue. (I only tried Tomcat 7, btw.) 5 19, 2013 11:12:11 AM org.apache.catalina.loader.WebappClassLoader loadClass INFO: Illegal access: this web application instance has been stopped already. Could not load org.apache.logging.log4j.core.config.NullConfiguration. 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 at org.apache.catalina.loader.WebappClassLoader.loadClass(WebappClassLoader.java:1600) at org.apache.catalina.loader.WebappClassLoader.loadClass(WebappClassLoader.java:1559) at org.apache.logging.log4j.core.LoggerContext.stop(LoggerContext.java:199) at org.apache.logging.log4j.core.LoggerContext$ShutdownThread.run(LoggerContext.java:418) Exception in thread " Thread -36" java.lang.NoClassDefFoundError: org/apache/logging/log4j/core/config/NullConfiguration at org.apache.logging.log4j.core.LoggerContext.stop(LoggerContext.java:199) at org.apache.logging.log4j.core.LoggerContext$ShutdownThread.run(LoggerContext.java:418) Caused by: java.lang.ClassNotFoundException: org.apache.logging.log4j.core.config.NullConfiguration at org.apache.catalina.loader.WebappClassLoader.loadClass(WebappClassLoader.java:1714) at org.apache.catalina.loader.WebappClassLoader.loadClass(WebappClassLoader.java:1559) ... 2 more 5 19, 2013 11:12:11 AM org.apache.coyote.AbstractProtocol pause INFO: Pausing ProtocolHandler [ "ajp-apr-8009" ] 5 19, 2013 11:12:11 AM org.apache.catalina.core.StandardService stopInternal Looks like Catalina's WebappClassLoader won't allow a web application to load new classes after it has been stopped. The problem seems to be the code here: public void stop() { configLock.lock(); try { if (status == Status.STOPPED) { return ; } status = Status.STOPPING; if (shutdownThread != null ) { Runtime .getRuntime().removeShutdownHook(shutdownThread); shutdownThread = null ; } Configuration prev = config; config = new NullConfiguration(); // <-- Tomcat won't let us do this updateLoggers(); prev.stop(); externalContext = null ; status = Status.STOPPED; } finally { configLock.unlock(); } } Here is what I tried: at the top of LoggerContext, declare a static field holding an instance of NullConfiguration. // LOG4J2-223 cannot load new class during stop() in web apps, so load this up front private static final NullConfiguration NULL_CONFIGURATION = new NullConfiguration(); Then, in the stop() method, instead of creating a new NullConfiguration, return the pre-loaded instance: status = Status.STOPPING; if (shutdownThread != null ) { Runtime .getRuntime().removeShutdownHook(shutdownThread); shutdownThread = null ; } Configuration prev = config; config = NULL_CONFIGURATION; updateLoggers(); prev.stop(); externalContext = null ; status = Status.STOPPED; To test this, I unzipped the log4j-223.war file and replaced these files: log4j-api-2.0-beta6.jar log4j-core-2.0-beta6.jar log4j-jcl-2.0-beta6.jar log4j-slf4j-impl-2.0-beta6.jar log4j-taglib-2.0-beta6.jar with these freshly built files: log4j-api-2.0-beta7-SNAPSHOT.jar log4j-core-2.0-beta7-SNAPSHOT.jar log4j-jcl-2.0-beta7-SNAPSHOT.jar log4j-slf4j-impl-2.0-beta7-SNAPSHOT.jar log4j-taglib-2.0-beta7-SNAPSHOT.jar Then I followed the same steps as Nick described above to check the result. Opening http://localhost:8080/log4j-223a/ gave (I actually got a Japanese error message but this is my rough translation): 500 - /index.jsp (line: 1, column: 1) absolute URI: http://logging.apache.org/log4j/tld/log cannot be resolved in web.xml or the deployed jar for this application I think this is related to the JSP Taglib, here is the stack trace for completeness: org.apache.jasper.JasperException: /index.jsp (line: 1, column: 1) absolute URI: http: //logging.apache.org/log4j/tld/log cannot be resolved in(?) web.xml or the deployed jar for this application org.apache.jasper.compiler.DefaultErrorHandler.jspError(DefaultErrorHandler.java:42) org.apache.jasper.compiler.ErrorDispatcher.dispatch(ErrorDispatcher.java:443) org.apache.jasper.compiler.ErrorDispatcher.jspError(ErrorDispatcher.java:89) org.apache.jasper.compiler.Parser.processIncludeDirective(Parser.java:324) org.apache.jasper.compiler.Parser.addInclude(Parser.java:375) org.apache.jasper.compiler.Parser.parse(Parser.java:132) org.apache.jasper.compiler.ParserController.doParse(ParserController.java:242) org.apache.jasper.compiler.ParserController.parse(ParserController.java:102) org.apache.jasper.compiler. Compiler .generateJava( Compiler .java:198) org.apache.jasper.compiler. Compiler .compile( Compiler .java:373) org.apache.jasper.compiler. Compiler .compile( Compiler .java:353) org.apache.jasper.compiler. Compiler .compile( Compiler .java:340) org.apache.jasper.JspCompilationContext.compile(JspCompilationContext.java:646) org.apache.jasper.servlet.JspServletWrapper.service(JspServletWrapper.java:357) org.apache.jasper.servlet.JspServlet.serviceJspFile(JspServlet.java:390) org.apache.jasper.servlet.JspServlet.service(JspServlet.java:334) javax.servlet.http.HttpServlet.service(HttpServlet.java:728) com.wrox.LoggingFilter.doFilter(LoggingFilter.java:32) Undeploying the webapp in the Tomcat manager did not work cleanly: webapps\log4j-223a\WEB-INF\lib\log4j-core-2.0-beta7-SNAPSHOT.jar was not removed and Tomcat gave these warnings in the console: 5 19, 2013 12:46:43 午後 org.apache.catalina.startup.ExpandWar deleteDir SEVERE: [C:\apps\apache-tomcat-7.0.40\webapps\log4j-223a\WEB-INF\lib] could not be completely deleted. The presence of the remaining files may cause p roblems 5 19, 2013 12:46:43 午後 org.apache.catalina.startup.ExpandWar deleteDir SEVERE: [C:\apps\apache-tomcat-7.0.40\webapps\log4j-223a\WEB-INF] could not be completely deleted. The presence of the remaining files may cause problems 5 19, 2013 12:46:43 午後 org.apache.catalina.startup.ExpandWar deleteDir SEVERE: [C:\apps\apache-tomcat-7.0.40\webapps\log4j-223a] could not be completely deleted. The presence of the remaining files may cause problems 5 19, 2013 12:46:43 午後 org.apache.catalina.startup.ExpandWar delete SEVERE: [C:\apps\apache-tomcat-7.0.40\webapps\log4j-223a] could not be completely deleted. The presence of the remaining files may cause problems 5 19, 2013 12:46:43 午後 org.apache.catalina.startup.HostConfig deployDirectory INFO: Web application directory C:\apps\apache-tomcat-7.0.40\webapps\log4j-223a deploying After this, Ctrl-C in the command prompt does shut down Tomcat without errors.
          Hide
          Remko Popma added a comment -

          The 500 error above is probably not related to Taglib. It also occurred after replacing the logging.jsp with a simple "Hello world" containing only HTML tags.

          Not sure if this is related, but the console also shows this:

          5 19, 2013 1:18:36 午後 org.apache.jasper.compiler.TldLocationsCache tldScanJar
          INFO: 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.
          
          Show
          Remko Popma added a comment - The 500 error above is probably not related to Taglib. It also occurred after replacing the logging.jsp with a simple "Hello world" containing only HTML tags. Not sure if this is related, but the console also shows this: 5 19, 2013 1:18:36 午後 org.apache.jasper.compiler.TldLocationsCache tldScanJar INFO: 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.
          Hide
          Nick Williams added a comment -

          Try going to http://localhost:8080/log4j-223a/files directly instead of http://localhost:8080/log4j-223a/.

          Cause: log4j-taglib*.jar contains a TLD (Tag Library Descriptor) used in the JSPs. The container must scan this JAR to pick up the TLD. However, since Log4j has never had a tag library until now, Tomcat has an exclusion built in that says not to scan log4j*.jar files for tag libraries (for which I have filed a bug, https://issues.apache.org/bugzilla/show_bug.cgi?id=54770). In my local Tomcat install, I removed the log4j*.jar exclusion from catalina.properties. You can either do the same, or go to http://localhost:8080/log4j-223a/files directly to skip all JSPs and therefore avoid TLD-loading errors.

          This is unrelated to the issue at hand, but is the cause of the new errors you saw. Just go to http://localhost:8080/log4j-223a/files directly (or remove the log4j*.jar exclusion from TOMCAT_HOME/conf/catalina.properties) to isolate the IllegalStateException behavior.

          It looks like your change may fix the error being displayed, but I don't think it resolves the underlying issue. The underlying issue appears to be a memory leak. By registering a shutdown hook, Log4j creates a thread with classes loaded in the servlet context class loader but held on to by the JVM. When Tomcat undeploys the application, the garbage collector will be unable to collect the servlet context class loader and any classes it loaded because of this. If you redeploy and undeploy the application several times, you will eventually get an OutOfMemoryError: perm gen space exception.

          What is this code trying to accomplish? Why are we registering a shutdown hook here? I question the necessity of this code, and its existence is creating a dangerous situation for web applications.

          Show
          Nick Williams added a comment - Try going to http://localhost:8080/log4j-223a/files directly instead of http://localhost:8080/log4j-223a/ . Cause: log4j-taglib*.jar contains a TLD (Tag Library Descriptor) used in the JSPs. The container must scan this JAR to pick up the TLD. However, since Log4j has never had a tag library until now, Tomcat has an exclusion built in that says not to scan log4j*.jar files for tag libraries (for which I have filed a bug, https://issues.apache.org/bugzilla/show_bug.cgi?id=54770 ). In my local Tomcat install, I removed the log4j*.jar exclusion from catalina.properties. You can either do the same, or go to http://localhost:8080/log4j-223a/files directly to skip all JSPs and therefore avoid TLD-loading errors. This is unrelated to the issue at hand, but is the cause of the new errors you saw. Just go to http://localhost:8080/log4j-223a/files directly (or remove the log4j*.jar exclusion from TOMCAT_HOME/conf/catalina.properties) to isolate the IllegalStateException behavior. It looks like your change may fix the error being displayed, but I don't think it resolves the underlying issue. The underlying issue appears to be a memory leak. By registering a shutdown hook, Log4j creates a thread with classes loaded in the servlet context class loader but held on to by the JVM. When Tomcat undeploys the application, the garbage collector will be unable to collect the servlet context class loader and any classes it loaded because of this. If you redeploy and undeploy the application several times, you will eventually get an OutOfMemoryError: perm gen space exception. What is this code trying to accomplish? Why are we registering a shutdown hook here? I question the necessity of this code, and its existence is creating a dangerous situation for web applications.
          Nick Williams made changes -
          Summary IlliegalStateException thrown during Tomcat shutdown IllegalStateException thrown during Tomcat shutdown
          Description 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
          INFO: Pausing ProtocolHandler ["http-nio-8080"]
          Apr 25, 2013 3:03:33 PM org.apache.coyote.AbstractProtocol pause
          INFO: Pausing ProtocolHandler ["ajp-nio-8009"]
          Apr 25, 2013 3:03:33 PM org.apache.catalina.core.StandardService stopInternal
          INFO: Stopping service Catalina
          Apr 25, 2013 3:03:33 PM org.apache.coyote.AbstractProtocol stop
          INFO: Stopping ProtocolHandler ["http-nio-8080"]
          Apr 25, 2013 3:03:33 PM org.apache.coyote.AbstractProtocol stop
          INFO: Stopping ProtocolHandler ["ajp-nio-8009"]
          Apr 25, 2013 3:03:33 PM org.apache.coyote.AbstractProtocol destroy
          INFO: Destroying ProtocolHandler ["http-nio-8080"]
          Apr 25, 2013 3:03:33 PM org.apache.coyote.AbstractProtocol destroy
          INFO: Destroying ProtocolHandler ["ajp-nio-8009"]
          Apr 25, 2013 3:03:33 PM org.apache.catalina.loader.WebappClassLoader loadClass
          INFO: Illegal access: this web application instance has been stopped already. Could not load org.apache.logging.log4j.core.config.NullConfiguration. 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
          at org.apache.catalina.loader.WebappClassLoader.loadClass(WebappClassLoader.java:1351)
          at org.apache.catalina.loader.WebappClassLoader.loadClass(WebappClassLoader.java:1310)
          at org.apache.logging.log4j.core.LoggerContext.stop(LoggerContext.java:171)
          at org.apache.logging.log4j.core.LoggerContext$ShutdownThread.run(LoggerContext.java:389)

          Exception in thread "Thread-18" java.lang.NoClassDefFoundError: org/apache/logging/log4j/core/config/NullConfiguration
          at org.apache.logging.log4j.core.LoggerContext.stop(LoggerContext.java:171)
          at org.apache.logging.log4j.core.LoggerContext$ShutdownThread.run(LoggerContext.java:389)
          Caused by: java.lang.ClassNotFoundException: org.apache.logging.log4j.core.config.NullConfiguration
          at org.apache.catalina.loader.WebappClassLoader.loadClass(WebappClassLoader.java:1465)
          at org.apache.catalina.loader.WebappClassLoader.loadClass(WebappClassLoader.java:1310)
          ... 2 more
          {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
          INFO: Pausing ProtocolHandler ["http-nio-8080"]
          Apr 25, 2013 3:03:33 PM org.apache.coyote.AbstractProtocol pause
          INFO: Pausing ProtocolHandler ["ajp-nio-8009"]
          Apr 25, 2013 3:03:33 PM org.apache.catalina.core.StandardService stopInternal
          INFO: Stopping service Catalina
          Apr 25, 2013 3:03:33 PM org.apache.coyote.AbstractProtocol stop
          INFO: Stopping ProtocolHandler ["http-nio-8080"]
          Apr 25, 2013 3:03:33 PM org.apache.coyote.AbstractProtocol stop
          INFO: Stopping ProtocolHandler ["ajp-nio-8009"]
          Apr 25, 2013 3:03:33 PM org.apache.coyote.AbstractProtocol destroy
          INFO: Destroying ProtocolHandler ["http-nio-8080"]
          Apr 25, 2013 3:03:33 PM org.apache.coyote.AbstractProtocol destroy
          INFO: Destroying ProtocolHandler ["ajp-nio-8009"]
          Apr 25, 2013 3:03:33 PM org.apache.catalina.loader.WebappClassLoader loadClass
          INFO: Illegal access: this web application instance has been stopped already. Could not load org.apache.logging.log4j.core.config.NullConfiguration. 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
          at org.apache.catalina.loader.WebappClassLoader.loadClass(WebappClassLoader.java:1351)
          at org.apache.catalina.loader.WebappClassLoader.loadClass(WebappClassLoader.java:1310)
          at org.apache.logging.log4j.core.LoggerContext.stop(LoggerContext.java:171)
          at org.apache.logging.log4j.core.LoggerContext$ShutdownThread.run(LoggerContext.java:389)

          Exception in thread "Thread-18" java.lang.NoClassDefFoundError: org/apache/logging/log4j/core/config/NullConfiguration
          at org.apache.logging.log4j.core.LoggerContext.stop(LoggerContext.java:171)
          at org.apache.logging.log4j.core.LoggerContext$ShutdownThread.run(LoggerContext.java:389)
          Caused by: java.lang.ClassNotFoundException: org.apache.logging.log4j.core.config.NullConfiguration
          at org.apache.catalina.loader.WebappClassLoader.loadClass(WebappClassLoader.java:1465)
          at org.apache.catalina.loader.WebappClassLoader.loadClass(WebappClassLoader.java:1310)
          ... 2 more{noformat}
          Hide
          Remko Popma added a comment - - edited

          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:

          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)
          

          Line numbers changed with my fix, so here is what at line 206 in LoggerContext:

          203	Configuration prev = config;
          204	config = NULL_CONFIGURATION;
          205	updateLoggers();
          206	prev.stop();
          207	externalContext = null;
          
          Show
          Remko Popma added a comment - - edited 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: 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) Line numbers changed with my fix, so here is what at line 206 in LoggerContext: 203 Configuration prev = config; 204 config = NULL_CONFIGURATION; 205 updateLoggers(); 206 prev.stop(); 207 externalContext = null ;
          Hide
          Nick Williams added a comment -

          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.

          Show
          Nick Williams added a comment - 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.
          Hide
          Remko Popma added a comment -

          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.

          Show
          Remko Popma added a comment - 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.
          Hide
          Nick Williams added a comment -

          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.

          Show
          Nick Williams added a comment - 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.
          Hide
          Remko Popma added a comment -

          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?)

          Show
          Remko Popma added a comment - 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?)
          Hide
          Ralph Goers added a comment -

          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.

          Show
          Ralph Goers added a comment - 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.
          Hide
          Remko Popma added a comment -

          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?

          Show
          Remko Popma added a comment - 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?
          Hide
          Ralph Goers added a comment -

          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".

          Show
          Ralph Goers added a comment - 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".
          Hide
          Remko Popma added a comment -

          Definitely one for the FAQ.

          The problem no longer occurs if the BasicContextSelector is configured.
          In Tomcat, this can be done by adding this line to $TOMCAT_HOME/conf/catalina.properties :
          Log4jContextSelector=org.apache.logging.log4j.core.selector.BasicContextSelector

          I'll try the Log4jContextListener next.

          Show
          Remko Popma added a comment - Definitely one for the FAQ. The problem no longer occurs if the BasicContextSelector is configured. In Tomcat, this can be done by adding this line to $TOMCAT_HOME/conf/catalina.properties : Log4jContextSelector=org.apache.logging.log4j.core.selector.BasicContextSelector I'll try the Log4jContextListener next.
          Hide
          Remko Popma added a comment -

          The listener did not go as smooth...

          First, I removed the above BasicContextSelector.
          Then, after deploying Nick's attached log4j-223.war, I modified\webapps\log4j-223\WEB-INF\web.xml as follows:

          <web-app xmlns="http://java.sun.com/xml/ns/javaee"
                     xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
                     xsi:schemaLocation="http://java.sun.com/xml/ns/javaee
                                         http://java.sun.com/xml/ns/javaee/web-app_3_1.xsd"
                     version="3.1">
          
              <display-name>Logging Integration Application</display-name>
          
          <!-- added listener -->
          	<listener>
          		<listener-class>org.apache.logging.log4j.core.web.Log4jContextListener</listener-class>
          	</listener>
          ...
          

          I also had to add log4j-web-2.0-beta6.jar to WEB-INF/lib.

          Undeploying gave the following (now familiar) error:
          FAIL - Unable to delete [C:\apps\apache-tomcat-7.0.40\webapps\log4j-223]. The continued presence of this file may cause problems.

          Under the webapps folder, this file was not deleted: webapps\log4j-223\WEB-INF\lib\log4j-core-2.0-beta6.jar
          However, shutting down Tomcat with Ctrl-C did not give any errors.

          Show
          Remko Popma added a comment - The listener did not go as smooth... First, I removed the above BasicContextSelector. Then, after deploying Nick's attached log4j-223.war, I modified\webapps\log4j-223\WEB-INF\web.xml as follows: <web-app xmlns= "http: //java.sun.com/xml/ns/javaee" xmlns:xsi= "http: //www.w3.org/2001/XMLSchema-instance" xsi:schemaLocation="http: //java.sun.com/xml/ns/javaee http: //java.sun.com/xml/ns/javaee/web-app_3_1.xsd" version= "3.1" > <display-name>Logging Integration Application</display-name> <!-- added listener --> <listener> <listener-class>org.apache.logging.log4j.core.web.Log4jContextListener</listener-class> </listener> ... I also had to add log4j-web-2.0-beta6.jar to WEB-INF/lib. Undeploying gave the following (now familiar) error: FAIL - Unable to delete [C:\apps\apache-tomcat-7.0.40\webapps\log4j-223] . The continued presence of this file may cause problems. Under the webapps folder, this file was not deleted: webapps\log4j-223\WEB-INF\lib\log4j-core-2.0-beta6.jar However, shutting down Tomcat with Ctrl-C did not give any errors.
          Hide
          Remko Popma added a comment - - edited

          I added the following text to the documentation in /web/src/site/xdoc/index.xml:

          ...
          To register this listener, make sure that the log4j-web-2.0.jar file is in the classpath (either in your web application's WEB-INF/lib directory or in the container's classpath) and add the following snippet to your web.xml:

            <listener>
              <listener-class>org.apache.logging.log4j.core.web.Log4jContextListener</listener-class>
            </listener>
          

          I hope that both these classpath locations are actually correct. Ralph, are they?

          Show
          Remko Popma added a comment - - edited I added the following text to the documentation in /web/src/site/xdoc/index.xml: ... To register this listener, make sure that the log4j-web-2.0.jar file is in the classpath (either in your web application's WEB-INF/lib directory or in the container's classpath) and add the following snippet to your web.xml: <listener> <listener-class>org.apache.logging.log4j.core.web.Log4jContextListener</listener-class> </listener> I hope that both these classpath locations are actually correct. Ralph, are they?
          Hide
          Nick Williams added a comment -

          I have two issues with all of this:

          1. "FAIL - Unable to delete [C:\apps\apache-tomcat-7.0.40\webapps\log4j-223]. The continued presence of this file may cause problems." <-- This means Log4j has a memory leak in web applications. The Log4j classes are still loaded by a class outside the web application and can't be garbage collected.
          2. Log4j 1 did not require users to configure a listener in order for logging to work properly. Log4j 2 users should not have to, either. It should "just work" like Log4j 1 did. If the only purpose of the log4j-web module is to make Log4j 2 work properly in web applications, I suggest that it should be removed completely and a better way should be found. Like I said, Log4j 1 works just fine without a listener.
          Show
          Nick Williams added a comment - I have two issues with all of this: "FAIL - Unable to delete [C:\apps\apache-tomcat-7.0.40\webapps\log4j-223] . The continued presence of this file may cause problems." <-- This means Log4j has a memory leak in web applications. The Log4j classes are still loaded by a class outside the web application and can't be garbage collected. Log4j 1 did not require users to configure a listener in order for logging to work properly. Log4j 2 users should not have to, either. It should "just work" like Log4j 1 did. If the only purpose of the log4j-web module is to make Log4j 2 work properly in web applications, I suggest that it should be removed completely and a better way should be found. Like I said, Log4j 1 works just fine without a listener.
          Hide
          Ralph Goers added a comment -

          Item 1 is a problem. I have a feeling I know what is causing it. I suspect there is a relationship between the LoggerContext and classloader that is not being removed.

          As for item 2 - Log4j 1 "just works" by not doing anything. That doesn't mean it is better. It doesn't close files or perform any cleanup. This may result in the loss of data during shutdown depending on how the appenders work.

          Show
          Ralph Goers added a comment - Item 1 is a problem. I have a feeling I know what is causing it. I suspect there is a relationship between the LoggerContext and classloader that is not being removed. As for item 2 - Log4j 1 "just works" by not doing anything. That doesn't mean it is better. It doesn't close files or perform any cleanup. This may result in the loss of data during shutdown depending on how the appenders work.
          Hide
          Nick Williams added a comment -

          Fair enough, but I still think there's a "better way" than requiring users to configure a listener. To me, philosophically, logging should "just work."

          What about Object#finalize()? If we created a finalizer for LoggerContext, it could check if the context had been stopped, and stop it if it had not. Then we wouldn't need a shutdown hook. In theory (and this would need to be tested), without a shutdown hook the LoggerContext would be garbage collected as soon as the web application was undeployed, resulting in the LoggerContext being closed without a listener.

          Show
          Nick Williams added a comment - Fair enough, but I still think there's a "better way" than requiring users to configure a listener. To me, philosophically, logging should "just work." What about Object#finalize() ? If we created a finalizer for LoggerContext , it could check if the context had been stopped, and stop it if it had not. Then we wouldn't need a shutdown hook. In theory (and this would need to be tested), without a shutdown hook the LoggerContext would be garbage collected as soon as the web application was undeployed, resulting in the LoggerContext being closed without a listener.
          Hide
          Nick Williams added a comment -

          The problem with Object#finalize(), it would appear after brief experimentation, is that it isn't called in a standalone application at JVM shutdown, so the shutdown hook would still be needed there. I'm going to continue to experiment a bit...

          Show
          Nick Williams added a comment - The problem with Object#finalize() , it would appear after brief experimentation, is that it isn't called in a standalone application at JVM shutdown, so the shutdown hook would still be needed there. I'm going to continue to experiment a bit...
          Hide
          Ralph Goers added a comment -

          I suspect that the "real" solution is going to be to make the BasicContextSelector the default. It should cause the behavior to be just like Log4j 1. I'm not really sure what ClassLoaderContextSelector is doing that is causing the problem though.

          Show
          Ralph Goers added a comment - I suspect that the "real" solution is going to be to make the BasicContextSelector the default. It should cause the behavior to be just like Log4j 1. I'm not really sure what ClassLoaderContextSelector is doing that is causing the problem though.
          Hide
          Nick Williams added a comment -

          So, in Tomcat anyway, Object#finalize() on a basic class appears to always be called if the application is undeployed while Tomcat continues to run, but it is not called if Tomcat just shuts down. So, unfortunately, this is not an acceptable replacement. :-/

          Show
          Nick Williams added a comment - So, in Tomcat anyway, Object#finalize() on a basic class appears to always be called if the application is undeployed while Tomcat continues to run, but it is not called if Tomcat just shuts down. So, unfortunately, this is not an acceptable replacement. :-/
          Hide
          Nick Williams added a comment -

          A couple of things, Ralph:

          1. ClassLoaderContextSelector appears to be using getCallerClass like ThrowableProxy was, which means it will break on Java 8. The same check for method parameters needs to be performed here. As in ThrowableProxy, I again wonder why we're looping through methods looking for one named getCallerClass instead of just calling getMethod("getCallerClass", int.class).
          2. I'm not exactly sure what the ContextSelector and LoggerContext do, and I don't understand the difference between BasicContextSelector and ClassLoaderContextSelector. Could you enlighten me?
          Show
          Nick Williams added a comment - A couple of things, Ralph: ClassLoaderContextSelector appears to be using getCallerClass like ThrowableProxy was, which means it will break on Java 8. The same check for method parameters needs to be performed here. As in ThrowableProxy , I again wonder why we're looping through methods looking for one named getCallerClass instead of just calling getMethod("getCallerClass", int.class) . I'm not exactly sure what the ContextSelector and LoggerContext do, and I don't understand the difference between BasicContextSelector and ClassLoaderContextSelector . Could you enlighten me?
          Hide
          Ralph Goers added a comment -

          See http://logging.apache.org/log4j/2.x/manual/architecture.html. Ceki does a good job of explaining the Logback LoggerContext and ContextSelector in his documentation. In particular look at http://logback.qos.ch/manual/loggingSeparation.html#tamingStaticRefs.

          The LoggerContext is the "anchor point" for all the logging. It references the configuration.

          The ClassLoaderContextSelector attempts to solve the problem Ceki described in the Taming Static Refs section. It creates LoggerContexts based on the ClassLoader that loaded the caller to getLogger. Thus, assuming the Log4j jars are on the Tomcat classpath, loggers should be able to be declared as static and still be cleaned up properly. I made this ContextSelector the default to insure that it would get exposure and testing. I'm suspecting however, that there is something that isn't being accounted for.

          Show
          Ralph Goers added a comment - See http://logging.apache.org/log4j/2.x/manual/architecture.html . Ceki does a good job of explaining the Logback LoggerContext and ContextSelector in his documentation. In particular look at http://logback.qos.ch/manual/loggingSeparation.html#tamingStaticRefs . The LoggerContext is the "anchor point" for all the logging. It references the configuration. The ClassLoaderContextSelector attempts to solve the problem Ceki described in the Taming Static Refs section. It creates LoggerContexts based on the ClassLoader that loaded the caller to getLogger. Thus, assuming the Log4j jars are on the Tomcat classpath, loggers should be able to be declared as static and still be cleaned up properly. I made this ContextSelector the default to insure that it would get exposure and testing. I'm suspecting however, that there is something that isn't being accounted for.
          Hide
          Nick Williams added a comment -

          Okay, I think I understand better.

          I don't think the problem is in the selector. Regardless of which selector is being used, the o.a.l.l.core.LoggerContext class is still the class ultimately instantiated. That class is the one adding the shutdown hook. The shutdown hook is responsible for the class loader memory leak, because the Runtime class's holding an instance of the shutdown hook means that the LoggerContext.ShutdownHook class can't be unloaded, which means the class loader and all of the classes it holds can't be garbage collected.

          Show
          Nick Williams added a comment - Okay, I think I understand better. I don't think the problem is in the selector. Regardless of which selector is being used, the o.a.l.l.core.LoggerContext class is still the class ultimately instantiated. That class is the one adding the shutdown hook. The shutdown hook is responsible for the class loader memory leak, because the Runtime class's holding an instance of the shutdown hook means that the LoggerContext.ShutdownHook class can't be unloaded, which means the class loader and all of the classes it holds can't be garbage collected.
          Hide
          Nick Williams added a comment -

          In addition to my comment above, I was looking through the log4j-web source for a minute and I'm a little confused. What's the difference between Log4jContextListener and JNDIContextFilter and when would you use one or the other or both?

          Show
          Nick Williams added a comment - In addition to my comment above, I was looking through the log4j-web source for a minute and I'm a little confused. What's the difference between Log4jContextListener and JNDIContextFilter and when would you use one or the other or both?
          Hide
          Ralph Goers added a comment -

          Remko stated above that if you use the BasicContextSelector with the Log4jContextListener everything is good. However, if you use the ClassLoaderContextSelector you still get the message

          FAIL - Unable to delete [C:\apps\apache-tomcat-7.0.40\webapps\log4j-223]. The continued presence of this file may cause problems.

          This implies that ClassLoaderContextSelector is hanging onto something.

          You are correct that the LoggerContext adds the shutdown hook. I suppose the way to deal with that is to add another attribute to the configuration element to enable the hook.

          Show
          Ralph Goers added a comment - Remko stated above that if you use the BasicContextSelector with the Log4jContextListener everything is good. However, if you use the ClassLoaderContextSelector you still get the message FAIL - Unable to delete [C:\apps\apache-tomcat-7.0.40\webapps\log4j-223] . The continued presence of this file may cause problems. This implies that ClassLoaderContextSelector is hanging onto something. You are correct that the LoggerContext adds the shutdown hook. I suppose the way to deal with that is to add another attribute to the configuration element to enable the hook.
          Hide
          Ralph Goers added a comment -

          You would use the JNDIContextFilter when you use the JNDIContextSelector. The context filter locates it via a JNDI lookup and then stores it in a ThreadLocal. Then whenever the LoggerContext is needed it is retrieved from the ThreadLocal.

          Show
          Ralph Goers added a comment - You would use the JNDIContextFilter when you use the JNDIContextSelector. The context filter locates it via a JNDI lookup and then stores it in a ThreadLocal. Then whenever the LoggerContext is needed it is retrieved from the ThreadLocal.
          Hide
          Nick Williams added a comment -

          I don't think the hook has to be able to be enabled/disabled. Log4jContextListener calls stop() on the LoggerContext, and stop() removes the shutdown hook. So, used this way, the shutdown hook isn't a problem, it just isn't used. That's why everything's okay when using the BasicContextSelector. (I'm not saying it's a bad idea to provide way to enable/disable the shutdown hook. It wouldn't hurt.)

          So here are the philosophical or real issues that need to be resolved/answered, from my perspective:

          1. Why does BasicContextSelector work and ClassLoaderContextSelector not work in a web application when a Log4jContextListener is properly used?
          2. Is there any way to make logging "just work" in a web application without creating a listener and/or filter? I'm starting to become convinced that there isn't, and that disappoints me.
          3. Would Log4jContextListener and JNDIContextFilter ever both be used at the same time, and would doing that cause a malfunction?

          Assuming the ultimate conclusion is that logging can't "just work" in a web application and a listener/filter is required, I would like to drastically simplify usage of the log4j-web module. My thoughts on it are:

          1. There should only be a listener, not a filter.
          2. There should be no init parameters; everything should be automatic and follow normal Log4j conventions.
          3. There should be a META-INF/web-fragment.xml file that creates the filter automatically so that if the user is using a Servlet 3.0 or newer container he doesn't even have to consciously create the filter, he just has to include the JAR.
          4. It should be in the Core module, so that it works automatically in web applications.

          I make these arguments because, here I am, a committer on the project and an avid reader of the documentation, and I still had no idea the Log4jContextListener and/or JNDIContextFilter were required to make logging work properly in a web application.

          Show
          Nick Williams added a comment - I don't think the hook has to be able to be enabled/disabled. Log4jContextListener calls stop() on the LoggerContext , and stop() removes the shutdown hook. So, used this way, the shutdown hook isn't a problem, it just isn't used. That's why everything's okay when using the BasicContextSelector . (I'm not saying it's a bad idea to provide way to enable/disable the shutdown hook. It wouldn't hurt.) So here are the philosophical or real issues that need to be resolved/answered, from my perspective: Why does BasicContextSelector work and ClassLoaderContextSelector not work in a web application when a Log4jContextListener is properly used? Is there any way to make logging "just work" in a web application without creating a listener and/or filter? I'm starting to become convinced that there isn't, and that disappoints me. Would Log4jContextListener and JNDIContextFilter ever both be used at the same time, and would doing that cause a malfunction? Assuming the ultimate conclusion is that logging can't "just work" in a web application and a listener/filter is required, I would like to drastically simplify usage of the log4j-web module. My thoughts on it are: There should only be a listener, not a filter. There should be no init parameters; everything should be automatic and follow normal Log4j conventions. There should be a META-INF/web-fragment.xml file that creates the filter automatically so that if the user is using a Servlet 3.0 or newer container he doesn't even have to consciously create the filter, he just has to include the JAR. It should be in the Core module, so that it works automatically in web applications. I make these arguments because, here I am, a committer on the project and an avid reader of the documentation, and I still had no idea the Log4jContextListener and/or JNDIContextFilter were required to make logging work properly in a web application.
          Hide
          Nick Williams added a comment - - edited

          Also, you said "You would use the JNDIContextFilter when you use the JNDIContextSelector." But I'm seeing a chicken-and-egg problem. If you're running Log4j in a web application, how do you specify that it should use the JNDIContextSelector before the JNDIContextFilter is initialized?

          Okay, I see now that one would include a log4j2.component.properties file in the WEB-INF/classes directory, and that it should contain a Log4jContextSelector property pointing to the correct class name. Note that I don't see any documentation in the manual that explains this process. If it's there, it sure is hard to find. So, back to my original 3 issues and 4 thoughts above.

          Show
          Nick Williams added a comment - - edited Also, you said "You would use the JNDIContextFilter when you use the JNDIContextSelector ." But I'm seeing a chicken-and-egg problem. If you're running Log4j in a web application, how do you specify that it should use the JNDIContextSelector before the JNDIContextFilter is initialized? Okay, I see now that one would include a log4j2.component.properties file in the WEB-INF/classes directory, and that it should contain a Log4jContextSelector property pointing to the correct class name. Note that I don't see any documentation in the manual that explains this process. If it's there, it sure is hard to find. So, back to my original 3 issues and 4 thoughts above.
          Hide
          Ralph Goers added a comment -

          The shutdown hook is necessary in applications that aren't web apps (i.e. - there is no equivalent of a Servlet context listener). Please remember that Log4j has to work in standalone apps, web apps where the jars in the Tomcat ClassLoader, web apps where each has the log4j classes, ejbs (yuck), etc.

          As I said, with the BasicContextListener the behavior you should get should match Log4j 1.x - it won't shutdown the LoggerContext and the appenders, etc. won't be gracefully cleaned up. Adding the context listener provides that.

          A filter and context listener do very different things. You can't set a ThreadLocal in a context listener. Likewise, unless you are using the JNDIContextSelector you don't really want to set the ThreadLocal.

          ContextSelectors are chosen via a system property. They can also be specified in the file "log4j2.component.properties" which is read when LogManager is first called.

          Show
          Ralph Goers added a comment - The shutdown hook is necessary in applications that aren't web apps (i.e. - there is no equivalent of a Servlet context listener). Please remember that Log4j has to work in standalone apps, web apps where the jars in the Tomcat ClassLoader, web apps where each has the log4j classes, ejbs (yuck), etc. As I said, with the BasicContextListener the behavior you should get should match Log4j 1.x - it won't shutdown the LoggerContext and the appenders, etc. won't be gracefully cleaned up. Adding the context listener provides that. A filter and context listener do very different things. You can't set a ThreadLocal in a context listener. Likewise, unless you are using the JNDIContextSelector you don't really want to set the ThreadLocal. ContextSelectors are chosen via a system property. They can also be specified in the file "log4j2.component.properties" which is read when LogManager is first called.
          Hide
          Ralph Goers added a comment -

          Oops. I missed the comment about web-fragment.xml. That is a good idea but it needs to make sure that whatever it is doing is applicable to all web apps that would be including the log4j-web jar.

          Show
          Ralph Goers added a comment - Oops. I missed the comment about web-fragment.xml. That is a good idea but it needs to make sure that whatever it is doing is applicable to all web apps that would be including the log4j-web jar.
          Hide
          Ralph Goers added a comment -

          If web-fragment.xml is in core how would you handle the following two scenarios:

          1. A container with multiple web applications. The log4j jars are in the Tomcat classpath and they all share the same configuration file.

          2. A container with multiple web applications. Each has their own copy of the log4j jars and each has their own configuration file.

          Show
          Ralph Goers added a comment - If web-fragment.xml is in core how would you handle the following two scenarios: 1. A container with multiple web applications. The log4j jars are in the Tomcat classpath and they all share the same configuration file. 2. A container with multiple web applications. Each has their own copy of the log4j jars and each has their own configuration file.
          Hide
          Nick Williams added a comment -

          I think you misunderstood my comment. I'm not suggesting the shutdown hook should be removed completely. I fully recognize it is needed in standalone apps. You said, "You are correct that the LoggerContext adds the shutdown hook. I suppose the way to deal with that is to add another attribute to the configuration element to enable the hook." My response was that I don't think it's a must to add the ability to enable/disable the hook because the listener and filter take actions that remove the hook.

          I think you're wrong about something, though. You said, "With the BasicContextListener [I think you meant BasicContextSelector] the behavior you should get should match Log4j 1.x - it won't shutdown the LoggerContext and the appenders, etc. won't be gracefully cleaned up. Adding the context listener provides that." That is not completely true all the time. Since LoggerContext creates a shutdown hook, it will shut down the LoggerContext and the appenders if the servlet container is shut down without undeploying the application. The only time the LoggerContext and appenders won't be shut down is if the application is undeployed before the container is shut down.

          Before we start discussing web-fragment.xml, etc., I want to get Log4jContextListener and JNDIContextFilter straight.

          • Log4jContextListener does the following:
            • On startup, it calls Configurator.initialize which loads the Log4j configuration and creates the correct selector (BasicContextSelector, ClassLoaderContextSelector, JNDIContextSelector, etc. based on properties). It then adds the returned LoggerContext to the ServletContext as a context attribute.
            • On shutdown, it calls Configurator.shutdown which calls stop() on the LoggerContext which, incidentally, results in the shutdown hook being removed.
          • JNDIContextFilter does the following:
            • On startup, it checks if the servlet context attribute for a LoggerContext is set. If it is, it does nothing and the filter essentially becomes a no-op. It then gets the LoggerContextFactory from the LogManager. If the factory is a Log4jContextFactory and if its selector is a NamedContextSelector (note: NOT a JNDIContextSelector), it adds the LoggerContext to the ServletContext as a context attribute. Otherwise, the filter essentially becomes a no-op.
            • On each request, it looks for the LoggerContext on the ServletContext and sets it to ContextAnchor.THREAD_CONTEXT if it exists.
            • On shutdown, it stops the LoggerContext which, incidentally, results in the shutdown hook being removed.
            • Questions:
              • Why is the JNDIContextFilter working with the NamedContextSelector instead of the JNDIContextSelector as previously explained?
              • Why does JNDIContextFilter have to set a thread local in doFilter? I don't see how the correct loggers won't be used if the thread local isn't set.
              • Am I correct in assuming that, based on all of this, the JNDIContextFilter will not work correctly use the NamedContextSelector if the Log4jContextListener is also in use (as-written), and will (perhaps incorrectly) add the LoggerContext created in the Log4jContextListener to the thread local if both are used?
          Show
          Nick Williams added a comment - I think you misunderstood my comment. I'm not suggesting the shutdown hook should be removed completely. I fully recognize it is needed in standalone apps. You said, "You are correct that the LoggerContext adds the shutdown hook. I suppose the way to deal with that is to add another attribute to the configuration element to enable the hook." My response was that I don't think it's a must to add the ability to enable/disable the hook because the listener and filter take actions that remove the hook. I think you're wrong about something, though. You said, "With the BasicContextListener [I think you meant BasicContextSelector] the behavior you should get should match Log4j 1.x - it won't shutdown the LoggerContext and the appenders, etc. won't be gracefully cleaned up. Adding the context listener provides that." That is not completely true all the time. Since LoggerContext creates a shutdown hook, it will shut down the LoggerContext and the appenders if the servlet container is shut down without undeploying the application. The only time the LoggerContext and appenders won't be shut down is if the application is undeployed before the container is shut down. Before we start discussing web-fragment.xml, etc., I want to get Log4jContextListener and JNDIContextFilter straight. Log4jContextListener does the following: On startup, it calls Configurator.initialize which loads the Log4j configuration and creates the correct selector ( BasicContextSelector , ClassLoaderContextSelector , JNDIContextSelector , etc. based on properties). It then adds the returned LoggerContext to the ServletContext as a context attribute. On shutdown, it calls Configurator.shutdown which calls stop() on the LoggerContext which, incidentally, results in the shutdown hook being removed. JNDIContextFilter does the following: On startup, it checks if the servlet context attribute for a LoggerContext is set. If it is, it does nothing and the filter essentially becomes a no-op. It then gets the LoggerContextFactory from the LogManager . If the factory is a Log4jContextFactory and if its selector is a NamedContextSelector ( note: NOT a JNDIContextSelector ), it adds the LoggerContext to the ServletContext as a context attribute. Otherwise, the filter essentially becomes a no-op. On each request, it looks for the LoggerContext on the ServletContext and sets it to ContextAnchor.THREAD_CONTEXT if it exists. On shutdown, it stops the LoggerContext which, incidentally, results in the shutdown hook being removed. Questions: Why is the JNDIContextFilter working with the NamedContextSelector instead of the JNDIContextSelector as previously explained? Why does JNDIContextFilter have to set a thread local in doFilter ? I don't see how the correct loggers won't be used if the thread local isn't set. Am I correct in assuming that, based on all of this, the JNDIContextFilter will not work correctly use the NamedContextSelector if the Log4jContextListener is also in use (as-written), and will (perhaps incorrectly) add the LoggerContext created in the Log4jContextListener to the thread local if both are used?
          Hide
          Ralph Goers added a comment - - edited

          Provided the Log4jContextListener is configured in web.xml shutdown now works fine with Tomcat 7 with revision 1484363.

          FWIW, the sample war provided was compiled with Java 7 not Java 6.

          Although the underlying error should now be fixed I am leaving this open to continue discussion on web-fragment.xml or if more still needs to be done.

          Show
          Ralph Goers added a comment - - edited Provided the Log4jContextListener is configured in web.xml shutdown now works fine with Tomcat 7 with revision 1484363. FWIW, the sample war provided was compiled with Java 7 not Java 6. Although the underlying error should now be fixed I am leaving this open to continue discussion on web-fragment.xml or if more still needs to be done.
          Hide
          Nick Williams added a comment -

          Ralph,

          My bad, I typoed. Meant to say the sample WAR was compiled with Java 7, not Java 6.

          If someone could respond to my analysis in the comment immediately above and let me know if my assumptions are correct and what the answers to my questions are, I'd be in a good position to make some recommendations about how I think this could all be improved, vis-à-vis web-fragment.xml.

          Show
          Nick Williams added a comment - Ralph, My bad, I typoed. Meant to say the sample WAR was compiled with Java 7, not Java 6. If someone could respond to my analysis in the comment immediately above and let me know if my assumptions are correct and what the answers to my questions are, I'd be in a good position to make some recommendations about how I think this could all be improved, vis-à-vis web-fragment.xml .
          Hide
          Ralph Goers added a comment -

          1. JNDIContextSelector implements the NamedContextSelector interface. In theory, JNDIContextFilter can work on any NamedContextSelector so I guess it really should be named NamedContextFilter.
          2. If the context isn't found in the ThreadLocal then JNDIContextSelector performs a JNDILookup to locate the context. Using the ThreadLocal avoids the need to do the JNDI lookup, which is much more expensive.
          3. Both should work fine if they are used together. Log4jContextListener will get control during web app deployment and set the context as a ServletContext attribute. On each request JNDIContextFilter will get the context from the attribute and store it in a ThreadLocal.

          Note that all the apps where I work run in JBoss 5, which doesn't support web-fragment.xml as far as I know. Also, I'd still like to know how to handle the two scenarios I asked about above.

          Show
          Ralph Goers added a comment - 1. JNDIContextSelector implements the NamedContextSelector interface. In theory, JNDIContextFilter can work on any NamedContextSelector so I guess it really should be named NamedContextFilter. 2. If the context isn't found in the ThreadLocal then JNDIContextSelector performs a JNDILookup to locate the context. Using the ThreadLocal avoids the need to do the JNDI lookup, which is much more expensive. 3. Both should work fine if they are used together. Log4jContextListener will get control during web app deployment and set the context as a ServletContext attribute. On each request JNDIContextFilter will get the context from the attribute and store it in a ThreadLocal. Note that all the apps where I work run in JBoss 5, which doesn't support web-fragment.xml as far as I know. Also, I'd still like to know how to handle the two scenarios I asked about above.
          Hide
          Nick Williams added a comment - - edited

          Okay, based on all of this, here are my suggestions on how I would improve this (sorry for my scarcity lately ... trying to catch up on chapters for the book). These suggestions are based on the following goals:

          1. Design web application support so that users of simple Log4j configurations (not using JNDI lookups for logging configuration) don't have to do any additional configuration to get Log4j to "just work" in a Servlet container. This goal is made with the understanding that this is only possible for users of Servlet 3.0, 3.1, or higher. Users of Servlet 2.5 will have to manually configure listeners and filters. It's the only way.
          2. Eliminate the need for web applications to have an additional JAR just to support proper configuration.
          3. Improve the documentation considerably so that it is abundantly clear how Log4j works in web applications.

          With these goals in mind, here are my recommendations:

          • Get rid of the log4j-web module and move this stuff into log4j-core. We'll need Timothy Ward's input on how this could impact OSGi support. In theory, I don't think we should have a problem. No other Log4j classes will refer to the listener or filter. These classes will only ever get loaded BY the Servlet container, in which case the Servlet API will already be loaded, so I don't think it would be possible to get NoClassDefFoundError s.
          • Create a /META-INF/web-fragment.xml file with the contents noted below. This will ensure that the Log4j fragment is loaded before any other fragments.
          • Create a Log4jWebInitializer class (doesn't implement any interfaces, package-private) to properly initialize and de-initialize Log4j in a Servlet container. It works like this: If the context parameters currently required by the JNDIContextFilter exist, it initializes Log4j the way JNDIContextFilter currently does. If they don't exist, it initializes Log4j the way Log4jContextListener currently does.
          • Create a Log4jServletContainerInitializer implements ServletContainerInitializer and a /META-INF/services/javax.servlet.ServletContainerInitializer file to go along with it. This initializer:
            • Initializes Log4j properly using the Log4jWebInitializer.
            • Installs a private listener to de-initialize Log4j when the container shuts down the application using the Log4jWebInitializer.
            • Installs the NamedContextFilter (renamed from JNDIContextFilter), which doesn't do any initialization/deinitialization, it just does what it currently does for doFilter.
          • Change the existing Log4jContextListener to use the Log4jWebInitializer.
          • Create a new manual page directly under the "MANUAL" menu heading on the homepage that explains how to use Log4j in a Servlet container:
            • If you're using Servlet 3.0 or higher, it "just works," but if you're also using JNDI you need to create the proper context parameters.
            • If you're using Servlet 2.5, you MUST add the Log4jContextListener (and the NamedContextFilter and context parameters if you're using JNDI) to your deployment descriptor.

          Now, to address some questions:

          1. "What to do about JBoss 5, which doesn't support web-fragment.xml?" JBoss 5 doesn't support web-fragment.xml because it's a Servlet 2.5 container, not a Servlet 3.0 container. Users of JBoss 5 would follow the Servlet 2.5 instructions just like all other users. Users of JBoss 6, 7, 8, etc., would follow the Servlet 3.0 instructions ("don't do anything").
          2. "A container with multiple web applications. The Log4j jars are in the Tomcat classpath and they all share the same configuration file." versus "A container with multiple web applications. Each has their own copy of the log4j jars and each has their own configuration file." Easy! The Log4jServletContainerInitializer will get executed for every application, whether the Log4j JARs are in the Tomcat classpath or in /WEB-INF/lib (this is per the Servlet specification). Each application will get its own context. Regardless of where the JARs are, that context will load the application's configuration file if it has its own, and will load the shared configuration if it doesn't have its own.

          Thoughts?

          web-fragment.xml
          <web-fragment ... metadata-complete="true">
              <name>log4j</name>
              <distributable/>
              <ordering>
                  <before>
                      <others/>
                  </before>
              </ordering>
          </web-fragment>
          Show
          Nick Williams added a comment - - edited Okay, based on all of this, here are my suggestions on how I would improve this (sorry for my scarcity lately ... trying to catch up on chapters for the book). These suggestions are based on the following goals: Design web application support so that users of simple Log4j configurations (not using JNDI lookups for logging configuration) don't have to do any additional configuration to get Log4j to "just work" in a Servlet container. This goal is made with the understanding that this is only possible for users of Servlet 3.0, 3.1, or higher. Users of Servlet 2.5 will have to manually configure listeners and filters. It's the only way. Eliminate the need for web applications to have an additional JAR just to support proper configuration. Improve the documentation considerably so that it is abundantly clear how Log4j works in web applications. With these goals in mind, here are my recommendations: Get rid of the log4j-web module and move this stuff into log4j-core. We'll need Timothy Ward 's input on how this could impact OSGi support. In theory, I don't think we should have a problem. No other Log4j classes will refer to the listener or filter. These classes will only ever get loaded BY the Servlet container, in which case the Servlet API will already be loaded, so I don't think it would be possible to get NoClassDefFoundError s. Create a /META-INF/web-fragment.xml file with the contents noted below. This will ensure that the Log4j fragment is loaded before any other fragments. Create a Log4jWebInitializer class (doesn't implement any interfaces, package-private) to properly initialize and de-initialize Log4j in a Servlet container. It works like this: If the context parameters currently required by the JNDIContextFilter exist, it initializes Log4j the way JNDIContextFilter currently does. If they don't exist, it initializes Log4j the way Log4jContextListener currently does. Create a Log4jServletContainerInitializer implements ServletContainerInitializer and a /META-INF/services/javax.servlet.ServletContainerInitializer file to go along with it. This initializer: Initializes Log4j properly using the Log4jWebInitializer . Installs a private listener to de-initialize Log4j when the container shuts down the application using the Log4jWebInitializer . Installs the NamedContextFilter (renamed from JNDIContextFilter ), which doesn't do any initialization/deinitialization, it just does what it currently does for doFilter . Change the existing Log4jContextListener to use the Log4jWebInitializer . Create a new manual page directly under the "MANUAL" menu heading on the homepage that explains how to use Log4j in a Servlet container: If you're using Servlet 3.0 or higher, it "just works," but if you're also using JNDI you need to create the proper context parameters. If you're using Servlet 2.5, you MUST add the Log4jContextListener (and the NamedContextFilter and context parameters if you're using JNDI) to your deployment descriptor. Now, to address some questions: "What to do about JBoss 5, which doesn't support web-fragment.xml?" JBoss 5 doesn't support web-fragment.xml because it's a Servlet 2.5 container, not a Servlet 3.0 container. Users of JBoss 5 would follow the Servlet 2.5 instructions just like all other users. Users of JBoss 6, 7, 8, etc., would follow the Servlet 3.0 instructions ("don't do anything"). "A container with multiple web applications. The Log4j jars are in the Tomcat classpath and they all share the same configuration file." versus "A container with multiple web applications. Each has their own copy of the log4j jars and each has their own configuration file." Easy! The Log4jServletContainerInitializer will get executed for every application, whether the Log4j JARs are in the Tomcat classpath or in /WEB-INF/lib (this is per the Servlet specification). Each application will get its own context. Regardless of where the JARs are, that context will load the application's configuration file if it has its own, and will load the shared configuration if it doesn't have its own. Thoughts? web-fragment.xml <web-fragment ... metadata-complete= "true" > <name> log4j </name> <distributable/> <ordering> <before> <others/> </before> </ordering> </web-fragment>
          Hide
          Gary Gregory added a comment -

          Nice deep dive Nick. I do like the idea of one less jar for a simpler for to configure web apps. This would add the Servlet API as an optional runtime dependency in Core, which is OK.

          Show
          Gary Gregory added a comment - Nice deep dive Nick. I do like the idea of one less jar for a simpler for to configure web apps. This would add the Servlet API as an optional runtime dependency in Core, which is OK.
          Hide
          Ralph Goers added a comment -

          Should all this enhancement stuff go into a separate Jira? It feels like the issue reported here has been resolved.

          Show
          Ralph Goers added a comment - Should all this enhancement stuff go into a separate Jira? It feels like the issue reported here has been resolved.
          Hide
          Nick Williams added a comment -

          That makes sense to me. I'll create it and close this.

          Show
          Nick Williams added a comment - That makes sense to me. I'll create it and close this.
          Hide
          Nick Williams added a comment -

          Confirmed. Created issue LOG4J2-270 based on further discussions related to this.

          Show
          Nick Williams added a comment - Confirmed. Created issue LOG4J2-270 based on further discussions related to this.
          Nick Williams made changes -
          Link This issue is related to LOG4J2-270 [ LOG4J2-270 ]
          Nick Williams made changes -
          Status Reopened [ 4 ] Closed [ 6 ]
          Resolution Fixed [ 1 ]
          Hide
          Barış Taşkend added a comment -

          I am facing same problem in Websphere. Did you solve this problem with this way Nick?

          Show
          Barış Taşkend added a comment - I am facing same problem in Websphere. Did you solve this problem with this way Nick?
          Hide
          Barış Taşkend added a comment -

          I am using log4j beta v9. But in websphere throws same exception. how did you solve this problem?

          Show
          Barış Taşkend added a comment - I am using log4j beta v9. But in websphere throws same exception. how did you solve this problem?
          Hide
          Erik Tennant added a comment -

          We are still seeing this exception in Tomcat 7.0.47 with log4j2 beta9.

          INFO: Illegal access: this web application instance has been stopped already. Could not load org.apache.logging.log4j.core.config.NullConfiguration. 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
          at org.apache.catalina.loader.WebappClassLoader.loadClass(WebappClassLoader.java:1588)
          at org.apache.catalina.loader.WebappClassLoader.loadClass(WebappClassLoader.java:1547)
          at org.apache.logging.log4j.core.LoggerContext.stop(LoggerContext.java:210)
          at org.apache.logging.log4j.core.LoggerContext$ShutdownThread.run(LoggerContext.java:437)

          Exception in thread "Thread-4" java.lang.NoClassDefFoundError: org/apache/logging/log4j/core/config/NullConfiguration
          at org.apache.logging.log4j.core.LoggerContext.stop(LoggerContext.java:210)
          at org.apache.logging.log4j.core.LoggerContext$ShutdownThread.run(LoggerContext.java:437)
          Caused by: java.lang.ClassNotFoundException: org.apache.logging.log4j.core.config.NullConfiguration
          at org.apache.catalina.loader.WebappClassLoader.loadClass(WebappClassLoader.java:1702)
          at org.apache.catalina.loader.WebappClassLoader.loadClass(WebappClassLoader.java:1547)
          ... 2 more

          We can set debug points and verify that Log4jServletContainerInitializer gets called on startup, and so does Log4jServletContextListener. However, on server shutdown, Log4jServletContextListener.contextDestroyed does not getting invoked.

          Note, that we are using spring's WebApplicationInitializer to bootstrap our webapp, we do not have a web.xml file. We configure log4j2 via a log4j2.xml on the classpath.

          Any advice?

          Show
          Erik Tennant added a comment - We are still seeing this exception in Tomcat 7.0.47 with log4j2 beta9. INFO: Illegal access: this web application instance has been stopped already. Could not load org.apache.logging.log4j.core.config.NullConfiguration. 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 at org.apache.catalina.loader.WebappClassLoader.loadClass(WebappClassLoader.java:1588) at org.apache.catalina.loader.WebappClassLoader.loadClass(WebappClassLoader.java:1547) at org.apache.logging.log4j.core.LoggerContext.stop(LoggerContext.java:210) at org.apache.logging.log4j.core.LoggerContext$ShutdownThread.run(LoggerContext.java:437) Exception in thread "Thread-4" java.lang.NoClassDefFoundError: org/apache/logging/log4j/core/config/NullConfiguration at org.apache.logging.log4j.core.LoggerContext.stop(LoggerContext.java:210) at org.apache.logging.log4j.core.LoggerContext$ShutdownThread.run(LoggerContext.java:437) Caused by: java.lang.ClassNotFoundException: org.apache.logging.log4j.core.config.NullConfiguration at org.apache.catalina.loader.WebappClassLoader.loadClass(WebappClassLoader.java:1702) at org.apache.catalina.loader.WebappClassLoader.loadClass(WebappClassLoader.java:1547) ... 2 more We can set debug points and verify that Log4jServletContainerInitializer gets called on startup, and so does Log4jServletContextListener. However, on server shutdown, Log4jServletContextListener.contextDestroyed does not getting invoked. Note, that we are using spring's WebApplicationInitializer to bootstrap our webapp, we do not have a web.xml file. We configure log4j2 via a log4j2.xml on the classpath. Any advice?

            People

            • Assignee:
              Unassigned
              Reporter:
              Ralph Goers
            • Votes:
              0 Vote for this issue
              Watchers:
              7 Start watching this issue

              Dates

              • Created:
                Updated:
                Resolved:

                Development