Some Eclipse Foundation services are deprecated, or will be soon. Please ensure you've read this important communication.

Bug 407371

Summary: Tomcat hangs during shutdown
Product: [RT] RAP Reporter: Daria Huber <daria.spam>
Component: RWTAssignee: Project Inbox <rap-inbox>
Status: RESOLVED FIXED QA Contact:
Severity: major    
Priority: P2 CC: ivan, michi.fischer, rsternberg, vasko
Version: 1.5   
Target Milestone: 2.2 RC1   
Hardware: All   
OS: All   
Whiteboard: sr212
Attachments:
Description Flags
Thread Dump none

Description Daria Huber CLA 2013-05-07 04:58:29 EDT
My RAP application has a timer which is a daemon. Without a timer I can stop Tomcat (V 6.0.35) without problems. Shutdown process takes only 10 - 20 seconds.

But if I start my application and excute a timer task then tomcat hangs on shutdown. Here is a part of a thread dump:

"RMI TCP Connection(3)-xxx.xxx.xxx.xxx" daemon prio=6 tid=0x0000000006172000 nid=0xdec runnable [0x000000000c06f000]
   java.lang.Thread.State: RUNNABLE
	at java.net.SocketInputStream.socketRead0(Native Method)
	at java.net.SocketInputStream.read(SocketInputStream.java:129)
	at java.io.BufferedInputStream.fill(BufferedInputStream.java:218)
	at java.io.BufferedInputStream.read(BufferedInputStream.java:237)
	- locked <0x00000000ee5b4f48> (a java.io.BufferedInputStream)
	at java.io.FilterInputStream.read(FilterInputStream.java:66)
	at sun.rmi.transport.tcp.TCPTransport.handleMessages(TCPTransport.java:517)
	at sun.rmi.transport.tcp.TCPTransport$ConnectionHandler.run0(TCPTransport.java:790)
	at sun.rmi.transport.tcp.TCPTransport$ConnectionHandler.run(TCPTransport.java:649)
	at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
	at java.lang.Thread.run(Thread.java:662)

   Locked ownable synchronizers:
	- <0x00000000ee577838> (a java.util.concurrent.locks.ReentrantLock$NonfairSync)

