Closed Bug 1394804 Opened 7 years ago Closed 7 years ago

DAMP doesn't capture the initial load time (lazy loading devtools means the first time the toolbox is loaded per process extra modules need to be imported)

Categories

(DevTools :: General, enhancement, P1)

Product:
DevTools
Component:
General
Type:
enhancement

Tracking

(firefox57 fixed)

Status:
RESOLVED FIXED
Milestone:
Firefox 57
Tracking Flags:
Tracking Status
firefox57 --- fixed

People

(Reporter: ochameau, Assigned: ochameau)

References

(Blocks 3 open bugs)

Details

(Whiteboard: [reserve-nosdk])

Attachments

(3 files)

Bug 1394804 - Lazy load all dependencies from DAMP.
59 bytes, text/x-review-board-request
bgrins
: review+
Details
Bug 1394804 - Restart firefox between each DAMP runs and record a "cold-load" run for the inspector.
59 bytes, text/x-review-board-request
jmaher
: review+
bgrins
: review+
Details
Bug 1394804 - Update and sign DAMP add-on.
59 bytes, text/x-review-board-request
ochameau
: review+
Details 
http://searchfox.org/mozilla-central/source/testing/talos/talos/tests/devtools/addon/content/damp.js
DAMP main file load many devtools resources before running the test, it basically revert bug 1359855 efforts. And it ends up ignore additional cost on the first load of tools, where we have to setup the module loader and load a bunch of framework modules (devtools.js/devtools-browser.js and their dependencies).

http://searchfox.org/mozilla-central/source/testing/talos/talos/tests/devtools/addon/content/damp.js#351
Also, it isn't clear if we run all tests once? Is "config.repeat" be greater than 1 on try? If so, it is going to ignore first load, which is expected to be much greater than the nexts.

In any case, the first test to run is going to be special as it will take framework/module loader load time into account, whereas all the nexts will be free from this task.
Blocks: 1393086
(In reply to Alexandre Poirot [:ochameau] from comment #0)
> http://searchfox.org/mozilla-central/source/testing/talos/talos/tests/
> devtools/addon/content/damp.js
> DAMP main file load many devtools resources before running the test, it
> basically revert bug 1359855 efforts. And it ends up ignore additional cost
> on the first load of tools, where we have to setup the module loader and
> load a bunch of framework modules (devtools.js/devtools-browser.js and their
> dependencies).
> 
> http://searchfox.org/mozilla-central/source/testing/talos/talos/tests/
> devtools/addon/content/damp.js#351
> Also, it isn't clear if we run all tests once? Is "config.repeat" be greater
> than 1 on try? If so, it is going to ignore first load, which is expected to
> be much greater than the nexts.
> 
> In any case, the first test to run is going to be special as it will take
> framework/module loader load time into account, whereas all the nexts will
> be free from this task.

I don't think that lazy loading the dependencies will make a difference in the measurements since the first measurement is dropped anyway: https://wiki.mozilla.org/Buildbot/Talos/Tests#DAMP / https://dxr.mozilla.org/mozilla-central/rev/1b4c59eef820b46eb0037aca68f83a15088db45f/testing/talos/talos/test.py#402-421.  I'm sure there's a way to not drop the first time, but I don't think it's what you want because:

1) only a single measurement for a single tool will capture the extra time for the initial open (the first time the toolbox opens in the test, which I believe is the webconsole).
2) it will just get averaged in with the 25 other cycles for the tool in (1) - I'm assuming you are wanting discreet measurement for cold open and warm open?).

I could be wrong about this, but I don't think Talos is the right tool if we wanted to capture the initial devtools install / startup time, since it happens only once per process. So even a mochitest might not work well for this since devtools will have been installed if it runs in a chunk after another test that opens the tools.
Comment on attachment 8902269 [details]
Bug 1394804 - Lazy load all dependencies from DAMP.

https://reviewboard.mozilla.org/r/173798/#review179092

