Bug 3292 - Adding new class takes very long (>20s) (1GEUGFQ)
Summary: Adding new class takes very long (>20s) (1GEUGFQ)
Status: RESOLVED WORKSFORME
Alias: None
Product: JDT
Classification: Eclipse Project
Component: Core (show other bugs)
Version: 2.0   Edit
Hardware: All All
: P3 normal (vote)
Target Milestone: 2.0 F3   Edit
Assignee: Jerome Lanneluc CLA
QA Contact:
URL:
Whiteboard:
Keywords:
Depends on:
Blocks:
 
Reported: 2001-10-10 22:52 EDT by Dani Megert CLA
Modified: 2002-06-05 07:18 EDT (History)
0 users

See Also:


Attachments

Note You need to log in before you can comment on or make changes to this bug.
Description Dani Megert CLA 2001-10-10 22:52:42 EDT
1. Open Object in type hierarchy
	2. Go to packages view
	3. Add a class which inherits from Object and extends:
			junit.framework.Test
			junit.framework.TestListener
			junit.util.TestSuiteLoader

	==> takes about 20 seconds

NOTES:

JW (6/5/01 10:33:38 AM)  This is the degenerate performance case.  If we have time, we should understand
	better where the time is going.  Anticipate no action for 0.9

MA (14.08.2001 12:35:16)
	Had a look at the cpu trace with OptimizeIt.
	Problem is that the wizard contains two operations: create package, create type. Each triggers a JavaElementChange.
	- The type hierarchy is updated twice.
	- The type hierarchy viewer is updated twice.

	Resource changes are all bundled by a IWorkbenchRunnable.
	createPackage and createType however trigger a JavaElementChange anyway.


.. cutted
59.3% - 78439 ms - org.eclipse.jdt.internal.ui.wizards.NewElementWizard.finishPage()
59.3% - 78439 ms - org.eclipse.jdt.internal.ui.wizards.NewElementWizard.invokeRunnable()
   59.3% - 78439 ms - org.eclipse.jface.wizard.WizardDialog.run()
      59.28% - 78419 ms - org.eclipse.jface.operation.ModalContext.run()
         59.28% - 78419 ms - org.eclipse.ui.actions.WorkspaceModifyOperation.run()
            59.28% - 78419 ms - org.eclipse.core.internal.resources.Workspace.run()
               34.97% - 46255 ms - org.eclipse.core.internal.resources.Workspace.endOperation() << collected resource deltas
                  32.42% - 42887 ms - org.eclipse.core.internal.resources.Workspace.broadcastChanges()
                     32.42% - 42887 ms - org.eclipse.core.internal.events.NotificationManager.broadcastChanges()
                        32.4% - 42867 ms - org.eclipse.core.internal.events.NotificationManager.broadcastChanges()
                           32.4% - 42862 ms - org.eclipse.core.internal.events.NotificationManager.notify()
                              32.39% - 42847 ms - org.eclipse.core.runtime.Platform.run()
                                 32.39% - 42847 ms - org.eclipse.core.internal.runtime.InternalPlatform.run()
                                    32.39% - 42847 ms - org.eclipse.core.internal.events.NotificationManager$1.run()
                                       31.53% - 41709 ms - org.eclipse.jdt.internal.core.JavaModelManager.resourceChanged()
                                          31.49% - 41658 ms - org.eclipse.jdt.internal.core.JavaModelManager.fire()
                                             29.27% - 38722 ms - org.eclipse.jdt.internal.core.hierarchy.TypeHierarchy.elementChanged()
                                                29.27% - 38722 ms - org.eclipse.jdt.internal.core.hierarchy.TypeHierarchy.fireChange()
                                                   29.27% - 38722 ms - org.eclipse.jdt.internal.ui.typehierarchy.TypeHierarchyLifeCycle.typeHierarchyChanged()
                                                      29.27% - 38722 ms - org.eclipse.jdt.internal.ui.typehierarchy.TypeHierarchyLifeCycle.fireChange()
                                                         29.27% - 38722 ms - org.eclipse.jdt.internal.ui.typehierarchy.TypeHierarchyViewPart.typeHierarchyChanged()
                                                            29.27% - 38722 ms - org.eclipse.swt.widgets.Display.syncExec()
                                             2.21% - 2936 ms - org.eclipse.jdt.ui.JavaElementContentProvider.elementChanged()
                                          0.02% - 36 ms - org.eclipse.jdt.internal.core.DeltaProcessor.processResourceDelta()
                                          0.0% - 10 ms - org.eclipse.jdt.internal.core.DeltaProcessor.checkProjectPropertyFileUpdate()
                                       0.76% - 1012 ms - org.eclipse.ui.views.tasklist.TaskListContentProvider.resourceChanged()
                                       0.04% - 60 ms - org.eclipse.jdt.internal.debug.core.JavaHotCodeReplaceManager.resourceChanged()
                                       0.01% - 25 ms - org.eclipse.search.internal.ui.SearchManager.resourceChanged()
                                       0.01% - 16 ms - org.eclipse.debug.internal.core.BreakpointManager.resourceChanged()
                                       0.0% - 10 ms - org.eclipse.jdt.internal.ui.packageview.ErrorTickManager.resourceChanged()
                                       0.0% - 5 ms - org.eclipse.vcm.internal.core.SharingManager$3.resourceChanged()
                                       0.0% - 5 ms - org.eclipse.ui.model.WorkbenchContentProvider.resourceChanged()
                                       0.0% - 5 ms - org.eclipse.debug.internal.ui.DebugUIPlugin.resourceChanged()
                              0.0% - 5 ms - java.lang.Object.toString()
                        0.01% - 20 ms - org.eclipse.core.internal.events.NotificationManager.getDelta()
                  2.53% - 3358 ms - org.eclipse.core.internal.events.BuildManager.build()
                  0.0% - 5 ms - org.eclipse.core.internal.utils.Policy.monitorFor()
               24.31% - 32159 ms - org.eclipse.ui.actions.WorkspaceModifyOperation$1.run()
                  24.31% - 32159 ms - org.eclipse.ui.actions.WorkspaceModifyDelegatingOperation.execute()
                     24.31% - 32159 ms - org.eclipse.jdt.internal.ui.wizards.NewClassCreationWizardPage$1.run()
                        24.31% - 32159 ms - org.eclipse.jdt.internal.ui.wizards.TypePage.createType()
                           20.72% - 27413 ms - org.eclipse.jdt.internal.core.PackageFragmentRoot.createPackageFragment()
                           2.65% - 3518 ms - org.eclipse.jdt.internal.core.CompilationUnit.createType()
                           0.58% - 773 ms - org.eclipse.jdt.internal.ui.codemanipulation.ImportsStructure.create()
                           0.12% - 167 ms - java.lang.ClassLoader.loadClass()
                           0.08% - 119 ms - org.eclipse.jdt.internal.core.Buffer.save()
                           0.05% - 79 ms - org.eclipse.jdt.internal.ui.codemanipulation.StubUtility.codeFormat()
                           0.03% - 46 ms - org.eclipse.jdt.internal.ui.wizards.NewClassCreationWizardPage.evalMethods()
                           0.02% - 34 ms - org.eclipse.jdt.internal.ui.codemanipulation.ImportsStructure.<init>()
                           0.0% - 5 ms - org.eclipse.jdt.internal.ui.wizards.TypePage.createTypeBody()
                           0.0% - 5 ms - org.eclipse.jdt.internal.ui.preferences.ImportOrganizePreferencePage.getImportOrderPreference()
               0.0% - 5 ms - org.eclipse.jface.wizard.ProgressMonitorPart.done()
      0.01% - 20 ms - org.eclipse.jface.wizard.WizardDialog.stopped()

	Move to jcore
