Bug 63832 - Unable to stop because WebappClassLoaderBase.checkThreadLocalMapForLeaks can't load class(class from deployed aplication - probably undeployed)
Summary: Unable to stop because WebappClassLoaderBase.checkThreadLocalMapForLeaks can'...
Status: RESOLVED FIXED
Alias: None
Product: Tomcat 9
Classification: Unclassified
Component: Catalina (show other bugs)
Version: 9.0.24
Hardware: PC All
: P2 normal (vote)
Target Milestone: -----
Assignee: Tomcat Developers Mailing List
URL:
Keywords:
Depends on:
Blocks:
 
Reported: 2019-10-10 13:00 UTC by Daniel Charczyński
Modified: 2019-11-26 15:04 UTC (History)
1 user (show)



Attachments

Note You need to log in before you can comment on or make changes to this bug.
Description Daniel Charczyński 2019-10-10 13:00:35 UTC
Tomcat is unable to stop because WebappClassLoaderBase.checkThreadLocalMapForLeaks can't load class(class from deployed aplication - probably undeployed)


10-Oct-2019 14:37:47.133 SEVERE [main] org.apache.catalina.core.ContainerBase.stopInternal A child container failed during stop
	java.util.concurrent.ExecutionException: java.lang.InternalError: Malformed class name
		at java.util.concurrent.FutureTask.report(FutureTask.java:122)
		at java.util.concurrent.FutureTask.get(FutureTask.java:192)
		at org.apache.catalina.core.ContainerBase.stopInternal(ContainerBase.java:982)
		at org.apache.catalina.util.LifecycleBase.stop(LifecycleBase.java:257)
		at org.apache.catalina.core.ContainerBase$StopChild.call(ContainerBase.java:1400)
		at org.apache.catalina.core.ContainerBase$StopChild.call(ContainerBase.java:1389)
		at java.util.concurrent.FutureTask.run$$$capture(FutureTask.java:266)
		at java.util.concurrent.FutureTask.run(FutureTask.java)
		at org.apache.tomcat.util.threads.InlineExecutorService.execute(InlineExecutorService.java:75)
		at java.util.concurrent.AbstractExecutorService.submit(AbstractExecutorService.java:134)
		at org.apache.catalina.core.ContainerBase.stopInternal(ContainerBase.java:976)
		at org.apache.catalina.util.LifecycleBase.stop(LifecycleBase.java:257)
		at org.apache.catalina.core.StandardService.stopInternal(StandardService.java:473)
		at org.apache.catalina.util.LifecycleBase.stop(LifecycleBase.java:257)
		at org.apache.catalina.core.StandardServer.stopInternal(StandardServer.java:994)
		at org.apache.catalina.util.LifecycleBase.stop(LifecycleBase.java:257)
		at org.apache.catalina.startup.Catalina.stop(Catalina.java:706)
		at org.apache.catalina.startup.Catalina.start(Catalina.java:668)
		at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
		at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
		at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
		at java.lang.reflect.Method.invoke(Method.java:498)
		at org.apache.catalina.startup.Bootstrap.start(Bootstrap.java:344)
		at org.apache.catalina.startup.Bootstrap.main(Bootstrap.java:475)
	Caused by: java.lang.InternalError: Malformed class name
		at java.lang.Class.getSimpleName(Class.java:1330)
		at java.lang.Class.getCanonicalName(Class.java:1399)
		at org.apache.catalina.loader.WebappClassLoaderBase.getPrettyClassName(WebappClassLoaderBase.java:2073)
		at org.apache.catalina.loader.WebappClassLoaderBase.checkThreadLocalMapForLeaks(WebappClassLoaderBase.java:2037)
		at org.apache.catalina.loader.WebappClassLoaderBase.checkThreadLocalsForLeaks(WebappClassLoaderBase.java:1965)
		at org.apache.catalina.loader.WebappClassLoaderBase.clearReferences(WebappClassLoaderBase.java:1632)
		at org.apache.catalina.loader.WebappClassLoaderBase.stop(WebappClassLoaderBase.java:1555)
		at org.apache.catalina.loader.WebappLoader.stopInternal(WebappLoader.java:443)
		at org.apache.catalina.util.LifecycleBase.stop(LifecycleBase.java:257)
		at org.apache.catalina.core.StandardContext.stopInternal(StandardContext.java:5432)
		at org.apache.catalina.util.LifecycleBase.stop(LifecycleBase.java:257)
		at org.apache.catalina.core.ContainerBase$StopChild.call(ContainerBase.java:1400)
		at org.apache.catalina.core.ContainerBase$StopChild.call(ContainerBase.java:1389)
		at java.util.concurrent.FutureTask.run$$$capture(FutureTask.java:266)
		at java.util.concurrent.FutureTask.run(FutureTask.java)
		at org.apache.tomcat.util.threads.InlineExecutorService.execute(InlineExecutorService.java:75)
		at java.util.concurrent.AbstractExecutorService.submit(AbstractExecutorService.java:134)
		at org.apache.catalina.core.ContainerBase.stopInternal(ContainerBase.java:976)
		... 21 more
