Bug 157089 - org.eclipse.hyades.ui.internal.provider.ResourceChangeUpdateProvider$UIUpdaterProvider maxes out CPU, blocks UI
Summary: org.eclipse.hyades.ui.internal.provider.ResourceChangeUpdateProvider$UIUpdate...
Status: CLOSED FIXED
Alias: None
Product: z_Archived
Classification: Eclipse Foundation
Component: TPTP (show other bugs)
Version: unspecified   Edit
Hardware: PC Windows XP
: P1 major (vote)
Target Milestone: ---   Edit
Assignee: Jerome Gout CLA
QA Contact:
URL:
Whiteboard:
Keywords: plan
: 147939 161415 (view as bug list)
Depends on: 164637
Blocks:
  Show dependency tree
 
Reported: 2006-09-12 15:24 EDT by Alex Bernstein CLA
Modified: 2016-05-05 10:31 EDT (History)
6 users (show)

See Also:


Attachments
performance graph (38.56 KB, image/gif)
2006-09-13 04:55 EDT, Jerome Gout CLA
no flags Details
Fix. (112.75 KB, patch)
2006-10-16 12:42 EDT, Julien Canches CLA
no flags Details | Diff

Note You need to log in before you can comment on or make changes to this bug.
Description Alex Bernstein CLA 2006-09-12 15:24:12 EDT
workbench cpu 100% consumed when 200 tests introduced to project only in TestPerspective.
Steps to repro.

1. Copy 200 unique test suites to project folder using Windows Explorer
2. Launch RPT workspace containing project with 200 unique tests
3. Observe greedy CPU consumption

200 unique tests can be found here \\jibe.raleigh.ibm.com\myShare\oldstuff\200tests
Comment 1 Alex Bernstein CLA 2006-09-12 16:26:30 EDT
Please disregard the path to the tests location. The tests will be available upon request.
Comment 2 Jerome Gout CLA 2006-09-13 04:55:25 EDT
Created attachment 50014 [details]
performance graph
Comment 3 Jerome Gout CLA 2006-09-13 04:56:16 EDT
I've tried reproduce this issue using the driver 4.2.1 used to make test pass.
This is pure TPTP driver without RPT.
I've duplicated a manual test suite (very simple) until 200 different files
using Windows explorer.
Then, I've launch TPTP with the test perspective open containing the test
navigator (in resource mode). After refreshing its content test suites appear
after 10sec (the CPU is 100% during this period).
If I try to switch to logical mode or close/open the test nav, it takes around
5sec to display test suites due to cache (CPU usage 100% during this period as
well)
Same duration is observed if I close/restart TPTP.

Same test has been performed using plugin actual junit test suite (used for
TPTP interanl tests) duplicated 1000 times.
Here is the snapshoot of the performance graph of my system (old test machine
DELL dimension 2300)

From a TPTP perspective, it seems that test navigator is scalable.
Comment 4 Mark D Dunn CLA 2006-09-13 08:15:39 EDT
Reassign to Jerome.  Change from blocker to critical.
Comment 5 Alex Bernstein CLA 2006-09-13 10:24:26 EDT
Here are some observations I have made while debugging the problem:

1. During refresh, each test is loaded into memory. RPT Tests tend to be much larger than simple manual tests, so loading them must be more time consuming.  Time spent in RPT code (i.e. ProxyNode and Factory) is in the range 5-20ms, which is to say, very small. Indeed most of time is spent loading the test.

2. Below is the typical stack trace that can be obtained by pausing Eclipse at any given moment during the delay/freeze. As you can see, the problem stems not from the fact that that loading large EMF tests into memory is a long operation, but rather that this is being done inside UI thread.

3. There are several ways to move processing and updating the UI into background. Jobs, UIJobs, LazyContentProvider, LazyLabelProviders and delayed decorators can all be used to improve visual user experience during long lasting ops. Perhaps TestNavigator can be changed to use one or more of these.

4. Finally, this problem does not appear to be specific to RPT. Any other product can potentially create large test assets and bring TestNavigator to a crawl.