Comment 1 DJ Houghton CLA 2001-10-29 17:07:22 EST
PRODUCT VERSION:
	0.118


Comment 2 Philipe Mulet CLA 2002-02-12 16:55:45 EST
Is this still occurring in our latest ? Might need to use a profiling tool
Comment 3 Dani Megert CLA 2002-02-13 04:44:23 EST
Retested on build 20020212
First time: 23s
Next time (another class with same layout): 13s
Comment 4 Olivier Thomann CLA 2002-02-14 10:35:00 EST
Is this good enough?
Comment 5 Dani Megert CLA 2002-02-15 02:49:31 EST
23/13 seconds to add a simple class is too long in my opinion
Comment 6 Jerome Lanneluc CLA 2002-04-29 05:24:22 EDT
According to OptimizeIt, only 20% of the time is now spent recomputing the 
hierarchy. The rest is spent opening the types in the hierarchy to answer 
questions like isInterface(), or exists(), etc.

We need to revisit the relationship between UI and Core on this. The best would 
be that the UI defines a set of functionality it needs to ask to the types so 
that Core can optimize these cases.

Propose to defer post 2.0.
Comment 7 Philipe Mulet CLA 2002-05-07 09:14:23 EDT
Deferring
Comment 8 Philipe Mulet CLA 2002-05-31 17:04:16 EDT
Test TP#2
Comment 9 Jerome Lanneluc CLA 2002-06-03 10:51:29 EDT
With the test case described above, it now takes 5s. 56% of the time is spent 
computing the hierarchy. The rest is in the UI.
Comment 10 Philipe Mulet CLA 2002-06-05 07:17:36 EDT
Closing
Comment 11 Philipe Mulet CLA 2002-06-05 07:18:08 EDT
Closed