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 45899 - Startup time regression of the very first start
Summary: Startup time regression of the very first start
Status: CLOSED FIXED
Alias: None
Product: platform
Classification: Unclassified
Component: Filesystems (show other bugs)
Version: 4.x
Hardware: PC All
: P2 blocker (vote)
Assignee: rmatous
URL:
Keywords: PERFORMANCE
Depends on:
Blocks: 49990
  Show dependency tree
 
Reported: 2004-07-07 18:40 UTC by Antonin Nebuzelsky
Modified: 2008-12-22 23:56 UTC (History)
3 users (show)

See Also:
Issue Type: DEFECT
Exception Reporter:


Attachments
A log showing repetitive refreshes and thread dumps (4.22 MB, text/plain)
2004-10-12 09:18 UTC, Petr Nejedly
Details

Note You need to log in before you can comment on or make changes to this bug.
Description Antonin Nebuzelsky 2004-07-07 18:40:14 UTC
There was a startup time regression introduced in
trunk between 5/13 and 5/20 for the very first
start (when new userdir is populated).

Profiler analysis, changelog searching and trial
runs with changed code removal shows that the fix
of issue 40762 (The Refresh Folder action should
check modified data files) causes the major (if
not the whole) part of the regression.
Comment 1 rmatous 2004-07-22 08:53:38 UTC
I believe this fix is right and shouldn't be reverted. I don't think
that in this case should be tracked regression because the previous
implemention was confusing, wrong and insufficient. Fixing it corrent
means also to pay for it. 

So don't consider regression but if this piece of code is
significantly slow in absolute time and can have negative impact then
 change summary add additional information and reopen.
Comment 2 Antonin Nebuzelsky 2004-08-11 10:24:07 UTC
Reopening.
Comment 3 Antonin Nebuzelsky 2004-08-11 10:24:30 UTC
Petre, please, investigate.
Comment 4 _ ttran 2004-09-07 09:01:57 UTC
Petr: what's the status of this bug?  Are you working on it?
Comment 5 Petr Nejedly 2004-10-07 14:28:46 UTC
Trung: No, I was fixing other P2's around.
I've started analysing this one deeper yesterday.
Comment 6 Petr Nejedly 2004-10-11 13:17:29 UTC
So my findings are these:
On the first start, we lose following amount of time in parts:
A) +200ms    ModuleList.read
B) +400ms    setURLs
C) +400ms    moduleInstalls
D) +1000ms   WinSys

On the other hand, we're actually faster in some places, so the final
time is +1.5s (7600 -> 9131) acc. to measurements on my Dell NB.

ad A) this is quite proportional to the increased number of processed
XMLs, 92 modules -> 118 modules

ad B) This clearly comes from Radek's change in AbstractFolder. If I
rollback his change, I get times much closer to release 3.6.
This is a regression and a bug! because additional time is spent
neither in parsing the layers nor in creating the binary image but
rather in firing/processing events from setDelegates. The overhead
caused by fixing 40762 should not apply here as no files on the disk
are actually touched and all that could happen is (properly reported)
"new" file added.

ad C) Most of the time here comes from new modules like
project.libraries, javacore, javaproject, j2seplatform
It is similar for subsequent starts as well
This part is probably currently investigated deeper by Radim


ad D) both WS loading and WS showing is slowed by about 500ms.
200ms of loading can be attributed to Radek's change, but the rest is
WinSys related (more functionality, more classes, ...)

Would it be possible to deactivate Radek's fix for SysFS?
Do we really care about external modifications of SysFS?
Reassigning to Radek as 600ms can be quite clearly attributed
to his fix of issue 40762 and can probably be worked-around.
Comment 7 rmatous 2004-10-11 15:21:36 UTC
Read-only files are excluded from refresh which should solve the
problem with setDelegates in ModuleLaye...FS.

/cvs/openide/src/org/openide/filesystems/AbstractFolder.java,v  <-- 
new revision: 1.84; previous revision: 1.83

Marked as fixed. Please verify and reopen if this fix isn't sufficient.
Comment 8 Petr Nejedly 2004-10-11 22:19:15 UTC
Won't help. The refresh is performed on FOs directly on SystemFS,
which is not r/o.
Anyway, I've added logging there athe the results were very
interesting: There were several tens of refreshes of just two folders!
The SFS:// and SFS://Modules/ were refreshed 35 times each and it
consumed most of the time in setDelegates call.
(please note that the Modules folder is probably the only SFS folder
populated so early in the startup cycle)
Comment 9 Petr Nejedly 2004-10-12 09:18:33 UTC
Created attachment 18218 [details]
A log showing repetitive refreshes and thread dumps
Comment 10 rmatous 2004-10-12 09:47:03 UTC
Why there is called refresh on FileObjects from XMLFileSystem. AFAIK
XMLFileSystem shouldn't be commonly used. Something seems to be wrong
with your setup.
Comment 11 Petr Nejedly 2004-10-12 10:23:10 UTC
Nothing wrong. There is one XMLFS used as an empty FS placeholder.
It is never filled with anything and has no children.
It is unrelated to this setDelegates problem.
Comment 12 rmatous 2004-10-21 11:02:15 UTC
/cvs/openide/src/org/openide/filesystems/AbstractFolder.java,v
new revision: 1.87; previous revision: 1.86

According to my meassurement this fix enhance performance of the very
first start significantly.

Moreover this fix seems to be right because refresh on MultiFileObject
invokes refresh on its delegates anyway.
Comment 13 Petr Nejedly 2004-10-21 15:17:09 UTC
OK, the time spent in setDelegates() is at the 3.6 level again.
Comment 14 _ rkubacki 2004-10-25 08:28:23 UTC
Actual results from our automated tests: 
WinXP 18.2 -> 17.0
Solaris 23.0 -> 21.2
JDS 2 15.2 -> 14.1
Win2K 16.2 -> 15.0