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

Bug 360630

Summary: Session reaper may wait forever when UIThread#terminateThread is called
Product: [RT] RAP Reporter: Clemens Schneider <hula.bula>
Component: RWTAssignee: Project Inbox <rap-inbox>
Status: RESOLVED FIXED QA Contact:
Severity: critical    
Priority: P3 CC: chris, ezanaga, ivan, jens.borrmann, stefanescu.a
Version: 1.5   
Target Milestone: 1.5 M3   
Hardware: All   
OS: All   
Whiteboard:

Description Clemens Schneider CLA 2011-10-12 04:52:35 EDT
We have an issue where the Tomcat session reaper (ContainerBackgroundProcessor) is waiting for a UIThread to be terminated but the UIThread does not return. As the session reaper thread waits forever it cannot remove other expired sessions.

Stacktrace of the UIThread:

Name: UIThread [49E28337D46A639854D3E1B016191112]
State: WAITING on org.eclipse.rwt.internal.lifecycle.UIThread@2faaff71
Total blocked: 420  Total waited: 387

Stack trace: 
java.lang.Object.wait(Native Method)
java.lang.Object.wait(Object.java:485)
org.eclipse.rwt.internal.lifecycle.UIThread.switchThread(UIThread.java:60)
org.eclipse.rwt.internal.lifecycle.RWTLifeCycle.sleep(RWTLifeCycle.java:311)
org.eclipse.swt.widgets.Display.sleep(Display.java:1128)
org.eclipse.jface.window.Window.runEventLoop(Window.java:829)
org.eclipse.jface.window.Window.open(Window.java:804)
org.eclipse.jface.dialogs.MessageDialog.open(MessageDialog.java:334)
org.eclipse.jface.dialogs.MessageDialog.open(MessageDialog.java:364)
org.eclipse.jface.dialogs.MessageDialog.openError(MessageDialog.java:431)
de.cas.open.rapclient.base.ui.dialogs.MessageDialogUtils.openError(MessageDialogUtils.java:57)
de.cas.open.rapclient.base.ui.dialogs.MessageDialogUtils.openError(MessageDialogUtils.java:65)
de.cas.open.rapclient.base.ui.dialogs.MessageDialogUtils.openError(MessageDialogUtils.java:69)
de.cas.open.rapclient.base.ui.UIPluginActivator$DialogUIExceptionHandler.openUserError(UIPluginActivator.java:101)
de.cas.open.rapclient.base.core.util.ExceptionUtils.handleUserException(ExceptionUtils.java:65)
de.cas.open.rapclient.base.core.util.ExceptionUtils.handleUserException(ExceptionUtils.java:88)
de.cas.open.rapclient.application.settingstabs.FormWithTabsFactory.createTabFolderWithTabs(FormWithTabsFactory.java:123)
de.cas.open.rapclient.application.internal.settings.AdminDialog.createControls(AdminDialog.java:65)
de.cas.open.rapclient.application.internal.settings.AdminDialog.<init>(AdminDialog.java:52)
de.cas.open.rapclient.application.infobar.AdminSettingsArea$1.widgetSelected(AdminSettingsArea.java:44)
org.eclipse.swt.events.SelectionEvent.dispatchToObserver(SelectionEvent.java:194)
org.eclipse.rwt.internal.events.Event.processEvent(Event.java:64)
org.eclipse.swt.events.TypedEvent.processEvent(TypedEvent.java:161)
org.eclipse.swt.events.TypedEvent.executeNext(TypedEvent.java:201)
org.eclipse.swt.widgets.Display.runPendingMessages(Display.java:1100)
org.eclipse.swt.widgets.Display.readAndDispatch(Display.java:1090)
org.eclipse.ui.internal.Workbench.runEventLoop(Workbench.java:2390)
org.eclipse.ui.internal.Workbench.runUI(Workbench.java:2351)
org.eclipse.ui.internal.Workbench.access$5(Workbench.java:2206)
org.eclipse.ui.internal.Workbench$4.run(Workbench.java:424)
org.eclipse.rap.ui.internal.RealmAdapterHook.runWithDefault(RealmAdapterHook.java:48)
org.eclipse.ui.internal.Workbench.createAndRunWorkbench(Workbench.java:427)
org.eclipse.ui.PlatformUI.createAndRunWorkbench(PlatformUI.java:157)
de.cas.open.rapclient.application.main.ApplicationEntryPoint.createWorkBench(ApplicationEntryPoint.java:247)
de.cas.open.rapclient.application.main.ApplicationEntryPoint.createUI(ApplicationEntryPoint.java:197)
org.eclipse.rwt.internal.lifecycle.EntryPointManager.createUI(EntryPointManager.java:92)
org.eclipse.rwt.internal.lifecycle.RWTLifeCycle.createUI(RWTLifeCycle.java:258)
org.eclipse.rwt.internal.lifecycle.RWTLifeCycle$UIThreadController.run(RWTLifeCycle.java:114)
java.lang.Thread.run(Thread.java:662)
org.eclipse.rwt.internal.lifecycle.UIThread.run(UIThread.java:102)