-------------------- stack trace ----------------------------------
XMLEntityScanner.skipSpaces() line: not available [local variables unavailable]	
XMLDocumentScannerImpl(XMLDocumentFragmentScannerImpl).scanStartElement() line: not available	
XMLDocumentScannerImpl$ContentDispatcher(XMLDocumentFragmentScannerImpl$FragmentContentDispatcher).dispatch(boolean) line: not available	
XMLDocumentScannerImpl(XMLDocumentFragmentScannerImpl).scanDocument(boolean) line: not available	
XIncludeAwareParserConfiguration(XML11Configuration).parse(boolean) line: not available	
XIncludeAwareParserConfiguration(XML11Configuration).parse(XMLInputSource) line: not available	
SAXParserImpl$JAXPSAXParser(XMLParser).parse(XMLInputSource) line: not available	
SAXParserImpl$JAXPSAXParser(AbstractSAXParser).parse(InputSource) line: not available	
SAXParserImpl.parse(InputSource, DefaultHandler) line: not available	
XMILoadImpl(XMLLoadImpl).load(XMLResource, InputStream, Map) line: 179	
FacadeResourceImpl(XMLResourceImpl).doLoad(InputStream, Map) line: 179	
FacadeResourceImpl.doLoad(InputStream, Map) line: 181	
FacadeResourceImpl(ResourceImpl).load(InputStream, Map) line: 1089	
FacadeResourceImpl(ResourceImpl).load(Map) line: 895	
ResourceSetImpl.demandLoad(Resource) line: 249	
ResourceSetImpl.demandLoadHelper(Resource) line: 264	
ResourceSetImpl.getResource(URI, boolean) line: 390	
EMFResourceProxyFactory.getEMFResource(IFile) line: 88	
EMFResourceProxyFactory.create(IFile, Object) line: 108	
FileProxyNodeCache.createProxy(IFile) line: 451	
FileProxyNodeCache.getProxy(IFile) line: 432	
FileProxyManager.getProxy(IFile, Object) line: 63	
--> TestResourceChangeUpdater.add(IResource, IResource[]) line: 171	
ResourceChangeUpdaterProvider$UIUpdaterProvider(ResourceChangeUpdaterProvider).processDelta(IResourceDelta) line: 227	
ResourceChangeUpdaterProvider$UIUpdaterProvider(ResourceChangeUpdaterProvider).processDelta(IResourceDelta) line: 203	
ResourceChangeUpdaterProvider$UIUpdaterProvider(ResourceChangeUpdaterProvider).doProcessDelta(IResourceDelta) line: 133	
ResourceChangeUpdaterProvider$UIUpdaterProvider.run() line: 67	
UILockListener.doPendingWork() line: 155	
UISynchronizer$1.run() line: 36	
RunnableLock.run() line: 35	
UISynchronizer(Synchronizer).runAsyncMessages(boolean) line: 123	
Display.runAsyncMessages(boolean) line: 3325	
Display.readAndDispatch() line: 2971	
Workbench.runEventLoop(Window$IExceptionHandler, Display) line: 1914	
Workbench.runUI() line: 1878	
Workbench.createAndRunWorkbench(Display, WorkbenchAdvisor) line: 419	
PlatformUI.createAndRunWorkbench(Display, WorkbenchAdvisor) line: 149	
IDEApplication.run(Object) line: 95	
PlatformActivator$1.run(Object) line: 78	
EclipseAppLauncher.runApplication(Object) line: 92	
EclipseAppLauncher.start(Object) line: 68	
EclipseStarter.run(Object) line: 400	
EclipseStarter.run(String[], Runnable) line: 177	
NativeMethodAccessorImpl.invoke0(Method, Object, Object[]) line: not available [native method]	
NativeMethodAccessorImpl.invoke(Object, Object[]) line: 64	
DelegatingMethodAccessorImpl.invoke(Object, Object[]) line: 4
Comment 6 Julien Canches CLA 2006-09-15 09:30:07 EDT
Will try to implement the asynchronous solution in i3.
Comment 7 Paul Slauenwhite CLA 2006-09-18 09:48:01 EDT
Please correct the version since there is no 4.2.2 release.
Comment 8 Julien Canches CLA 2006-10-16 12:42:33 EDT
Created attachment 52041 [details]
Fix.
Comment 9 Julien Canches CLA 2006-10-18 04:16:47 EDT
Adjusting priority to reflect severity.
Comment 10 Jerome Gout CLA 2006-10-19 05:14:07 EDT
*** Bug 161415 has been marked as a duplicate of this bug. ***
Comment 11 Paul Slauenwhite CLA 2006-10-20 14:53:04 EDT
Please target to 4.4 since all non-blocking/critical defects will be deferred as decided in today's AG call.
Comment 12 Cindy Jin CLA 2006-11-10 10:52:24 EST
I got out of memory error when I tried to open a test execution history folder at the Test Navigator view in the Test Perspective. There are around 10 test execution history in that folder.
!ENTRY org.eclipse.ui 4 0 2006-11-10 10:47:09.750
!MESSAGE java.lang.OutOfMemoryError
!STACK 0
java.lang.OutOfMemoryError
	at java.lang.Class.getInterfaces(Native Method)
	at org.eclipse.ui.internal.ObjectContributorManager.computeInterfaceOrder(ObjectContributorManager.java:148)
	at org.eclipse.ui.internal.ObjectContributorManager.getCommonClasses(ObjectContributorManager.java:649)
	at org.eclipse.ui.internal.ObjectContributorManager.getContributors(ObjectContributorManager.java:576)
	at org.eclipse.ui.internal.decorators.LightweightDecoratorManager.getDecoratorsFor(LightweightDecoratorManager.java:290)
	at org.eclipse.ui.internal.decorators.LightweightDecoratorManager.getDecorations(LightweightDecoratorManager.java:315)
	at org.eclipse.ui.internal.decorators.DecorationScheduler$1.ensureResultCached(DecorationScheduler.java:338)
	at org.eclipse.ui.internal.decorators.DecorationScheduler$1.run(DecorationScheduler.java:308)
	at org.eclipse.core.internal.jobs.Worker.run(Worker.java:58)


