1230280 - 2% Win7 e10s ts_paint, win8 paint regression on fx.team (v.45) on Nov 27, 2015 from push 19876a153a00

Status: RESOLVED INVALID

(Hello (Loop) :: Client, defect, P2)

Description

[Joel Maher ( :jmaher ) (UTC -8)]

A small ts_paint regression exists from some patches in bug 1223573 which landed on Nov 27th on fx-team.  After some retriggers:
https://treeherder.mozilla.org/#/jobs?repo=fx-team&filter-searchStr=talos%20e10s%20other%20win&fromchange=556ab9e3521b&tochange=d7152cc38e8f

we can see a compareview:
https://treeherder.mozilla.org/perf.html#/compare?originalProject=fx-team&originalRevision=f48352b311eb&newProject=fx-team&newRevision=19876a153a00&filter=ts_paint&showOnlyConfident=1

these are small regressions and from what I can tell the only real regressions coming from this specific push are the ts_paint ones.  These are small, but seem to be real (despite the large volume of noise- shifting patterns of noise!)

Comment 1

[Joel Maher ( :jmaher ) (UTC -8)]

Mark, sorry to bother you on so many bugs- finally catching up on all the alerts that have been coming in.  This is small- but we should see if there is something simple to fix this vs ignore it completely.  Maybe this is expected and we can have it documented here in this bug.

Comment 2

[Mark Banner (:standard8)]

Ok, so I'm guessing this is a similar issue to the size bug - there's extra initialisation going on for the add-on. We're also registering style sheets that we weren't before.

I'm not sure which would be the biggest impact - the add-on registration or the style sheets, but I would guess it could be either of them, and I doubt there's much we could do here.

Comment 3

[Joel Maher ( :jmaher ) (UTC -8)]

is there a quick check we could do to see if it is the registration or the style sheets?  The more we understand the better we can make decisions in the future even if there is nothing to fix for this specific issue.

Comment 4

[Mark Banner (:standard8)]

You could probably just comment it out in the code:

http://hg.mozilla.org/mozilla-central/annotate/5ba77225c957/browser/extensions/loop/bootstrap.js#l800

Perhaps not fully the same, but it might be close enough.

Comment 5

[Joel Maher ( :jmaher ) (UTC -8)]

pushed to try:
baseline: https://treeherder.mozilla.org/#/jobs?repo=try&revision=53859be1a511
removed code: https://treeherder.mozilla.org/#/jobs?repo=try&revision=3155506346cc

compare view: https://treeherder.mozilla.org/perf.html#/compare?originalProject=try&originalRevision=53859be1a511&newProject=try&newRevision=3155506346cc

I imagine in 2 hours we will have data- lets look at this then.

Comment 6

[Joel Maher ( :jmaher ) (UTC -8)]

ok, commenting out the style sheet code:
https://hg.mozilla.org/try/rev/de7d9e9896c5

didn't do the trick according to compare chooser:
https://treeherder.mozilla.org/perf.html#/compare?originalProject=try&originalRevision=53859be1a511&newProject=try&newRevision=3155506346cc&showOnlyImportant=0

We have pretty much identical results for the baseline and the commented out version.

Comment 7

[Brad Lassey [:blassey] (use needinfo?)]

Mark, are you tracking this?

Comment 8

[Mark Banner (:standard8)]