Stacktrace of the ContainerBackgroundProcessor:

Name: ContainerBackgroundProcessor[StandardEngine[Catalina]]
State: WAITING on org.eclipse.rwt.internal.lifecycle.UIThread@2faaff71
Total blocked: 1.409  Total waited: 125.582

Stack trace: 
java.lang.Object.wait(Native Method)
java.lang.Thread.join(Thread.java:1186)
java.lang.Thread.join(Thread.java:1239)
org.eclipse.rwt.internal.lifecycle.UIThread.terminateThread(UIThread.java:118)
org.eclipse.rwt.internal.lifecycle.UIThread.interceptShutdown(UIThread.java:148)
org.eclipse.rwt.internal.service.SessionStoreImpl.valueUnbound(SessionStoreImpl.java:160)
org.apache.catalina.session.StandardSession.removeAttributeInternal(StandardSession.java:1676)
org.apache.catalina.session.StandardSession.expire(StandardSession.java:791)
   - locked org.apache.catalina.session.StandardSession@326e4caa
org.apache.catalina.session.StandardSession.isValid(StandardSession.java:575)
org.apache.catalina.session.ManagerBase.processExpires(ManagerBase.java:700)
org.apache.catalina.session.ManagerBase.backgroundProcess(ManagerBase.java:685)
org.apache.catalina.core.ContainerBase.backgroundProcess(ContainerBase.java:1316)
org.apache.catalina.core.ContainerBase$ContainerBackgroundProcessor.processChildren(ContainerBase.java:1601)
org.apache.catalina.core.ContainerBase$ContainerBackgroundProcessor.processChildren(ContainerBase.java:1610)
org.apache.catalina.core.ContainerBase$ContainerBackgroundProcessor.processChildren(ContainerBase.java:1610)
org.apache.catalina.core.ContainerBase$ContainerBackgroundProcessor.run(ContainerBase.java:1590)
java.lang.Thread.run(Thread.java:662)


