Bug 551152 - UI freezes on startup via DynamicSourcesWorkingSetUpdater
Summary: UI freezes on startup via DynamicSourcesWorkingSetUpdater
Status: CLOSED DUPLICATE of bug 551676
Alias: None
Product: JDT
Classification: Eclipse Project
Component: UI (show other bugs)
Version: 4.14   Edit
Hardware: PC Linux
: P3 normal (vote)
Target Milestone: ---   Edit
Assignee: JDT-UI-Inbox CLA
QA Contact:
URL:
Whiteboard:
Keywords:
Depends on:
Blocks:
 
Reported: 2019-09-17 05:17 EDT by Andrey Loskutov CLA
Modified: 2020-03-02 04:19 EST (History)
1 user (show)

See Also:


Attachments
My working sets (1.19 MB, text/xml)
2019-09-17 08:17 EDT, Andrey Loskutov CLA
no flags Details

Note You need to log in before you can comment on or make changes to this bug.
Description Andrey Loskutov CLA 2019-09-17 05:17:29 EDT
In recent 4.14 builds I constantly see UI freezes in the range of 2 - 3 seconds (sometimes even few in same session) reported on startup due DynamicSourcesWorkingSetUpdater.


I have workspace with 30 Java working sets containing 144 opened / 230 closed Java/PDE projects.

Below few examples:

Stack Trace
	at java.base@11.0.2/java.lang.Throwable.fillInStackTrace(Native Method)
	at java.base@11.0.2/java.lang.Throwable.fillInStackTrace(Throwable.java:787)
	at java.base@11.0.2/java.lang.Throwable.<init>(Throwable.java:270)
	at java.base@11.0.2/java.lang.Exception.<init>(Exception.java:66)
	at org.eclipse.core.runtime.CoreException.<init>(CoreException.java:46)
	at org.eclipse.jdt.core.JavaModelException.<init>(JavaModelException.java:75)
	at org.eclipse.jdt.internal.core.JavaElement.newNotPresentException(JavaElement.java:573)
	at org.eclipse.jdt.internal.core.JavaModelManager.getPerProjectInfoCheckExistence(JavaModelManager.java:2525)
	at org.eclipse.jdt.internal.core.JavaProject.getPerProjectInfo(JavaProject.java:2341)
	at org.eclipse.jdt.internal.core.JavaProject.getResolvedClasspath(JavaProject.java:2400)
	at org.eclipse.jdt.internal.core.JavaProject.getClasspathEntryFor(JavaProject.java:1821)
	at org.eclipse.jdt.internal.core.PackageFragmentRoot.getHandleMemento(PackageFragmentRoot.java:511)
	at org.eclipse.jdt.internal.core.JavaElement.getHandleMemento(JavaElement.java:362)
	at org.eclipse.jdt.internal.core.JavaElement.getHandleIdentifier(JavaElement.java:355)
	at org.eclipse.jdt.internal.ui.PersistableJavaElementFactory.saveState(PersistableJavaElementFactory.java:80)
	at org.eclipse.ui.internal.WorkingSet$2.run(WorkingSet.java:210)
	at org.eclipse.core.runtime.SafeRunner.run(SafeRunner.java:45)
	at org.eclipse.ui.internal.WorkingSet.saveState(WorkingSet.java:206)
	at org.eclipse.ui.internal.AbstractWorkingSetManager$6.run(AbstractWorkingSetManager.java:460)
	at org.eclipse.core.runtime.SafeRunner.run(SafeRunner.java:45)
	at org.eclipse.ui.internal.AbstractWorkingSetManager.saveWorkingSetState(AbstractWorkingSetManager.java:452)
	at org.eclipse.ui.internal.AbstractWorkingSetManager.saveWorkingSetState(AbstractWorkingSetManager.java:440)
	at org.eclipse.ui.internal.AbstractWorkingSetManager.saveState(AbstractWorkingSetManager.java:778)
	at org.eclipse.ui.internal.WorkingSetManager.saveState(WorkingSetManager.java:137)
	at org.eclipse.ui.internal.WorkingSetManager.workingSetChanged(WorkingSetManager.java:156)
	at org.eclipse.ui.internal.AbstractWorkingSet.fireWorkingSetChanged(AbstractWorkingSet.java:137)
	at org.eclipse.ui.internal.WorkingSet.setElements(WorkingSet.java:222)
	at org.eclipse.jdt.internal.ui.workingsets.DynamicSourcesWorkingSetUpdater$2.run(DynamicSourcesWorkingSetUpdater.java:234)
	at org.eclipse.jdt.internal.ui.workingsets.DynamicSourcesWorkingSetUpdater$UpdateUIJob.runInUIThread(DynamicSourcesWorkingSetUpdater.java:98)
	at org.eclipse.ui.progress.UIJob.lambda$0(UIJob.java:95)
	at org.eclipse.ui.progress.UIJob$$Lambda$636/0x00000008409f9c40.run(Unknown Source)
	at org.eclipse.swt.widgets.RunnableLock.run(RunnableLock.java:40)
	at org.eclipse.swt.widgets.Synchronizer.runAsyncMessages(Synchronizer.java:185)
	at org.eclipse.swt.widgets.Display.runAsyncMessages(Display.java:4879)
	at org.eclipse.swt.widgets.Display.readAndDispatch(Display.java:4411)