(In reply to Brad Lassey [:blassey] (use needinfo?) from comment #7)
> Mark, are you tracking this?

Roughly. Unfortunately I have very little experience of these perf tests so I've been relying on Joel.

I'm also not sure there is much that we can do about it - but that depends on where the issue is. Taking out the style sheets was my best guess. I guess we could try taking out most of bootstrap.js and see if anything changes.

Also cc'ing other folks who might have experience of this area.

Comment 9

[Mike Conley (:mconley) (:⚙️)]

I'll see if I can tease a profile out of this for you.

Comment 10

[Mike de Boer [:mikedeboer]]

I'll be driving this bug.

Mike, what kind of profile were you thinking about?

Comment 11

[Mike Conley (:mconley) (:⚙️)]

Bah - sorry I never got to this - holidays happened.

Pushed for profiling to try:

Without bug 1223573 ("good"): https://treeherder.mozilla.org/#/jobs?repo=try&revision=33a9120cc7a9
With bug 1223573 ("bad"): https://treeherder.mozilla.org/#/jobs?repo=try&revision=57eadf5209e7

Comment 12

[Mike Conley (:mconley) (:⚙️)]

Bah - and resetting the needinfo on myself to do the analysis once these come in.

Comment 13

[Mike Conley (:mconley) (:⚙️)]

Without bug 1223573 ("good"): http://people.mozilla.org/~bgirard/cleopatra/?zippedProfile=http://mozilla-releng-blobs.s3.amazonaws.com/blobs/Try/sha512/4a7716581f9e907b6de6c695dda90b52898c208285bdb03c20838c8cdca155731d99b30aeb3f1222a0d72b0fbfcb39e6da46e5da210db2b38c436bae3335b8eb&pathInZip=profile_ts_paint/startup/cycle_0.sps#report=fa9d39114117e8457e207ab0229cd65e7fd6ed88&javascriptOnly=true&selection=0,920

With bug 1223573 ("bad"): http://people.mozilla.org/~bgirard/cleopatra/?zippedProfile=http://mozilla-releng-blobs.s3.amazonaws.com/blobs/Try/sha512/b1057a5a693d509d49fe64cf285a14f84dfc268a08e0dcf6b5656d3c2bc0f32f8a4836c1cd2ba0a18478047b247fb321d566423f1c01ebae712780d6dab905f4&pathInZip=profile_ts_paint/startup/cycle_0.sps#report=0ece5dfba1e78d98fb685e19db7a91168f0bd81e&javascriptOnly=true&selection=0,878

What I'm seeing is us greatly increasing the amount of time inside AddonManager's _startProvider method. Specifically, the "createLoopButton" call causes CustomizableUI to initialize itself, which starts up some expensive machinery.

mikedeboer, if you're going to investigate this, I suggest looking at the samples inside the AddonManager startup stuff in the "bad" profile, and see how things have been re-arranged.

Comment 14

[Mike Conley (:mconley) (:⚙️)]

This is not e10s only (it seems to affect Win8 64, Linux 64, and Windows XP, all non-e10s), so minusing.

Comment 15

[GitHub Autolander Bot]

Attachment: [loop] mikedeboer:bug-1230280-startupPerf > mozilla:master

Comment 16

[Mike de Boer [:mikedeboer]]

https://treeherder.mozilla.org/#/jobs?repo=try&revision=19c44aa17fab

Comment 17

[Mike de Boer [:mikedeboer]]

Compare-talos link for try push in comment 16: https://treeherder.mozilla.org/perf.html#/compare?originalProject=try&originalRevision=44426d7a2be1&newProject=try&newRevision=954756924698&framework=1&showOnlyImportant=0

Comment 18

[Joel Maher ( :jmaher ) (UTC -8)]

not sure what the two pushes are on try, but ts_paint isn't looking as a regression.

Comment 19

[Mike de Boer [:mikedeboer]]

(In reply to Joel Maher (:jmaher) from comment #18)
> not sure what the two pushes are on try, but ts_paint isn't looking as a
> regression.

The newRevision commit contains the 'fix' I wanted to test out if it'd resolve the regression. It doesn't, unfortunately.

Comment 20

[Mark Banner (:standard8)]

If the theory is that this is invoking the CustomizableUI that's at issue, was a similar regression seen when the pocket add-on landed?

Comment 21

[Mark Banner (:standard8)]

Mike, here's a thought: Pocket landed after we did, but uses the same startup flow that we do - create the widget when the add-on's startup() function is called.

Your try push only moved the creating for the widget for Hello, not for Pocket.

Maybe we need to fix both add-ons to fix the regression?

In the event this does fix it, maybe customisable UI could be set to warn/reject if a createWidget or other call comes in before the expected startup?

Comment 22

[Mike de Boer [:mikedeboer]]

Could be true - not sure unless we try!

Comment 23

[Mark Banner (:standard8)]

Ed, its possibly getting a bit late for this bug now, but could you take on doing a fix as per my comment 21?

I think Mike can help with which try pushes to do / how to get perf info.

Comment 24

[Joel Maher ( :jmaher ) (UTC -8)]

Ed, also ping me or ask questions in the bug, running on try is fairly easy and viewing the results are not too difficult once you know where to look.

Comment 25

[Ed Lee :Mardak]

Baseline ts_paint:
https://hg.mozilla.org/try/rev/f52121663cedf7a7bc3ca2d53672098f7522e4d1
https://treeherder.mozilla.org/#/jobs?repo=try&revision=f52121663ced
talos-linux64-ix: 1173, 1180, 1179, 1173, 1187 -> 1,178 average
tst-linux64-spot: 2747, 2478, 2802, 2627, 2626 -> 2,656 average

browser-ui-startup-complete ts_paint:
https://hg.mozilla.org/try/rev/44bf96fe66adee013f1417e90e6b4e49a64b94fb
https://treeherder.mozilla.org/#/jobs?repo=try&revision=44bf96fe66ad
talos-linux64-ix: 1180, 1185, 1170, 1183, 1182 -> 1,180 average
tst-linux64-spot: 2715, 2760, 2505, 2272, 2651 -> 2,581 average

Not much change for the first set of machines but roughly 2% for the tst-* machines (although the variance is much higher).

https://treeherder.mozilla.org/perf.html#/compare?originalProject=try&originalRevision=f52121663ced&newProject=try&newRevision=44bf96fe66ad&framework=7&filter=ts_paint&showOnlyImportant=0

Comment 26

[William Lachance (:wlach)]

(In reply to Ed Lee :Mardak from comment #25)
> Not much change for the first set of machines but roughly 2% for the tst-*
> machines (although the variance is much higher).

Please just ignore the tst-* results, that's an experiment gone wrong. See bug 1260926.

Comment 27

[Mark Banner (:standard8)]

What's the way forward here now? Or do we close this as won't/can't fix?

Comment 28

[Joel Maher ( :jmaher ) (UTC -8)]

I don't see a clear path forward here- since then this test has a lot of ups and downs, overall trend regression though:
https://treeherder.mozilla.org/perf.html#/graphs?timerange=31536000&series=%5Bfx-team,0a72b9ed3cc2021d1ba469cce3d2881f4324dd07,1%5D&highlightedRevisions=f48352b311eb&highlightedRevisions=19876a153a00&zoom=1443500964009.7402,1460991372000,932.0631970260223,1105.1115241635687

https://treeherder.mozilla.org/perf.html#/graphs?timerange=31536000&series=%5Bfx-team,8a41738d21b57ca7c1c9ebba50ff2239be4091cc,1%5D&highlightedRevisions=f48352b311eb&highlightedRevisions=19876a153a00&zoom=1444796549786.7966,1460991372000,1006.5055762081784,1331.7843866171004

https://treeherder.mozilla.org/perf.html#/graphs?timerange=31536000&series=%5Bfx-team,fbde9e2cd431162414e14f2226146e4f5d913d36,1%5D&highlightedRevisions=f48352b311eb&highlightedRevisions=19876a153a00&zoom=1444421511798.7014,1460991372000,942.007434944238,1227.5092936802973


I think a win here would be to instead focus on this test and look at the profiling for hints of where to optimize.

Comment 29

[Mike Conley (:mconley) (:⚙️)]

If it's any consolation, I have a fix for a completely unrelated bug that looks like it might give us a nice ts_paint win across the board (bug 1261842), so I don't know how much we should prioritize this investigation, tbh.

Comment 30

[u572625]

hello removed so we can close this bug

Comment 31

[:Gijs (he/him)]

(In reply to timse201 from comment #30)
> hello removed so we can close this bug

Mark, OOI, was there a perf win when Hello got removed again?

Comment 32

[Mark Banner (:standard8)]

Yes ts_paint did improve, although cart regressed for some reason. See bug 1290808.