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

Bug 341016

Summary: CompilationUnit.codeSelect(...) very slow (was: JavaElementHyperlinkDetector triggers AST creation on UI thread)
Product: [Eclipse Project] JDT Reporter: Sergey Prigogin <eclipse.sprigogin>
Component: CoreAssignee: Satyam Kandula <satyam.kandula>
Status: VERIFIED FIXED QA Contact:
Severity: major    
Priority: P3 CC: abhisheks, daniel_megert, jarthana, remy.suen, satyam.kandula, tparker
Version: 3.6.2Keywords: performance
Target Milestone: 3.8 M6   
Hardware: PC   
OS: Linux   
Whiteboard:
Bug Depends on: 365499    
Bug Blocks:    
Attachments:
Description Flags
Project to demonstrates the problem none

Description Sergey Prigogin CLA 2011-03-25 18:28:09 EDT
Pressing of Ctrl key, which is frequently done as part of Copy/Paste operation may freeze UI for over 30 seconds. Here is a call stack during the freeze.

"main" prio=10 tid=0x08962800 nid=0x4716 runnable [0xffdd1000]
   java.lang.Thread.State: RUNNABLE
	at (C/C++) __kernel_vsyscall( ())
	at (C/C++) Monitor::ILock(Thread*)( (/usr/local/buildtools/java/jdk6-google-v3/bin/../jre/lib/i386/client/libjvm.so))
	at (C/C++) Monitor::lock_without_safepoint_check(Thread*)( (/usr/local/buildtools/java/jdk6-google-v3/bin/../jre/lib/i386/client/libjvm.so))
	at (C/C++) Monitor::lock_without_safepoint_check()( (/usr/local/buildtools/java/jdk6-google-v3/bin/../jre/lib/i386/client/libjvm.so))
	at (C/C++) SafepointSynchronize::block(JavaThread*)( (/usr/local/buildtools/java/jdk6-google-v3/bin/../jre/lib/i386/client/libjvm.so))
	at (C/C++) JavaThread::check_safepoint_and_suspend_for_native_trans(JavaThread*)( (/usr/local/buildtools/java/jdk6-google-v3/bin/../jre/lib/i386/client/libjvm.so))
	at (C/C++) JavaThread::check_special_condition_for_native_trans(JavaThread*)( (/usr/local/buildtools/java/jdk6-google-v3/bin/../jre/lib/i386/client/libjvm.so))
	at java.util.zip.ZipFile.open(Native Method)
	at java.util.zip.ZipFile.<init>(ZipFile.java:131)
	at java.util.zip.ZipFile.<init>(ZipFile.java:148)
	at org.eclipse.jdt.internal.core.JavaModelManager.getZipFile(JavaModelManager.java:2518)
	at org.eclipse.jdt.internal.core.JarPackageFragmentRoot.getJar(JarPackageFragmentRoot.java:152)
	at org.eclipse.jdt.internal.core.ClassFile.getJarBinaryTypeInfo(ClassFile.java:343)
	at org.eclipse.jdt.internal.core.ClassFile.existsUsingJarTypeCache(ClassFile.java:207)
	at org.eclipse.jdt.internal.core.NameLookup.seekTypesInBinaryPackage(NameLookup.java:1015)
	at org.eclipse.jdt.internal.core.NameLookup.seekTypes(NameLookup.java:990)
	at org.eclipse.jdt.internal.core.NameLookup.findType(NameLookup.java:776)
	at org.eclipse.jdt.internal.core.NameLookup.findType(NameLookup.java:660)
	at org.eclipse.jdt.internal.core.NameLookup.findType(NameLookup.java:619)
	at org.eclipse.jdt.internal.core.SearchableEnvironment.find(SearchableEnvironment.java:101)
	at org.eclipse.jdt.internal.core.SearchableEnvironment.findType(SearchableEnvironment.java:287)
	at org.eclipse.jdt.internal.compiler.lookup.LookupEnvironment.askForType(LookupEnvironment.java:128)
	at org.eclipse.jdt.internal.compiler.lookup.PackageBinding.getTypeOrPackage(PackageBinding.java:183)
	at org.eclipse.jdt.internal.compiler.lookup.Scope.getTypeOrPackage(Scope.java:2613)
	at org.eclipse.jdt.internal.compiler.lookup.Scope.getType(Scope.java:2330)
	at org.eclipse.jdt.internal.compiler.ast.SingleTypeReference.getTypeBinding(SingleTypeReference.java:44)
	at org.eclipse.jdt.internal.compiler.ast.TypeReference.internalResolveType(TypeReference.java:131)
	at org.eclipse.jdt.internal.compiler.ast.TypeReference.resolveType(TypeReference.java:203)
	at org.eclipse.jdt.internal.compiler.ast.TypeReference.resolveTypeArgument(TypeReference.java:211)
	at org.eclipse.jdt.internal.compiler.ast.ParameterizedSingleTypeReference.internalResolveType(ParameterizedSingleTypeReference.java:180)
	at org.eclipse.jdt.internal.compiler.ast.ParameterizedSingleTypeReference.resolveType(ParameterizedSingleTypeReference.java:278)
	at org.eclipse.jdt.internal.compiler.lookup.SourceTypeBinding.resolveTypeFor(SourceTypeBinding.java:1264)
	at org.eclipse.jdt.internal.compiler.lookup.SourceTypeBinding.fields(SourceTypeBinding.java:660)
	at org.eclipse.jdt.internal.compiler.lookup.SourceTypeBinding.faultInTypesForFieldsAndMethods(SourceTypeBinding.java:638)
	at org.eclipse.jdt.internal.compiler.lookup.CompilationUnitScope.faultInTypes(CompilationUnitScope.java:468)
	at org.eclipse.jdt.internal.codeassist.SelectionEngine.select(SelectionEngine.java:918)
	at org.eclipse.jdt.internal.core.Openable.codeSelect(Openable.java:162)
	at org.eclipse.jdt.internal.core.CompilationUnit.codeSelect(CompilationUnit.java:377)
	at org.eclipse.jdt.internal.core.CompilationUnit.codeSelect(CompilationUnit.java:371)
	at org.eclipse.jdt.internal.ui.javaeditor.JavaElementHyperlinkDetector.detectHyperlinks(JavaElementHyperlinkDetector.java:67)
	at org.eclipse.ui.texteditor.HyperlinkDetectorRegistry$HyperlinkDetectorDelegate.detectHyperlinks(HyperlinkDetectorRegistry.java:80)
	at org.eclipse.jface.text.hyperlink.HyperlinkManager.findHyperlinks(HyperlinkManager.java:276)
	- locked <0xbdf3c3c8> (a [Lorg.eclipse.jface.text.hyperlink.IHyperlinkDetector;)
	at org.eclipse.jface.text.hyperlink.HyperlinkManager.mouseMove(HyperlinkManager.java:452)
	at org.eclipse.swt.widgets.TypedListener.handleEvent(TypedListener.java:205)
	at org.eclipse.swt.widgets.EventTable.sendEvent(EventTable.java:84)
	at org.eclipse.swt.widgets.Widget.sendEvent(Widget.java:1258)
	at org.eclipse.swt.widgets.Display.runDeferredEvents(Display.java:3540)
	at org.eclipse.swt.widgets.Display.readAndDispatch(Display.java:3161)
	at org.eclipse.ui.internal.Workbench.runEventLoop(Workbench.java:2644)
	at org.eclipse.ui.internal.Workbench.runUI(Workbench.java:2606)
	at org.eclipse.ui.internal.Workbench.access$4(Workbench.java:2440)
	at org.eclipse.ui.internal.Workbench$7.run(Workbench.java:683)
	at org.eclipse.core.databinding.observable.Realm.runWithDefault(Realm.java:332)
	at org.eclipse.ui.internal.Workbench.createAndRunWorkbench(Workbench.java:676)
	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 (C/C++) [Unknown frame (generated stub/JIT)]([Unknown source])
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:616)
	at org.eclipse.equinox.launcher.Main.invokeFramework(Main.java:619)
	at org.eclipse.equinox.launcher.Main.basicRun(Main.java:574)
	at org.eclipse.equinox.launcher.Main.run(Main.java:1407)
