Bug 337007 - Opening a simple java file after a reboot regressing from 3.4 -> 3.6.1
Summary: Opening a simple java file after a reboot regressing from 3.4 -> 3.6.1
Status: RESOLVED WORKSFORME
Alias: None
Product: JDT
Classification: Eclipse Project
Component: Text (show other bugs)
Version: 3.6.1   Edit
Hardware: PC Windows XP
: P2 normal (vote)
Target Milestone: 3.7 M7   Edit
Assignee: Deepak Azad CLA
QA Contact:
URL:
Whiteboard:
Keywords: performance
Depends on:
Blocks:
 
Reported: 2011-02-11 15:38 EST by Matthew Martire CLA
Modified: 2011-04-19 06:01 EDT (History)
4 users (show)

See Also:


Attachments
Project Test containing HelloWorldApp.java file (1.47 KB, application/x-zip-compressed)
2011-02-14 15:24 EST, Matthew Martire CLA
no flags Details
Info of plugins loaded by Runtime Spy (865 bytes, text/csv)
2011-02-15 16:55 EST, Matthew Martire CLA
no flags Details
Info of plugins loaded by Runtime Spy (889 bytes, text/csv)
2011-02-15 16:56 EST, Matthew Martire CLA
no flags Details
Plugins activated on opening a Java Editor - 3.6.2 vs 3.4 (1.02 KB, application/vnd.ms-excel)
2011-04-15 08:10 EDT, Deepak Azad CLA
no flags Details

Note You need to log in before you can comment on or make changes to this bug.
Description Matthew Martire CLA 2011-02-11 15:38:58 EST
Build Identifier: 3.6.1 M20100909-0800

Our adopter product's release cycle went from the 3.4 stream straight to the 3.6.1 stream. The regression from 3.4 to 3.6.1 is about ~1.5s but it has steadily been regressing for the past several releases in between. 
The following numbers show from the time of double click on the java file to when the editor opens (in seconds). Different runs of this test on the same eclipse are separated by commas:

3.4
----
3.3, 3.3, 3.1

3.4.2
------
3.6, 3.9, 3.6

3.5
----
4.1, 4.4, 4.2

3.5.2
------
4.6, 4.4, 4.4

3.6.1
------
4.7, 4.9, 4.7

I can provide cpu profiles of this using yourkit. I can also provide plugin activations using Runtime Spy. 


Reproducible: Always

Steps to Reproduce:
1.On an empty workspace, create a new Java Project
2.Create a Hello World class
3.close the java editor
4.close eclipse
5.reboot the machine
6.open eclipse
7.double click the java file
Comment 1 Dani Megert CLA 2011-02-14 03:05:37 EST
I assume your measurement does not include the startup time, but does your measurement wait until the workbench is up and ready?

Can you please:
- attach your test file(s)
- try with pure Eclipse SDK build:
http://download.eclipse.org/eclipse/downloads/drops/R-3.6.1-201009090800/index.php
- try whether the Text Editor shows the same regression?

Thanks!
Comment 2 Matthew Martire CLA 2011-02-14 15:24:42 EST
Created attachment 188951 [details]
Project Test containing HelloWorldApp.java file
Comment 3 Matthew Martire CLA 2011-02-14 15:26:39 EST
All measurements were taken after the workbench had started and settled. I've attached the project that contains the java file that I used to open. 

Timings for the build that you pointed me to (in seconds):
4.0, 4.1, 4.1

Text editor timings (in seconds):

3.4 
----
2.5, 2.4, 2.4


3.6.1 
----
2.7, 2.7, 2.7
Comment 4 Dani Megert CLA 2011-02-15 02:29:43 EST
From comment 1:
>Can you please:
>- try with pure Eclipse SDK build:

Thanks.
Comment 5 Dani Megert CLA 2011-02-15 02:31:37 EST
Can you please redo your tests with a pure Eclipse SDK and attach the profiles for that? Thanks.
Comment 6 Matthew Martire CLA 2011-02-15 10:01:24 EST
which versions of eclipse do you want profiles for? What do you mean by pure Eclipse SDK? The file that I used to do the testing in comment 3 was eclipse-SDK-3.6.1-win32.zip from that link you posted in comment 1.
Comment 7 Dani Megert CLA 2011-02-15 10:21:43 EST
(In reply to comment #6)
> which versions of eclipse do you want profiles for? What do you mean by pure
> Eclipse SDK? The file that I used to do the testing in comment 3 was
> eclipse-SDK-3.6.1-win32.zip from that link you posted in comment 1.
That's what I meant/wanted (didn't see that in your previous post).
Comment 8 Matthew Martire CLA 2011-02-15 16:55:11 EST
Created attachment 189048 [details]
Info of plugins loaded by Runtime Spy

