Bug 543151 - Reconcile Is Triggered On Working Copy Causing Severe Decrease Of UI Responsiveness
Summary: Reconcile Is Triggered On Working Copy Causing Severe Decrease Of UI Responsi...
Status: NEW
Alias: None
Product: JDT
Classification: Eclipse Project
Component: Core (show other bugs)
Version: 4.6   Edit
Hardware: PC Windows All
: P3 major (vote)
Target Milestone: ---   Edit
Assignee: Jay Arthanareeswaran CLA
QA Contact:
URL:
Whiteboard: stalebug
Keywords:
Depends on:
Blocks:
 
Reported: 2019-01-03 10:59 EST by David Christensen CLA
Modified: 2023-02-18 16:57 EST (History)
6 users (show)

See Also:


Attachments
UI Responsiveness Monitor Log (495.94 KB, text/plain)
2019-01-03 11:05 EST, David Christensen CLA
no flags Details

Note You need to log in before you can comment on or make changes to this bug.
Description David Christensen CLA 2019-01-03 10:59:32 EST
This is a case where UI is frozen for several seconds making the workbench unusable. 

There are operations identified by user that triggers this behavior; tooltips (Breadcrumbs mouse hover), tooltips2 (Content Assist) and Save a Java file.

Logs were collected using UI Responsiveness Monitor (attachment). The pattern highlighted in traces is as follows:

[Here the top of the stack in high Java IO:]
 Trace^M
        at java.io.FileInputStream.open0(Native Method)^M
        at java.io.FileInputStream.open(FileInputStream.java:212)^M
        at java.io.FileInputStream.<init>(FileInputStream.java:152)^M
        at org.eclipse.core.internal.filesystem.local.LocalFile.openInputStream(LocalFile.java:380)^M
        at org.eclipse.core.internal.localstore.FileSystemResourceManager.read(FileSystemResourceManager.java:853)^M
        at org.eclipse.core.internal.resources.File.getContents(File.java:277)^M
        at org.eclipse.jdt.internal.core.util.Util.getResourceContentsAsCharArray(Util.java:1190)^M
        at org.eclipse.jdt.internal.core.CompilationUnit.getContents(CompilationUnit.java:652)^M
...
[here Compiler.process forward calls]
...
at org.eclipse.jdt.internal.compiler.Compiler.process(Compiler.java:853)^M
at org.eclipse.jdt.core.dom.CompilationUnitResolver.resolve(CompilationUnitResolver.java:883)^M
at org.eclipse.jdt.core.dom.CompilationUnitResolver.resolve(CompilationUnitResolver.java:588)^M
at org.eclipse.jdt.core.dom.ASTParser.createASTs(ASTParser.java:899)^M
at org.eclipse.jdt.apt.core.internal.env.BaseProcessorEnv.createASTs(BaseProcessorEnv.java:857)^M
at org.eclipse.jdt.apt.core.internal.env.ReconcileEnv.openPipeline(ReconcileEnv.java:108)^M
at org.eclipse.jdt.apt.core.internal.env.AbstractCompilationEnv.newReconcileEnv(AbstractCompilationEnv.java:97)^M
at org.eclipse.jdt.apt.core.internal.APTDispatchRunnable.reconcile(APTDispatchRunnable.java:219)^M
at org.eclipse.jdt.apt.core.internal.APTDispatchRunnable.runAPTDuringReconcile(APTDispatchRunnable.java:167)^M
at org.eclipse.jdt.apt.core.internal.AptCompilationParticipant.reconcile(AptCompilationParticipant.java:213)^M
at org.eclipse.jdt.internal.core.ReconcileWorkingCopyOperation$1.run(ReconcileWorkingCopyOperation.java:258)^M
at org.eclipse.core.runtime.SafeRunner.run(SafeRunner.java:42)^M
at org.eclipse.jdt.internal.core.ReconcileWorkingCopyOperation.notifyParticipants(ReconcileWorkingCopyOperation.java:245)^M
at org.eclipse.jdt.internal.core.ReconcileWorkingCopyOperation.executeOperation(ReconcileWorkingCopyOperation.java:95)^M
at org.eclipse.jdt.internal.core.JavaModelOperation.run(JavaModelOperation.java:724)^M
at org.eclipse.jdt.internal.core.JavaModelOperation.runOperation(JavaModelOperation.java:790)^M
at org.eclipse.jdt.internal.core.CompilationUnit.reconcile(CompilationUnit.java:1250)^M
at org.eclipse.jdt.internal.core.CompilationUnit.reconcile(CompilationUnit.java:1211)^M
...