I would not expect this to affect results for the reasons I mention in comment 2.  Feel free to re-request review if I'm wrong about that
Attachment #8902269 - Flags: review?(bgrinstead) → review-
What about in addition to this change, add a test dedicated to first toolbox open, which would be registered first in sequenceArray? This test would open the tools against the inspector (which is the most used tool).
It looks like it would work. But may be not, I don't quite follow how talos/damp runs.
What are tpcycles and tppagecycles? It looks like tppagecycles maps to config.repeat?
(In reply to Alexandre Poirot [:ochameau] from comment #4)
> What about in addition to this change, add a test dedicated to first toolbox
> open, which would be registered first in sequenceArray? This test would open
> the tools against the inspector (which is the most used tool).

I believe this would still only get one 'cold startup' measurement per test no matter how many cycles, since the modules would be cached after the first time they are imported.

> It looks like it would work. But may be not, I don't quite follow how
> talos/damp runs.
> What are tpcycles and tppagecycles? It looks like tppagecycles maps to
> config.repeat?

I could be wrong about this but I believe tppagecycles is the numer of times that damp.html gets reloaded, and doesn't affect config.repeat. So for each time damp.html/damp.js runs it does each of these tests once, waiting 100ms between them: http://searchfox.org/mozilla-central/rev/cd82cacec2cf734768827ff85ba2dba90a534c5e/testing/talos/talos/tests/devtools/addon/content/damp.html#9-23. Then talos reloads damp.html and does it again, 25 times total. Joel, is that right?
Flags: needinfo?(jmaher)
Summary: DAMP doesn't reflect user's experience → DAMP doesn't capture the initial load time (lazy loading devtools means the first time the toolbox is loaded per process extra modules need to be imported)
(In reply to Brian Grinstead [:bgrins] from comment #2)
> I don't think that lazy loading the dependencies will make a difference in
> the measurements since the first measurement is dropped anyway:
> https://wiki.mozilla.org/Buildbot/Talos/Tests#DAMP /
> https://dxr.mozilla.org/mozilla-central/rev/
> 1b4c59eef820b46eb0037aca68f83a15088db45f/testing/talos/talos/test.py#402-421.
> I'm sure there's a way to not drop the first time, but I don't think it's
> what you want because:

The run that we ignore is an entire browser session. We do this to make sure that the startup caches are populated and that we have similar warm start conditions for each run. That's not necessarily ideal in terms of capturing real world user experience, but cold start measurements are far too chaotic to be useful for regression testing.
(In reply to Kris Maglione [:kmag] from comment #6)
> The run that we ignore is an entire browser session. We do this to make sure
> that the startup caches are populated and that we have similar warm start
> conditions for each run. That's not necessarily ideal in terms of capturing
> real world user experience, but cold start measurements are far too chaotic
> to be useful for regression testing.

Actually, I think I'm wrong about that, in this case. We do do a warm-up run like I described, but I think that's separate from the filter here.

It might be a good idea to have a separate cold start metric for this test, and do multiple runs with 1 cold start and 5-10 warm starts.
:bgrins, correct- tppagecycles it the total number of times the pageloader addon will reload the page we are testing, in this case damp.html.

If we want to change things or test differently, that is an option, just ask!
Flags: needinfo?(jmaher)
Instead of reloading damp.html 25 times, could we instead load it once but restart firefox 25 times?
Then we would only need to run a cold startup test before all the others.

Also, if we ignore the first dataset, may be we could run only the "simple" test and skip the complicated?
Just to speed up the results. Also, do we need 25 runs? That looks like a lot!

I've been looking a lot at running perf test as mochitest and the noise comes from various code from Firefox that runs asynchronously (and slowly, for over 30s up to 1minute). Waiting for this code to complete and disabling noise like session restore may help having more stable numbers.

Finally, talos and damp are very cryptic as it involves many codebases that very few people know:
xul, xul overlay, html page, xul addon, chrome-content communication, various kind of manifests...
Couldn't talos python app run a given browser-mochitest instead and make everything much simplier?

I'm currently looking into using a regular mochitest for tracking devtools performances, and use awsy to plot its data on perfherder.
The only difference between mochitest+awsy and talos+damp is that damp runs multiple time and involves averages/medians.
That is a significant difference as mochitest+awsy has to output stable numbers, so you can't efficiently track time probes.

But being able to write a regular mochitest make it so much easier, most devtools engineers would be able to contribute to it.
Whiteboard: [nosdk]
we have platform_microbenchmarks which allow for posting data from gtests.  It is possible to use 'mochitest' and post numbers to perfherder- the danger in perf testing is when an environment is so fluid we need to have certainty and consistency as much as possible.  Our time based metrics are run on standalone hardware, mochitests are run on arbitrary VM's in the cloud- we have no guarantee of the hardware the mochitests runs on.  The other consideration is generating alerts and surfacing the data to people- There is a lot of work that goes into getting alerts generated and turning them into bugs- most of the problems revolve around scheduling (the lack of running the test on every push) which is typically caused by bad commits.

It all depends on your goal and who will benefit from the performance test.
Assignee: nobody → poirot.alex
Status: NEW → ASSIGNED
Flags: qe-verify-
Priority: -- → P1
Target Milestone: --- → Firefox 57
Whiteboard: [nosdk] → [reserve-nosdk]
Sorry, I think I was bit off-topic in comment 9 by discussing about how talos could be more approachable overall.

To focus on the main issue of this bug, we would mostly need to run a given test and restart firefox between each run.
So. Today, we reload damp.html file to run tests again. We run Firefox only once.
But instead, could we restart firefox instead of reloading damp.html?

Would it be about using:
  cycles = 25
  tppagecycles = 1
instead of:
  tppagecycles = 25
from here:
  http://searchfox.org/mozilla-central/source/testing/talos/talos/test.py#402-421

Then, if we can do so, in damp.js we would run a special test first, focusing on cold start for just one tool.
For the record, here is a random DAMP run:
https://archive.mozilla.org/pub/firefox/try-builds/schien@mozilla.com-e5cfac6814cfe32fa7ad6a8bf084bb874d4d7fd7/try-linux64/try_ubuntu64_hw_test-g2-e10s-bm104-tests1-linux-build477.txt.gz

The very first webconsole opening is:
simple.webconsole.open.DAMP: 1486.1

Whereas all the following are more than 2x faster:
simple.webconsole.open.DAMP: 613.9
simple.webconsole.open.DAMP: 528.8
simple.webconsole.open.DAMP: 580.2
simple.webconsole.open.DAMP: 600.1
simple.webconsole.open.DAMP: 619.9
simple.webconsole.open.DAMP: 570.9
simple.webconsole.open.DAMP: 558.1
simple.webconsole.open.DAMP: 640.7
simple.webconsole.open.DAMP: 627.9
simple.webconsole.open.DAMP: 556.3
simple.webconsole.open.DAMP: 644.7
simple.webconsole.open.DAMP: 645.2
simple.webconsole.open.DAMP: 619.2
simple.webconsole.open.DAMP: 661.8
simple.webconsole.open.DAMP: 652.0
simple.webconsole.open.DAMP: 603.9
simple.webconsole.open.DAMP: 547.4
simple.webconsole.open.DAMP: 622.4
simple.webconsole.open.DAMP: 598.5
simple.webconsole.open.DAMP: 578.3
simple.webconsole.open.DAMP: 576.4
simple.webconsole.open.DAMP: 574.7
simple.webconsole.open.DAMP: 617.2
simple.webconsole.open.DAMP: 629.4
we could switch damp to run in a method of restarting the browser between each load- this is more expensive, I would probably reduce the number of loads from 25 to 15 or something like that.  this would be some non-trivial work as we need to collect and coalesce the numbers from the test and report them at the end.  We have other tests that do this, but they only produce 1 or 2 data points, not a large volume of data points to track.

Another thing with that method is that the first time might still have a higher hit as we keep the profile around between restarts instead of a [semi-]fresh profile we would see on the first data point.

:rwood, I know you had done some work to support multiple data points from ts_paint, do you think we could extend that to support a larger object full of data points?  I know we can do it, but is this a 1-2 day project or a week or so?
Flags: needinfo?(rwood)
And to be clear, we don't want to replace the data that DAMP is currently gathering. Maybe this 'restart firefox and get a measurement of the initial devtools load' should be a new test altogether - tacking it onto the front of DAMP seems like it may be complicated from the Talos end.
we could do  a damp load time, we have these 'startup' style tests already:
ts_paint - measures launching the browser
sessionrestore - measures the time to sessionrestore (+ a few variations)
tpaint - measures the time to open a new window once the browser has been loaded.

It sounds like the measurement we really want is ts_paint+devtools load; we would just need to have a simple page that loads devtools and then reports the number.  Here is what we do for ts_paint:
http://searchfox.org/mozilla-central/source/testing/talos/talos/startup_test/tspaint_test.html
(In reply to Joel Maher ( :jmaher) (UTC-5) from comment #13)
...
> :rwood, I know you had done some work to support multiple data points from
> ts_paint, do you think we could extend that to support a larger object full
> of data points?  I know we can do it, but is this a 1-2 day project or a
> week or so?

Not sure exactly what you mean, but extending it to add extra data points on each iteration/run yes, that should only take a couple of days. Each data point would ultimately be reported separately and appear like separate tests in the perfherder data output.
Flags: needinfo?(rwood)
I don't get why I don't see all the new test runs, it should introduce a new data set, similar to "simple" and "complicated". A new data set starting with "cold" should be run.

https://treeherder.mozilla.org/perf.html#/comparesubtest?originalProject=mozilla-central&newProject=try&newRevision=c15c10055926a1e7e6bf7d0d59a8b0784bffb596&originalSignature=edaec66500db21d37602c99daa61ac983f21a6ac&newSignature=edaec66500db21d37602c99daa61ac983f21a6ac&framework=1&selectedTimeRange=172800

This new patch should restart Firefox 5 times and run 1 "cold" test for each tool before running 5 "warm" tests (as before).
It seems to behave correctly locally, but not on try.
At the end we should still have 25 runs for the existing tests, and an additonal 5runs for cold start.
Comment on attachment 8902269 [details]
Bug 1394804 - Lazy load all dependencies from DAMP.

https://reviewboard.mozilla.org/r/173798/#review181402

This seems fine to me, assuming that the second part does what we want (awaiting Joel's review for that)
Attachment #8902269 - Flags: review?(bgrinstead) → review+
Comment on attachment 8904311 [details]
Bug 1394804 - Restart firefox between each DAMP runs and record a "cold-load" run for the inspector.

https://reviewboard.mozilla.org/r/176084/#review181528

unfortunately this won't work- we never restart the browser :(  the idea seems correct, but in practice is it not working.  cycles is used for startup_tests where we get a list of values from the browser output, then aggregate those over time.  If you look carefully at the log you will notice that we always use the same PID for firefox.
Attachment #8904311 - Flags: review?(jmaher) → review-
:rwood, can you help out here and get the cold start damp test working with :ochamaeu?
Flags: needinfo?(rwood)
Also, as I mentioned in Comment 14 we can be flexible about this being done either inside of DAMP or in a new talos test, depending on what's easier from the talos end.
Comment on attachment 8904311 [details]
Bug 1394804 - Restart firefox between each DAMP runs and record a "cold-load" run for the inspector.

https://reviewboard.mozilla.org/r/176084/#review181538

Clearing my review, as it sounds like this doesn't do what we want it to
Attachment #8904311 - Flags: review?(bgrinstead)
(In reply to Joel Maher ( :jmaher) (UTC-5) from comment #21)
> Comment on attachment 8904311 [details]
> Bug 1394804 - Restart firefox between each DAMP runs and record a
> "cold-load" run for the inspector.
> 
> https://reviewboard.mozilla.org/r/176084/#review181528
> 
> unfortunately this won't work- we never restart the browser :(  the idea
> seems correct, but in practice is it not working.  cycles is used for
> startup_tests where we get a list of values from the browser output, then
> aggregate those over time.  If you look carefully at the log you will notice
> that we always use the same PID for firefox.

That's not what I see...

https://treeherder.mozilla.org/#/jobs?repo=try&revision=c15c10055926a1e7e6bf7d0d59a8b0784bffb596&selectedJob=128308896
https://archive.mozilla.org/pub/firefox/try-builds/apoirot@mozilla.com-c15c10055926a1e7e6bf7d0d59a8b0784bffb596/try-linux64/try_ubuntu64_hw_test-g2-e10s-bm103-tests1-linux-build2240.txt.gz
08:37:34     INFO -  TEST-INFO | started process 11148 (/builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpSOWlMw/profile -tp file:/builds/slave/test/build/tests/talos/talos/tests/devtools/damp.manifest.develop -tpchrome -tpnoisy -tploadnocache -tpcycles 1 -tppagecycles 5)
08:42:32     INFO -  TEST-INFO | started process 23936 (/builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpSOWlMw/profile -tp file:/builds/slave/test/build/tests/talos/talos/tests/devtools/damp.manifest.develop -tpchrome -tpnoisy -tploadnocache -tpcycles 1 -tppagecycles 5)
08:47:25     INFO -  TEST-INFO | started process 4279 (/builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpSOWlMw/profile -tp file:/builds/slave/test/build/tests/talos/talos/tests/devtools/damp.manifest.develop -tpchrome -tpnoisy -tploadnocache -tpcycles 1 -tppagecycles 5)
08:52:18     INFO -  TEST-INFO | started process 16806 (/builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpSOWlMw/profile -tp file:/builds/slave/test/build/tests/talos/talos/tests/devtools/damp.manifest.develop -tpchrome -tpnoisy -tploadnocache -tpcycles 1 -tppagecycles 5)
08:57:08     INFO -  TEST-INFO | started process 29310 (/builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpSOWlMw/profile -tp file:/builds/slave/test/build/tests/talos/talos/tests/devtools/damp.manifest.develop -tpchrome -tpnoisy -tploadnocache -tpcycles 1 -tppagecycles 5)

There is 5 firefox processes being run. And we run DAMP tests 5 times in each of these starts.
What is broken, and I would like some help with, is that my changes made to damp.js are not used on try.
It works as-expected locally, but not when pushed on try. Is that related to the signed add-on?

Here is the valid result I get locally (I commented code to only run cold and simple test for the inspector to speed things up):
PERFHERDER_DATA: {"framework": {"name": "talos"}, "suites": [{"extraOptions": ["e10s"], "name": "damp", "lowerIsBetter": true, "alertThreshold": 2.0, "value": 718.3603241615403, "subtests": [{"name": "cold.inspector.open.DAMP", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [2947.74, 2473.285, 2289.6899999999987, 2457.9249999999993, 3055.550000000001], "value": 2947.74, "unit": "ms"}, {"name": "cold.inspector.reload.DAMP", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [377.72500000000036, 311.22999999999956, 361.8099999999995, 403.77000000000044, 357.71500000000015], "value": 377.72500000000036, "unit": "ms"}, {"name": "cold.inspector.close.DAMP", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [617.9000000000015, 414.6949999999997, 335.26500000000124, 411.2600000000002, 491.0450000000019], "value": 617.9000000000015, "unit": "ms"}, {"name": "simple.inspector.open.DAMP", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [1809.7649999999994, 2137.029999999999, 2060.215, 2307.3300000000017, 1507.2899999999936, 1322.3150000000023, 1857.9700000000012, 1761.4650000000001, 1412.7150000000001, 1769.9000000000015, 1379.2700000000004, 1319.5250000000015, 1448.9750000000022, 1503.5499999999993, 1443.6900000000023, 1535.5400000000009, 1529.4300000000003, 1596.0699999999997, 1561.7849999999999, 1643.1949999999997, 1658.4950000000026, 1923.0600000000013, 1784.8300000000017, 1525.7350000000006, 1509.310000000005], "value": 2098.6224999999995, "unit": "ms"}, {"name": "simple.inspector.reload.DAMP", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [477.1399999999994, 381.869999999999, 433.73999999999796, 745.9499999999971, 535.6599999999962, 367.2599999999984, 514.1399999999994, 390.73499999999694, 433.255000000001, 237.01000000000204, 629.1800000000003, 370.369999999999, 385.39500000000044, 378.2350000000006, 357.6299999999974, 275.89000000000306, 259.9850000000006, 394.0499999999993, 367.59500000000116, 375.7900000000009, 1064.4449999999997, 461.375, 297.8000000000029, 433.3099999999977, 347.0249999999942], "value": 484.6999999999971, "unit": "ms"}, {"name": "simple.inspector.close.DAMP", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [769.8450000000012, 477.51000000000204, 215.84000000000015, 890.0149999999994, 464.5400000000009, 455.6100000000006, 501.5400000000009, 566.244999999999, 462.4499999999971, 576.8000000000029, 664.5300000000025, 368.369999999999, 382.244999999999, 450.46000000000276, 456.34999999999854, 142.86499999999796, 447.6499999999978, 544.8549999999996, 646.885000000002, 538.7999999999956, 1769.170000000002, 387.52000000000044, 953.4650000000001, 423.5650000000023, 418.27999999999884], "value": 471.02500000000146, "unit": "ms"}, {"name": "cold.inspector.open.DAMP", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [2947.74, 2473.285, 2289.6899999999987, 2457.9249999999993, 3055.550000000001], "value": 2473.285, "unit": "ms"}, {"name": "cold.inspector.reload.DAMP", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [377.72500000000036, 311.22999999999956, 361.8099999999995, 403.77000000000044, 357.71500000000015], "value": 311.22999999999956, "unit": "ms"}, {"name": "cold.inspector.close.DAMP", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [617.9000000000015, 414.6949999999997, 335.26500000000124, 411.2600000000002, 491.0450000000019], "value": 414.6949999999997, "unit": "ms"}, {"name": "simple.inspector.open.DAMP", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [1809.7649999999994, 2137.029999999999, 2060.215, 2307.3300000000017, 1507.2899999999936, 1322.3150000000023, 1857.9700000000012, 1761.4650000000001, 1412.7150000000001, 1769.9000000000015, 1379.2700000000004, 1319.5250000000015, 1448.9750000000022, 1503.5499999999993, 1443.6900000000023, 1535.5400000000009, 1529.4300000000003, 1596.0699999999997, 1561.7849999999999, 1643.1949999999997, 1658.4950000000026, 1923.0600000000013, 1784.8300000000017, 1525.7350000000006, 1509.310000000005], "value": 1765.6825000000008, "unit": "ms"}, {"name": "simple.inspector.reload.DAMP", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [477.1399999999994, 381.869999999999, 433.73999999999796, 745.9499999999971, 535.6599999999962, 367.2599999999984, 514.1399999999994, 390.73499999999694, 433.255000000001, 237.01000000000204, 629.1800000000003, 370.369999999999, 385.39500000000044, 378.2350000000006, 357.6299999999974, 275.89000000000306, 259.9850000000006, 394.0499999999993, 367.59500000000116, 375.7900000000009, 1064.4449999999997, 461.375, 297.8000000000029, 433.3099999999977, 347.0249999999942], "value": 411.994999999999, "unit": "ms"}, {"name": "simple.inspector.close.DAMP", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [769.8450000000012, 477.51000000000204, 215.84000000000015, 890.0149999999994, 464.5400000000009, 455.6100000000006, 501.5400000000009, 566.244999999999, 462.4499999999971, 576.8000000000029, 664.5300000000025, 368.369999999999, 382.244999999999, 450.46000000000276, 456.34999999999854, 142.86499999999796, 447.6499999999978, 544.8549999999996, 646.885000000002, 538.7999999999956, 1769.170000000002, 387.52000000000044, 953.4650000000001, 423.5650000000023, 418.27999999999884], "value": 533.8924999999999, "unit": "ms"}, {"name": "cold.inspector.open.DAMP", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [2947.74, 2473.285, 2289.6899999999987, 2457.9249999999993, 3055.550000000001], "value": 2289.6899999999987, "unit": "ms"}, {"name": "cold.inspector.reload.DAMP", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [377.72500000000036, 311.22999999999956, 361.8099999999995, 403.77000000000044, 357.71500000000015], "value": 361.8099999999995, "unit": "ms"}, {"name": "cold.inspector.close.DAMP", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [617.9000000000015, 414.6949999999997, 335.26500000000124, 411.2600000000002, 491.0450000000019], "value": 335.26500000000124, "unit": "ms"}, {"name": "simple.inspector.open.DAMP", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [1809.7649999999994, 2137.029999999999, 2060.215, 2307.3300000000017, 1507.2899999999936, 1322.3150000000023, 1857.9700000000012, 1761.4650000000001, 1412.7150000000001, 1769.9000000000015, 1379.2700000000004, 1319.5250000000015, 1448.9750000000022, 1503.5499999999993, 1443.6900000000023, 1535.5400000000009, 1529.4300000000003, 1596.0699999999997, 1561.7849999999999, 1643.1949999999997, 1658.4950000000026, 1923.0600000000013, 1784.8300000000017, 1525.7350000000006, 1509.310000000005], "value": 1446.3325000000023, "unit": "ms"}, {"name": "simple.inspector.reload.DAMP", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [477.1399999999994, 381.869999999999, 433.73999999999796, 745.9499999999971, 535.6599999999962, 367.2599999999984, 514.1399999999994, 390.73499999999694, 433.255000000001, 237.01000000000204, 629.1800000000003, 370.369999999999, 385.39500000000044, 378.2350000000006, 357.6299999999974, 275.89000000000306, 259.9850000000006, 394.0499999999993, 367.59500000000116, 375.7900000000009, 1064.4449999999997, 461.375, 297.8000000000029, 433.3099999999977, 347.0249999999942], "value": 374.3024999999998, "unit": "ms"}, {"name": "simple.inspector.close.DAMP", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [769.8450000000012, 477.51000000000204, 215.84000000000015, 890.0149999999994, 464.5400000000009, 455.6100000000006, 501.5400000000009, 566.244999999999, 462.4499999999971, 576.8000000000029, 664.5300000000025, 368.369999999999, 382.244999999999, 450.46000000000276, 456.34999999999854, 142.86499999999796, 447.6499999999978, 544.8549999999996, 646.885000000002, 538.7999999999956, 1769.170000000002, 387.52000000000044, 953.4650000000001, 423.5650000000023, 418.27999999999884], "value": 416.3525000000009, "unit": "ms"}, {"name": "cold.inspector.open.DAMP", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [2947.74, 2473.285, 2289.6899999999987, 2457.9249999999993, 3055.550000000001], "value": 2457.9249999999993, "unit": "ms"}, {"name": "cold.inspector.reload.DAMP", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [377.72500000000036, 311.22999999999956, 361.8099999999995, 403.77000000000044, 357.71500000000015], "value": 403.77000000000044, "unit": "ms"}, {"name": "cold.inspector.close.DAMP", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [617.9000000000015, 414.6949999999997, 335.26500000000124, 411.2600000000002, 491.0450000000019], "value": 411.2600000000002, "unit": "ms"}, {"name": "simple.inspector.open.DAMP", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [1809.7649999999994, 2137.029999999999, 2060.215, 2307.3300000000017, 1507.2899999999936, 1322.3150000000023, 1857.9700000000012, 1761.4650000000001, 1412.7150000000001, 1769.9000000000015, 1379.2700000000004, 1319.5250000000015, 1448.9750000000022, 1503.5499999999993, 1443.6900000000023, 1535.5400000000009, 1529.4300000000003, 1596.0699999999997, 1561.7849999999999, 1643.1949999999997, 1658.4950000000026, 1923.0600000000013, 1784.8300000000017, 1525.7350000000006, 1509.310000000005], "value": 1578.9274999999998, "unit": "ms"}, {"name": "simple.inspector.reload.DAMP", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [477.1399999999994, 381.869999999999, 433.73999999999796, 745.9499999999971, 535.6599999999962, 367.2599999999984, 514.1399999999994, 390.73499999999694, 433.255000000001, 237.01000000000204, 629.1800000000003, 370.369999999999, 385.39500000000044, 378.2350000000006, 357.6299999999974, 275.89000000000306, 259.9850000000006, 394.0499999999993, 367.59500000000116, 375.7900000000009, 1064.4449999999997, 461.375, 297.8000000000029, 433.3099999999977, 347.0249999999942], "value": 371.692500000001, "unit": "ms"}, {"name": "simple.inspector.close.DAMP", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [769.8450000000012, 477.51000000000204, 215.84000000000015, 890.0149999999994, 464.5400000000009, 455.6100000000006, 501.5400000000009, 566.244999999999, 462.4499999999971, 576.8000000000029, 664.5300000000025, 368.369999999999, 382.244999999999, 450.46000000000276, 456.34999999999854, 142.86499999999796, 447.6499999999978, 544.8549999999996, 646.885000000002, 538.7999999999956, 1769.170000000002, 387.52000000000044, 953.4650000000001, 423.5650000000023, 418.27999999999884], "value": 541.8274999999976, "unit": "ms"}, {"name": "cold.inspector.open.DAMP", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [2947.74, 2473.285, 2289.6899999999987, 2457.9249999999993, 3055.550000000001], "value": 3055.550000000001, "unit": "ms"}, {"name": "cold.inspector.reload.DAMP", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [377.72500000000036, 311.22999999999956, 361.8099999999995, 403.77000000000044, 357.71500000000015], "value": 357.71500000000015, "unit": "ms"}, {"name": "cold.inspector.close.DAMP", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [617.9000000000015, 414.6949999999997, 335.26500000000124, 411.2600000000002, 491.0450000000019], "value": 491.0450000000019, "unit": "ms"}, {"name": "simple.inspector.open.DAMP", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [1809.7649999999994, 2137.029999999999, 2060.215, 2307.3300000000017, 1507.2899999999936, 1322.3150000000023, 1857.9700000000012, 1761.4650000000001, 1412.7150000000001, 1769.9000000000015, 1379.2700000000004, 1319.5250000000015, 1448.9750000000022, 1503.5499999999993, 1443.6900000000023, 1535.5400000000009, 1529.4300000000003, 1596.0699999999997, 1561.7849999999999, 1643.1949999999997, 1658.4950000000026, 1923.0600000000013, 1784.8300000000017, 1525.7350000000006, 1509.310000000005], "value": 1655.2825000000012, "unit": "ms"}, {"name": "simple.inspector.reload.DAMP", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [477.1399999999994, 381.869999999999, 433.73999999999796, 745.9499999999971, 535.6599999999962, 367.2599999999984, 514.1399999999994, 390.73499999999694, 433.255000000001, 237.01000000000204, 629.1800000000003, 370.369999999999, 385.39500000000044, 378.2350000000006, 357.6299999999974, 275.89000000000306, 259.9850000000006, 394.0499999999993, 367.59500000000116, 375.7900000000009, 1064.4449999999997, 461.375, 297.8000000000029, 433.3099999999977, 347.0249999999942], "value": 390.1674999999959, "unit": "ms"}, {"name": "simple.inspector.close.DAMP", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [769.8450000000012, 477.51000000000204, 215.84000000000015, 890.0149999999994, 464.5400000000009, 455.6100000000006, 501.5400000000009, 566.244999999999, 462.4499999999971, 576.8000000000029, 664.5300000000025, 368.369999999999, 382.244999999999, 450.46000000000276, 456.34999999999854, 142.86499999999796, 447.6499999999978, 544.8549999999996, 646.885000000002, 538.7999999999956, 1769.170000000002, 387.52000000000044, 953.4650000000001, 423.5650000000023, 418.27999999999884], "value": 420.9225000000006, "unit": "ms"}]}]}

And again, when I run this patch locally, everything looks good to me. Firefox restarts 5 times, the numbers look good. cold.inspector.open is significantly bigger than simple.inspector.open, as expected.
Flags: needinfo?(jmaher)
I ran another try with exactly what I tested locally (just the inspector with cold and simple tests),
and it really doesn't consider any change I made to damp.js:
https://treeherder.mozilla.org/#/jobs?repo=try&revision=8a184bfeff00d051606a0126b2374c35af89558a&selectedJob=128827626
https://archive.mozilla.org/pub/firefox/try-builds/apoirot@mozilla.com-8a184bfeff00d051606a0126b2374c35af89558a/try-linux64/try_ubuntu64_hw_test-g2-e10s-bm104-tests1-linux-build599.txt.gz
Python changes on the other hand seems to be considered.

Do we have to bug someone to update the xpi everytime we want to test a DAMP patch?
http://searchfox.org/mozilla-central/source/testing/talos/talos/tests/devtools/addon/devtools-signed.xpi
when running locally and on try, we run in 'develop' mode, this uses the raw source for the addon:
http://searchfox.org/mozilla-central/source/testing/talos/talos/ffsetup.py#96

in looking at this, I believe there is a bug as try has changed around and I see in the above log branch-name=Try-Non-PGO, so that would explain why your changes are not being seen (I just filed bug 1397222 to fix it properly)

I am really curious about why we can restart the browser with pageloader, possibly this does work and we can do this!
Flags: needinfo?(jmaher)
Comment on attachment 8904311 [details]
Bug 1394804 - Restart firefox between each DAMP runs and record a "cold-load" run for the inspector.

Looks like this patch even work as-expected on try:
https://treeherder.mozilla.org/perf.html#/comparesubtest?originalProject=mozilla-central&newProject=try&newRevision=527341ed12c473fc7b83f4a37fb277ea321de9d3&originalSignature=edaec66500db21d37602c99daa61ac983f21a6ac&newSignature=edaec66500db21d37602c99daa61ac983f21a6ac&filter=.open&framework=1&selectedTimeRange=172800

Data make sense, no significant change [at least not significant to perfherder] appear to warm numbers (simple.*, complicated.*).
Cold numbers (cold.*) are all biggers than warm ones.
And especially webconsole which is the first one to run and bundles the additional cost of devtools framework.
May be we could introduce a dedicated test to cover just devtools framework.
Attachment #8904311 - Flags: review- → review?(jmaher)
BTW, if:
https://hg.mozilla.org/try/rev/49f47d153d91a12a9edaaa3bac88793f88eafc14
makes sense to you I can upload it to bug 1397222.
Otherwise I will let python/automation expert handle this.
Blocks: damp
Comment on attachment 8904311 [details]
Bug 1394804 - Restart firefox between each DAMP runs and record a "cold-load" run for the inspector.

https://reviewboard.mozilla.org/r/176084/#review182334

I see that we run this 5 times, but oddly it seems as though we have a reporting problem- the resulting PERFHERDER_JSON had 5 duplicate copies of the data (25 replicates/subtest - 5 identical copies) where as normally we just publish a single copy of the data.

Please file a bug to work on that, specifically ensure that we account for 'cycles' and coalesce results, here is the code area:
http://searchfox.org/mozilla-central/source/testing/talos/talos/output.py#58

the last thing to do here is to ensure we sign the addon- we have instructions up here:
https://wiki.mozilla.org/EngineeringProductivity/HowTo/SignExtensions#Signing_an_Addon

feel free to ask for help if you run into problems signing the extension- after the extension signing there is no need for a new review.
Attachment #8904311 - Flags: review?(jmaher) → review+
Flags: needinfo?(rwood)
Depends on: 1398069
FYI, you have some eslint failures with this patch (you may have seen them already?):

https://treeherder.mozilla.org/#/jobs?repo=try&revision=83816b664edd3e75856b05a83dc8ef1d37006ff9&selectedJob=129517130
Flags: needinfo?(poirot.alex)
I'm unable to sign the addon :x

$ jpm sign --api-key xxx --api-secret yyy --xpi devtools-signed.xpi 
JPM [error] FAIL
Error: Unsupported file type "undefined"
    at DecompressZip.extractFile (/mnt/desktop/gecko/jpm/node_modules/decompress-zip/lib/decompress-zip.js:309:11)
    at /mnt/desktop/gecko/jpm/node_modules/decompress-zip/lib/decompress-zip.js:242:28
    at Array.forEach (native)
    at DecompressZip.extractFiles (/mnt/desktop/gecko/jpm/node_modules/decompress-zip/lib/decompress-zip.js:241:11)
    at /mnt/desktop/gecko/jpm/node_modules/decompress-zip/lib/decompress-zip.js:121:21
    at _fulfilled (/mnt/desktop/gecko/jpm/node_modules/q/q.js:854:54)
    at self.promiseDispatch.done (/mnt/desktop/gecko/jpm/node_modules/q/q.js:883:30)
    at Promise.promise.promiseDispatch (/mnt/desktop/gecko/jpm/node_modules/q/q.js:816:13)
    at /mnt/desktop/gecko/jpm/node_modules/q/q.js:624:44
    at runSingle (/mnt/desktop/gecko/jpm/node_modules/q/q.js:137:13)

I had to install jpm from github sources, as npm install would install 1.0.3 version, which doesn't support sign...
Github version is 1.3.1.

Any idea how to have a working jpm?
:rwood, you recently signed pageloader, have you had issues?
Flags: needinfo?(rwood)
No it worked fine for me last time I signed the pageloader addon. I notice in comment 35 though,

"$ jpm sign --api-key xxx --api-secret yyy --xpi devtools-signed.xpi"

'devtools-signed.xpi' - confused by this name, it should point to your .xpi file that you zipped, that is not signed yet - this argument is not the name of the xpi to be created, but the name of the unsigned xpi that you wish to sign

i.e. the one you created with 'zip -r my-addon.xpi .'
Flags: needinfo?(rwood)
Oh! I thought it would sign in-place, so I did: 'zip -r devtools-signed.xpi .'

It works if I use devtools.xpi (and not update the already signed devtools-signed.xpi)

Thanks for your help!
Flags: needinfo?(poirot.alex)
Comment on attachment 8904311 [details]
Bug 1394804 - Restart firefox between each DAMP runs and record a "cold-load" run for the inspector.

https://reviewboard.mozilla.org/r/176084/#review186578

::: testing/talos/talos/tests/devtools/addon/content/damp.js:539
(Diff revision 2)
> +
> +    // Run cold test only once
> +    let topWindow = getMostRecentBrowserWindow();
> +    if (!topWindow.coldRunDAMP) {
> +      topWindow.coldRunDAMP = true;
> +      tests = tests.concat(this._getToolLoadingTests(SIMPLE_URL, "cold"));

It seems like this means it will run the cold measurement for each of the tools. After the first tool is opened none of the others will be a cold measurement, so shouldn't this only run the open test on a single tool (like inspector)?
Attachment #8904311 - Flags: review?(bgrinstead)
(In reply to Brian Grinstead [:bgrins] from comment #40)
> Comment on attachment 8904311 [details]
> Bug 1394804 - Restart firefox between each DAMP runs and record a
> "cold-load" run for the inspector.
> 
> https://reviewboard.mozilla.org/r/176084/#review186578
> 
> ::: testing/talos/talos/tests/devtools/addon/content/damp.js:539
> (Diff revision 2)
> > +
> > +    // Run cold test only once
> > +    let topWindow = getMostRecentBrowserWindow();
> > +    if (!topWindow.coldRunDAMP) {
> > +      topWindow.coldRunDAMP = true;
> > +      tests = tests.concat(this._getToolLoadingTests(SIMPLE_URL, "cold"));
> 
> It seems like this means it will run the cold measurement for each of the
> tools. After the first tool is opened none of the others will be a cold
> measurement, so shouldn't this only run the open test on a single tool (like
> inspector)?

I made this on purpose as I thought each panel would still load its own set of module on cold runs.

The inspector load is going to load most module, but when you open the console for the first time,
it will still load for the first time all module that are used by the console but not by the inspector.

You can see that it is quite different for webconsole:
https://treeherder.mozilla.org/perf.html#/comparesubtest?originalProject=mozilla-central&newProject=try&newRevision=c010e20c507db8b7407a78d6d54bc2ff200eb449&originalSignature=edaec66500db21d37602c99daa61ac983f21a6ac&newSignature=edaec66500db21d37602c99daa61ac983f21a6ac&filter=console.open&framework=1&selectedTimeRange=172800
cold.open 581.82 versus simple.open 529.79

But it doesn't highlight major difference for the debugger: 715.17 versus 710.73
https://treeherder.mozilla.org/perf.html#/comparesubtest?originalProject=mozilla-central&newProject=try&newRevision=c010e20c507db8b7407a78d6d54bc2ff200eb449&originalSignature=edaec66500db21d37602c99daa61ac983f21a6ac&newSignature=edaec66500db21d37602c99daa61ac983f21a6ac&filter=debugger.open&framework=1&selectedTimeRange=172800

Neither netmonitor 586.83 versus 583.79:
https://treeherder.mozilla.org/perf.html#/comparesubtest?originalProject=mozilla-central&newProject=try&newRevision=c010e20c507db8b7407a78d6d54bc2ff200eb449&originalSignature=edaec66500db21d37602c99daa61ac983f21a6ac&newSignature=edaec66500db21d37602c99daa61ac983f21a6ac&filter=netmonitor.open&framework=1&selectedTimeRange=172800

So I have a mixed feeling.
Knowing that, do you think I should only run the inspector?
Flags: needinfo?(bgrinstead)
Let me know if you disagree but I'd rather be really targeted and just collect a cold inspector open because:

1) It's the only real 'cold open' (presumably each subsequent tool will become more and more 'warm' as we see with the debugger/netmonitor)
2) There will be less work to do and data to analyze for each push, and I don't think we'll be getting value out of the subsequent tools that isn't captured in their simple measurements
3) I don't think we even need reload and close times - correct me if I'm wrong but I don't expect a difference between cold and warm here and think (2) applies in that case
Flags: needinfo?(bgrinstead)
Thanks for your feedback, yes I think it makes sense to lower the number of results!
Here is an updated patch that only records cold inspector open.

And a try run:
https://treeherder.mozilla.org/#/jobs?repo=try&revision=6bcbf9d8a4cee132c615a9cdcc897cc08341f962
Blocks: 1401187
Comment on attachment 8904311 [details]
Bug 1394804 - Restart firefox between each DAMP runs and record a "cold-load" run for the inspector.

https://reviewboard.mozilla.org/r/176084/#review186776

Thanks, this looks good.

::: testing/talos/talos/tests/devtools/addon/content/damp.js:307
(Diff revision 3)
> +    await this.testTeardown();
> +  },
>  
> +  _getToolLoadingTests(url, label) {
>      let subtests = {
> -      webconsoleOpen: Task.async(function* () {
> +      inspectorOpen: Task.async(function* () {

Is there a reason to change the test order now that cold open is separated out as a different test

::: testing/talos/talos/tests/devtools/addon/content/damp.js:544
(Diff revision 3)
>      let tests = [];
> +
> +    if (config.subtests.indexOf("inspectorOpen") > -1) {
> +      // Run cold test only once
> +      let topWindow = getMostRecentBrowserWindow();
> +      if (!topWindow.coldRunDAMP) {

Does this condition get hit? I thought startTest would only be called once per process but I'm not sure
Attachment #8904311 - Flags: review?(bgrinstead) → review+
Comment on attachment 8904311 [details]
Bug 1394804 - Restart firefox between each DAMP runs and record a "cold-load" run for the inspector.

https://reviewboard.mozilla.org/r/176084/#review186780

Also, please make sure to re-sign before landing
(In reply to Brian Grinstead [:bgrins] from comment #46)
> Comment on attachment 8904311 [details]
> Bug 1394804 - Restart firefox between each DAMP runs and record a
> "cold-load" run for the inspector.
> 
> https://reviewboard.mozilla.org/r/176084/#review186776
> 
> Thanks, this looks good.
> 
> ::: testing/talos/talos/tests/devtools/addon/content/damp.js:307
> (Diff revision 3)
> > +    await this.testTeardown();
> > +  },
> >  
> > +  _getToolLoadingTests(url, label) {
> >      let subtests = {
> > -      webconsoleOpen: Task.async(function* () {
> > +      inspectorOpen: Task.async(function* () {
> 
> Is there a reason to change the test order now that cold open is separated
> out as a different test

It isn't as important as before. But it seems to still have an impact.
It looks like the first "simple" test has an overhead.
See the results for the patch you r+:
https://treeherder.mozilla.org/perf.html#/comparesubtest?originalProject=mozilla-central&newProject=try&newRevision=6bcbf9d8a4cee132c615a9cdcc897cc08341f962&originalSignature=edaec66500db21d37602c99daa61ac983f21a6ac&newSignature=edaec66500db21d37602c99daa61ac983f21a6ac&framework=1&selectedTimeRange=172800
There seem to be a transfert from simple.console to simple.inspector

I'll revert that chance and see if this transfert still exists.
It surely hides something!

> 
> ::: testing/talos/talos/tests/devtools/addon/content/damp.js:544
> (Diff revision 3)
> >      let tests = [];
> > +
> > +    if (config.subtests.indexOf("inspectorOpen") > -1) {
> > +      // Run cold test only once
> > +      let topWindow = getMostRecentBrowserWindow();
> > +      if (!topWindow.coldRunDAMP) {
> 
> Does this condition get hit? I thought startTest would only be called once
> per process but I'm not sure

Yes, it is called 5 times, for each warm test.
It relates to tppagecycles = 5 from test.py. Before this patch is was called 25 times.
Comment on attachment 8909819 [details]
Bug 1394804 - Update and sign DAMP add-on.

https://reviewboard.mozilla.org/r/181324/#review187032
Attachment #8909819 - Flags: review?(poirot.alex) → review+
(In reply to Alexandre Poirot [:ochameau] from comment #48)
> I'll revert that chance and see if this transfert still exists.
> It surely hides something!

https://treeherder.mozilla.org/perf.html#/comparesubtest?originalProject=mozilla-central&newProject=try&newRevision=29f6dec73c7badf9c5f948c681a3743206d47bba&originalSignature=edaec66500db21d37602c99daa61ac983f21a6ac&newSignature=edaec66500db21d37602c99daa61ac983f21a6ac&framework=1&selectedTimeRange=172800

If I don't change test order, results for simple.* don't change.
I don't know what is going on, but I wish I knew!
Pushed by apoirot@mozilla.com:
https://hg.mozilla.org/integration/autoland/rev/1e3b88f4c9bd
Lazy load all dependencies from DAMP. r=bgrins
https://hg.mozilla.org/integration/autoland/rev/a42d926ae8a8
Restart firefox between each DAMP runs and record a "cold-load" run for the inspector. r=bgrins,jmaher
https://hg.mozilla.org/integration/autoland/rev/2fb9198e5a1d
Update and sign DAMP add-on. r=ochameau
Depends on: 1401886
Product: Firefox → DevTools
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Creator:
Created:
Updated:
Size: