Closed Bug 123947 Opened 23 years ago Closed 23 years ago

startup (ts) and new window (txul) both increased 1.8%

Categories

(Core :: Networking: File, defect, P1)

Product:
Core
Component:
Networking: File
Type:
defect

Tracking

()

Status:
RESOLVED FIXED
Milestone:
mozilla0.9.9

People

(Reporter: cathleennscp, Assigned: cathleennscp)

Details

(Keywords: perf, regression)

Attachments

(2 files)

graph of bz backout
3.69 KB, image/png
Details
Patch to apply to current trunk to back me out
85.92 KB, patch
Details | Diff | Splinter Review 
between 2/4 9:30pm and 2/5 4am, ts and txul increased about 1.8% each.

sleekstack tinderbox showed

                   startup (ts)      new window (txul)
                   -----------        ----------------
2/4 17:58-21:28       5404                 1418
2/4 21:28-00:47       5446                 1439
2/5 00:47-03:35       5491                 1444
2/5 03:35-04:10       5501                 1449


Here is a list of check-in during 21:28-00:47 build
http://tinderbox.mozilla.org/bonsai/cvsquery.cgi?module=MozillaTinderboxAll&date=explicit&mindate=1012873920&maxdate=1012886879

CC'ing everyone on the check-in log.  We need everyone to re-exame their
check-in, and let us know if you caused or didn't cause the regression.
Keywords: perf, regression
Summary: startup (ts) and new window (txul) both increased 1.8% → startup (ts) and new window (txul) both increased 1.8%
All I did was back out a fix I checked in the previous day, so not me.
My change _could_ have made some string comparisons slower....  It would make it
faster to tell if A and B are different strings and a maybe a tiny bit slower to
tell that they are the same string.

Can someone run the performance tests with my changes in and out?  I don't
really have a way of testing that...
i recall checking ts and txul after my checkin, and it appeared to have no
visible effect.
I had a look at both my changes and AFAICT neither could impact performance in
any way what so ever. One of the checkins affect default values for a few
properties on some HTML elements that I doubt are even accessed when starting
mozilla, and the other one fixes up cloning of document fragments, which I also
doubt we ever do in mozilla.
I tried backing out my patch locally.

Before my changes landed:

Startup (ms): 5437 3649 3827 3021 3078 2954 3650 3272 3383 3084
Average: 3535
Median:  ~3330

openingTimes=1056,1013,1025,1034,1034,1000,1033,1030,1033
avgOpenTime:1029
minOpenTime:1000
maxOpenTime:1056
medOpenTime:1033
__xulWinOpenTime:1033

After my changes landed:

Startup (ms): 4128 3708 3027 3361 3670 3611 3585 3067 3622 3554
Average:  3533
Median: ~3600

openingTimes=1044,1107,1069,1000,1038,1021,1054,1009,1019
avgOpenTime:1040
minOpenTime:1000
maxOpenTime:1107
medOpenTime:1038
__xulWinOpenTime:1038

It _looks_ like I may be the culprit but someone who is used to making sense of
this data should look.
More testing for WindowOpen (3 tests each without my patch and with it) shows:  

Without my changes:

avgOpenTime:1029
minOpenTime:993
maxOpenTime:1067
medOpenTime:1042
----
avgOpenTime:1024
minOpenTime:993
maxOpenTime:1053
medOpenTime:1024
----
avgOpenTime:1037
minOpenTime:1010
maxOpenTime:1077
medOpenTime:1037

With my changes:

avgOpenTime:1027
minOpenTime:1000
maxOpenTime:1046
medOpenTime:1027
----
avgOpenTime:1034
minOpenTime:1002
maxOpenTime:1075
medOpenTime:1033
----
avgOpenTime:1032
minOpenTime:1020
maxOpenTime:1051
medOpenTime:1030

Conclusion:  My change does not affect window open significantly.
Off to test startup in more detail next.  
More startup numbers _with_ my patch:  

3643 3689 3171 3336 2935 3675
Average: 3408
Median: ~3400

