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

RESOLVED FIXED in mozilla0.9.9

Status

()

Core
Networking: File
P1
normal
RESOLVED FIXED
16 years ago
13 years ago

People

(Reporter: Cathleen, Assigned: Cathleen)

Tracking

({perf, regression})

Trunk
mozilla0.9.9
perf, regression
Points:
---

Firefox Tracking Flags

(Not tracked)

Details

Attachments

(2 attachments)

(Assignee)

Description

16 years ago
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.
(Assignee)

Updated

16 years ago
Keywords: perf, regression
Summary: startup (ts) and new window (txul) both increased 1.8% → startup (ts) and new window (txul) both increased 1.8%

Comment 1

16 years ago
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...

Comment 3

16 years ago
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.

Comment 9

16 years ago
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.

Comment 10

16 years ago
Created attachment 68675 [details]
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.
(Assignee)

Comment 11

16 years ago
--> 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?

Comment 13

16 years ago
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.
Created attachment 68725 [details] [diff] [review]
Patch to apply to current trunk to back me out

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...

Comment 15

16 years ago
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.....

Comment 17

16 years ago
-> rpotts
Assignee: bzbarsky → rpotts
Status: ASSIGNED → NEW

Comment 18

16 years ago
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

Comment 19

16 years ago
Umm...we seem to be out of candidates.

Comment 20

16 years ago
-> cathleen (again)  sorry :-(
Assignee: rpotts → cathleen
(Assignee)

Comment 21

16 years ago
rpotts, what was the timeframe your backout happened?  
If it's late afternoon, there appear to be a drop in startup on most tinderboxes...

Comment 22

16 years ago
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
(Assignee)

Comment 23

16 years ago
the time frame sounds about right, correspond to tinderbox drop.  
I will verify.  :-)

Comment 24

16 years ago
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
(Assignee)

Comment 25

16 years ago
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?

Comment 26

16 years ago
so are the current tinderbox numbers 'normal'?  or are we still slower than we
were before?

Comment 27

16 years ago
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...

Comment 28

16 years ago
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

Comment 29

16 years ago
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.
(Assignee)

Comment 30

16 years ago
assuming this is fixed, since rpotts backed out around the time we saw a drop in
perf graph.
Status: NEW → RESOLVED
Last Resolved: 16 years ago
Resolution: --- → FIXED

Updated

13 years ago
Component: XP Miscellany → Networking: File
You need to log in before you can comment on or make changes to this bug.