This Bugzilla instance is a read-only archive of historic NetBeans bug reports. To report a bug in NetBeans please follow the project's instructions for reporting issues.

Bug 252069

Summary:	Optimize 'Background Scan' phase of the 'Open Project Group' action
Product:	projects	Reporter:	NukemBy
Component:	Maven	Assignee:	Tomas Stupka <tstupka>
Status:	NEW ---
Severity:	normal	CC:	markiewb
Priority:	P3
Version:	8.1
Hardware:	PC
OS:	Windows 7 x64
Issue Type:	ENHANCEMENT	Exception Reporter:
Attachments:	OpenProjects+BgScan.npss bgscan-CssIndexer$1-run-17800ms.png bgscan-QuerySupport-findRoots-17700ms.png bgscan-JavaCustomIndexer$Factory-scanStarted-7600ms.png bgscan-APTUtils-get-3500ms.png bgscan-IndexingSuport-isValid-2100ms.png bgscan-IndexingSuport-isValid-2100ms.png Switch+Project+Group-6mins.npss

Description NukemBy 2015-04-24 10:26:16 UTC

Created attachment 153356 [details]
OpenProjects+BgScan.npss

This is fork from that issues:
https://netbeans.org/bugzilla/show_bug.cgi?id=250833

Use-case is:

  - Start empty NetBeans and switch to a Project Group ...
  - ... it contains large multi-module MAVEN project (300 modules, 7000 source files).
  - It takes 1.5 minute to open and I feel there is some space to improve performance.

During  'Open Project Group' action there are two phases:
  1. Open Projects   - takes 45 seconds
  2. Background Scan - takes 40 seconds

This issue is about "phase 2" - "Background Scan".

Attached is the full selfsampler for the whole action. Part after first 45 seconds are relevant (with around last 2 seconds while I was stopping profiler).

Things that I feel can be improved:

* bgscan-CssIndexer$1-run-17800ms.png 
  --> bgscan-QuerySupport-findRoots-17700ms.png

  Really much time is spent in CssIndexer which in turn calls QuerySupport.findRoots() what consumes 99.5% of the CssIndexer.


* bgscan-JavaCustomIndexer$Factory-scanStarted-7600ms.png

  Most of the time it waits for something else, but there is some significant CPU usage to beginStandardTransaction()

* bgscan-APTUtils-get-3500ms.png

  It seems to me something is not well-cached here

Comment 1 NukemBy 2015-04-24 10:27:07 UTC

Created attachment 153357 [details]
bgscan-CssIndexer$1-run-17800ms.png

Comment 2 NukemBy 2015-04-24 10:27:29 UTC

Created attachment 153358 [details]
bgscan-QuerySupport-findRoots-17700ms.png

Comment 3 NukemBy 2015-04-24 10:28:09 UTC

Created attachment 153359 [details]
bgscan-JavaCustomIndexer$Factory-scanStarted-7600ms.png

Comment 4 NukemBy 2015-04-24 10:28:35 UTC

Created attachment 153360 [details]
bgscan-APTUtils-get-3500ms.png

Comment 5 NukemBy 2015-04-24 10:28:53 UTC

Created attachment 153361 [details]
bgscan-IndexingSuport-isValid-2100ms.png

Comment 6 NukemBy 2015-04-24 10:31:06 UTC

One more thing

* bgscan-IndexingSuport-isValid-2100ms.png

  Not sure what "isValid()" is doing, but it consumes 2 secs of CPU time. Seems too much for 'is' method.

Comment 7 NukemBy 2015-04-24 10:31:30 UTC

Created attachment 153362 [details]
bgscan-IndexingSuport-isValid-2100ms.png

Comment 8 NukemBy 2015-04-24 16:05:49 UTC

Created attachment 153376 [details]
Switch+Project+Group-6mins.npss

Comment 9 NukemBy 2015-04-24 16:17:05 UTC

One more use-case (around 6 minutes of total time) ...

- Opened a project group (300 modules)
- Attached to target JVM for debugging
- Noticed that i'm using wrong Project Group - target JVM process is running from 'release' branch, while i opened 'dev' branch
- Closed current 'dev' project group (set Project Group = none)

  ... 6 minutes start from here ...

- Started opening 'release' project group (same 300 modules, but with slightly different sources)
- Went away for coffee ...
- ... returned in around 2 mins hoping to start working and got background scan at only around '40%'
- Started Self profiler - bgscan progress bar was slowly going until 100% and after that (12:51:40 in selfprofiler) something was still bg-scanned without progressbar for around 50 seconds.

Selfprofiler is attached - Switch+Project+Group-6mins.npss

Did not try to dig deep this time. Just noticed that JsfCustomIndexer took around 80 seconds of CPU time.