When the WebAppClassLoader stops it manually sets all static and final variables to null in the clearReferences method. This results in NPEs for any thread that was not stopped and not expecting its final or static variables to be null. This is particularly a problem with hot deploys since the unload fails and terminating the deploy.
You are not supposed to have any threads associated with this classloader at this point.
Note that if you want a "fix", you can offer a patch disabling this code (with a system property or some other mechanism like that).
Here is a patch that uses a system property to disable this feature. The patch was made against tomcat 5.5.20 source. --- WebappClassLoader.java.orig 2006-09-12 11:12:42.000000000 -0400 +++ WebappClassLoader.java 2006-11-29 09:03:42.000000000 -0500 @@ -163,7 +163,12 @@ public class WebappClassLoader * resources. */ boolean antiJARLocking = false; - + + /** + * Use clearReferences experimental code to deal with possible memory leaks. + */ + private static final boolean ENABLE_CLEAR_REFERENCES = Boolean.valueOf (System.getProperty ("org.apache.catalina.loader.WebappClassLoader.ENABLE_CLEAR_REFERENCES", "true" )).booleanValue(); + // ----------------------------------------------------------- Constructors @@ -1489,7 +1494,9 @@ public class WebappClassLoader // Clearing references should be done before setting started to // false, due to possible side effects - clearReferences(); + if(ENABLE_CLEAR_REFERENCES) { + clearReferences(); + } started = false;
I provided a patch to work around this issue.
Just marking as an enhancement.
The patch was bad: it is wrong to disable the whole method.
Here is a new patch that disables only the code which resets the static and final variables. --- WebappClassLoader.java.orig 2006-09-12 11:12:42.000000000 -0400 +++ WebappClassLoader.java 2006-12-05 08:34:52.000000000 -0500 @@ -163,7 +163,16 @@ public class WebappClassLoader * resources. */ boolean antiJARLocking = false; - + + /** + * Use experimental code in clearReferences to reset static and final variables + * to deal with possible memory leaks. + */ + private static final boolean ENABLE_NULLING_STATIC_FINAL_REFERENCES = + Boolean.valueOf(System.getProperty( + "org.apache.catalina.loader.WebappClassLoader.ENABLE_NULLI NG_STATIC_FINAL_REFERENCES", + "true")).booleanValue(); + // ----------------------------------------------------------- Constructors @@ -1585,46 +1594,48 @@ public class WebappClassLoader // Null out any static or final fields from loaded classes, // as a workaround for apparent garbage collection bugs - Iterator loadedClasses = ((HashMap) resourceEntries.clone()).values ().iterator(); - while (loadedClasses.hasNext()) { - ResourceEntry entry = (ResourceEntry) loadedClasses.next(); - if (entry.loadedClass != null) { - Class clazz = entry.loadedClass; - try { - Field[] fields = clazz.getDeclaredFields(); - for (int i = 0; i < fields.length; i++) { - Field field = fields[i]; - int mods = field.getModifiers(); - if (field.getType().isPrimitive() - || (field.getName().indexOf("$") != -1)) { - continue; - } - if (Modifier.isStatic(mods)) { - try { - field.setAccessible(true); - if (Modifier.isFinal(mods)) { - if (!((field.getType().getName ().startsWith("java.")) - || (field.getType().getName ().startsWith("javax.")))) { - nullInstance(field.get(null)); + if(ENABLE_NULLING_STATIC_FINAL_REFERENCES) { + Iterator loadedClasses = ((HashMap) resourceEntries.clone ()).values().iterator(); + while (loadedClasses.hasNext()) { + ResourceEntry entry = (ResourceEntry) loadedClasses.next(); + if (entry.loadedClass != null) { + Class clazz = entry.loadedClass; + try { + Field[] fields = clazz.getDeclaredFields(); + for (int i = 0; i < fields.length; i++) { + Field field = fields[i]; + int mods = field.getModifiers(); + if (field.getType().isPrimitive() + || (field.getName().indexOf("$") != -1)) { + continue; + } + if (Modifier.isStatic(mods)) { + try { + field.setAccessible(true); + if (Modifier.isFinal(mods)) { + if (!((field.getType().getName ().startsWith("java.")) + || (field.getType().getName ().startsWith("javax.")))) { + nullInstance(field.get(null)); + } + } else { + field.set(null, null); + if (log.isDebugEnabled()) { + log.debug("Set field " + field.getName() + + " to null in class " + clazz.getName()); + } } - } else { - field.set(null, null); + } catch (Throwable t) { if (log.isDebugEnabled()) { - log.debug("Set field " + field.getName () - + " to null in class " + clazz.getName()); + log.debug("Could not set field " + field.getName() + + " to null in class " + clazz.getName(), t); } } - } catch (Throwable t) { - if (log.isDebugEnabled()) { - log.debug("Could not set field " + field.getName() - + " to null in class " + clazz.getName(), t); - } } } - } - } catch (Throwable t) { - if (log.isDebugEnabled()) { - log.debug("Could not clean fields for class " + clazz.getName(), t); + } catch (Throwable t) { + if (log.isDebugEnabled()) { + log.debug("Could not clean fields for class " + clazz.getName(), t); + } } } }
This is causing a problem for me also and I think requires a fix other than the patch given here. I get the following stack trace which shows that the error occurs on Tomcat's clean up thread and therefore should be addressed with a more permanent fix. The problem arises because Tomcat tries to null a static/final field of a type that has not yet been loaded, which causes the class initializer to run. In my case, that initializer fetched a log from Commons Logging, which had (presumably) already been "cleaned up" by Tomcat, and threw an NPE. [FATAL] LoggingInit - Failed to obtain logger returning simple logger for CONFIG.com.commons.monitoring.util.Instrument <org.apache.commons.logging.LogConfigurationException: java.lang.NullPointerException (Caused by java.lang.NullPointerException) >org.apache.commons.logging.LogConfigurationException: java.lang.NullPointerException (Caused by java.lang.NullPointerException) at org.apache.commons.logging.impl.LogFactoryImpl.newInstance (LogFactoryImpl.java:538) at org.apache.commons.logging.impl.LogFactoryImpl.getInstance (LogFactoryImpl.java:235) at org.apache.commons.logging.LogFactory.getLog(LogFactory.java:370) at com.commons.logging.LoggingInit.getLog(LoggingInit.java:334) at sun.reflect.GeneratedMethodAccessor22.invoke(Unknown Source) at sun.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source) at java.lang.reflect.Method.invoke(Unknown Source) at com.commons.catalog.CatalogUtils.getLog(CatalogUtils.java:75) at com.commons.catalog.GenericTrace.<init>(GenericTrace.java:279) at com.commons.catalog.SimpleTrace.<init>(SimpleTrace.java:34) at com.commons.monitoring.util.Instrument.<clinit> (AbstractRuntimeInstrument.java:44) at sun.misc.Unsafe.ensureClassInitialized(Native Method) at sun.reflect.UnsafeFieldAccessorFactory.newFieldAccessor(Unknown Source) at sun.reflect.ReflectionFactory.newFieldAccessor(Unknown Source) at java.lang.reflect.Field.acquireFieldAccessor(Unknown Source) at java.lang.reflect.Field.getFieldAccessor(Unknown Source) at java.lang.reflect.Field.get(Unknown Source) at org.apache.catalina.loader.WebappClassLoader.clearReferences (WebappClassLoader.java:1612) at org.apache.catalina.loader.WebappClassLoader.stop (WebappClassLoader.java:1496) at org.apache.catalina.loader.WebappLoader.stop(WebappLoader.java:734) at org.apache.catalina.core.StandardContext.stop (StandardContext.java:4398) at org.apache.catalina.core.ContainerBase.stop(ContainerBase.java:1067) at org.apache.catalina.core.ContainerBase.stop(ContainerBase.java:1067) at org.apache.catalina.core.StandardEngine.stop(StandardEngine.java:448) at org.apache.catalina.core.StandardService.stop (StandardService.java:510) at org.apache.catalina.core.StandardServer.stop(StandardServer.java:734) at org.apache.catalina.startup.Catalina.stop(Catalina.java:602) at org.apache.catalina.startup.Catalina.start(Catalina.java:577) at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at sun.reflect.NativeMethodAccessorImpl.invoke(Unknown Source) at sun.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source) at java.lang.reflect.Method.invoke(Unknown Source) at org.apache.catalina.startup.Bootstrap.start(Bootstrap.java:295) at org.apache.catalina.startup.Bootstrap.main(Bootstrap.java:433) Caused by: java.lang.NullPointerException Upgrading Commons Logging to v1.1 on Tomcat's server classpath removes the NPE but the problem isn't really fixed. Possible solution is to use two phases: first collect all the non-null Fields (Field.get will cause the declared type to be loaded) then null them.
Created attachment 22408 [details] Adds preliminary pass to clearReferences to prevent untimely class initialization This issue is resulting in bugs (40212 and 43867, specifically maybe others) being reported to log4j. The patch seems reasonable and compiles, but has not been tested. I'm putting here and inviting those currently tracking 43867 to check that it fixes the problems that they are observing and add comments here.
Curt's patch fixes the problem without disabling any part of the code.
BTW, this causes Tomcat to hang when shutting down (randomly) for me. It happens rather frequently and is a problem because I restart Tomcat nightly (due to unrelated memory leak problems). I am increasing severity to "major" but leaving the priority as is. Curt I will gladly test out your patch if you can provide me with a drop-in JAR file or otherwise indicate how I can patch my existing Tomcat system without rebuilding the entire thing from source.
Could this bug be taken into consideration? In my case, I have the symptoms outlined in bug #43867 and this is caused by the following situation (I'm using Tomcat 5.5.26): - WebappClassLoader.clearReferences() at line 1617 inspects some static fields in order to set them to null afterwards, using reflection - one of these fields seems to be a field of an Axis2 class (I have an Axis2 Servlet with load-on-startup configured in my web.xml); field.get(null) causes the VM to pass through sun.misc.Unsafe.ensureClassInitialized(Class) (in other words: Tomcat is trying to inspect a static field of a class that hasn't ever be initialized before) - that method of Sun implementation causes specifically org.apache.axis2.context.OperationContext to be initialized; this class has a static field declared as: private static final Log log = LogFactory.getLog(OperationContext.class); - this static declaration causes a new Log4JLogger to be created; this is still in charge of the WebappClassLoader, so when Log4JLogger constructor calls getLogger(), a call to org.apache.log4j.LogManager.getLoggerRepository() is made - however, at this time the static field repositorySelector is null, probabily because it has been set to null by a previous iteration of the same loop that is in running in WebappClassLoader.clearReferences() (this is just a hypothesis) So, from what I have said, I think that either: - WebappClassLoader.clearReferences() should skip to inspect fields of classes that have not been initialized yet, otherwise they will be initialized at that point (and it might be too late!) - I didn't look at Curt's patch, but I assume he worked on this issue and he followed a 2-pass approach that also solves it I hope this helps in any way. Mauro.
FYI, Glassfish fixed this bug within a week of being reported: https://glassfish.dev.java.net/issues/show_bug.cgi?id=6637 I'll leave it up to you to draw your own conclusions.
This has been fixed in trunk and proposed for 6.0.x and 5.5.x Keep in mind that ENABLE_CLEAR_REFERENCES=true is intended to: a) work around GC issues in old JVMs (unlikely to an issue with current jvms) b) work around one source of memory leaks in webapps that are buggy or use buggy libraries The very nature of the ENABLE_CLEAR_REFERENCES code is that it is likely to cause problems - as it does with log4j. Whilst this patch (thanks for the patch by the way) will reduce the chances or seeing errors, it will not eliminate them. A better approach is to set ENABLE_CLEAR_REFERENCES=false and to use a profiler to identify and fix the root causes of any memory leaks. A well-written app using well behaved libraries should not need ENABLE_CLEAR_REFERENCES=true If when doing this you find a memory leak in the Tomcat code (hopefully you won't - all the ones we know about should be fixed) then please open a new Bugzilla entry and report it.
Thanks again for the patch. It has been applied to 5.5.x and 6.0.x and will be included in 5.5.29 and 6.0.21 onwards.