Created attachment 152329 [details]
pack of selfsampler
es) and experience weird performance issues with this.
I can’t share sources of my project, but I’ve created similar setup using ‘open-source’ apache maven projects.
Below are the use-cases (Netbeans & Java x64 - -J-XX:PermSize=256M -J-Xmx3500M, Win7, intel Core i5-3470 3.2GHz, sources are on SSD drive).
1. Extract BackgroundScan.zip
2. Launch get-sources.cmd (script is for Findows, for linux has to be converted to *.sh)
3. After all sources are downloaded ...
4. ... Open root module in 1_all\pom.xml -> right-click
-> Open All Required Projects
-> then Close IDE – (wait until modules are opened,
but do not waiting for background scan to start)
5. Start NetBeans - it will start reopening last workspace
6. ... around 1 minute takes "opening of projects" – this is the message in status bar.
Of this time
a. 30 seconds progress bar does not appear
(see: selfsampler - opening project - 0 - starting.npss)
b. 30 seconds something happens with progress bar going from 0 to 100%
(see: selfsampler - opening project - 1 - in-progress.npss)
7. ... after that message "Background scan of the projects" appears – it takes *6 minutes*
8. Close IDE and Start it once again ...
9. ... "opening of projects" again takes around 1 minute
10. ... "Background scan" finished in around 15 seconds (that is good timing)
11. Close IDE
12. Go to "1_all" and execute
mvn -fae install -Dmaven.test.skip=true
this builds all source modules, some errors are possible but I don’t care
for this test – build takes really long (mostly to download required.
artifacts). To speedup build same command can be executed in parallel
in each sub-folder, these sources are independant.
13. After build is finished - start IDE once again ...
a. ... "opening of projects" takes around 1 minute as usual
b. ... "Background scan" runs around 6 minutes instead of 15 seconds
(why it takes so long? - i've captured selfsampler "bg-scan"
at 1%, 10% and 100% - last 100% took around 30 seconds)
14. Restart IDE once again ...
a. ... "opening of projects" takes around 1 minute as usual
b. ... "Background scan" runs around 1:30 minutes ...
15. Now try creating new empty project – it will take around 30 seconds
(just to close current modules). This means switch between workspaces is a real pain.
These were use-cases I was able reproduce more-or-less stably.
Below are the problems I experience from time to time, but I do not
have stable way to reproduce:
1. Initial background scan of the sources takes around 6 minutes
2. On my particular project I’m receiving following message in IDE log
"Invalidating facelets libraries due to a library descriptor change"
Comes from: web.jsf.editor\src\org\netbeans\modules\web\jsf\editor\facelets\FaceletsLibrarySupport.java
In regular conditions background scan finishes in around 1:30 minutes
and I get around 5 such messages, but sometime loading takes 6-10 minutes
and I get plenty (100..200..???) of such messages
3. After refactoring/renaming method in IDE 'background scan' typically takes
around 5 seconds and prevents renaming of next method until scan
is completed. Sometime scan also runs unexpectedly long – minute or so.
PS: I've tried to see what NetBeans is doing during "background scan" ... it appears that on compiled maven projects NONE of .java files are read during opening of project and scan (i used process monitor to identify that - https://technet.microsoft.com/en-us/library/bb896645.aspx, applied filter "Operation" contains "Read", "Path" ends with ".java"). This sounds weird to me.
Created attachment 152330 [details]
Created attachment 152348 [details]
20 seconds of self sampler while bg scan was running for 10 minutes
Created attachment 152349 [details]
IDE log for the same
Created attachment 152350 [details]
Hot points from the npss attached before
Created attachment 152351 [details]
Hot points from the npss attached before - dig deeper
Things sometime are getting worse - for no obvious reason today that same "test apache project" was bg-scanned for 10+ minutes.
The only difference between previous test is the way i get to opening that project:
1. Start NB with project group containing my production MAVEN projects - ~300 modules, 7000 files.
2. Switch to "(none)" Project Group
3. Switch to "Apache Test" project group - bg scan was running for more than 10 minutes
Somewhere in-between I've started SelfProfiler - i was not surprised that almost all time goes into MAVEN-related classes - see https://bugzilla-attachments-250833.netbeans.org/bugzilla/attachment.cgi?id=152350.
Created attachment 152355 [details]
Capture from process monitor - see: https://technet.microsoft.com/en-us/library/bb896645.aspx
According to process monitor - during 15 seconds of bg scan NB queried attributes of various folders 213000 times - 14200/second (All of these are calls to parent operating system). Such implementation cannot be quick.
Which version of the JDK are you using? Can you use the latest one and try this process again?
On the daily basis I'm using Jdk7 (1.7.0_72), because my production project is still on Java7. I've started NB with Java8-u32/x64 and have got absolutely same behavior as on Java7, and by the way have reproduced another strange problem - it looks like in-memory "indexes" keep alive after switching to another Project group.
Here are the steps i did right now:
1. Started NB (with Java8)
2. It opened last "Project Group" - it was the "my production one"
3. I switched to the "(none)" Project Group, waited until all processes are stopped
4. I switched to "big Apache" test Project Group - background scan is currently still running for somewhat 10+ minutes and ... I see plenty of messages "INFO [FaceletsLibrarySupport]: Invalidating facelets libraries due to a library descriptor change." in IDE log. I've never seen this message with "Apache sources" when I open that project in fresh IDE (on startup). This means that my initial "production project" which was opened initially still somehow affects scanning of currently open "Apache" project, but they are compleeetly unrelated.
Created attachment 152378 [details]
selfsampler with "Invalidating facelets libraries due to a library descriptor change"
Created attachment 152379 [details]
selfsampler with "Invalidating facelets libraries due to a library descriptor change" (screenshot)
BTW: my sources have nothing to do with JSF - I have no idea why JSF comes in during background scan.
And one more weird thing, just got into that use-case ...
If I close NB with Project Group full of Maven modules and then start it - initial opening and bg scan of that project group takes at least 2+ minutes. (this is my typical performance test).
If I close NB with "(none)" Project Group (i.e. NB is empty), Start empty NB and only then switch to Project Group with plenty of Maven Modules - "opening of the projects" takes 35 seconds (vs. typical 60-65 seconds) + "bg scan" completes in 15 seconds (vs 1:00..1:30 minutes) - with total of 50 seconds. Tested this twice with the same result. Isn't it strange? Why same action has such different performance?
We will look at this problem.
Not sure, this problem can be partially related -
thanks for the thorough report
lets summarize the particular problems:
1.) external mvn install causes a long background scan in a subsequent IDE start
at least in the given example the mvn install command generates java files which then have to be scanned. This of course takes longer as when there are no new or modified files. You can also compare the particular log output ...
a bg scan right after mvn install was executed before IDE start
Complete indexing of 1,615 source roots took: 293,052 ms (New or modified files: 1,823, Deleted files: 0)
a bg scan after a restart when everything was already scanned and no files were changed
Complete indexing of 1,613 source roots took: 31,013 ms (New or modified files: 0, Deleted files: 0)
2.) closing project group with many mvn projects takes a long time
i believe this is tracked in issue #250869
3.) some long background scans correlate with many JSF related logs even though there are no JSF related projects opened in the IDE
seems like JFS is jumping into scanning even though it doesn't have to.
Filed a separate issue #251973
as a workaround - you can try to deactivate the JSF in your IDE
4.) sometimes refactorings cause an unusually long background scan
the time necessary to rescan depends on how many files were affected by the particular change. If a significant part of your projects was touch by the refactoring then also the scan will take a while. In case you think there is something specific to it and that it perhaps isn't addressed by other points at this place then feel free to file a new issue. Please, if possible, also attach a complete snapshot and message.log from such refactoring action.
5.) switching big project groups triggers an unusually long scan
unfortunately, we weren't able to reproduce - each try resulted into times in accord with the times listed in 1.) - if there were no touched files then the overall scan time did not overreach what would be expected
6.) project open and scanning times differ when starting NB with a project group vs starting NB with no project opened and switching to a project group afterwards
similar as in 5.) we weren't able to properly reproduce. There was a slight difference between those two times (starting with none and switching to PG was aprox 13%-25% faster then starting directly with a PG). Please note that while it seems to be the same actions, things might differ on implementation level as well as in interference with other IDE processes during and right after startup (actually this action was also a big longer). Do far hard to say what could be the particular problem ...
7.) MavenForBinaryQueryImpl is heavy on work during bg scan (https://bugzilla-attachments-250833.netbeans.org/bugzilla/attachment.cgi?id=152350)
There might be some potential for a faster performance but not sure about possible side effects and afaik those particular calls are happening only during some phases and it probably won't have any dramatic effect on the overall time. Filed issue #251990 to cover that
will close this as worksforme as the to be fixed problems are now tracked in separated issues
Thanks for attention to this issue.
Will recheck behavior after MavenForBinaryQueryImpl$BinResult.getRoots() problem will get fixed.
I've checked current status. It seems that fixing MavenForBinaryQueryImpl.getRoots() reduced time of bgscan from 1.5 minutes to around 40 seconds. Thanks.
Meanwhile overall 1.5 minutes to open the project still seems to me to be too long for that action. I've analysed current selfprofiler on my real project and filed 2 other issues:
Optimize 'Open Projects' phase of the 'Open Project Group' action
Optimize 'Background Scan' phase of the 'Open Project Group' action