Comment 13 Julien Canches CLA 2006-11-10 11:08:17 EST
(In reply to comment #12)
> I got out of memory error when I tried to open a test execution history folder
> at the Test Navigator view in the Test Perspective. There are around 10 test
> execution history in that folder.
> !ENTRY org.eclipse.ui 4 0 2006-11-10 10:47:09.750
> !MESSAGE java.lang.OutOfMemoryError

Cindy, the fix to the following defects are likely to address this problem:
160224 TestNavigator: proxies should not use the common resource...
160221 [Performance] TestNavigator: Large execution results display is excessively slow
These fixes, which will be available in 4.4, address a number of scalibility & performance issues with large resources.
Comment 14 amehrega CLA 2006-11-14 16:28:22 EST
I'm getting similar problems with a small project using the candidate i3 build:  TPTP-4.3.0-200611070100.  I am not able to reproduce this problem on my laptop but I am able to consistently reproduce it on my desktop. Here are the steps:

1) Create a Java project 
2) Create a TPTP JUnit under the project
3) Create a TPTP manual test suite under the project
4) Switch to the test perspective
5) Click the "Logical" toolbar item of the test navigator
6) Expand the project

The workbench consistently hangs on my desktop.  Here's the stack trace of the main thread (retrieved using a runtime workbench):

Collections$SynchronizedSet(Collections$SynchronizedCollection).add(Object) line: not available	
FileProxyNodeCache.addResourceListener(IResourceChangeListener) line: 284	
DefaultTypeProvider.<init>() line: 48	
TypeProviderManager$DefaultTypeProviderInfo.<init>(TypeProviderManager, String) line: 111	
TypeProviderManager.getTypeProviderProxyNode(IProject, String) line: 183	
LogicalTestNavigatorProvider.getTypeProviders(IProject) line: 85	
LogicalTestNavigatorProvider.getChildren(Object) line: 68	
TreeViewer(AbstractTreeViewer).getRawChildren(Object) line: 1166	
TreeViewer.getRawChildren(Object) line: 768	
TreeViewer(AbstractTreeViewer).getFilteredChildren(Object) line: 574	
TreeViewer(AbstractTreeViewer).getSortedChildren(Object) line: 543	
.
.
.




