In Tomcat 5, I get a java.lang.ThreadDeath exception when I reload my application. The origin lies in the log4j library: java.lang.ThreadDeath at org.apache.catalina.loader.WebappClassLoader.loadClass(WebappClassLoader.java:1270) at org.apache.catalina.loader.WebappClassLoader.loadClass(WebappClassLoader.java:1230) at java.lang.ClassLoader.loadClassInternal(ClassLoader.java:315) at org.apache.log4j.HTMLLayout.format(HTMLLayout.java:129) at org.apache.log4j.net.SMTPAppender.sendBuffer(Unknown Source) at org.apache.log4j.net.SMTPAppender.append(Unknown Source) at org.apache.log4j.AppenderSkeleton.doAppend(AppenderSkeleton.java:221) at org.apache.log4j.helpers.AppenderAttachableImpl.appendLoopOnAppenders(AppenderAttachableImpl.java:57) at org.apache.log4j.Category.callAppenders(Category.java:187) at org.apache.log4j.Category.forcedLog(Category.java:372) at org.apache.log4j.Category.log(Category.java:864) at org.apache.commons.logging.impl.Log4JLogger.error(Log4JLogger.java:192) at org.apache.catalina.session.StandardManager.start(StandardManager.java:706) at org.apache.catalina.core.StandardContext.start(StandardContext.java:4226) at org.apache.catalina.core.StandardContext.reload(StandardContext.java:2990) at org.apache.catalina.manager.ManagerServlet.reload(ManagerServlet.java:1019) at org.apache.catalina.manager.ManagerServlet.doGet(ManagerServlet.java:377) at javax.servlet.http.HttpServlet.service(HttpServlet.java:743) at javax.servlet.http.HttpServlet.service(HttpServlet.java:856) at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:284) at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:204) at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:257) at org.apache.catalina.core.StandardValveContext.invokeNext(StandardValveContext.java:151) at org.apache.catalina.core.StandardPipeline.invoke(StandardPipeline.java:567) at org.apache.catalina.core.StandardContextValve.invokeInternal(StandardContextValve.java:245) at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:199) at org.apache.catalina.core.StandardValveContext.invokeNext(StandardValveContext.java:151) at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:587) at org.apache.catalina.core.StandardValveContext.invokeNext(StandardValveContext.java:149) at org.apache.catalina.core.StandardPipeline.invoke(StandardPipeline.java:567) at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:184) at org.apache.catalina.core.StandardValveContext.invokeNext(StandardValveContext.java:151) at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:164) at org.apache.catalina.core.StandardValveContext.invokeNext(StandardValveContext.java:149) at org.apache.catalina.core.StandardPipeline.invoke(StandardPipeline.java:567) at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:156) at org.apache.catalina.core.StandardValveContext.invokeNext(StandardValveContext.java:151) at org.apache.catalina.core.StandardPipeline.invoke(StandardPipeline.java:567) at org.apache.catalina.core.ContainerBase.invoke(ContainerBase.java:972) at org.apache.coyote.tomcat5.CoyoteAdapter.service(CoyoteAdapter.java:206) at org.apache.coyote.http11.Http11Processor.process(Http11Processor.java:833) at org.apache.coyote.http11.Http11Protocol$Http11ConnectionHandler.processConnection(Http11Protocol.java:732) at org.apache.tomcat.util.net.TcpWorkerThread.runIt(PoolTcpEndpoint.java:619) at org.apache.tomcat.util.threads.ThreadPool$ControlRunnable.run(ThreadPool.java:688) at java.lang.Thread.run(Thread.java:536) According to Tomcat developers, it is "This is the old issue of log4j trying to use the previous classloader" (cf bug #26372).
This is generally caused by using configureAndWatch() when configuring Log4j which starts up a thread which won't stop unless specifically shut down by LogManager.shutdown(). This should be done in the contextDestroyed() method of a servlet context listener. I have never seen this issue since I began calling shutdown(). BTW, if you are using configureAndWatch() in a web environment, don't. It isn't a good idea. Better to have a configuration servlet or other mechanism to dynamically modify Log4j workings at runtime than to have Log4j spawn a thread. It will only cause you grief. I'm marking this as worksforme. Please reopen if the suggested solution does not work for you. Jake
I don't use (explicitely) configureAndWatch(). In my webapp I just place a log4j.xml in the /WEB-INF/classes directory and I let log4j configures itself automagically. According to the javadoc documentation (for the log4j.properties, no mention of log4j.xml) the automatic configuration uses configure() and not configureAndWatch(). I'll show if LogManager.shutdown() at context destruction helps.
Jacob, thanks for your suggestion - this fixes the problem for about 80% of the time, but I'm still getting sporadious ThreadDeaths when reloading via the Ant-Tasks. I'm configuring log4j via a .properties-file. Any other suggestions?
It doesn't solve the problem for me either. Furthermore I think that a shutdown() of log4j can't bring the expected behavior. Indeed Tomcat classes use lo4j too (through commons-logging) and would need to log after a contextDestroyed() method of a context listener has been called.
Yaan, are you saying that the ThreadDeath message still contains references to Log4j in the stack trace after using LogManager.shutdown()? Or does it now look like it is coming from something else? Do you (or any other libraries in your app) start threads in your app that you don't clean up at application shutdown? Marc, same question to you. Furthermore, LogManager.shutdown() shuts down the LoggerRepository connected to the current running application. This is decided based on the type of repository selector being used. You are correct that, by default, the default logger repository is used and if LogManager.shutdown() is used without havin used a custom logger repository selector, it will shut down logging for all applications using that logger repository. However, there are two ways to avoid this affecting other apps.... 1. Put log4j.jar in WEB-INF/lib which automatically scopes the default logger repository to the current webapp, not to the rest of the server. This is thanks to Tomcat's implementation of servlet spec recommended classloading behavior where the WebappClassLoader is checked first for libraries to load rather than using normal Java2 classloading behavior where the parent classloader would be checked first. Do this for all of your apps and you will have complete logging separation without taking any further steps. 2. Use a custom repository selector. This will provide for a separate logger repository based on, for instance, each app's JNDI context or Classloader. Read more about this here.... http://nagoya.apache.org/wiki/apachewiki.cgi?Log4JProjectPages/AppContainerLogging Using this, you can have a single instance of Log4j at the server level which is also avialable to all applications and all logging will be separated for all. As such, LogManager.shutdown() calls will only affect the application it was called from. Jake
Jake, the ThreadDeath always comes from log4j. As far as I know, I don't have threads that are not cleaned up. To 1: I use a log4j.jar per application. My logj.jar are already in WEB-INF/lib To 2: I have to take time to look at it. It seems interesting.
Jacob, thanks for getting back. I tried hard (about 20 times) and provoked another stacktrace for you ;-) ***** java.lang.ThreadDeath at org.apache.catalina.loader.WebappClassLoader.loadClass (WebappClassLoader.java:1227) at org.apache.catalina.loader.WebappClassLoader.loadClass (WebappClassLoader.java:1187) at java.lang.ClassLoader.loadClassInternal(ClassLoader.java:302) at org.apache.log4j.spi.LoggingEvent.<init>(LoggingEvent.java:145) at org.apache.log4j.Category.forcedLog(Category.java:372) at org.apache.log4j.Category.log(Category.java:864) at org.apache.commons.logging.impl.Log4JLogger.error (Log4JLogger.java:192) at org.apache.catalina.session.StandardManager.start (StandardManager.java:659) at org.apache.catalina.core.StandardContext.start (StandardContext.java:4199) at org.apache.catalina.core.StandardContext.reload (StandardContext.java:2963) at org.apache.catalina.manager.ManagerServlet.reload (ManagerServlet.java:972) at org.apache.catalina.manager.ManagerServlet.doGet (ManagerServlet.java:330) at javax.servlet.http.HttpServlet.service(HttpServlet.java:697) at javax.servlet.http.HttpServlet.service(HttpServlet.java:810) at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter (ApplicationFilterChain.java:237) at org.apache.catalina.core.ApplicationFilterChain.doFilter (ApplicationFilterChain.java:157) at org.apache.catalina.core.StandardWrapperValve.invoke (StandardWrapperValve.java:214) at org.apache.catalina.core.StandardValveContext.invokeNext (StandardValveContext.java:104) at org.apache.catalina.core.StandardPipeline.invoke (StandardPipeline.java:520) at org.apache.catalina.core.StandardContextValve.invokeInternal (StandardContextValve.java:198) at org.apache.catalina.core.StandardContextValve.invoke (StandardContextValve.java:152) at org.apache.catalina.core.StandardValveContext.invokeNext (StandardValveContext.java:104) at org.apache.catalina.authenticator.AuthenticatorBase.invoke (AuthenticatorBase.java:540) at org.apache.catalina.core.StandardValveContext.invokeNext (StandardValveContext.java:102) at org.apache.catalina.core.StandardPipeline.invoke (StandardPipeline.java:520) at org.apache.catalina.core.StandardHostValve.invoke (StandardHostValve.java:137) at org.apache.catalina.core.StandardValveContext.invokeNext (StandardValveContext.java:104) at org.apache.catalina.valves.ErrorReportValve.invoke (ErrorReportValve.java:117) at org.apache.catalina.core.StandardValveContext.invokeNext (StandardValveContext.java:102) at org.apache.catalina.core.StandardPipeline.invoke (StandardPipeline.java:520) at org.apache.catalina.core.StandardEngineValve.invoke (StandardEngineValve.java:109) at org.apache.catalina.core.StandardValveContext.invokeNext (StandardValveContext.java:104) at org.apache.catalina.core.StandardPipeline.invoke (StandardPipeline.java:520) at org.apache.catalina.core.ContainerBase.invoke(ContainerBase.java:929) at org.apache.coyote.tomcat5.CoyoteAdapter.service (CoyoteAdapter.java:160) at org.apache.coyote.http11.Http11Processor.process (Http11Processor.java:793) at org.apache.coyote.http11.Http11Protocol$Http11ConnectionHandler.processConnectio n(Http11Protocol.java:702) at org.apache.tomcat.util.net.TcpWorkerThread.runIt (PoolTcpEndpoint.java:571) at org.apache.tomcat.util.threads.ThreadPool$ControlRunnable.run (ThreadPool.java:644) at java.lang.Thread.run(Thread.java:534) *** I don't start any threads myself nor do the libraries I use (well, I suppose - using Struts and the usual commons-* stuff), my log4j-1.2.8-jar is in my WEB- INF/lib, I'm not using *any* shared libraries, all of them are in the webapp's /lib (went through this pain often enough..). This is a real problem when reloading applications in TC used on production servers since it will kill the application - only solution is to restart TC..
I think there is a solution for the above problem (stack trace). Normally you call the logger within each class like this: Logger myLogger = Logger.getLogger(MyClass.class) Now lets suppose yout classes name is not MyClass but instead MyOwnClass and you call your logger as shown above. Then the argument does not match the correct class name and you will get the described stack trace. So check each call of your logger for the appropriate class names. That should fix the problem. Thorsten
I have the same problem with tomcat 5.0.24. It happens when jsp page has errors - I reload context and tomcat gives ThreadDeath exception when I try to call this jsp using browser. Tomcat works correctly for some time and then this exception occur after next reload.
But log4J doesnt cause a ThreadDeath when in Tomcat 4.*... so is it something with tomcat 5??? also, in my stacktrace it is not even in log4J... and my app used to work in Tomcat4.1.28... now I am in the latest 5.* and I get this error... Thanks, Chris java.lang.ThreadDeath at org.apache.catalina.loader.WebappClassLoader.loadClass (WebappClassLoader.java:1229) at org.apache.catalina.loader.WebappClassLoader.loadClass (WebappClassLoader.java:1189) at java.beans.Introspector.instantiate(Introspector.java:1322) at java.beans.Introspector.findExplicitBeanInfo(Introspector.java:393) at java.beans.Introspector.<init>(Introspector.java:342) at java.beans.Introspector.getBeanInfo(Introspector.java:144) at org.apache.commons.beanutils.PropertyUtils.getPropertyDescriptors (PropertyUtils.java:949) at org.apache.commons.beanutils.PropertyUtils.getPropertyDescriptors (PropertyUtils.java:979) at org.apache.commons.beanutils.PropertyUtils.getPropertyDescriptor (PropertyUtils.java:887) at org.apache.commons.beanutils.PropertyUtils.getSimpleProperty (PropertyUtils.java:1172) at org.apache.commons.beanutils.PropertyUtils.getNestedProperty (PropertyUtils.java:772) at org.apache.commons.beanutils.PropertyUtils.getProperty (PropertyUtils.java:801) at org.apache.catalina.core.StandardWrapperValve.invoke (StandardWrapperValve.java:255) at org.apache.catalina.core.StandardValveContext.invokeNext (StandardValveContext.java:104) at org.apache.catalina.core.StandardPipeline.invoke (StandardPipeline.java:520) at org.apache.catalina.core.StandardContextValve.invokeInternal (StandardContextValve.java:198) at org.apache.catalina.core.StandardContextValve.invoke (StandardContextValve.java:152) at org.apache.catalina.core.StandardValveContext.invokeNext (StandardValveContext.java:104) at org.apache.catalina.core.StandardPipeline.invoke (StandardPipeline.java:520) at org.apache.catalina.core.StandardHostValve.invoke (StandardHostValve.java:137) at org.apache.catalina.core.StandardValveContext.invokeNext (StandardValveContext.java:104) at org.apache.catalina.valves.ErrorReportValve.invoke (ErrorReportValve.java:117) at org.apache.catalina.core.StandardValveContext.invokeNext (StandardValveContext.java:102) at org.apache.catalina.core.StandardPipeline.invoke (StandardPipeline.java:520) at org.apache.catalina.core.StandardEngineValve.invoke (StandardEngineValve.java:109) at org.apache.catalina.core.StandardValveContext.invokeNext (StandardValveContext.java:104) at org.apache.catalina.core.StandardPipeline.invoke (StandardPipeline.java:520) at org.apache.catalina.core.ContainerBase.invoke (ContainerBase.java:929) at org.apache.coyote.tomcat5.CoyoteAdapter.service (CoyoteAdapter.java:160) at org.apache.coyote.http11.Http11Processor.process (Http11Processor.java:793) at org.apache.coyote.http11.Http11Protocol$Http11ConnectionHandler.processConnecti on(Http11Protocol.java:702) at org.apache.tomcat.util.net.TcpWorkerThread.runIt (PoolTcpEndpoint.java:571) at org.apache.tomcat.util.threads.ThreadPool$ControlRunnable.run (ThreadPool.java:644) at java.lang.Thread.run(Thread.java:534)
Chris, Can you describe what you were doing to get that stack trace? Were you restarting the webapp? I don't see that in the stack trace, but you never know. It would be great to prove that this is more an issue with Tomcat5 than with Log4j. Your stack trace helps make the case since it doesn't seem to be related to Log4j, although it could be that the same issue is happening, just in a different library. Jake
Thanks for following up. Upon further investigation, I only get this error when running Tomcat in debug mode with the sysdeo plugin for eclipse (Tomcat 5, Eclipse 3.0). I think it is a classloader problem in Sysdeo (saw a post online of someone who had the same idea). When running Tomcat in standalone mode with the same app I do not get a ThreadDeath, so Im fine with closing this bug... Sorry for the inconvenience... Chris
This error occurs in Tomcat 5.0.24 with context that has Axis library. Besides Axis library there are ordinary jsp pages. Error occurs when tomcat was reloaded, and jsp page with syntax error is being compiled
Actually, my problem was not with Sysdeo. I replaced Sysdeo with MyEclipse debugging plugin, and got the same error. I reverted back to Tomcat 4.1.28, and I do not get the error. I started Tomcat, hit the controller of my app and got the Stacktrace in the other post by me... I hope this is fixed soon as we need features in the newer Servlet spec... Thanks! ps. If you have trouble reproducing this, I can zip up my open source dev env and post it for someone, and you can debug my app and see the error. :)
Chris, can you just attach it to this bug report? Jake
We are getting this error simply by compiling classes to our webapp classes directory. This happens _nearly_ on every compile we do, but never used to happen. SEVERE: Exception invoking periodic operation: java.lang.ThreadDeath at org.apache.catalina.loader.WebappClassLoader.loadClass (WebappClassLoader.java:1229) at org.apache.catalina.loader.WebappClassLoader.loadClass (WebappClassLoader.java:1189) at java.lang.ClassLoader.loadClassInternal(Unknown Source) at org.apache.log4j.spi.LoggingEvent.<init>(LoggingEvent.java:145) at org.apache.log4j.Category.forcedLog(Category.java:372) at org.apache.log4j.Category.log(Category.java:864) at org.apache.commons.logging.impl.Log4JLogger.error (Log4JLogger.java:192) at org.apache.catalina.session.StandardManager.start (StandardManager.java:659) at org.apache.catalina.core.StandardContext.start (StandardContext.java:4272) at org.apache.catalina.core.StandardContext.reload (StandardContext.java:3021) at org.apache.catalina.core.StandardContext.backgroundProcess (StandardContext.java:4629) at org.apache.catalina.core.ContainerBase$ContainerBackgroundProcessor.processChild ren(ContainerBase.java:1619) at org.apache.catalina.core.ContainerBase$ContainerBackgroundProcessor.processChild ren(ContainerBase.java:1628) at org.apache.catalina.core.ContainerBase$ContainerBackgroundProcessor.processChild ren(ContainerBase.java:1628) at org.apache.catalina.core.ContainerBase$ContainerBackgroundProcessor.run (ContainerBase.java:1608) at java.lang.Thread.run(Unknown Source) As I say, we can reproduce this almost at will with a recompile of classes which of course makes Tomcat reload.
From a cursory looks, it looks more like a Tomcat bug related to commons- logging rather than log4j itself. Maybe this bug should be filed as a Tomcat bug rather than a log4j bug?
It looks like Ceki is right. I looked at the WebClassLoader source at it is throwing the ThreadDeath exception because the WebClassLoader was stopped. Did you not mention that you get this exception everytime that you hot deploy your web application? Here is the code within tomcat that is throwing the exception: // Don't load classes if class loader is stopped if (!started) { log.info(sm.getString("webappClassLoader.stopped")); throw new ThreadDeath(); } The sm variable is a static protected variable. It seems to me that it is not properly being reset somehow.
I just realized that I incorrectly mentioned the sm variable instead of the started variable in my previous explanation. I meant to say the started variable was not set correctly becaues the classes start method was not called before trying to use the classload to load the class. It still is a bug within the tomcat code base and not the log4j code base. Sorry about that :-(
Adding tomcat-dev@jakarta.apache.org as we should keep track of this. What's the solution then? Not log at all while restarting a webapp?
--- Begin Text by Craig McClanahan --- The reason that LogFactory instances are stored in a map keyed by context class loader was to meet a functional requirement that each webapp could have independently configured constellations of Log instances, created by independent LogFactory instances, per webapp -- even if commons-logging.jar itself is installed into a shared class loader (i.e. common/lib or shared/lib in Tomcat). This is why you can't just use a static variable, because there would only be one LogFactory instance across the entire Tomcat JVM. In addition, there is no other reasonable key that is specific to a webapp, but *not* specific to the Servlet API (tying commons-logging use to require servlet.jar would not be a good thing). In order to allow cleanup of these allocated instances, the LogFactory.release() method may be used to ask a LogFactory to release all of its Log instances. In addition, the static LogFactory.release(ClassLoader) method releases references to the LogFactory instance for that class loader. I believe that both of these APIs were just added in 1.0.4. Inside Tomcat, then, a webapp using c-l can add a ServletContextListener whose contextDestroyed() method calls the appropriate release methods to clean up. --- End text by Craig McClanahan --- So to the people who reported this: please try adding such a ServletContextListener and using the above methods that Craig mentioned, and let us know if that makes the error go away.
I can confirm that the following does _not_ solve the ThreadDeath exception when Tomcat reloads the context following a class compile. import org.apache.log4j.LogManager; import org.apache.commons.logging.LogFactory; public void contextDestroyed(ServletContextEvent scE) { LogManager.shutdown(); LogFactory.releaseAll(); }
It seems to me that tomcat reuses these classloaders and I have a feeling that when the classloader is being reused. The classloader start method does not get called, causing the classloader to not have been "started", generating the ThreadDeath exception whenever the loadClass method is called.
What are you basing this on? Any code references would be nice.
I was looking at the WebappClassLoader class and it contains a started attribute that is used to determine that if the WebappClassLoader instance was started before it can be used to load classes. The started attribute is set using the classes start and stop methods. The ThreadDeath exception is being thrown because when the WebappClassLoader instance is calling the loadClass method it checks that the started attribute is true. If it isn't, it throws the ThreadDeath exception. I then looked at the StandardContext class. It contains a method called reload that is used whenever it wants to reload that particular web application associated to that instance of StandardContext. I also noticed that the StandardContext method will associate a single WebappLoader to the StandardContext instance. This WebappLoader contain the ClassLoader used by this StandardContext web application. The assignment of the WebappLoader is done only once and it is done within the start method only. This method initially checks if the WebappLoader has been associated to the StandardContext. It will then only assign a WebappLoader to the StandardContext if their was none. I deduced by looking at these sections of the code that it seems like whenever a StandardContext web application is being reloaded. Its WebappLoader WebappClassLoader start method is not be called before loading any of the web application classes. It does seem like its stop method is being called whenever the web application is being stopped. This is why I believe that the WebappClassLoader is not being properly setup before being used. I am basing this on looking at the code only. I have not tried to debug this case. It is only a theory based on observations and nothing else.
I've got the same exception, but without log4j envolvement. To reproduce try this: 1. In TC 5.0.27 login to admin application. 2. Under the Host->Create New Context create the new context pointing to some JSP webapp outside standard webapps directory. 3. When finished successfuly, try to invoke this application and you should get ThreadDeath exception. BTW, it is working fine when deploying to the standard webapps directory. Here is a stack: java.lang.ThreadDeath at org.apache.catalina.loader.WebappClassLoader.loadClass (WebappClassLoader.java:1229) at org.apache.catalina.loader.WebappClassLoader.loadClass (WebappClassLoader.java:1189) at org.apache.jasper.compiler.Parser.parseCustomTag(Parser.java:1316) at org.apache.jasper.compiler.Parser.parseElements(Parser.java:1560) at org.apache.jasper.compiler.Parser.parse(Parser.java:126) at org.apache.jasper.compiler.ParserController.doParse (ParserController.java:220) at org.apache.jasper.compiler.ParserController.parse (ParserController.java:101) at org.apache.jasper.compiler.Compiler.generateJava(Compiler.java:203) at org.apache.jasper.compiler.Compiler.compile(Compiler.java:470) at org.apache.jasper.compiler.Compiler.compile(Compiler.java:451) at org.apache.jasper.compiler.Compiler.compile(Compiler.java:439) at org.apache.jasper.JspCompilationContext.compile (JspCompilationContext.java:511) at org.apache.jasper.servlet.JspServletWrapper.service (JspServletWrapper.java:295) at org.apache.jasper.servlet.JspServlet.serviceJspFile (JspServlet.java:292) at org.apache.jasper.servlet.JspServlet.service(JspServlet.java:236) at javax.servlet.http.HttpServlet.service(HttpServlet.java:802) at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter (ApplicationFilterChain.java:237) at org.apache.catalina.core.ApplicationFilterChain.doFilter (ApplicationFilterChain.java:157) at org.apache.catalina.core.StandardWrapperValve.invoke (StandardWrapperValve.java:214) at org.apache.catalina.core.StandardValveContext.invokeNext (StandardValveContext.java:104) at org.apache.catalina.core.StandardPipeline.invoke (StandardPipeline.java:520) at org.apache.catalina.core.StandardContextValve.invokeInternal (StandardContextValve.java:198) at org.apache.catalina.core.StandardContextValve.invoke (StandardContextValve.java:152) at org.apache.catalina.core.StandardValveContext.invokeNext (StandardValveContext.java:104) at org.apache.catalina.core.StandardPipeline.invoke (StandardPipeline.java:520) at org.apache.catalina.core.StandardHostValve.invoke (StandardHostValve.java:137) at org.apache.catalina.core.StandardValveContext.invokeNext (StandardValveContext.java:104) at org.apache.catalina.valves.ErrorReportValve.invoke (ErrorReportValve.java:117) at org.apache.catalina.core.StandardValveContext.invokeNext (StandardValveContext.java:102) at org.apache.catalina.core.StandardPipeline.invoke (StandardPipeline.java:520) at org.apache.catalina.core.StandardEngineValve.invoke (StandardEngineValve.java:109) at org.apache.catalina.core.StandardValveContext.invokeNext (StandardValveContext.java:104) at org.apache.catalina.core.StandardPipeline.invoke (StandardPipeline.java:520) at org.apache.catalina.core.ContainerBase.invoke(ContainerBase.java:929) at org.apache.coyote.tomcat5.CoyoteAdapter.service (CoyoteAdapter.java:160) at org.apache.coyote.http11.Http11Processor.process (Http11Processor.java:799) ...
Per Jay Paulsen's findings archived at http://marc.theaimsgroup.com/? t=109578393000004&r=1&w=2, please try adding the Introspector.flush call to your shutdown code and re-testing. Thanks.
Running the embedded Tomcat 5.5.4, after I stop and start() a web context, I got the following exception (and the AxisServlet does not run). However, with the exact same web application in the standalone Tomcat 5.5.4, I don't get any exception (and the AxisServlet runs ok) - Starting Coyote HTTP/1.1 on http-80 - Illegal access: this web application instance has been stopped already. Could not load META-INF/services/org.apache.axis.EngineConfigurationFactory. 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. - Illegal access: this web application instance has been stopped already. Could not load org/apache/axis/configuration/EngineConfigurationFactoryServlet.class. 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. - Illegal access: this web application instance has been stopped already. Could not load org.apache.axis.configuration.EngineConfigurationFactoryServlet. 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. - StandardWrapper.Throwable java.lang.ThreadDeath at org.apache.catalina.loader.WebappClassLoader.loadClass(WebappClassLoader.java:1221) at org.apache.catalina.loader.WebappClassLoader.loadClass(WebappClassLoader.java:1181) at org.apache.commons.discovery.ResourceClass$1.run(ResourceClass.java:77) at java.security.AccessController.doPrivileged(Native Method) at org.apache.commons.discovery.ResourceClass.loadClass(ResourceClass.java:73) at org.apache.axis.configuration.EngineConfigurationFactoryFinder$1.run(EngineConfigurationFactoryFinder.java:122) at java.security.AccessController.doPrivileged(Native Method) at org.apache.axis.configuration.EngineConfigurationFactoryFinder.newFactory(EngineConfigurationFactoryFinder.java:113) at org.apache.axis.transport.http.AxisServletBase.getEngineEnvironment(AxisServletBase.java:247) at org.apache.axis.transport.http.AxisServletBase.getEngine(AxisServletBase.java:170) at org.apache.axis.transport.http.AxisServletBase.getOption(AxisServletBase.java:370) at org.apache.axis.transport.http.AxisServletBase.init(AxisServletBase.java:110) at javax.servlet.GenericServlet.init(GenericServlet.java:211) at org.apache.catalina.core.StandardWrapper.loadServlet(StandardWrapper.java:1053) at org.apache.catalina.core.StandardWrapper.load(StandardWrapper.java:886) at org.apache.catalina.core.StandardContext.loadOnStartup(StandardContext.java:3817) at org.apache.catalina.core.StandardContext.start(StandardContext.java:4079) - Servlet /axis threw load() exception javax.servlet.ServletException: Servlet.init() for servlet AdminServlet threw exception at org.apache.catalina.core.StandardWrapper.loadServlet(StandardWrapper.java:1095) at org.apache.catalina.core.StandardWrapper.load(StandardWrapper.java:886) at org.apache.catalina.core.StandardContext.loadOnStartup(StandardContext.java:3817) at org.apache.catalina.core.StandardContext.start(StandardContext.java:4079)
I meant the AdminServlet did not run. The AxisServlet ran fine.
Hi! I'm also experiencing ThreadDeath with Log4j on Tomcat 5.0.28 (bundled with NetBeans 4.0) when restarting applications. I understand you've already seen a lot of stack traces in this discussion. So I'll just give a part of mine: ========================================== Caused by: java.lang.ThreadDeath at org.apache.catalina.loader.WebappClassLoader.loadClass(WebappClassLoader.java:1229) at org.apache.catalina.loader.WebappClassLoader.loadClass(WebappClassLoader.java:1189) at java.lang.ClassLoader.loadClassInternal(ClassLoader.java:302) at org.apache.log4j.NDC.get(NDC.java:201) at org.apache.log4j.spi.LoggingEvent.getNDC(LoggingEvent.java:229) etc... ========================================== Seems like NDC is arranging its instances in a Hashtable with key being the current thread. That might be the reason of such behaviour. Have you thought of switching to ThreadLocal? I'm not sure about how it may affect the performance though. Thanks
I'm not sure why this issue remains open, given that #26372 has been closed. Whenever there is a ThreadDeath thrown from WebappClassLoader.loadClass() during a webapp restart, it is due to Tomcat invalidating the webapp's ClassLoader while threads are still executing a (long-running) service() method (or even lifecycle method). Tomcat waits 2 seconds, then invalidates the ClassLoader and restarts the app, resulting in a ThreadDeath thrown by the ClassLoader if new class load requests occur. See my comment in #26372 . Given that #26372 has been marked invalid (read as -1 for a configurable [or perhaps longer] wait-time for current requests to complete, prior to invalidating the ClassLoader and restarting the webapp), I think that this issue should now be closed. This is a Tomcat issue for restartable webapps, not a log4j issue.
Closing as consensus indicates that it is a Tomcat issue. Wish there was a better resolution than "INVALID", but that seems to be the closest fit.
I found a solution. copy the log4j jar file and rename to another file name, such as log4j-1.2.6.jar. put the both log4j jar files to WEB-INF lib directory.
Your solution seems more like black magic to me. What do you think you've fixed? And what is it about having 2 log4j jars in WEB-INF/lib changes the thread death behavior? You do realize that the thread death stuff is sporadic, right? You've performed an action and have found that you haven't gotten the error. You attribute the success to your action where, in reality, you can't know whether it was your action or dumb luck that led to success... unless you actually do know the real cause/effect relationship. If so, we're all ears! Until then, this is black magic. Jake
*** Bug 36616 has been marked as a duplicate of this bug. ***
although many comments say log4j has nothing to do with it which is theoretically probably true, most of the time it appears like log4j is causing the issue. my latest threaddeath which i get around 5 times per day I suppose after about 5 reloads indicates INFO: Illegal access: this web application instance has been stopped already. Could not load org.apache.log4j.spi.ThrowableInformation. 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. It does always appear to be this SPI class as long as I can remember. A naiive thought but perhaps if there were a way to stop this class entering loadClass at the wrong time the threaddeath would disappear for most common cases since everyone uses log4j with tomcat.
I second that motion. I also keep on seeing that "org.apache.log4j.spi.ThrowableInformation" error and I redeploy my application a few hundred times a day (while developing under Netbeans) so this issue is very critical to me. It would also be invaluable to have a minimal testcase for this. Yoav (of Tomcat) has mentioned he'd work on a fix for this issue but we need a testcase first (he can't reproduce it on his end).
(In reply to comment #36) > although many comments say log4j has nothing to do with it which is > theoretically probably true, most of the time it appears like log4j is causing > the issue. my latest threaddeath which i get around 5 times per day I suppose > after about 5 reloads indicates > > INFO: Illegal access: this web application instance has been stopped already. > Could not load org.apache.log4j.spi.ThrowableInformation. 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. > > It does always appear to be this SPI class as long as I can remember. A naiive > thought but perhaps if there were a way to stop this class entering loadClass > at the wrong time the threaddeath would disappear for most common cases since > everyone uses log4j with tomcat. I don't see the point of blaming log4j as is. It's the same problem with any shared library which would keep objects related to a webapp, while at the same time being disconnected from the lifecycle (at best, memory leaking will occur). I'd say the concept is to be blamed, but there are few solutions. Problems can also be caused by not setting the context classloader well (I did fix some more issues related to this in 5.5.9+, as JULI is quite sensitive to that). I think the current code is now clean related to this.
hey, i wasn't really blaming log4j, i just noted from the many many posts for this bug that log4j came up a lot and taking a pragmatic view thought it may be addressable. however, i appreciate that if you were to do that, then where would you stop if other libs caused the same issue. it wouldn't be good to pollute tomcat's code to bypass known issues for sure. i jsut think that since it's mostly this log4j class causing the issue, someone somewhere could change the root cause. i don't know .. just thinking out load ;)
Remy, I am using Tomcat 5.5.9, and log4j is only being loaded within the webapp context (not global) and I still get this problem. To date everyone keeps on talking theory but no one had yet to offer a practical solution. Both Brett and Yoav have suggested one, which is to allow a configurable timeout value before the ClassLoader is invalidated. Granted it's not foolproof (who knows how big the timeout needs to be), but at least it's a practical solution. You mention there are some other solutions, what are some of your practical solutions to this problem?
Idea, would it be possible to swap class loaders like a DJ does with Records. Let the class loader still exist beyond the contextDestroy() call. But only for a limited wall clock time or until the next re-deploy for the same context (whichever comes first). We don't want to hold N generations of class loaders during multiple re-deploys. I'm not sure if Java allows this, but can a supperior management thread poll all its child threads (or all threads in the JVM) and enquire details about the execution context of that thread. This would allow a background poll of all threads to occurr to identify which execution threads are still using a class loader that we are trying to shutdown. If there are none we can cleanup sooner. This seems like an obvious need from the JVM given the long running nature of the JVM and the hierarchical class loader mechanism. I do understand the servlet spec does not mandate what happens, so what we get is a bonus to us, but I'm more for the view of lets be a leader and write an implementation thats robust and useful to the general population then maybe a specification will be written from it for other implementors follow. Maybe this is as odds with TCs boilerplate implementation, but when an issue causes so much pain to the community its time to bear arms.
(In reply to comment #41) > Idea, would it be possible to swap class loaders like a DJ does with Records. > Let the class loader still exist beyond the contextDestroy() call. No.
Ok, no reply from Remy. So on the one hand this isn't a log4j issue, on the other hand it isn't being fixed in Tomcat... I'll ask again, does anyone have a minimal testcase for reproducing this issue?
The testcase is fairly straightforward - all you need is a servlet with a service() method with say a (generous) twenty second sleep in it (during which you will request a reload of the context), followed by any code that will cause a class to be loaded. Hit the servlet with a service request, and reload the webapp during the sleep. Tomcat will have invalidated the classloader (and reloaded the context) by the time the sleep completes, and you should see a ThreadDeath thrown.
Brett, There seems to be a mismatch between your test-case description and what I've been experiencing on my end. What I see on my end is request #1 is run to termination, I request a reload of the webapp, Tomcat's manager fails the reload operation and indicates a ThreadDeath has occured. I fully expect the request to get ThreadDeath if it continues running beyond the scope of a context reload but what I am seeing (and I consider this a bug) is Tomcat dishing out a ThreadDeath to a completely unrelated request. If I try sending out request #2 after the reload operation returns ThreadDeath, the request will fail with yet another exception. From this point onward Tomcat is in some sort of bad state and no matter how many times I try manager stop/start/reload it'll always fail. I am forced to fully shutdown Tomcat and restart it. New requests to the webapp now work. You can read more about this here: http://www.netbeans.org/issues/show_bug.cgi?id=62529 Do you have any idea why this is occuring? I have been unable to narrow this down to a minimal testcase. I saw it once in my minimal testcase, but too rare to be of any use. In my original application I see it on the first manager/reload request. I will continue trying to isolate the problem.
Gili, You asked for a minimal testcase showing ThreadDeath being thrown, so that's what I described :). You should try it out - perhaps it will assist in understanding the specifics of the problem you are having there. You should bear in mind that this is no longer considered a bug, as the issue is pretty well understood now. To re-raise as a bug you would need to be able to demostrate incorrect behaviour by Tomcat's classloaders. There are workarounds for the fact that Tomcat does not allow the service() threads timeout to be configured. Other invalid references to classloaders may be harder to track down, perhaps this is what you are experiencing. I couldn't see any of your stack-traces above. Perhaps they will highlight the operation that caused the ThreadDeath to be thrown.
(In reply to comment #45) I request a reload of the webapp, Tomcat's manager fails the reload > operation and indicates a ThreadDeath has occured. I fully expect the request to > get ThreadDeath if it continues running beyond the scope of a context reload but > what I am seeing (and I consider this a bug) is Tomcat dishing out a ThreadDeath > to a completely unrelated request. If I try sending out request #2 after the > reload operation returns ThreadDeath, the request will fail with yet another > exception. From this point onward Tomcat is in some sort of bad state and no > matter how many times I try manager stop/start/reload it'll always fail. I am > forced to fully shutdown Tomcat and restart it. New requests to the webapp now work. The annoyance I get is that Tomcat states the ThreadDeath that occurs wont upset the re-deployed web-app, but it does. No further requests to tomcat on the web-app are possible. The only way out is a container restart. I think maybe this is a genuine different problem but I've no proof yet. Maybe as a helpful suggestion, Tomcat could emit in the ThreadDeath exception message the Thread.getId() and Thread.getName() of the thread that is dying, this would be useful anyway to help fix your application and put us developers in the picture as to exactly what died. throw new java.lang.ThreadDeath("of Thread#"+Thread.currentThread().getThreadId()+" "+Thread.currentThread().getName()); Would such a trival patch be accepted ? Unfortunatly I've had no time this week to investigate further, I'm eyeing up hacking on JMP (Java Profiler) to get a class loader report from heap snapshots then dumping out all references between objects that cross to a different class loader. Maybe someone knows of a tool already for this ?