Stack Trace
	at java.base@11.0.2/java.nio.HeapCharBuffer.<init>(HeapCharBuffer.java:75)
	at java.base@11.0.2/java.nio.CharBuffer.wrap(CharBuffer.java:393)
	at java.base@11.0.2/sun.nio.cs.StreamEncoder.implWrite(StreamEncoder.java:280)
	at java.base@11.0.2/sun.nio.cs.StreamEncoder.write(StreamEncoder.java:125)
	at java.base@11.0.2/sun.nio.cs.StreamEncoder.write(StreamEncoder.java:135)
	at java.base@11.0.2/java.io.OutputStreamWriter.write(OutputStreamWriter.java:229)
	at java.base@11.0.2/java.io.PrintWriter.write(PrintWriter.java:542)
	at java.base@11.0.2/java.io.PrintWriter.write(PrintWriter.java:559)
	at java.base@11.0.2/java.io.PrintWriter.print(PrintWriter.java:686)
	at org.eclipse.ui.XMLMemento$DOMWriter.startTag(XMLMemento.java:656)
	at org.eclipse.ui.XMLMemento$DOMWriter.print(XMLMemento.java:618)
	at org.eclipse.ui.XMLMemento$DOMWriter.print(XMLMemento.java:628)
	at org.eclipse.ui.XMLMemento$DOMWriter.print(XMLMemento.java:628)
	at org.eclipse.ui.XMLMemento.save(XMLMemento.java:574)
	at org.eclipse.ui.internal.AbstractWorkingSetManager.saveState(AbstractWorkingSetManager.java:783)
	at org.eclipse.ui.internal.WorkingSetManager.saveState(WorkingSetManager.java:137)
	at org.eclipse.ui.internal.WorkingSetManager.workingSetChanged(WorkingSetManager.java:156)
	at org.eclipse.ui.internal.AbstractWorkingSet.fireWorkingSetChanged(AbstractWorkingSet.java:137)
	at org.eclipse.ui.internal.WorkingSet.setElements(WorkingSet.java:222)
	at org.eclipse.jdt.internal.ui.workingsets.DynamicSourcesWorkingSetUpdater$2.run(DynamicSourcesWorkingSetUpdater.java:234)
	at org.eclipse.jdt.internal.ui.workingsets.DynamicSourcesWorkingSetUpdater$UpdateUIJob.runInUIThread(DynamicSourcesWorkingSetUpdater.java:98)
	at org.eclipse.ui.progress.UIJob.lambda$0(UIJob.java:95)
	at org.eclipse.ui.progress.UIJob$$Lambda$636/0x00000008409f9c40.run(Unknown Source)
	at org.eclipse.swt.widgets.RunnableLock.run(RunnableLock.java:40)
	at org.eclipse.swt.widgets.Synchronizer.runAsyncMessages(Synchronizer.java:185)
	at org.eclipse.swt.widgets.Display.runAsyncMessages(Display.java:4879)
	at org.eclipse.swt.widgets.Display.readAndDispatch(Display.java:4411)



Stack Trace
	at java.base@11.0.2/java.lang.Throwable.fillInStackTrace(Native Method)
	at java.base@11.0.2/java.lang.Throwable.fillInStackTrace(Throwable.java:787)
	at java.base@11.0.2/java.lang.Throwable.<init>(Throwable.java:270)
	at java.base@11.0.2/java.lang.Exception.<init>(Exception.java:66)
	at org.eclipse.core.runtime.CoreException.<init>(CoreException.java:46)
	at org.eclipse.jdt.core.JavaModelException.<init>(JavaModelException.java:75)
	at org.eclipse.jdt.internal.core.JavaElement.newNotPresentException(JavaElement.java:573)
	at org.eclipse.jdt.internal.core.JavaModelManager.getPerProjectInfoCheckExistence(JavaModelManager.java:2525)
	at org.eclipse.jdt.internal.core.JavaProject.getPerProjectInfo(JavaProject.java:2341)
	at org.eclipse.jdt.internal.core.JavaProject.getResolvedClasspath(JavaProject.java:2400)
	at org.eclipse.jdt.internal.core.JavaProject.getClasspathEntryFor(JavaProject.java:1821)
	at org.eclipse.jdt.internal.core.PackageFragmentRoot.getHandleMemento(PackageFragmentRoot.java:511)
	at org.eclipse.jdt.internal.core.JavaElement.getHandleMemento(JavaElement.java:362)
	at org.eclipse.jdt.internal.core.JavaElement.getHandleIdentifier(JavaElement.java:355)
	at org.eclipse.jdt.internal.ui.PersistableJavaElementFactory.saveState(PersistableJavaElementFactory.java:80)
	at org.eclipse.ui.internal.WorkingSet$2.run(WorkingSet.java:210)
	at org.eclipse.core.runtime.SafeRunner.run(SafeRunner.java:45)
	at org.eclipse.ui.internal.WorkingSet.saveState(WorkingSet.java:206)
	at org.eclipse.ui.internal.AbstractWorkingSetManager$6.run(AbstractWorkingSetManager.java:460)
	at org.eclipse.core.runtime.SafeRunner.run(SafeRunner.java:45)
	at org.eclipse.ui.internal.AbstractWorkingSetManager.saveWorkingSetState(AbstractWorkingSetManager.java:452)
	at org.eclipse.ui.internal.AbstractWorkingSetManager.saveWorkingSetState(AbstractWorkingSetManager.java:440)
	at org.eclipse.ui.internal.AbstractWorkingSetManager.saveState(AbstractWorkingSetManager.java:778)
	at org.eclipse.ui.internal.WorkingSetManager.saveState(WorkingSetManager.java:137)
	at org.eclipse.ui.internal.WorkingSetManager.workingSetChanged(WorkingSetManager.java:156)
	at org.eclipse.ui.internal.AbstractWorkingSet.fireWorkingSetChanged(AbstractWorkingSet.java:137)
	at org.eclipse.ui.internal.WorkingSet.setElements(WorkingSet.java:222)
	at org.eclipse.jdt.internal.ui.workingsets.DynamicSourcesWorkingSetUpdater$2.run(DynamicSourcesWorkingSetUpdater.java:234)
	at org.eclipse.jdt.internal.ui.workingsets.DynamicSourcesWorkingSetUpdater$UpdateUIJob.runInUIThread(DynamicSourcesWorkingSetUpdater.java:98)
	at org.eclipse.ui.progress.UIJob.lambda$0(UIJob.java:95)
	at org.eclipse.ui.progress.UIJob$$Lambda$585/0x0000000840978440.run(Unknown Source)
	at org.eclipse.swt.widgets.RunnableLock.run(RunnableLock.java:40)
	at org.eclipse.swt.widgets.Synchronizer.runAsyncMessages(Synchronizer.java:185)
	at org.eclipse.swt.widgets.Display.runAsyncMessages(Display.java:4879)
	at org.eclipse.swt.widgets.Display.readAndDispatch(Display.java:4411)
