Bug 474045 - findSecondaryType blocked by sleeping Indexing Thread
Summary: findSecondaryType blocked by sleeping Indexing Thread
Status: RESOLVED FIXED
Alias: None
Product: JDT
Classification: Eclipse Project
Component: Core (show other bugs)
Version: 4.5   Edit
Hardware: All All
: P3 major (vote)
Target Milestone: 4.6 M5   Edit
Assignee: Markus Keller CLA
QA Contact:
URL:
Whiteboard:
Keywords:
: 491136 (view as bug list)
Depends on:
Blocks:
 
Reported: 2015-07-31 10:36 EDT by Sven Efftinge CLA
Modified: 2016-04-06 05:11 EDT (History)
6 users (show)

See Also:


Attachments

Note You need to log in before you can comment on or make changes to this bug.
Description Sven Efftinge CLA 2015-07-31 10:36:23 EDT
PDE's APIAnalysisBuilder uses JavaModelManager#secondaryTypes (see [PDE Builder Stack]). That is potentially blocked by a huge number of pending indexing jobs (IJob).
I did a re-fresh after a branch switch and a canceled import and had around 15.000 of those little jobs to be processes. That wouldn't be so bad if the indexing thread would not wait 50ms between each job.

See JobManager.java:412
  if (this.awaitingClients == 0)
    Thread.sleep(50);

I think the situation would be improved if at least the sleeping would be avoided in cases where a client waits.

[PDE Builder Stack]

Thread [Worker-11] (Suspended)	
	Thread.sleep(long) line: not available [native method]	
	JavaModelManager.secondaryTypes(IJavaProject, boolean, IProgressMonitor) line: 4573	
	NameLookup.findSecondaryType(String, String, IJavaProject, boolean, IProgressMonitor) line: 592	
	NameLookup.findType(String, IPackageFragment, boolean, int, boolean, boolean) line: 773	
	NameLookup.findType(String, String, boolean, int, boolean, boolean, boolean, IProgressMonitor) line: 663	
	NameLookup.findType(String, boolean, int, boolean, boolean, boolean, IProgressMonitor) line: 845	
	JavaProject.findType(String, NameLookup, boolean, IProgressMonitor) line: 1277	
	JavaProject.findType(String, WorkingCopyOwner, IProgressMonitor) line: 1366	
	JavaProject.findType(String, IProgressMonitor) line: 1270	
	LeakFieldProblemDetector(AbstractProblemDetector).createProblem(IReference, IJavaProject) line: 183	
	LeakFieldProblemDetector(AbstractProblemDetector).createProblems() line: 526	
	ReferenceAnalyzer.analyze(IApiComponent, IApiTypeContainer, IProgressMonitor) line: 263	
	BaseApiAnalyzer.checkApiUsage(IBuildContext, IApiComponent, IProgressMonitor) line: 1206	
	BaseApiAnalyzer.analyzeComponent(BuildState, IApiFilterStore, Properties, IApiBaseline, IApiComponent, IBuildContext, IProgressMonitor) line: 271	
	ApiAnalysisBuilder.buildAll(IApiBaseline, IApiBaseline, IProgressMonitor) line: 754	
	ApiAnalysisBuilder.build(int, Map<String,String>, IProgressMonitor) line: 369
Comment 1 Jay Arthanareeswaran CLA 2015-08-03 02:24:27 EDT
Not sure if we can simply reduce the sleep time. Manoj, please take a look.
Comment 2 Markus Keller CLA 2015-12-07 11:20:57 EST
I just ran into this problem as well, see bug 483814. In my case, the UI thread was blocked during a Save Action (Organize Imports).

AFAIK, the 50ms delay is meant to avoid generating excessive system load when the indexing is done in the background and nobody actually waits for the index. This delay should not be reduced without a good reason. 

org.eclipse.jdt.internal.core.JavaModelManager#secondaryTypes(IJavaProject, boolean, IProgressMonitor) actually waits for the index, but it wrongly does this by polling ("while (this.indexManager.awaitingJobsCount() > 0)"). Since JobManager#awaitingClients stays 0, the indexing doesn't speed up when it should.