Comment 1 Sergey Prigogin CLA 2011-03-25 18:32:04 EDT
A similar bug 324232 was fixed in CDT. See org.eclipse.cdt.ui/src/org/eclipse/cdt/internal/ui/editor/CElementHyperlinkDetector.java for the solution.
Comment 2 Dani Megert CLA 2011-03-26 03:46:37 EDT
Sergey, what you see is not the normal/full AST. It's a lightweight version used by code assist/select.

Can you please provide the version you're using and more detailed steps to reproduce the 30s delay? Also, provide some more stack traces. Maybe you run into bug 160192?
Comment 3 Sergey Prigogin CLA 2011-03-28 16:11:48 EDT
(In reply to comment #2)
> Sergey, what you see is not the normal/full AST. It's a lightweight version
> used by code assist/select.

It's a limited consolation since the operation still takes long time under some conditions.

> Can you please provide the version you're using and more detailed steps to
> reproduce the 30s delay?

Version: 3.6.1
Build id: M20100909-0800

The 30-second delay is determined by the number of jar files in the class path and the performance of the file system where the jar files are located. In this case there are hundreds of jar files on a slow file system.

> Also, provide some more stack traces.

There stack trace in the bug description is typical. I've included another one below.

> Maybe you run into bug 160192?

This bug is significantly worse than bug 160192 since the latter is triggered by an explicit copy/paste operation, but this one causes a UI freeze on mere pressing the Ctrl key.

Here is another call stack for the same problem:

"main" prio=10 tid=0x080c1800 nid=0x7dcd runnable [0xffdcf000..0xffdd07a4]
   java.lang.Thread.State: RUNNABLE
        at java.io.FileInputStream.readBytes(Native Method)
        at java.io.FileInputStream.read(FileInputStream.java:236)
        at org.eclipse.jdt.internal.core.index.DiskIndex.readCategoryTable(DiskIndex.java:614)
        - locked <0x7c618e68> (a org.eclipse.jdt.internal.core.index.DiskIndex)
        at org.eclipse.jdt.internal.core.index.DiskIndex.addQueryResults(DiskIndex.java:202)
        at org.eclipse.jdt.internal.core.index.Index.query(Index.java:137)
        at org.eclipse.jdt.internal.core.search.matching.TypeDeclarationPattern.queryIn(TypeDeclarationPattern.java:310)
        at org.eclipse.jdt.core.search.SearchPattern.findIndexMatches(SearchPattern.java:2109)
        at org.eclipse.jdt.internal.core.search.matching.MatchLocator.findIndexMatches(MatchLocator.java:264)
        at org.eclipse.jdt.internal.core.search.PatternSearchJob.search(PatternSearchJob.java:97)
        at org.eclipse.jdt.internal.core.search.PatternSearchJob.execute(PatternSearchJob.java:63)
        at org.eclipse.jdt.internal.core.search.processing.JobManager.performConcurrentJob(JobManager.java:276)
        at org.eclipse.jdt.internal.core.search.BasicSearchEngine.searchAllTypeNames(BasicSearchEngine.java:1122)
        at org.eclipse.jdt.internal.core.SearchableEnvironment.findTypes(SearchableEnvironment.java:456)
        at org.eclipse.jdt.internal.core.SearchableEnvironment.findTypes(SearchableEnvironment.java:308)
        at org.eclipse.jdt.internal.codeassist.SelectionEngine.select(SelectionEngine.java:938)
        at org.eclipse.jdt.internal.core.Openable.codeSelect(Openable.java:162)
        at org.eclipse.jdt.internal.core.CompilationUnit.codeSelect(CompilationUnit.java:375)
        at org.eclipse.jdt.internal.core.CompilationUnit.codeSelect(CompilationUnit.java:369)
        at org.eclipse.jdt.internal.ui.javaeditor.JavaElementHyperlinkDetector.detectHyperlinks(JavaElementHyperlinkDetector.java:67)
        at org.eclipse.ui.texteditor.HyperlinkDetectorRegistry$HyperlinkDetectorDelegate.detectHyperlinks(HyperlinkDetectorRegistry.java:80)
        at org.eclipse.jface.text.hyperlink.HyperlinkManager.findHyperlinks(HyperlinkManager.java:263)
        - locked <0x7acaba58> (a [Lorg.eclipse.jface.text.hyperlink.IHyperlinkDetector;)
        at org.eclipse.jface.text.hyperlink.HyperlinkManager.mouseMove(HyperlinkManager.java:439)
        at org.eclipse.swt.widgets.TypedListener.handleEvent(TypedListener.java:199)
        at org.eclipse.swt.widgets.EventTable.sendEvent(EventTable.java:84)
        at org.eclipse.swt.widgets.Widget.sendEvent(Widget.java:1176)
        at org.eclipse.swt.widgets.Display.runDeferredEvents(Display.java:3493)
        at org.eclipse.swt.widgets.Display.readAndDispatch(Display.java:3112)
        at org.eclipse.ui.internal.Workbench.runEventLoop(Workbench.java:2405)
        at org.eclipse.ui.internal.Workbench.runUI(Workbench.java:2369)
        at org.eclipse.ui.internal.Workbench.access$4(Workbench.java:2221)
        at org.eclipse.ui.internal.Workbench$5.run(Workbench.java:500)
        at org.eclipse.core.databinding.observable.Realm.runWithDefault(Realm.java:332)
        at org.eclipse.ui.internal.Workbench.createAndRunWorkbench(Workbench.java:493)
        at org.eclipse.ui.PlatformUI.createAndRunWorkbench(PlatformUI.java:149)
        at org.eclipse.ui.internal.ide.application.IDEApplication.start(IDEApplication.java:113)
        at org.eclipse.equinox.internal.app.EclipseAppHandle.run(EclipseAppHandle.java:194)
        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:368)
        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:57)
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
        at java.lang.reflect.Method.invoke(Method.java:616)
        at org.eclipse.equinox.launcher.Main.invokeFramework(Main.java:559)
        at org.eclipse.equinox.launcher.Main.basicRun(Main.java:514)
        at org.eclipse.equinox.launcher.Main.run(Main.java:1311)