"Thread-20" prio=6 tid=0x00000000060e2800 nid=0xd18 in Object.wait() [0x000000000a09c000]
   java.lang.Thread.State: WAITING (on object monitor)
	at java.lang.Object.wait(Native Method)
	- waiting on <0x00000000c2c746e8> (a org.eclipse.equinox.http.servlet.internal.ServletRegistration)
	at java.lang.Object.wait(Object.java:485)
	at org.eclipse.equinox.http.servlet.internal.Registration.destroy(Registration.java:34)
	- locked <0x00000000c2c746e8> (a org.eclipse.equinox.http.servlet.internal.ServletRegistration)
	at org.eclipse.equinox.http.servlet.internal.ServletRegistration.destroy(ServletRegistration.java:37)
	at org.eclipse.equinox.http.servlet.internal.ProxyServlet.unregister(ProxyServlet.java:153)
	- locked <0x00000000c1ff2048> (a org.eclipse.equinox.http.servlet.HttpServiceServlet)
	at org.eclipse.equinox.http.servlet.internal.HttpServiceImpl.unregister(HttpServiceImpl.java:88)
	- locked <0x00000000c1a27d78> (a org.eclipse.equinox.http.servlet.internal.HttpServiceImpl)
	at org.eclipse.rap.rwt.osgi.internal.ApplicationReferenceImpl.unregisterServlet(ApplicationReferenceImpl.java:210)
	at org.eclipse.rap.rwt.osgi.internal.ApplicationReferenceImpl.unregisterServlets(ApplicationReferenceImpl.java:131)
	at org.eclipse.rap.rwt.osgi.internal.ApplicationReferenceImpl.stopRWTApplication(ApplicationReferenceImpl.java:119)
	at org.eclipse.rap.rwt.osgi.internal.ApplicationReferenceImpl.doStopApplication(ApplicationReferenceImpl.java:111)
	at org.eclipse.rap.rwt.osgi.internal.ApplicationReferenceImpl.stopApplication(ApplicationReferenceImpl.java:95)
	at org.eclipse.rap.ui.internal.servlet.HttpServiceTracker.removedService(HttpServiceTracker.java:52)
	at org.eclipse.rap.ui.internal.servlet.HttpServiceTracker.removedService(HttpServiceTracker.java:1)
	at org.osgi.util.tracker.ServiceTracker$Tracked.customizerRemoved(ServiceTracker.java:956)
	at org.osgi.util.tracker.ServiceTracker$Tracked.customizerRemoved(ServiceTracker.java:1)
	at org.osgi.util.tracker.AbstractTracked.untrack(AbstractTracked.java:341)
	at org.osgi.util.tracker.ServiceTracker.close(ServiceTracker.java:375)
	at org.eclipse.rap.ui.internal.servlet.HttpServiceTracker.close(HttpServiceTracker.java:64)
	at org.eclipse.ui.internal.WorkbenchPlugin.stop(WorkbenchPlugin.java:1340)
	at org.eclipse.osgi.framework.internal.core.BundleContextImpl$2.run(BundleContextImpl.java:771)
	at java.security.AccessController.doPrivileged(Native Method)
	at org.eclipse.osgi.framework.internal.core.BundleContextImpl.stop(BundleContextImpl.java:764)
	at org.eclipse.osgi.framework.internal.core.BundleHost.stopWorker(BundleHost.java:510)
	at org.eclipse.osgi.framework.internal.core.AbstractBundle.suspend(AbstractBundle.java:566)
	at org.eclipse.osgi.framework.internal.core.Framework.suspendBundle(Framework.java:1206)
	at org.eclipse.osgi.framework.internal.core.StartLevelManager.decFWSL(StartLevelManager.java:592)
	at org.eclipse.osgi.framework.internal.core.StartLevelManager.doSetStartLevel(StartLevelManager.java:257)
	- locked <0x00000000c1525658> (a java.lang.Object)
	at org.eclipse.osgi.framework.internal.core.StartLevelManager.shutdown(StartLevelManager.java:215)
	at org.eclipse.osgi.framework.internal.core.InternalSystemBundle.suspend(InternalSystemBundle.java:284)
	at org.eclipse.osgi.framework.internal.core.Framework.shutdown(Framework.java:692)
	- locked <0x00000000c1457618> (a org.eclipse.osgi.framework.internal.core.Framework)
	at org.eclipse.osgi.framework.internal.core.Framework.close(Framework.java:600)
	- locked <0x00000000c1457618> (a org.eclipse.osgi.framework.internal.core.Framework)
	at org.eclipse.core.runtime.adaptor.EclipseStarter.shutdown(EclipseStarter.java:399)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
	at java.lang.reflect.Method.invoke(Method.java:597)
	at org.eclipse.equinox.servletbridge.FrameworkLauncher.stop(FrameworkLauncher.java:742)
	- locked <0x00000000c152b3d8> (a org.eclipse.equinox.servletbridge.FrameworkLauncher)
	at org.eclipse.equinox.servletbridge.BridgeServlet.destroy(BridgeServlet.java:77)
	at org.apache.catalina.core.StandardWrapper.unload(StandardWrapper.java:1436)
	- locked <0x00000000c1b030e8> (a org.apache.catalina.core.StandardWrapper)
	at org.apache.catalina.core.StandardWrapper.stop(StandardWrapper.java:1784)
	at org.apache.catalina.core.StandardContext.stop(StandardContext.java:4872)
	- locked <0x00000000c1b03ce8> (a org.apache.catalina.core.StandardContext)
	at org.apache.catalina.core.ContainerBase.removeChild(ContainerBase.java:936)
	at org.apache.catalina.startup.HostConfig.undeployApps(HostConfig.java:1359)
	at org.apache.catalina.startup.HostConfig.stop(HostConfig.java:1330)
	at org.apache.catalina.startup.HostConfig.lifecycleEvent(HostConfig.java:326)
	at org.apache.catalina.util.LifecycleSupport.fireLifecycleEvent(LifecycleSupport.java:142)
	at org.apache.catalina.core.ContainerBase.stop(ContainerBase.java:1098)
	- locked <0x00000000c102cd60> (a org.apache.catalina.core.StandardHost)
	at org.apache.catalina.core.ContainerBase.stop(ContainerBase.java:1110)
	- locked <0x00000000c102cc28> (a org.apache.catalina.core.StandardEngine)
	at org.apache.catalina.core.StandardEngine.stop(StandardEngine.java:468)
	at org.apache.catalina.core.StandardService.stop(StandardService.java:604)
	- locked <0x00000000c102cc28> (a org.apache.catalina.core.StandardEngine)
	at org.apache.catalina.core.StandardServer.stop(StandardServer.java:788)
	at org.apache.catalina.startup.Catalina.stopServer(Catalina.java:408)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
	at java.lang.reflect.Method.invoke(Method.java:597)
	at org.apache.catalina.startup.Bootstrap.stopServer(Bootstrap.java:338)
	at org.apache.catalina.startup.Bootstrap.main(Bootstrap.java:416)

   Locked ownable synchronizers:
	- None

