Closed Bug 27510 Opened 23 years ago Closed 21 years ago

[tracking] Too much read from disk on startup

Categories

(Core :: XPCOM, defect, P3)

x86
Windows NT
defect

Tracking

()

RESOLVED FIXED
mozilla0.9.8

People

(Reporter: bratell, Assigned: dveditz)

References

Details

(Keywords: perf)

I looked at Windows 2000's "bytes read"-meter and noticed that Mozilla reads 
26,261,410 bytes just to open the "choose profile"-window. Then it goes up 
to 30,148,823 when opening the first browser window. That's a little too much I 
think. 

I had no idea where to send this performance bug, so please reassign it to 
whoever can have a look at this issue.
Compare with Netscape 4.71 which reads less than 1 MB during startup. 600 KB 
something if I remember correctly.

My measurements where done with a debug build by the way, which probably added 
some MB to the numbers.
Keywords: perf
Chris, do you already have numbers that would narrow this down a bit?  I doubt 
that it's profile manager specific, we're just lucky enough to open the first 
window...
Assignee: selmer → waterson
I did an analyze with ntfilemon from http://www.sysinternals.com and then let 
the log go through a program that summarized the information. The result can 
be found in http://a27.ib.student.liu.se/mzbytes2.txt where the number is the 
number of read bytes.  The most interesting part I think is the top line:

FILE                                                         BYTES
G:\mozilla\\mozilla\dist\WIN32_D.OBJ\bin\component.reg      33718272
J:\WINNT\mozregistry.dat                                      380928
G:\mozilla\\mozilla\dist\WIN32_D.OBJ\bin\res\wincharset.properties 327680
J:\WINNT\nsreg.dat                                            253952

33 MB seems a little strange. Can that be true? In that case something must be 
really wrong. The lines in the log adding up to the 33 MB is lines like:
397 20:28:45 mozilla.exe:508 FASTIO_READ 
G:\mozilla\\mozilla\dist\WIN32_D.OBJ\bin\component.reg SUCCESS Offset: 262144 
Length: 65536

This analyze doesn't include anything loaded by the system by the way. I might 
do an analyze including system I/O tomorrow, but now it's getting late.

I'll change component to XPCOM Registry. It can't be more wrong than "Profile 
Manager".
Component: Profile Manager BackEnd → XPCOM Registry
This may be a known problem (I seem to remember there being some discussion
about the registry being read many times at startup).

Question: were these results collected on the "first run"? (During which
component autoregistration may have caused several passes through the registry?)
Or was it on a "subsequent run" (during which autoreg should have -not- been
performed)?
Assignee: waterson → dp
QA Contact: gbush → leger
It was a subsequent run. As if I could get it right the first time? :-)
Nothing in the debug console output that mentions any registration problems 
either.
AutoReg is run each time, only the SelfRegister step is skipped for already 
known .DLL's.  Beta bug 12817 deals with this.

That won't help *this* problem, though, because we always need to read the 
registry data. Beta bug 15115 covers this issue.
Assignee: dp → dveditz
I'm NOT closing this as a duplicate of bug 15115, instead I'll make it a 
dependency. There is something else going on here too (the .properties file for 
one) that will probably be clearer once 15115 is out of the way. That one is 
definitely the bulk of the problem, though -- we need a different registry 
format.
Depends on: 15115
I've finally done a new measurement including system and it looks much better
now. The reading of the registry is down from more than 30 MB to "only" 11.5 MB.
The bad news is that still is too much too be good. A new offender is
history.dat that is read in full no more than six times (according to the amount
of data read).

The full list can be found at <http://a27.ib.student.liu.se/mzbytes3.txt>. The
top is:

%MOZROOT\component.reg                                     11526144
%MOZPROFILEROOT\Users50\mozProfile-1\history.dat             458752
%MOZROOT\res\wincharset.properties                           327680
%MOZROOT\chrome\navigator\locale\en-US\navigator.dtd         131072
%MOZROOT\chrome\global\skin\default\animthrob_single.gif     131072

Keywords: helpwanted
Summary: Too much read from disk on startup → [Help Wanted] Too much read from disk on startup
Target Milestone: M16
Depends on: 30753
Blocks: 7251
M16 has been out for a while now, these bugs target milestones need to be 
updated.
bratell@lysator.liu.se can you test the newest build and post here the results? 
Now I've tested a new build (from CVS this night) and things looks the same or 
even a little worse. We still read component.reg way too much. We are now at 15 
MB after being as low as 11 MB. The measurements were made on a run with no 
registration of components. If measuring the first run, things are way worse.

component.reg                                            15794176
mozregistry.dat                                            126976
packages\core\communicator\content\bookmarks\bookmarks.js   87862
components\xpti.dat                                         86522
chrome\skins\modern\global\skin\animthrob.gif               85842
chrome\packages\core\navigator\content\navigator.js         50594
...
TOTAL                                                    17417967

The full list is on <http://caesar.homeip.net/mzbytes4.txt> (the previous lists 
are now on <http://caesar.homeip.net/mzbytes2.txt> and 
<http://caesar.homeip.net/mzbytes3.txt>).

Also clearing milestone field since M16 is long since gone.
Target Milestone: M16 → ---
dveditz...you'll need to mark verified if fixed.
Keywords: verifyme
QA Contact: leger → dveditz
Clearing verifyme keyword, this has not been fixed and thus cannot be verified.

kandrot is working on the component.reg part of the problem under another bug
Keywords: verifyme
Depends on: 46707
Depends on: 74815
Anyone want to work on this?  Cc'ing neo-dp.

/be
I'll be working on parts of this as well...
Glad to help. May be Dan can direct/coordinate.
No longer blocks: 7251
Blocks: 7251
The old items mentioned here are more or less fixed (will look at bug 46707).
I'm sure more can be done but it's much better to identify individual items and
hang them off this one than to keep piling on. Calling this a meta bug.
Depends on: 76329
Keywords: helpwantedmeta
Summary: [Help Wanted] Too much read from disk on startup → [tracking] Too much read from disk on startup
Target Milestone: --- → mozilla0.9.8
The old items have been fixed, and the performance team has filed new bugs as
new things are found. FIXED
Status: NEW → RESOLVED
Closed: 21 years ago
Keywords: meta
Resolution: --- → FIXED
No longer depends on: 46707
Component: XPCOM Registry → XPCOM
QA Contact: dveditz → xpcom
You need to log in before you can comment on or make changes to this bug.