Comment 1 Till Brychcy CLA 2019-09-17 07:54:18 EDT
So all 30 working sets are saved each time any working set is changed, which gets expensive.

Solution ideas:
- Add API to platform to specify that some working sets need not be saved at all and then use this in jdt.ui for the dynamic working sets.
- Detect if the working set contents have changed at all and only trigger events / saving if there is a delta.
- Maybe AbstractWorkingSetManager can do the saving in another thread?
Comment 2 Andrey Loskutov CLA 2019-09-17 08:12:59 EDT
(In reply to Till Brychcy from comment #1)
> So all 30 working sets are saved each time any working set is changed, which
> gets expensive.
> 
> Solution ideas:
> - Add API to platform to specify that some working sets need not be saved at
> all and then use this in jdt.ui for the dynamic working sets.

Would be my favorite, especially if the two working sets duplicate the file size (they contain all the sources I manage in all other working sets).

> - Detect if the working set contents have changed at all and only trigger
> events / saving if there is a delta.

Detection would first need to restore (JDT) elements, which will require similar or more time (locks etc)

> - Maybe AbstractWorkingSetManager can do the saving in another thread?

I assume there is too much code assumed that save/notifications are sent on UI thread.

Another idea: create this two working sets on demand only? I honestly never ever used them, neither in UI nor to search something, so all the work here is done without any reason from my kind of user point of view.
Comment 3 Stephan Herrmann CLA 2019-09-17 08:16:27 EDT
(analysis written before I saw the discussion between Till and Andrey).


(In reply to Andrey Loskutov from comment #0)
> org.eclipse.jdt.internal.core.JavaProject.getClasspathEntryFor(JavaProject.
> java:1821)
> 	at
> org.eclipse.jdt.internal.core.PackageFragmentRoot.
> getHandleMemento(PackageFragmentRoot.java:511)

This particular method call is new from bug 466299.

You don't have lots of "extra attributes" defined in .classpath, do you?

I'm a bit surprised about the situation: it looks like s.o. holds (valid?) Java Elements but when those are asked about the containing IJavaProject, they notice that the project does not have the Java nature.

All this seems to be orchestrated in DynamicSourcesWorkingSetUpdater. Here we iterate IJavaProjects obtained from JavaModel.getJavaProjects(). So I assume those projects indeed have the Java nature. Still the package fragment roots obtained from these projects seem to lack the Java nature, as can be seen by appearance of JavaModelManager.java:2525 in the stack.

Looking closer at the stack frames around WorkingSet.setElements() I'm no longer sure which elements trigger the issue? Perhaps its not the good elements freshly collected by DynamicSourcesWorkingSetUpdater, but the *old* working sets? At Eclipse start up, what is the content of dynamic working sets?


I s.o. can explain this use case and why it should be valid, then I can try to prevent triggering the expensive operation, e.g., like I do in the constructor of JarPackageFragmentRoot. But I'm afraid such change could possibly spoil the newly achieve consistency (when we ignore extra attributes even if present, only because the project was not yet fully resolved).
Comment 4 Andrey Loskutov CLA 2019-09-17 08:17:02 EDT
Created attachment 279905 [details]
My working sets

Hold on, I've just checked *what* do I have in the working sets file, this seem to be a bug.

See attachment: it contains *multiple* "Java Test Sources" and "Java Main Sources" working sets with *different* ID's.

How that?

This is my main workspace that I keep since ever for SDK development.
Comment 5 Till Brychcy CLA 2019-09-17 08:30:03 EDT
(In reply to Andrey Loskutov from comment #4)
> Created attachment 279905 [details]
> My working sets
> 
> Hold on, I've just checked *what* do I have in the working sets file, this
> seem to be a bug.
> 
> See attachment: it contains *multiple* "Java Test Sources" and "Java Main
> Sources" working sets with *different* ID's.
> 
> How that?
> 
> This is my main workspace that I keep since ever for SDK development.

That really is strange.

(I just quickly checked using grep -c ... I don't have any duplicates in my more than 25 workspaces)
Comment 6 Andrey Loskutov CLA 2020-03-02 04:19:05 EST
I will address the persistence issue via bug 551676 comment 5.

*** This bug has been marked as a duplicate of bug 551676 ***