It appears that the deadlock is being caused when a resource change listener is being added to FileProxyNodeCache.
Comment 15 amehrega CLA 2006-11-14 18:04:55 EST
The attached patch seems to resolve the problem mentioned under comment #14
Comment 16 Paul Slauenwhite CLA 2006-11-14 22:24:42 EST
Julien, has this patch been well tested?  
Comment 17 Paul Slauenwhite CLA 2006-11-14 22:25:25 EST
Bob and Sheldon: Can you verify that this patch resolves your problems?
Comment 18 Paul Slauenwhite CLA 2006-11-14 22:29:04 EST
Alex, can you provide a TPTP-specific description on how to recreate this defect?
Comment 19 Julien Canches CLA 2006-11-15 04:27:33 EST
(In reply to comment #18)
> Alex, can you provide a TPTP-specific description on how to recreate this
> defect?

Paul, I got a copy of Alex's 200 test suites, and I could reproduce and address the problem. I would not recommend delivering the patch at this stage, as it introduces many threading risks (with this patch, most test navigator tasks get performed in a background job). However, I can come with a subset of this patch that specifically addresses the deadlock.
Comment 20 Paul Slauenwhite CLA 2006-11-15 07:11:43 EST
(In reply to comment #19)

Thanks Julien.  Can make the proposed subset of this patch available for Ali, Bob and Sheldon to try?  If it resolves their problems, we will propose the new patch for 4.3 once it has been thoroughly tested.
Comment 21 Paul Slauenwhite CLA 2006-11-15 07:26:12 EST
This appears to be specific to hyperthread or multi-core machine (e.g. seen on desktops and not laptops) and may be JRE-specific. 

Bob/Ali/Sheldon:  Is your machine hyperthread or multi-core machine?  Also, what JRE are you using?
Comment 22 Julien Canches CLA 2006-11-15 08:51:55 EST
I have created bugzilla 164637 to track the deadlock issue. The patch will be attached there.
Comment 23 amehrega CLA 2006-11-15 10:35:10 EST
(In reply to comment #21)
> This appears to be specific to hyperthread or multi-core machine (e.g. seen on
> desktops and not laptops) and may be JRE-specific. 
> Bob/Ali/Sheldon:  Is your machine hyperthread or multi-core machine?  Also,
> what JRE are you using?

My desktop is a hyperthread machine and I'm using the same JRE 1.4.2 brand on my desktop and laptop.
Comment 24 Sheldon Lee-Loy CLA 2006-11-15 10:45:52 EST
(In reply to comment #21)
> This appears to be specific to hyperthread or multi-core machine (e.g. seen on
> desktops and not laptops) and may be JRE-specific. 
> Bob/Ali/Sheldon:  Is your machine hyperthread or multi-core machine?  Also,
> what JRE are you using?

I recreated this problem on my T40 laptop using IBM JDK 1.4.2 SR3.
Comment 25 Jerome Gout CLA 2007-01-16 08:43:22 EST
*** Bug 147939 has been marked as a duplicate of this bug. ***
Comment 26 Paul Slauenwhite CLA 2007-01-16 10:26:05 EST
Reassigning to the component leads to triage for 4.4.
Comment 27 Jerome Gout CLA 2007-02-28 12:10:31 EST
Patch applied and checked in
Comment 28 Paul Slauenwhite CLA 2007-06-02 14:51:39 EDT
Reporter: Please verify and close in preparation for shutting down the TPTP 4.4 release.  Thanks.
Comment 29 jkubasta CLA 2008-04-15 13:11:05 EDT
Verified, so closing