[here stack segment inherent to each operation (save,breadcrumb hover,content assist)

....
[here continues with the 'main' thread stack part]


Is this a usual behavior? What could be triggering the reconcile? Could it be executed by a background thread?

Sorry, it is not possible to provide a sample test case with a sample project.
Comment 1 David Christensen CLA 2019-01-03 11:05:54 EST
Created attachment 277057 [details]
UI Responsiveness Monitor Log
Comment 2 Dani Megert CLA 2019-01-04 05:10:39 EST
The main problem reported for JDT Core is happening during save and not with other operations.

The other reported delays are due to one or more Clear Case listeners (e.g. selection) that do stuff.

Please unshare (disconnect from Clear Case team provider) one of the projects where you see the issue and test whether the problem persists.
Comment 3 Dani Megert CLA 2019-01-04 05:11:32 EST
Note to JDT Core devs: APT is involved here.
Comment 4 Dani Megert CLA 2019-01-04 05:24:55 EST
Could also be related to bug 541054.
Comment 5 David Christensen CLA 2019-01-08 11:59:41 EST
(In reply to Dani Megert from comment #2)
> The main problem reported for JDT Core is happening during save and not with
> other operations.
> 


There are records in the logs that belongs to JavaEditorBreadcrumb. Is it a 'save' op ?

at org.eclipse.jdt.internal.corext.util.JavaModelUtil.reconcile(JavaModelUtil.java:609)
at org.eclipse.jdt.internal.ui.actions.SelectionConverter.getElementAtOffset(SelectionConverter.java:284)
at org.eclipse.jdt.internal.ui.javaeditor.JavaEditorBreadcrumb.getCurrentInput(JavaEditorBreadcrumb.java:824)
at org.eclipse.jdt.internal.ui.javaeditor.JavaEditorBreadcrumb$ElementChangeListener$1.run(JavaEditorBreadcrumb.java:467)
at org.eclipse.swt.widgets.RunnableLock.run(RunnableLock.java:35)


> The other reported delays are due to one or more Clear Case listeners (e.g.
> selection) that do stuff.
 
Clear Case Team has looked at this records. Do you think Clear Case could interfere with 'save' or other operations?

> Please unshare (disconnect from Clear Case team provider) one of the
> projects where you see the issue and test whether the problem persists.

A test where Clear Case plugin was not installed, does not showed improvement in the overall performance. Nevertheless I will run more tests. For this bug, I would like to lost the focus to Clear Case as it is another line on investigation. also the records in the log that I am trying to highlight are not related to Clear Case, please correct me if I am wrong.


Is there any comment related to JDT or APT?

Thank you
Comment 6 Jay Arthanareeswaran CLA 2019-01-08 23:41:15 EST
I looked at the code that calls upon reconcile from SelectionConverter and it appears to have always been there. Noopur, do you know why we need reconcile in this scenario?
Comment 7 Noopur Gupta CLA 2019-01-09 04:34:35 EST
(In reply to Jay Arthanareeswaran from comment #6)
> I looked at the code that calls upon reconcile from SelectionConverter and
> it appears to have always been there. Noopur, do you know why we need
> reconcile in this scenario?
Looks like the working copy must be reconciled before code resolve:
https://git.eclipse.org/c/jdt/eclipse.jdt.ui.git/commit/?id=19423ffa175f1e70a6a46a93c2f3ba8304339bd5
Comment 8 Kit Lo CLA 2019-01-09 16:09:49 EST
Noopur, what bug number was the commit for? Jay, do you think that was causing the UI freeze?
Comment 9 Noopur Gupta CLA 2019-01-09 16:31:10 EST
(In reply to Kit Lo from comment #8)
> Noopur, what bug number was the commit for?

The commit was added in the year 2003 which I got through the revision history. It doesn't have a bug number in the commit message. Dani, do you remember why it was necessary? 

If the freeze was not happening in the previous release being used then probably something changed during reconcile causing the issue now.
Comment 10 Dani Megert CLA 2019-01-11 12:09:22 EST
(In reply to Noopur Gupta from comment #9)
> (In reply to Kit Lo from comment #8)
> > Noopur, what bug number was the commit for?
> 
> The commit was added in the year 2003 which I got through the revision
> history. It doesn't have a bug number in the commit message. Dani, do you
> remember why it was necessary? 

At least back then the code would have returned the wrong element without reconcile. Anyway, this was in 2003 so, that code is not really relevant for the reported issue.
Comment 11 David Christensen CLA 2019-01-12 20:56:35 EST
Another test was run this time, disabling annotation processing in 'Java Compiler>Annotation Processing' and the delays disappeared. More tests are coming soon. Want to collect traces to compare.
Comment 12 Jay Arthanareeswaran CLA 2019-01-16 00:49:49 EST
Looks like bug 541844 is relevant too (according to bug 541844, comment #18).
Comment 13 Eclipse Genie CLA 2021-01-06 14:09:42 EST
This bug hasn't had any activity in quite some time. Maybe the problem got resolved, was a duplicate of something else, or became less pressing for some reason - or maybe it's still relevant but just hasn't been looked at yet.

If you have further information on the current state of the bug, please add it. The information can be, for example, that the problem still occurs, that you still want the feature, that more information is needed, or that the bug is (for whatever reason) no longer relevant.

--
The automated Eclipse Genie.
Comment 14 Eclipse Genie CLA 2023-02-18 16:57:35 EST
This bug hasn't had any activity in quite some time. Maybe the problem got resolved, was a duplicate of something else, or became less pressing for some reason - or maybe it's still relevant but just hasn't been looked at yet.

If you have further information on the current state of the bug, please add it. The information can be, for example, that the problem still occurs, that you still want the feature, that more information is needed, or that the bug is (for whatever reason) no longer relevant.

--
The automated Eclipse Genie.