10-Oct-2019 14:37:47.134 SEVERE [main] org.apache.catalina.core.ContainerBase.stopInternal A child container failed during stop
	java.util.concurrent.ExecutionException: org.apache.catalina.LifecycleException: A child container failed during stop
		at java.util.concurrent.FutureTask.report(FutureTask.java:122)
		at java.util.concurrent.FutureTask.get(FutureTask.java:192)
		at org.apache.catalina.core.ContainerBase.stopInternal(ContainerBase.java:982)
		at org.apache.catalina.util.LifecycleBase.stop(LifecycleBase.java:257)
		at org.apache.catalina.core.StandardService.stopInternal(StandardService.java:473)
		at org.apache.catalina.util.LifecycleBase.stop(LifecycleBase.java:257)
		at org.apache.catalina.core.StandardServer.stopInternal(StandardServer.java:994)
		at org.apache.catalina.util.LifecycleBase.stop(LifecycleBase.java:257)
		at org.apache.catalina.startup.Catalina.stop(Catalina.java:706)
		at org.apache.catalina.startup.Catalina.start(Catalina.java:668)
		at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
		at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
		at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
		at java.lang.reflect.Method.invoke(Method.java:498)
		at org.apache.catalina.startup.Bootstrap.start(Bootstrap.java:344)
		at org.apache.catalina.startup.Bootstrap.main(Bootstrap.java:475)
	Caused by: org.apache.catalina.LifecycleException: A child container failed during stop
		at org.apache.catalina.core.ContainerBase.stopInternal(ContainerBase.java:990)
		at org.apache.catalina.util.LifecycleBase.stop(LifecycleBase.java:257)
		at org.apache.catalina.core.ContainerBase$StopChild.call(ContainerBase.java:1400)
		at org.apache.catalina.core.ContainerBase$StopChild.call(ContainerBase.java:1389)
		at java.util.concurrent.FutureTask.run$$$capture(FutureTask.java:266)
		at java.util.concurrent.FutureTask.run(FutureTask.java)
		at org.apache.tomcat.util.threads.InlineExecutorService.execute(InlineExecutorService.java:75)
		at java.util.concurrent.AbstractExecutorService.submit(AbstractExecutorService.java:134)
		at org.apache.catalina.core.ContainerBase.stopInternal(ContainerBase.java:976)
		... 13 more
10-Oct-2019 14:37:47.135 SEVERE [main] org.apache.catalina.startup.Catalina.stop Error stopping Catalina
	org.apache.catalina.LifecycleException: A child container failed during stop
		at org.apache.catalina.core.ContainerBase.stopInternal(ContainerBase.java:990)
		at org.apache.catalina.util.LifecycleBase.stop(LifecycleBase.java:257)
		at org.apache.catalina.core.StandardService.stopInternal(StandardService.java:473)
		at org.apache.catalina.util.LifecycleBase.stop(LifecycleBase.java:257)
		at org.apache.catalina.core.StandardServer.stopInternal(StandardServer.java:994)
		at org.apache.catalina.util.LifecycleBase.stop(LifecycleBase.java:257)
		at org.apache.catalina.startup.Catalina.stop(Catalina.java:706)
		at org.apache.catalina.startup.Catalina.start(Catalina.java:668)
		at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
		at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
		at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
		at java.lang.reflect.Method.invoke(Method.java:498)
		at org.apache.catalina.startup.Bootstrap.start(Bootstrap.java:344)
		at org.apache.catalina.startup.Bootstrap.main(Bootstrap.java:475)
Comment 1 Remy Maucherat 2019-10-11 10:03:20 UTC
The exception is properly caught, *but* because of the severity of it it is allowed to fall through (java.lang.InternalError is a VirtualMachineError). Then the stop process does not complete due to that.

The code causing the error is reconstructing the class name from a Class object, so it's rather worrying/weird that it fails.

IMO, the fix is in the InlineExecutorService: it should emulate an executor with a one thread pool, so it should not propagate an exception/error out of its execute method and log the trace as severe instead. I will attepmt a fix and see how testing goes.
Comment 2 Remy Maucherat 2019-10-11 12:37:14 UTC
After testing, the InlineExecutorService does the part properly using a FutureTask, so nothing to fix here.

Problems are:
- ContainerBase.stopInternal throws a LifecycleException on any failure
- If working around that, StandardContext.stopInternal remains in STOPPING state which causes further LifecycleException