Comment 4 Sergey Prigogin CLA 2011-03-29 03:08:00 EDT
Dani, does the change in the title of this bug mean that you consider AST creation on UI thread to be acceptable?
Comment 5 Dani Megert CLA 2011-03-29 03:12:26 EDT
(In reply to comment #4)
> Dani, does the change in the title of this bug mean that you consider AST
> creation on UI thread to be acceptable?

Please read comment 2 again. It's really a very lightweight thing which can't be compared to the real AST. And yes, this is acceptable and won't be changed. What's not acceptable is the delay in the UI thread and this needs to be investigated (==> need a reproducible test case ;-) and then fixed.
Comment 6 Dani Megert CLA 2011-03-29 03:13:41 EDT
(In reply to comment #5)
> (In reply to comment #4)
> > Dani, does the change in the title of this bug mean that you consider AST
> > creation on UI thread to be acceptable?
> 
Just to clarify my previous comment: "no", the normal AST which is available via JDT Core API should not be created in the UI thread if possible.
Comment 7 Sergey Prigogin CLA 2011-03-29 03:20:22 EDT
(In reply to comment #5)
> Please read comment 2 again. It's really a very lightweight thing which can't
> be compared to the real AST. And yes, this is acceptable and won't be changed.
> What's not acceptable is the delay in the UI thread and this needs to be
> investigated (==> need a reproducible test case ;-) and then fixed.

Do you imply that building of lightweight AST should never trigger reading of jar files?
Comment 8 Dani Megert CLA 2011-03-29 03:27:31 EDT
(In reply to comment #7)
> (In reply to comment #5)
> > Please read comment 2 again. It's really a very lightweight thing which can't
> > be compared to the real AST. And yes, this is acceptable and won't be changed.
> > What's not acceptable is the delay in the UI thread and this needs to be
> > investigated (==> need a reproducible test case ;-) and then fixed.
> 
> Do you imply that building of lightweight AST should never trigger reading of
> jar files?

I don't imply anything ;-). codeSelect(...) needs to be fast and so far we didn't have an issue with its performance and we would have noticed it, because codeSelect is used very frequently.
Comment 9 Dani Megert CLA 2011-03-29 03:32:57 EDT
I suspect you see bug 281848.
Comment 10 Sergey Prigogin CLA 2011-03-29 03:47:15 EDT
(In reply to comment #8)
> I don't imply anything ;-). codeSelect(...) needs to be fast and so far we
> didn't have an issue with its performance and we would have noticed it, because
> codeSelect is used very frequently.

How is it possible to guarantee performance of codeSelect(...) if it's allowed to read jar files from disk? With many large jar files to read it's guaranteed to be slow, isn't it? 

(In reply to comment #9)
> I suspect you see bug 281848.

Bug 281848 is about PDE projects. The problem reported in this bug is for plain Java projects.
Comment 11 Dani Megert CLA 2011-03-29 04:00:22 EDT
> How is it possible to guarantee performance of codeSelect(...) if it's allowed
> to read jar files from disk? With many large jar files to read it's guaranteed
> to be slow, isn't it? 
There's never a guarantee. Assume you have your file on a floppy and open it: it will take some time even though we want opening a file to be fast.

> (In reply to comment #9)
> > I suspect you see bug 281848.
> Bug 281848 is about PDE projects. The problem reported in this bug is for 
> plain Java projects.
OK, good to know. However, as said before we need a concrete test case.
Comment 12 Sergey Prigogin CLA 2011-03-29 04:17:27 EDT
(In reply to comment #11)
> > How is it possible to guarantee performance of codeSelect(...) if it's allowed
> > to read jar files from disk? With many large jar files to read it's guaranteed
> > to be slow, isn't it? 
> There's never a guarantee. Assume you have your file on a floppy and open it:
> it will take some time even though we want opening a file to be fast.

That's why any operation that reads from files, especially from many files, should be considered potentially slow and should never be attempted on the UI thread.

> > (In reply to comment #9)
> > > I suspect you see bug 281848.
> > Bug 281848 is about PDE projects. The problem reported in this bug is for 
> > plain Java projects.
> OK, good to know. However, as said before we need a concrete test case.

I contend that the call stack provided in the bug is sufficient. A mere existence of a code path from JavaElementHyperlinkDetector.detectHyperlinks to ZipFile.open is problematic. The only way to guarantee performance of JavaElementHyperlinkDetector.detectHyperlinks is to make sure that it never attempts to read jar files.
Comment 13 Dani Megert CLA 2011-03-29 04:20:46 EDT
> I contend that the call stack provided in the bug is sufficient. A mere
> existence of a code path from JavaElementHyperlinkDetector.detectHyperlinks to
> ZipFile.open is problematic. The only way to guarantee performance of
> JavaElementHyperlinkDetector.detectHyperlinks is to make sure that it never
> attempts to read jar files.
And I only say that if we have a test case the chances will be higher that this bug gets addressed.
Comment 14 Satyam Kandula CLA 2011-03-29 05:56:27 EDT
Sergey, 
I will have a look at this. I could try simulating lot of jars, but is it possible for you to provide the test case.
Comment 15 Sergey Prigogin CLA 2011-03-29 16:14:43 EDT
(In reply to comment #14)
> Sergey, 
> I will have a look at this. I could try simulating lot of jars, but is it
> possible for you to provide the test case.

It is not possible to provide a realistic test case due to confidentiality issues. There is no need to simulate a lot of jars. If JavaElementHyperlinkDetector.detectHyperlinks method reads a single jar, nothing would prevent it from reading many jars in a larger project. The bottom line is that jars should never be read on the UI thread.
Comment 16 Satyam Kandula CLA 2011-04-06 05:12:14 EDT
Created attachment 192621 [details]
Project to demonstrates the problem

I could reproduce the behavior with the attached project. Go to the bottom  of the TestManyTypeReferences and then try to do a CTRL-Select of some lines and one could see the IDE hanging. 

JDT Model caches required information and a read of a jar file is not generally required. As the reconciler would have compiled the source code shown in the editor, much of the types used in the editor file would have been cached. The problem comes if the file itself has more number of types than the cache size. Note that there are around 2000 type references in the testcase here. 

I will spend some time to see if there can be some improvements the can be done in JDT/Core.
Comment 17 Sergey Prigogin CLA 2011-04-06 13:17:51 EDT
(In reply to comment #16)
I doubt that knowing types is necessary for hyperlink detection. The only function of hyperlink detection is to underline the hyperlink, which can be done without an AST even in C++, which has more complex grammar than Java (see org.eclipse.cdt.ui/src/org/eclipse/cdt/internal/ui/editor/CElementHyperlinkDetector.java). Hyperlink navigation does require complete type knowledge, but it is completely separate from the hyperlink detection.
Comment 18 Satyam Kandula CLA 2011-04-07 09:14:36 EDT
(In reply to comment #17)
I see in CElementHyperlinkDetector that if AST creation takes time, the file is scanned rather than parsed. Is it being correct in all the cases? That doesn't seem to be working in Java. I could see at least one case. Consider a line 'pkg.X var;', the hyper link detector doesn't show anything for pkg if pkg is a package, but if pkg is a class it will show an underline. Hence the selection need to be resolved. 

I am not sure what else CElementHyperlinkDetector does, but the Java link detector also shows a popup depending on the type of the element. The type of the element cannot be easily found just using the scanner.

Actually the parsing is not taking any time, it's the resolving that takes considerable time. Very less resolving is being done for selection on method or field declarations and this doesn't take any time. There is more resolving being done, if selection is some statement of a method and hence that takes considerable time. The resolving does seem necessary, may be there is some scope of improvement there. 

I think the usage of the cache can be improved which I am exploring now.
Comment 19 Satyam Kandula CLA 2011-04-07 11:06:32 EDT
I do think there are some cases where the cache can be improved, but I need to make sure that helps and hence having a real use case will be helpful. As you will not be able to give that, can you describe the file you are having problem with, the following questions could help. 
1. How many import's ending with .* are in the java file - More *'s could impact the cache? 
2. Are there really many type references in the java file? 
3. How big is the file? 
4. What selections were really taking lot of time?
Comment 20 Terry Parker CLA 2012-02-03 17:00:09 EST
(In reply to comment #19)
> I do think there are some cases where the cache can be improved, but I need to
> make sure that helps and hence having a real use case will be helpful. As you
> will not be able to give that, can you describe the file you are having problem
> with, the following questions could help. 

To answer Satyam's first three questions first:

> 1. How many import's ending with .* are in the java file - More *'s could
> impact the cache? 
There are no imports ending with .*, that is discouraged practice here.

> 2. Are there really many type references in the java file? 
No, the problem is independent of the number of type references in the file, it is caused by the JavaModelCache's jar type cache being undersized by a factor of 3-4, causing many cache misses followed by expensive jar file reads.

> 3. How big is the file? 
The size of the source file doesn't affect performance.

I downloaded the BigProject attachment, ran it with JDT at head under 32-bit Linux, and verified that it does recreate the problem reported in this bug when run with default "-Xms40m -Xmx384m" VM arguments.  I temporarily enabled javamodel/cache tracing to validate that the JavaModelCache's jar type cache was indeed overflowing.  In this case the jar type cache is undersized by a factor of 4.5.

To see how much time was taken for each hyperlink lookup, I turned on the "VERBOSE" variable in NameLookup, added a static high water mark variable and disabled other profiling/debugging. In NameLoopkup#seekTypesInBinaryPackage, lookups for variables at the end of the file all took > 500ms, with a cap of 990ms, but many times hyperlink detection never provided a hyperlink, whereas in 3.7 the UI hung until the hyperlink detection returned. Is this behavior new in the platform UI for 3.8?

Then I applied the patch from bug 365499 and adjusted the jar type cache up by a factor of 10.  With a sufficiently sized jar type cache, I saw a maximum time in NameLoopkup#seekTypesInBinaryPackage of 120ms, and there were no cases of hyperlink detection not occurring.

Is the patch in bug 365499 along the lines for what you had in mind for fix for this bug?


> 4. What selections were really taking lot of time?
Selections of import statements always take a long time.  But that is likely a separate bug.  Looking at the code in SelectionEngine.select(), selections of imports take a separate path than the one documented in this bug.  It does the following:
  org.eclipse.jdt.internal.core.search.BasicSearchEngine.searchAllTypeNames(BasicSearchEngine.java:1135)
  org.eclipse.jdt.internal.core.SearchableEnvironment.findTypes(SearchableEnvironment.java:456)
  org.eclipse.jdt.internal.core.SearchableEnvironment.findTypes(SearchableEnvironment.java:308)
  org.eclipse.jdt.internal.codeassist.SelectionEngine.select(SelectionEngine.java:869)

BasicSearchEngine.searchAllTypeNames() searches for all top-level types in the Java index, rather than using the JavaModelCache.  For our projects, the Java index is huge (a sample project has 6768 files totaling 171M in the .metadata/.plugins/org.eclipse.jdt.core folder.)  Is this expensive operation on the UI thread really needed for discovering hyperlinks on import statements?  Based on your answer I can file a separate bug for that.
Comment 21 Terry Parker CLA 2012-02-03 18:30:30 EST
(In reply to comment #20)
> (In reply to comment #19)
> > I do think there are some cases where the cache can be improved, but I need to
> > make sure that helps and hence having a real use case will be helpful. As you
> > will not be able to give that, can you describe the file you are having problem
> > with, the following questions could help. 
> 
> To answer Satyam's first three questions first:
> 
> > 1. How many import's ending with .* are in the java file - More *'s could
> > impact the cache? 
> There are no imports ending with .*, that is discouraged practice here.
> 
> > 2. Are there really many type references in the java file? 
> No, the problem is independent of the number of type references in the file, it
> is caused by the JavaModelCache's jar type cache being undersized by a factor
> of 3-4, causing many cache misses followed by expensive jar file reads.
> 
> > 3. How big is the file? 
> The size of the source file doesn't affect performance.
> 
> I downloaded the BigProject attachment, ran it with JDT at head under 32-bit
> Linux, and verified that it does recreate the problem reported in this bug when
> run with default "-Xms40m -Xmx384m" VM arguments.  I temporarily enabled
> javamodel/cache tracing to validate that the JavaModelCache's jar type cache
> was indeed overflowing.  In this case the jar type cache is undersized by a
> factor of 4.5.
> 
> To see how much time was taken for each hyperlink lookup, I turned on the
> "VERBOSE" variable in NameLookup, added a static high water mark variable and
> disabled other profiling/debugging. In NameLoopkup#seekTypesInBinaryPackage,
> lookups for variables at the end of the file all took > 500ms, with a cap of
> 990ms, but many times hyperlink detection never provided a hyperlink, whereas
> in 3.7 the UI hung until the hyperlink detection returned. Is this behavior new
> in the platform UI for 3.8?

I amend my comment about the UI not freezing up in 3.8.  The UI stays unresponsive for multiple seconds, just as it does in 3.7.

> 
> Then I applied the patch from bug 365499 and adjusted the jar type cache up by
> a factor of 10.  With a sufficiently sized jar type cache, I saw a maximum time
> in NameLoopkup#seekTypesInBinaryPackage of 120ms, and there were no cases of
> hyperlink detection not occurring.
> 
> Is the patch in bug 365499 along the lines for what you had in mind for fix for
> this bug?
> 
> 
> > 4. What selections were really taking lot of time?
> Selections of import statements always take a long time.  But that is likely a
> separate bug.  Looking at the code in SelectionEngine.select(), selections of
> imports take a separate path than the one documented in this bug.  It does the
> following:
>  
> org.eclipse.jdt.internal.core.search.BasicSearchEngine.searchAllTypeNames(BasicSearchEngine.java:1135)
>  
> org.eclipse.jdt.internal.core.SearchableEnvironment.findTypes(SearchableEnvironment.java:456)
>  
> org.eclipse.jdt.internal.core.SearchableEnvironment.findTypes(SearchableEnvironment.java:308)
>  
> org.eclipse.jdt.internal.codeassist.SelectionEngine.select(SelectionEngine.java:869)
> 
> BasicSearchEngine.searchAllTypeNames() searches for all top-level types in the
> Java index, rather than using the JavaModelCache.  For our projects, the Java
> index is huge (a sample project has 6768 files totaling 171M in the
> .metadata/.plugins/org.eclipse.jdt.core folder.)  Is this expensive operation
> on the UI thread really needed for discovering hyperlinks on import statements?
>  Based on your answer I can file a separate bug for that.
Comment 22 Satyam Kandula CLA 2012-02-07 08:12:20 EST
(In reply to comment #20)
> Is the patch in bug 365499 along the lines for what you had in mind for fix for
> this bug?
Yes, one part of my thoughts was to increase the cache size. Does increasing this size helping well in your project. 
I also think there could be some improvements in the way package-info.java files could be handled. Cache for them are used up even if the package-info.java are not used :(.

As I understand from the other bug you have filed, you have many jars. Does multiple jars have packages of the same name? I think some improvements can be done in this case too. 

> 
> 
> > 4. What selections were really taking lot of time?
> Selections of import statements always take a long time.  But that is likely a
> separate bug.  Looking at the code in SelectionEngine.select(), selections of
> imports take a separate path than the one documented in this bug.  It does the
> following:
>  Based on your answer I can file a separate bug for that.
Sure, please file a separate bug for this.
Comment 23 Terry Parker CLA 2012-02-07 11:05:56 EST
(In reply to comment #22)
> (In reply to comment #20)
> > Is the patch in bug 365499 along the lines for what you had in mind for fix for
> > this bug?
> Yes, one part of my thoughts was to increase the cache size. Does increasing
> this size helping well in your project.

Yes, increasing the jar type cache does solve one set of delays that we run into.
 
> I also think there could be some improvements in the way package-info.java
> files could be handled. Cache for them are used up even if the
> package-info.java are not used :(.

Which cache do these go into?  I can experiment with that.
> 
> As I understand from the other bug you have filed, you have many jars. Does
> multiple jars have packages of the same name? I think some improvements can be
> done in this case too. 

Yes, there may be multiple jars providing classes in the same Java package: code and tests are in separate jars, and generated code for things like data communication (protocol buffers) may be provided by multiple jars.  I don't see any of the other caches in JavaModelCache approach more than a few percent full.  In particular, the assumption that the root cache needs to get bumped up to reflect the number of library jars on the classpath doesn't hold for us, resulting in less than 0.3% utilization of that cache.

I haven't seen any indication that multiple package fragments for the same package cause a performance problem for us, but maybe I don't know what to look for.  Why do you suspect there may be a performance issue there?
> 
> > 
> > 
> > > 4. What selections were really taking lot of time?
> > Selections of import statements always take a long time.  But that is likely a
> > separate bug.  Looking at the code in SelectionEngine.select(), selections of
> > imports take a separate path than the one documented in this bug.  It does the
> > following:
> >  Based on your answer I can file a separate bug for that.
> Sure, please file a separate bug for this.

I'll do that, with a test case that demonstrates the delay.
Comment 24 Satyam Kandula CLA 2012-02-08 03:44:17 EST
(In reply to comment #23)
> > I also think there could be some improvements in the way package-info.java
> > files could be handled. Cache for them are used up even if the
> > package-info.java are not used :(.
> 
> Which cache do these go into?  I can experiment with that.
These go into the jarTypeCache.

> > As I understand from the other bug you have filed, you have many jars. Does
> > multiple jars have packages of the same name? I think some improvements can be
> > done in this case too. 
> 
> Yes, there may be multiple jars providing classes in the same Java package:
> code and tests are in separate jars, and generated code for things like data
> communication (protocol buffers) may be provided by multiple jars.  I don't see
> any of the other caches in JavaModelCache approach more than a few percent
> full.  In particular, the assumption that the root cache needs to get bumped up
> to reflect the number of library jars on the classpath doesn't hold for us,
> resulting in less than 0.3% utilization of that cache.
> 
> I haven't seen any indication that multiple package fragments for the same
> package cause a performance problem for us, but maybe I don't know what to look
> for.  Why do you suspect there may be a performance issue there?
More jars might have to be opened to extract the right file. I think some optimization can be done here, but we may not gain much. 

> I'll do that, with a test case that demonstrates the delay.
Sure. This will help.
Comment 25 Terry Parker CLA 2012-02-15 20:05:07 EST
(In reply to comment #24)
> (In reply to comment #23)
> > > I also think there could be some improvements in the way package-info.java
> > > files could be handled. Cache for them are used up even if the
> > > package-info.java are not used :(.
> > 
> > Which cache do these go into?  I can experiment with that.
> These go into the jarTypeCache.

In our case only the JRE and a handful of third party libraries have package-info.java files, so it won't represent a big savings for us.
> 
> > > As I understand from the other bug you have filed, you have many jars. Does
> > > multiple jars have packages of the same name? I think some improvements can be
> > > done in this case too. 
> > 
> > Yes, there may be multiple jars providing classes in the same Java package:
> > code and tests are in separate jars, and generated code for things like data
> > communication (protocol buffers) may be provided by multiple jars.  I don't see
> > any of the other caches in JavaModelCache approach more than a few percent
> > full.  In particular, the assumption that the root cache needs to get bumped up
> > to reflect the number of library jars on the classpath doesn't hold for us,
> > resulting in less than 0.3% utilization of that cache.
> > 
> > I haven't seen any indication that multiple package fragments for the same
> > package cause a performance problem for us, but maybe I don't know what to look
> > for.  Why do you suspect there may be a performance issue there?
> More jars might have to be opened to extract the right file. I think some
> optimization can be done here, but we may not gain much. 

Generally targeted searches aren't proving to be an issue.  We see performance issues when the entire classpath gets walked--for example, JavaProject.newNameLookup() eventually calls through to JarPackageFragmentRoot.computeChildren() for each library entry.

> 
> > I'll do that, with a test case that demonstrates the delay.
> Sure. This will help.

I filed bug 371555 for this.

Will you have a chance to comment on bug 365499?  I believe that is a good fix for this particular bug.
Comment 26 Satyam Kandula CLA 2012-02-15 23:40:39 EST
(In reply to comment #25)
> In our case only the JRE and a handful of third party libraries have
> package-info.java files, so it won't represent a big savings for us.
Actually, the absence of these files is also stored :). This was done so that the jar doesn't need to be opened every time. I believe there can be some improvements that can be done. 

> Generally targeted searches aren't proving to be an issue.  We see performance
> issues when the entire classpath gets walked--for example,
> JavaProject.newNameLookup() eventually calls through to
> JarPackageFragmentRoot.computeChildren() for each library entry.
Does increasing the cache helping this too? 


> Will you have a chance to comment on bug 365499?  I believe that is a good fix
> for this particular bug.
Sure, will do.
Comment 27 Terry Parker CLA 2012-02-17 02:57:37 EST
(In reply to comment #26)
> (In reply to comment #25)
> > In our case only the JRE and a handful of third party libraries have
> > package-info.java files, so it won't represent a big savings for us.
> Actually, the absence of these files is also stored :). This was done so that
> the jar doesn't need to be opened every time. I believe there can be some
> improvements that can be done. 
> 
> > Generally targeted searches aren't proving to be an issue.  We see performance
> > issues when the entire classpath gets walked--for example,
> > JavaProject.newNameLookup() eventually calls through to
> > JarPackageFragmentRoot.computeChildren() for each library entry.
> Does increasing the cache helping this too? 

Unfortunately no.  I'll be filing a separate bug for that.
> 
> 
> > Will you have a chance to comment on bug 365499?  I believe that is a good fix
> > for this particular bug.
> Sure, will do.

Thanks for moving that forward.
Comment 28 Terry Parker CLA 2012-02-17 12:45:32 EST
(In reply to comment #27)
> (In reply to comment #26)
> > (In reply to comment #25)
> > > In our case only the JRE and a handful of third party libraries have
> > > package-info.java files, so it won't represent a big savings for us.
> > Actually, the absence of these files is also stored :). This was done so that
> > the jar doesn't need to be opened every time. I believe there can be some
> > improvements that can be done. 
> > 
> > > Generally targeted searches aren't proving to be an issue.  We see performance
> > > issues when the entire classpath gets walked--for example,
> > > JavaProject.newNameLookup() eventually calls through to
> > > JarPackageFragmentRoot.computeChildren() for each library entry.
> > Does increasing the cache helping this too? 
> 
> Unfortunately no.  I'll be filing a separate bug for that.
> > 
> > 
> > > Will you have a chance to comment on bug 365499?  I believe that is a good fix
> > > for this particular bug.
> > Sure, will do.
> 
> Thanks for moving that forward.

BTW, marking this bug as dependent on 365499 and closing it when that is resolved makes sense to me.  If I see performance issues with multiple jars containing packages of the same name or with package-info.java files I'll file more targeted bugs for those.
Comment 29 Satyam Kandula CLA 2012-02-21 04:00:57 EST
> BTW, marking this bug as dependent on 365499 and closing it when that is
> resolved makes sense to me.  If I see performance issues with multiple jars
> containing packages of the same name or with package-info.java files I'll file
> more targeted bugs for those.

Sure and thanks.
Comment 30 Satyam Kandula CLA 2012-02-21 04:02:47 EST
The fix for bug 365499 helps. Resolving as per Terry's comments.
Comment 31 Jay Arthanareeswaran CLA 2012-03-13 09:36:30 EDT
Verified for 3.8 M6 using build I20120312-1800