I only see the regression after you reboot the machine. The warm version of this test is on par or even improved slightly from 3.4->3.6.1. 
This may mean that it is plugin loading/activation is causing the regression.  I can supply yourkit profiles if you think they are of value. 

I used Runtime Spy to gather plugin loading information and am uploading a .csv file you can open as a spreadsheet.
Comment 9 Matthew Martire CLA 2011-02-15 16:56:30 EST
Created attachment 189049 [details]
Info of plugins loaded by Runtime Spy
Comment 10 Dani Megert CLA 2011-02-17 05:29:35 EST
This is probably a result of having more bundles and lazy loading working better (i.e. less loading than in previous releases but as a consequence we need to load more on first call).

Deepak, please take a look.
Comment 11 Deepak Azad CLA 2011-04-15 08:10:09 EDT
Created attachment 193358 [details]
Plugins activated on opening a Java Editor - 3.6.2 vs 3.4

Indeed org.eclipse.compare.core is an extra plug-in that is activated by 3.6.2. Note that in 3.4 even after the editor is opened o.e.compare.core is not activated. 

I wonder if o.e.compare.core is really needed while opening a Java Editor...
Comment 12 Deepak Azad CLA 2011-04-15 08:35:41 EDT
Looks like AbstractTextEditor activates o.e.compare.core

Activating bundle: org.eclipse.compare.core
Bundle activation stack:
	org.eclipse.compare.core
Class loading stack:
	org.eclipse.compare.rangedifferencer.AbstractRangeDifferenceFactory