When looking at the source, this scenario can only come true when the call to getThread().interrupt() (UIThread#terminateThread() (line 115)) occurs just before the other thread enters wait state in UIThread#switchThread() (line 59). In this case, both threads are waiting forever and none of them is being notified.
Without further investigation: Shouldn't UIThread#terminateThread() first try to obtain a lock (UIThread#getLock()) and when in possession of the lock then interrupt the thread?
Comment 1 Clemens Schneider CLA 2011-10-12 04:53:55 EDT
Changed version to 1.5, as the source in UIThread did not change compared to 1.3
Comment 2 RĂ¼diger Herrmann CLA 2011-10-15 05:37:43 EDT
(In reply to comment #0)
> Without further investigation: Shouldn't UIThread#terminateThread() first try to
> obtain a lock (UIThread#getLock()) and when in possession of the lock then
> interrupt the thread?
This sounds reasonable. I changed the code as suggested. The changes will be available in builds >= 2011-10-15.
Would you be able to give it a try and report back here if the issue is gone?
Comment 3 Jens Borrmann CLA 2011-12-21 00:35:04 EST
We stumbled upon this issue, too, when performing some elementary stress tests with our application using a 1.4.0 version. We backported the patch and did not face the problem since then.
Comment 4 Ralf Sternberg CLA 2012-01-27 12:06:24 EST
Since the suggested fix seems to have cured the problem, I'll close this bug. Please reopen if you observe the problem again.
Comment 5 Adrian Stefanescu CLA 2013-06-04 06:42:27 EDT
The UIThread dlock still occurs.

A worker thread and the session scavange got stuck.


####################################################################################
Name: HashSessionScavenger-1
####################################################################################
State: WAITING on org.eclipse.rwt.internal.lifecycle.UIThread@238836bb
Total blocked: 28  Total waited: 5.200

Stack trace: 
 java.lang.Object.wait(Native Method)
java.lang.Thread.join(Unknown Source)
java.lang.Thread.join(Unknown Source)
org.eclipse.rwt.internal.lifecycle.UIThread.terminateThread(UIThread.java:119)
org.eclipse.rwt.internal.lifecycle.UIThread.interceptShutdown(UIThread.java:149)
org.eclipse.rwt.internal.service.SessionStoreImpl.valueUnbound(SessionStoreImpl.java:182)
org.eclipse.jetty.server.session.AbstractSession.unbindValue(AbstractSession.java:489)
org.eclipse.jetty.server.session.AbstractSession.clearAttributes(AbstractSession.java:340)
org.eclipse.jetty.server.session.AbstractSession.doInvalidate(AbstractSession.java:307)
org.eclipse.jetty.server.session.HashedSession.doInvalidate(HashedSession.java:72)
org.eclipse.jetty.server.session.AbstractSession.timeout(AbstractSession.java:285)
   - locked org.eclipse.jetty.server.session.HashedSession@6e018d18
org.eclipse.jetty.server.session.HashSessionManager.scavenge(HashSessionManager.java:309)
org.eclipse.jetty.server.session.HashSessionManager$2.run(HashSessionManager.java:274)
java.util.TimerThread.mainLoop(Unknown Source)
java.util.TimerThread.run(Unknown Source)


####################################################################################
Name: UIThread [1u0sc3difmbpn1g5wi4npliyyb]
####################################################################################
State: WAITING on org.eclipse.rwt.internal.lifecycle.UIThread@238836bb
Total blocked: 66  Total waited: 1.112

Stack trace: 
 java.lang.Object.wait(Native Method)
java.lang.Object.wait(Object.java:485)
org.eclipse.rwt.internal.lifecycle.UIThread.switchThread(UIThread.java:59)
org.eclipse.rwt.internal.lifecycle.RWTLifeCycle.sleep(RWTLifeCycle.java:232)
org.eclipse.swt.widgets.Display.sleep(Display.java:1176)
org.eclipse.ui.application.WorkbenchAdvisor.eventLoopIdle(WorkbenchAdvisor.java:361)
org.eclipse.ui.internal.Workbench.runEventLoop(Workbench.java:2734)
org.eclipse.ui.internal.Workbench.runUI(Workbench.java:2694)
org.eclipse.ui.internal.Workbench.access$5(Workbench.java:2530)
org.eclipse.ui.internal.Workbench$5.run(Workbench.java:702)
org.eclipse.core.databinding.observable.Realm.runWithDefault(Realm.java:332)
org.eclipse.ui.internal.Workbench.createAndRunWorkbench(Workbench.java:685)
org.eclipse.ui.PlatformUI.createAndRunWorkbench(PlatformUI.java:157)
com.atoss.atc.web.core.Application.createUI(Application.java:58)
org.eclipse.rwt.internal.lifecycle.RWTLifeCycle.createUI(RWTLifeCycle.java:177)
org.eclipse.rwt.internal.lifecycle.RWTLifeCycle$UIThreadController.run(RWTLifeCycle.java:289)
java.lang.Thread.run(Unknown Source)
org.eclipse.rwt.internal.lifecycle.UIThread.run(UIThread.java:102)
Comment 6 Adrian Stefanescu CLA 2013-06-04 06:59:22 EDT
I can't set the bug on REOPEN

I would say the problem is the "lock object". In this case the actual Thread instance is used as lock object. Then the Thread.join() also tries to get a lock on the tread instance/lock object. 

I would say if terminateThread() is stopped between interrupt() and join() and the worker thread ends up again in switchThread() it will go on "wait" and nobody notifies it while the Thread on terminateThread() method waits to get a lock on the thread instance. In the meantime the scavenger thread blocks all access to the session object with "AbstractSession.doInvalidate"

The fix would be to have a separated "lock" in the place of "this"


####################################################################################
Name: New I/O client worker #88-1
####################################################################################
State: BLOCKED on org.eclipse.jetty.server.session.HashedSession@6e018d18 owned by: HashSessionScavenger-1
Total blocked: 5.693  Total waited: 0

Stack trace: 
 org.eclipse.jetty.server.session.AbstractSession.setAttribute(AbstractSession.java:408)
org.eclipse.equinox.http.servlet.internal.HttpSessionAdaptor.setAttribute(HttpSessionAdaptor.java:96)
org.eclipse.rap.rwt.osgi.internal.HttpSessionWrapper.setAttribute(HttpSessionWrapper.java:78)
.....RAPConnectionObserver.connectionLost(RAPConnectionObserver.java:32)
Comment 7 Ivan Furnadjiev CLA 2013-06-04 07:05:19 EDT
(In reply to comment #6)
> I can't set the bug on REOPEN
As this is an old bug related to RAP 1.4, please create a separate bug and provide your findings there. Which RAP version is affected?