I think JavaModelManager#secondaryTypes(..) should just use JobManager#performConcurrentJob(IJob, int, IProgressMonitor), passing IJob.WaitUntilReady to tell the index to finish without delays.
Comment 3 Eclipse Genie CLA 2015-12-07 12:54:38 EST
New Gerrit change created: https://git.eclipse.org/r/62139
Comment 4 Markus Keller CLA 2015-12-07 13:16:04 EST
(In reply to Eclipse Genie from comment #3)
> New Gerrit change created: https://git.eclipse.org/r/62139

Here's what I meant. This fix dramatically reduces the UI freeze to just the time it takes to actually perform the indexing. As long as bug 483814 is not fixed, the user is still not able to cancel the Save, but at least the waiting time is reduced.

Bug 118789 added the "while (this.indexManager.awaitingJobsCount() > 0)" loop, but doesn't explain why it was done that way.

I'm not an expert in the search infrastructure, and I just implemented the IJob to look like a PatternSearchJob. There may be better ways to do this.

org.eclipse.jdt.internal.core.SearchableEnvironment#findConstructorDeclarations(..) has a similar loop, and probably suffers from the same problem.

I would NOT push this for M4, but wait for early M5.
Comment 5 Timo Kinnunen CLA 2015-12-08 10:51:03 EST
(In reply to comment #2)
> AFAIK, the 50ms delay is meant to avoid generating excessive system load when
> the indexing is done in the background and nobody actually waits for the index.
> This delay should not be reduced without a good reason.

A fixed length sleep is a wrong tool for managing system load. It doesn't account for: 

- CPU load changing with time, necessitating adjustments to hit load factor targets; as it doesn't measure CPU load. 
- differences between CPUs, leading to wrong work:sleep ratios on some systems; as it doesn't measure CPU speed
- the host environment not accounting for the system management activities it performs; as it doesn't coordinate with its environment.

In addition 50ms can be both an enormously long (imagine scrolling an editor on a 60Hz display had 3 to 4 frames of input lag) time and also an insignificant (if followed by e.g. a hard drive powering up from a sleep state for several seconds) time. 

This is clearly a hack and it's time for it to go.
Comment 6 Timo Kinnunen CLA 2015-12-08 11:02:47 EST
Oh, and of course it ignores InterruptedException, so it's also actively hostile to system management others may be performing. Yes, of course it ignores InterruptedException :P
Comment 7 Stefan Xenos CLA 2015-12-08 15:44:07 EST
Does APIAnalysisBuilder need to run synchronously? Rather than blocking, couldn't it just register a callback with the indexer and perform API analysis after indexing is finished?
Comment 8 Markus Keller CLA 2015-12-15 12:33:18 EST
(In reply to Stefan Xenos from comment #7)
> Does APIAnalysisBuilder need to run synchronously? Rather than blocking,
> couldn't it just register a callback with the indexer and perform API
> analysis after indexing is finished?

That's exactly what
    this.indexManager.performConcurrentJob(.., IJob.WaitUntilReady, ..)
in my patch does.

I'll add the fix for SearchableEnvironment#findConstructorDeclarations(..) and release.
Comment 10 Markus Keller CLA 2015-12-15 14:59:33 EST
(In reply to Markus Keller from comment #8)
> That's exactly what [..] my patch does.

"Exactly" was an exaggeration. IJavaProject#findType(..) needs to block, and it now does this efficiently by registering a callback with the indexer.

The APIAnalysisBuilder runs in a Job and cannot continue until it gets the required information. Even if it would be rewritten to run asynchronously, it would still have to wait for the index to be done as soon as it tried to do any work on another project. Making it asynchronous would need a complete rewrite of the JDT Core APIs.
Comment 11 Manoj N Palat CLA 2016-01-05 01:32:56 EST
(In reply to Eclipse Genie from comment #9)
> Gerrit change https://git.eclipse.org/r/62139 was merged to [master].
> Commit:
> http://git.eclipse.org/c/jdt/eclipse.jdt.core.git/commit/
> ?id=fcf41d3b46ba97e9e4d60c5ee97c3384b6432cf6

Verified for Eclipse Neon 4.6M5 Build id: I20151229-0800 by code changes.
Comment 12 Markus Keller CLA 2016-01-08 16:54:31 EST
Manoj, I don't see this fix in R4_5_maintenance, hence the bug must not be marked as FIXED with milestone 4.5.2.
Comment 13 Markus Keller CLA 2016-02-02 14:50:48 EST
I tried to find steps to reproduce in R4_5_maintenance, but I could find any. The steps from bug 483814 don't work in 4.5, since the unresolvable imports get removed earlier and don't result in conflicting names that could lead to a search for secondary types. Moving out of 4.5.2
Comment 14 Dani Megert CLA 2016-04-06 05:11:18 EDT
*** Bug 491136 has been marked as a duplicate of this bug. ***