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.
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.
--> 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.
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...
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.....
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
Last Resolved: 17 years ago
Resolution: --- → FIXED
You need to log in before you can comment on or make changes to this bug.