"Timer-1" daemon prio=6 tid=0x0000000006175000 nid=0xd4c in Object.wait() [0x000000000ca6f000]
   java.lang.Thread.State: TIMED_WAITING (on object monitor)
	at java.lang.Object.wait(Native Method)
	- waiting on <0x00000000ec2b6748> (a java.util.TaskQueue)
	at java.util.TimerThread.mainLoop(Timer.java:509)
	- locked <0x00000000ec2b6748> (a java.util.TaskQueue)
	at java.util.TimerThread.run(Timer.java:462)

   Locked ownable synchronizers:
	- None


My efforts:
1) Declarate Timer as a daemon. 
2) I tried to stop timer task in "contextDestroyed" in ServletContextListener but it's too late. My tomcat logs "INFO: Stopping service Catalina" and hangs for 3-4 minutes. The method "contextDestroyed" is executed after that. 
I have at least one Timer per session. In worst case I have to wait over 10 minutes.

As I see application hangs on waiting for lock under synchronized method org.eclipse.equinox.http.servlet.internal.Registration.destroy. But why? And what it has to do with my timer task?
Comment 1 Ivan Furnadjiev CLA 2013-05-09 03:27:48 EDT
This was an issue with RAP 1.5 when UICallBack was active (blocked request was waiting) during the Tomcat shutdown. I thought that we have a bug opened about it, but I can't find it. I believe (can't reproduce it) that the issue is fixed in RAP 2.0. Please reopen if the issue persists in RAP 2.0+.
Comment 2 Daria Huber CLA 2013-05-10 02:58:23 EDT
(In reply to comment #1)
> This was an issue with RAP 1.5 when UICallBack was active (blocked request
> was waiting) during the Tomcat shutdown. I thought that we have a bug opened
> about it, but I can't find it. I believe (can't reproduce it) that the issue
> is fixed in RAP 2.0. Please reopen if the issue persists in RAP 2.0+.

Thank's for your quick reply.

