We consistently observe ~105 regression in initial scanning time of Limewire project . E.g. measured here: http://wiki.netbeans.org/NB69ScanningMeasurements
Here are fresh numbers with current build (measured time of first opening of project till scanning is finished - via stopwatch, also added times reported by RepositoryUpdater).
* 107.3s (complete indexing 46 binary roots: 16765ms, 2 source roots: 81750ms)
* 106.2s (complete indexing 46 binary roots: 17937ms, 2 source roots: 85969ms)
* 111.9s (complete indexing 46 binary roots: 18030ms, 2 source roots: 86219ms)
NB 6.9 201005132200
* 119.1s (complete indexing 46 binary roots: 20328ms, 2 source roots: 90125ms)
* 118.7s (complete indexing 46 binary roots: 19797ms, 2 source roots: 90625ms)
* 118.9s (complete indexing 46 binary roots: 20313ms, 2 source roots: 90437ms)
Going to attach messages.log with detailed info. Not able to create comparable NPS yet, sorry.
Created attachment 99119 [details]
log from NB 6.8
Created attachment 99120 [details]
log from NB 6.9
From 6.8's log:
Indexing of: jar:file:/C:/BuildNB1/ide12/jsstubs/allstubs.zip!/ took: 3843 ms (New or modified files: 189, Deleted files: 0)
Indexing of: file:/D:/Projects/NetBeans/lime_69/lime6/src/ took: 80954 ms (New or modified files: 2531, Deleted files: 0)
From 6.9's log:
Indexing of: jar:file:/C:/BuildNB2/ide/jsstubs/allstubs.zip!/ took: 5859 ms (New or modified files: 189, Deleted files: 0) [Adding listeners took: 0 ms]
Indexing of: file:/D:/Projects/NetBeans/lime_69/lime6/src/ took: 86453 ms (New or modified files: 2531, Deleted files: 0) [Adding listeners took: 500 ms]
According to the release rules (please correct me if I'm wrong) this is a post cut-off P2, which means no waiver is needed. And on the performance meeting on Monday we all agreed that this is not a release stopper, which means that we are not going to escalate it to P1.
Not a stopper, does not have to be waived, IMO...
I've managed to create profiling snapshots with the same sampling method in both IDEs, attaching.
Created attachment 99134 [details]
snapshot from 6.8
Created attachment 99135 [details]
snapshot from 6.9
The 6.9 snapshot seems strange - there does not seem to be any indexing activity. Isn't it snapshot from first editor opening?
Created attachment 99140 [details]
correct snapshot for 6.9
Attached something else for 6.9, sorry. Here it is...
As for different slowdown for the 2 source roots (allstubs.zip and lime6/src): note that they are processed in different order. NB 6.9 starts with allstubs.zip, so might be just warming up on it...
Well, comparing the snapshots I think we can safely attribute the slowdown to the new javac...
parse: 32316 vs 34096 ~ +5.5%
generate: 26746 vs 26510 ~ -0.01%
analyze: 5585 vs 5514 ~ -0.01%
enterTrees: 3550 vs 6111 ~ +72%
total: 73516 vs 79713 ~ +8%
(In reply to comment #4)
> I've managed to create profiling snapshots with the same sampling method in
> both IDEs, attaching.
Thanks a lot for the snapshots, Tomasi!
Here are some observations:
- scanBinaries 19124ms vs 20804ms
but in 6.9 seems to be a new SpringBinaryIndexer (1931ms)
-scanSources 87599ms vs 96767ms
-Crawler.getResources() 6567ms vs 6914ms but in average with rest of the methods except index the same.
-index 80824ms vs 89240ms
-JavaCustomIndexer 75239ms vs 82012ms
-parse 31209ms vs 33576ms
-FileInputStream.<init> 26243ms vs 28740ms - the additional work done by TopSecurityManager
-addAptGenerated - 1767ms new and can be removed when no apt and probably optimized for apt by some contract among FM and CW.
-enterTrees 3550 vs 6053 - apt related - Dusan know how to improve this when no ap.
-COSIndexer - takes longer time, but it seems to be the first to initialize libraries - not important
-indexEmbedding 3574ms vs 5553ms
-JSIndexer 847ms vs 1763ms - TokenSequence.moveNext 18ms vs 544ms
-HtmlIndexer seems to be added or it's slower
> but in 6.9 seems to be a new SpringBinaryIndexer (1931ms)
But Limewire does not use Spring, right? So there should not be any penalty; Spring support should not cause slowdown for projects that don't use Spring. Or, only very minimal slowdown.
HtmlIndexer is new to 6.9; indexing of only 3 files took 620ms which is quite a lot.
Even given the fact that the time contains initialization of one DTD model (269ms) which also involves classloading.
There are also two calls to HtmlGSFParser.parse() which took 91ms.
As for the HTML indexing I forgot to mention that a significat portion of the time is spent in classloading. Since there are only four indexed html files in the project the aggregated time may seem to be quite high per file. But if the classloading and initializations which happens only once per ide session are substracted, the performance seem reasonable to me. Given that I do not plan to do any improvements on this area.
So, it seems that SpringBinaryIndexer is not efficient since it is checking for org.springframework.core.SpringVersion class inside every
library. The idea was to collect all xsd inside spring jars to use them in code completion in spring config files. But it seems that presence of the spring framework should be checked somehow (or at least the name of the library), before searching the class inside the library.
Added fix which should decrease the scanning time
The javacard's annotation processor no longer uses the hardcoded APs approach:
APT processing should not bring any overhead when there no processors to run:
Integrated into 'main-golden', will be available in build *201005260001* on http://bits.netbeans.org/dev/nightly/ (upload may still be in progress)
User: Jan Lahoda <email@example.com>
Log: #186285: javacard's annotation processor should run using standard AnnotationProcessorQuery.Result, rather than hardcoded processors.
I assume this is now fixed.
6.8 FCS: 110179ms
6.9 FCS: 133865ms
*** Bug 182297 has been marked as a duplicate of this bug. ***
The fix has been ported into the release691 branch.
verified in 6.9.1