Not sure yet what the best strategy is, probably avoid the first item, and be more robust about the end state in case of a StandardContext.stopInternal error.
Comment 3 Remy Maucherat 2019-10-11 16:25:40 UTC
The root cause was that the container state was not properly set to FAILED on a JVM error exception class.
The fix will be in 9.0.28, 8.5.48 and 7.0.98.
Comment 4 Daniel Charczyński 2019-10-14 08:33:29 UTC
Thanks a lot.
Which commit solve this problem?
Comment 5 Daniel Charczyński 2019-11-25 10:46:48 UTC
It looks like problem is not solved...

Current stacktrace on version 8.5.49

25-Nov-2019 11:15:37.790 SEVERE [Catalina-startStop-2] org.apache.catalina.core.ContainerBase.stopInternal A child container failed during stop
	java.util.concurrent.ExecutionException: java.lang.InternalError: Malformed class name
		at java.util.concurrent.FutureTask.report(FutureTask.java:122)
		at java.util.concurrent.FutureTask.get(FutureTask.java:192)
		at org.apache.catalina.core.ContainerBase.stopInternal(ContainerBase.java:990)
		at org.apache.catalina.util.LifecycleBase.stop(LifecycleBase.java:257)
		at org.apache.catalina.core.ContainerBase$StopChild.call(ContainerBase.java:1428)
		at org.apache.catalina.core.ContainerBase$StopChild.call(ContainerBase.java:1417)
		at java.util.concurrent.FutureTask.run(FutureTask.java:266)
		at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
		at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
		at java.lang.Thread.run(Thread.java:748)
	Caused by: java.lang.InternalError: Malformed class name
		at java.lang.Class.getSimpleName(Class.java:1330)
		at java.lang.Class.getCanonicalName(Class.java:1399)
		at org.apache.catalina.loader.WebappClassLoaderBase.getPrettyClassName(WebappClassLoaderBase.java:2049)
		at org.apache.catalina.loader.WebappClassLoaderBase.checkThreadLocalMapForLeaks(WebappClassLoaderBase.java:2013)
		at org.apache.catalina.loader.WebappClassLoaderBase.checkThreadLocalsForLeaks(WebappClassLoaderBase.java:1941)
		at org.apache.catalina.loader.WebappClassLoaderBase.clearReferences(WebappClassLoaderBase.java:1610)
		at org.apache.catalina.loader.WebappClassLoaderBase.stop(WebappClassLoaderBase.java:1550)
		at org.apache.catalina.loader.WebappLoader.stopInternal(WebappLoader.java:446)
		at org.apache.catalina.util.LifecycleBase.stop(LifecycleBase.java:257)
		at org.apache.catalina.core.StandardContext.stopInternal(StandardContext.java:5439)
		... 7 more
Comment 6 Remy Maucherat 2019-11-25 11:16:10 UTC
The issue should be fixed: it is about not stopping and cleaning up properly. As I said before: The root cause was that the container state was not properly set to FAILED on a JVM error exception class.

The "root cause" is of course not fixed, since it is a classloader problem most likely caused by your application. It is logged and things will go on from there. Feel free to investigate about it on the user mailing list, but please do not reopen the report for now.
Comment 7 Rafał Gała 2019-11-26 14:44:57 UTC
I agree it is a problem with an application, but should this exception cause such serious Tomcat shutdown problems? We are using Apache Commons Daemon to run Tomcat as a Windows service. When we stop the Windows service (net stop... or Stop from services.msc), it fails to shutdown because Tomcat shutdown process somehow hangs after this exception occurs. As a result, after about 10 minutes of waiting the JVM is dumped.

Currently we are unable to fix this issue as this is related to Finagle library which uses ThreadLocal variables that wrap scala objects. When Tomcat shuts down it calls getClass metod on one of those objects and then calls getCanonicalName on the class object which fails with above exception. Here is the name that is causing the exception: com.twitter.util.Local$Context$EmptyContext$
Comment 8 Remy Maucherat 2019-11-26 14:58:35 UTC
The fix is preventing improper cleanups but won't go too far beyond that, so a JVM error class exception is still going to go through. This behavior is specific to VirtualMachineError (except for StackOverflowError which is filtered out as recoverable).

If your application doesn't work with the cleanups and you cannot fix the application, you can disable these, look at the options in the documentation. The warnings and checks are supposed to warn you about likely bugs and leaks, if you cannot do anything about them, well ...
https://ci.apache.org/projects/tomcat/tomcat9/docs/config/context.html#Standard_Implementation
Comment 9 Rafał Gała 2019-11-26 15:04:25 UTC
Thank you very much for this, will surely come in handy. 

I would like to add one more thing - the issue does not exist when Tomcat is run on JDK11. There have been some fixes related to class naming introduced in JDK9. If someone struggles with similar problem then upgrading to JDK9+ may be a possible way to go.