Do you think it is possible to patch (or workaround) this bug in RAP 1.5?
Comment 3 Ivan Furnadjiev CLA 2013-05-10 03:13:35 EDT
(In reply to comment #2)
> (In reply to comment #1)
> > This was an issue with RAP 1.5 when UICallBack was active (blocked request
> > was waiting) during the Tomcat shutdown. I thought that we have a bug opened
> > about it, but I can't find it. I believe (can't reproduce it) that the issue
> > is fixed in RAP 2.0. Please reopen if the issue persists in RAP 2.0+.
> 
> Thank's for your quick reply.
> 
> Do you think it is possible to patch (or workaround) this bug in RAP 1.5?
No... I don't think so. UICallBack was renamed (ServerPushSession) and redesigned in RAP 2.0. Together with all the API changes in RAP 2.0 it's not possible to extract a patch.
Comment 4 Daria Huber CLA 2013-06-03 07:41:35 EDT
Is it possible to kill my timer on shutdown? I tried with ServletContextListener and HttpSessionListener. I passed my timer object with HttpSessionEvent and tried to kill it on "contextDestroyed".  But my application hangs already before the method "contextDestroyed" is executed. 
I have the same problem with ProgressMonitorDialog which blocks UIThread on a database query. During shutdown on a long running query I get a deadlock. I would like to kill my database thread on a shutdown. But it is the same problem as with the timer. "contextDestroyed" is executed too late. I tried with a database connection timeout, but my ProgressMonitorDialog still hangs.
I can't just switch to RAP 2.X and have to find a solution for RAP 1.5. Have you any idea?
I would be glad for any propose....
Comment 5 Ivan Furnadjiev CLA 2013-06-18 03:49:09 EDT
I will reopen this bug, because I've managed to reproduce a Tomcat hang on shutdown with our Workbench Demo and latest RAP 2.1 (master). In "Planning" perspective start a "Job with Dialog" and try to shutdown the Tomcat when the progress is running. Maybe this is related to bug 409843 or even it's a duplicate, but I will keep this bug open till we prove it.
Comment 6 Ivan Furnadjiev CLA 2013-06-18 03:58:00 EDT
Using a distinct (final) lock object instead of 'this' in UIThread#getLock as suggested in bug 409843 does not fix the hang.
Comment 7 Ivan Furnadjiev CLA 2013-06-18 05:33:34 EDT
More info from YourKit - after Tomcat shutdown two thread are still waiting:

UIThread [183b969] [WAITING] CPU time: 3s
java.lang.Object.wait()
org.eclipse.rap.rwt.internal.lifecycle.UIThread.switchThread()
org.eclipse.rap.rwt.internal.lifecycle.RWTLifeCycle.sleep()
org.eclipse.swt.widgets.Display.sleep()
org.eclipse.ui.application.WorkbenchAdvisor.eventLoopIdle(Display)
org.eclipse.ui.internal.Workbench.runEventLoop(Window$IExceptionHandler, Display)
org.eclipse.ui.internal.Workbench.runUI()
org.eclipse.ui.internal.Workbench.access$5(Workbench)
org.eclipse.ui.internal.Workbench$5.run()
org.eclipse.core.databinding.observable.Realm.runWithDefault(Realm, Runnable)
org.eclipse.ui.internal.Workbench.createAndRunWorkbench(Display, WorkbenchAdvisor)
org.eclipse.ui.PlatformUI.createAndRunWorkbench(Display, WorkbenchAdvisor)
org.eclipse.rap.demo.DemoWorkbench.createUI()
org.eclipse.rap.rwt.internal.lifecycle.RWTLifeCycle.createUI()
org.eclipse.rap.rwt.internal.lifecycle.RWTLifeCycle$UIThreadController.run()
java.lang.Thread.run()
org.eclipse.rap.rwt.internal.lifecycle.UIThread.run()

Worker-JM [WAITING] CPU time: 0
java.lang.Object.wait(long)
org.eclipse.core.internal.jobs.InternalWorker.run()
Comment 8 Ivan Furnadjiev CLA 2013-06-18 07:36:48 EDT
It's absolutely the same hang with RAP 1.5 - this issue is not a regression.
Comment 9 Ivan Furnadjiev CLA 2013-06-19 08:47:43 EDT
Created attachment 232539 [details]
Thread Dump

This is the thread dump attached to
http://www.eclipse.org/forums/index.php/mv/msg/488636/1064034/#msg_1064034
In this thread dump the main Tomcat thread is blocked. This is not the case with my observation with Workbench Demo, where the Tomcat main thread is not blocked, but JavaVM is not destroyed.
Daria, could you provide a simple project to reproduce the blocked Tomcat main thread?
Comment 10 Vasko Tchoumatchenko CLA 2013-10-01 02:52:55 EDT
A started but "unused" ServerPushSession (aka. UICallBack) will also prevent Tomcat from a graceful shutdown.

The stack trace below illustrates a situation where Registration.destroy() waits for the RWTServlet to finish processing the request. Since the request is blocked on the server, Tomcat shutdown will not finish. 

"localhost-startStop-2" - Thread t@90
   java.lang.Thread.State: WAITING
	at java.lang.Object.wait(Native Method)
	- waiting on <8c5318> (a org.eclipse.equinox.http.servlet.internal.ServletRegistration)
	at java.lang.Object.wait(Object.java:503)
	at org.eclipse.equinox.http.servlet.internal.Registration.destroy(Registration.java:34)
	at org.eclipse.equinox.http.servlet.internal.ServletRegistration.destroy(ServletRegistration.java:37)
	at org.eclipse.equinox.http.servlet.internal.ProxyServlet.unregister(ProxyServlet.java:153)
	- locked <175f1c8> (a org.eclipse.equinox.http.servlet.HttpServiceServlet)
	at org.eclipse.equinox.http.servlet.internal.HttpServiceImpl.unregister(HttpServiceImpl.java:88)
	- locked <1ebb3fb> (a org.eclipse.equinox.http.servlet.internal.HttpServiceImpl)
	at org.eclipse.rap.rwt.osgi.internal.ApplicationReferenceImpl.unregisterServlet(ApplicationReferenceImpl.java:210)
	at org.eclipse.rap.rwt.osgi.internal.ApplicationReferenceImpl.unregisterServlets(ApplicationReferenceImpl.java:131)
	at org.eclipse.rap.rwt.osgi.internal.ApplicationReferenceImpl.stopRWTApplication(ApplicationReferenceImpl.java:119)
	at org.eclipse.rap.rwt.osgi.internal.ApplicationReferenceImpl.doStopApplication(ApplicationReferenceImpl.java:111)
	at org.eclipse.rap.rwt.osgi.internal.ApplicationReferenceImpl.stopApplication(ApplicationReferenceImpl.java:95)
	at org.eclipse.rap.ui.internal.servlet.HttpServiceTracker.removedService(HttpServiceTracker.java:52)
	at org.eclipse.rap.ui.internal.servlet.HttpServiceTracker.removedService(HttpServiceTracker.java:1)
	at org.osgi.util.tracker.ServiceTracker$Tracked.customizerRemoved(ServiceTracker.java:956)
	at org.osgi.util.tracker.ServiceTracker$Tracked.customizerRemoved(ServiceTracker.java:1)
	at org.osgi.util.tracker.AbstractTracked.untrack(AbstractTracked.java:341)
	at org.osgi.util.tracker.ServiceTracker.close(ServiceTracker.java:375)
	at org.eclipse.rap.ui.internal.servlet.HttpServiceTracker.close(HttpServiceTracker.java:64)
	at org.eclipse.ui.internal.WorkbenchPlugin.stop(WorkbenchPlugin.java:1332)
...
Comment 11 Ralf Sternberg CLA 2013-11-26 10:57:02 EST
Fixed as of commit 578019c1948fb46b09912b187b3c2bc46e5860a5.

The problem was that the servlet bridge blocks the calling thread while unregistering servlets with standing requests. This lead to a lock state when trying to undeploy an application that has waiting push requests.

To resolve the issue, servlets are now unregistered *after* the ApplicationContext is stopped. Stopping the application releases these push requests, so that unregistering does not block anymore.
Comment 12 Ralf Sternberg CLA 2014-01-27 07:42:12 EST
+1 for backporting to 2.1.2.
If this fix has any unwanted side-effects, they would only affect the shutdown of an application, no regressions should be introduced at runtime.
Comment 13 Ivan Furnadjiev CLA 2014-01-29 05:31:14 EST
Backported to 2.1-maintenance branch with change https://git.eclipse.org/r/21232.