Stack trace:
java.lang.Throwable
	at org.eclipse.core.runtime.internal.stats.StatsManager.traceActivate(StatsManager.java:167)
	at org.eclipse.core.runtime.internal.stats.StatsManager.startActivation(StatsManager.java:141)
	at org.eclipse.core.runtime.internal.stats.StatsManager.watchBundle(StatsManager.java:111)
	at org.eclipse.osgi.baseadaptor.BaseAdaptor$3.watchBundle(BaseAdaptor.java:356)
	at org.eclipse.osgi.framework.internal.core.BundleHost.startWorker(BundleHost.java:363)
	at org.eclipse.osgi.framework.internal.core.AbstractBundle.start(AbstractBundle.java:284)
	at org.eclipse.osgi.framework.util.SecureAction.start(SecureAction.java:417)
	at org.eclipse.osgi.internal.loader.BundleLoader.setLazyTrigger(BundleLoader.java:265)
	at org.eclipse.core.runtime.internal.adaptor.EclipseLazyStarter.postFindLocalClass(EclipseLazyStarter.java:106)
	at org.eclipse.osgi.baseadaptor.loader.ClasspathManager.findLocalClass(ClasspathManager.java:453)
	at org.eclipse.osgi.internal.baseadaptor.DefaultClassLoader.findLocalClass(DefaultClassLoader.java:216)
	at org.eclipse.osgi.internal.loader.BundleLoader.findLocalClass(BundleLoader.java:393)
	at org.eclipse.osgi.internal.loader.SingleSourcePackage.loadClass(SingleSourcePackage.java:33)
	at org.eclipse.osgi.internal.loader.BundleLoader.findClassInternal(BundleLoader.java:466)
	at org.eclipse.osgi.internal.loader.BundleLoader.findClass(BundleLoader.java:422)
	at org.eclipse.osgi.internal.loader.BundleLoader.findClass(BundleLoader.java:410)
	at org.eclipse.osgi.internal.baseadaptor.DefaultClassLoader.loadClass(DefaultClassLoader.java:107)
	at java.lang.ClassLoader.loadClass(ClassLoader.java:609)
	at java.lang.J9VMInternals.verifyImpl(Native Method)
	at java.lang.J9VMInternals.verify(J9VMInternals.java:72)
	at java.lang.J9VMInternals.initialize(J9VMInternals.java:134)
	at org.eclipse.ui.texteditor.quickdiff.QuickDiff.createQuickDiffAnnotationModel(QuickDiff.java:136)
	at org.eclipse.ui.internal.texteditor.LineNumberColumn.getAnnotationModelWithDiffer(LineNumberColumn.java:656)
	at org.eclipse.ui.internal.texteditor.LineNumberColumn.installChangeRulerModel(LineNumberColumn.java:604)
	at org.eclipse.ui.internal.texteditor.LineNumberColumn.updateQuickDiffVisibility(LineNumberColumn.java:443)
	at org.eclipse.ui.internal.texteditor.LineNumberColumn.initialize(LineNumberColumn.java:248)
	at org.eclipse.ui.internal.texteditor.LineNumberColumn.createControl(LineNumberColumn.java:124)
	at org.eclipse.jface.text.source.CompositeRuler.addDecorator(CompositeRuler.java:563)
	at org.eclipse.ui.texteditor.AbstractTextEditor$11.run(AbstractTextEditor.java:1710)
	at org.eclipse.core.runtime.SafeRunner.run(SafeRunner.java:42)
	at org.eclipse.ui.texteditor.AbstractTextEditor$ColumnSupport.addColumn(AbstractTextEditor.java:1713)
	at org.eclipse.ui.texteditor.AbstractTextEditor$ColumnSupport.setColumnVisible(AbstractTextEditor.java:1697)
	at org.eclipse.ui.texteditor.AbstractDecoratedTextEditor.showChangeInformation(AbstractDecoratedTextEditor.java:564)
	at org.eclipse.ui.texteditor.AbstractDecoratedTextEditor.createPartControl(AbstractDecoratedTextEditor.java:445)
	at org.eclipse.jdt.internal.ui.javaeditor.JavaEditor.createPartControl(JavaEditor.java:3104)
	at org.eclipse.jdt.internal.ui.javaeditor.CompilationUnitEditor.createPartControl(CompilationUnitEditor.java:1475)
	at org.eclipse.ui.internal.EditorReference.createPartHelper(EditorReference.java:670)
	at org.eclipse.ui.internal.EditorReference.createPart(EditorReference.java:465)
	at org.eclipse.ui.internal.WorkbenchPartReference.getPart(WorkbenchPartReference.java:595)
	at org.eclipse.ui.internal.EditorAreaHelper.setVisibleEditor(EditorAreaHelper.java:271)
	at org.eclipse.ui.internal.EditorManager.setVisibleEditor(EditorManager.java:1429)
	at org.eclipse.ui.internal.EditorManager$5.runWithException(EditorManager.java:942)
	at org.eclipse.ui.internal.StartupThreading$StartupRunnable.run(StartupThreading.java:31)
	at org.eclipse.swt.widgets.RunnableLock.run(RunnableLock.java:35)
	at org.eclipse.swt.widgets.Synchronizer.runAsyncMessages(Synchronizer.java:134)
	at org.eclipse.swt.widgets.Display.runAsyncMessages(Display.java:4041)
	at org.eclipse.swt.widgets.Display.readAndDispatch(Display.java:3660)
	at org.eclipse.ui.application.WorkbenchAdvisor.openWindows(WorkbenchAdvisor.java:803)
	at org.eclipse.ui.internal.Workbench$31.runWithException(Workbench.java:1567)
	at org.eclipse.ui.internal.StartupThreading$StartupRunnable.run(StartupThreading.java:31)
	at org.eclipse.swt.widgets.RunnableLock.run(RunnableLock.java:35)
	at org.eclipse.swt.widgets.Synchronizer.runAsyncMessages(Synchronizer.java:134)
	at org.eclipse.swt.widgets.Display.runAsyncMessages(Display.java:4041)
	at org.eclipse.swt.widgets.Display.readAndDispatch(Display.java:3660)
	at org.eclipse.ui.internal.Workbench.runUI(Workbench.java:2548)
	at org.eclipse.ui.internal.Workbench.access$4(Workbench.java:2438)
	at org.eclipse.ui.internal.Workbench$7.run(Workbench.java:671)
	at org.eclipse.core.databinding.observable.Realm.runWithDefault(Realm.java:332)
	at org.eclipse.ui.internal.Workbench.createAndRunWorkbench(Workbench.java:664)
	at org.eclipse.ui.PlatformUI.createAndRunWorkbench(PlatformUI.java:149)
	at org.eclipse.ui.internal.ide.application.IDEApplication.start(IDEApplication.java:115)
	at org.eclipse.equinox.internal.app.EclipseAppHandle.run(EclipseAppHandle.java:196)
	at org.eclipse.core.runtime.internal.adaptor.EclipseAppLauncher.runApplication(EclipseAppLauncher.java:110)
	at org.eclipse.core.runtime.internal.adaptor.EclipseAppLauncher.start(EclipseAppLauncher.java:79)
	at org.eclipse.core.runtime.adaptor.EclipseStarter.run(EclipseStarter.java:369)
	at org.eclipse.core.runtime.adaptor.EclipseStarter.run(EclipseStarter.java:179)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:48)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:37)
	at java.lang.reflect.Method.invoke(Method.java:600)
	at org.eclipse.equinox.launcher.Main.invokeFramework(Main.java:620)
	at org.eclipse.equinox.launcher.Main.basicRun(Main.java:575)
	at org.eclipse.equinox.launcher.Main.run(Main.java:1408)
	at org.eclipse.equinox.launcher.Main.main(Main.java:1384)
Comment 13 Dani Megert CLA 2011-04-15 08:39:31 EDT
>Indeed org.eclipse.compare.core is an extra plug-in that is activated by 3.6.2.
This is expected: we use the diff algorithm that was previously implemented in text.
Comment 14 Deepak Azad CLA 2011-04-19 06:01:19 EDT
The performance regression is because an extra plugin is activated when the Java editor is opened. Plus this only affects the first time an editor is opened. 

There is nothing we can do here.