[
https://issues.apache.org/jira/browse/LOG4J2-223?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=13661487#comment-13661487
]
Remko Popma commented on LOG4J2-223:
------------------------------------
with the above steps I was able to reproduce the issue. (I only tried Tomcat 7,
btw.)
{code}
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
{code}
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:
{code}
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();
}
}
{code}
Here is what I tried: at the top of LoggerContext, declare a static field
holding an instance of NullConfiguration.
{code}
// LOG4J2-223 cannot load new class during stop() in web apps, so load this up
front
private static final NullConfiguration NULL_CONFIGURATION = new
NullConfiguration();
{code}
Then, in the stop() method, instead of creating a new NullConfiguration, return
the pre-loaded instance:
{code}
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;
{code}
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:
{code}
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)
{code}
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:
{code}
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
{code}
After this, Ctrl-C in the command prompt does shut down Tomcat without errors.
> IlliegalStateException thrown during Tomcat shutdown
> ----------------------------------------------------
>
> Key: LOG4J2-223
> URL: https://issues.apache.org/jira/browse/LOG4J2-223
> Project: Log4j 2
> Issue Type: Bug
> Components: Core
> Affects Versions: 2.0-beta5
> Reporter: Ralph Goers
> Priority: Critical
> Fix For: 2.0-beta7
>
> Attachments: log4j-223.war
>
>
> 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
--
This message is automatically generated by JIRA.
If you think it was sent incorrectly, please contact your JIRA administrators
For more information on JIRA, see: http://www.atlassian.com/software/jira
---------------------------------------------------------------------
To unsubscribe, e-mail: log4j-dev-unsubscr...@logging.apache.org
For additional commands, e-mail: log4j-dev-h...@logging.apache.org