The noise in the data is so high, I'm not sure what to make of it.... :(
There's no way it was my checkin, xbl form controls wouldn't affect startup.

I can run a tinderbox in test-mode for any set of changes;
if you have a patch you want to test send me some mail.
Attached image graph of bz backout — 
middle hump is bz's changes backed out, so Ts looks like him.
Txul is mostly flat/noisy, too hard to conclude anything.
--> bz

based on mcafee's test data from tinderbox, looks like fix for bug 115289
Compare() to Equals() slowed down startup.
Assignee: cathleen → bzbarsky
Status: NEW → ASSIGNED
Priority: -- → P1
Target Milestone: --- → mozilla0.9.9
I'm confused by the graph, actually... let me see if I get this straight:

1)  The part before about 02:45 on 02/08 is a build from _before_ I landed my
    string changes or a build with my string changes backed out.
2)  The part after that time/date includes my changes
3)  Things happening after noon on 02/08 are irrelevant

mcafee, that correct?
the graph has data in three spots, ABA.
A=trunk build, B=your backout.  B is the middle data.

Boris, can you attach a non-backout version of your patch?
I can try this again on another tbox if you like.

I think it would be just as fast for you to just back the stuff
out, see what all the numbers do, and possibly check it back 
in again if the numbers don't move.  We will have to do some of
this, I don't think this is such a bad thing.
OK, this is a patch to apply to the current trunk to back out my string
changes.

I'm going to try landing it in pieces over the weekend for a few cycles at a
time to see which part may be causing issues...
Backing out boris made no difference. I suggest trying danm's 14:27
checkin next. I've emailed him.

I allowed biesi to check in fix for Fabian's smoketest blocker since
his checkin didn't seem to be responsible for the slowdown and backing
out only from mozilla.org would break the commercial tree.
OK, I've relanded my patch since backing it out did nothing.  Looking at the
checkin list the most likely next culprits are the nsFileChannel changes by
rpotts for Ts, I think.....
-> rpotts
Assignee: bzbarsky → rpotts
Status: ASSIGNED → NEW
he nsFileChannel changes were backed out the next day... due to other
regressions :-(

So, if the startup time didn't get better the next day, it wasn't me ;-)

-- rick
Umm...we seem to be out of candidates.
-> cathleen (again)  sorry :-(
Assignee: rpotts → cathleen
rpotts, what was the timeframe your backout happened?  
If it's late afternoon, there appear to be a drop in startup on most tinderboxes...
The change was backed out in rev 1.117 at 16:28 pm

http://bonsai.mozilla.org/cvslog.cgi?file=mozilla/netwerk/protocol/file/src/nsFi
leChannel.cpp
the time frame sounds about right, correspond to tinderbox drop.  
I will verify.  :-)
hey cathleen,

let me know if *all* the time was associated with the FileChannel change... 
cause i'm going to have to re-land it once i figure out why linux hung ;-)

-- rick

tinderbox doesn't display check-in logs for that many days back...  it's going
to be a hard one to figure out.  

(wish we had known about the backout, or rick had watched the numbers :-( )

mcafee, do you know any tinderbox trick that can help figure this one out?
so are the current tinderbox numbers 'normal'?  or are we still slower than we
were before?

bonsai can show you any checkins back to the beginning of time.. I seem to be
able to go back over a week with the "Show Previous 24 hours" link at the bottom
of tinderbox...
so, can this bug be closed until i re-land my nsFileChannel changes ;-)

I promise to look into why more time is being spent on startup before they land
again :-)

-- rick

alecf: as you go back in time, tinderbox tends to lose the vertical
information and just lumps everyone into one checkin window.
It's probably a bug, or we're not keeping status somehow.
assuming this is fixed, since rpotts backed out around the time we saw a drop in
perf graph.
Status: NEW → RESOLVED
Closed: 23 years ago
Resolution: --- → FIXED
Component: XP Miscellany → Networking: File
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Creator:
Created:
Updated:
Size: