Open
Bug 1404118
Opened 7 years ago
Updated 2 years ago
Async stack saving in RDP Requests seems to slow down netmonitor
Categories
(DevTools :: Netmonitor, enhancement, P3)
DevTools
Netmonitor
Tracking
(firefox57 fix-optional)
NEW
Tracking | Status | |
---|---|---|
firefox57 | --- | fix-optional |
People
(Reporter: ochameau, Unassigned)
References
Details
https://perfht.ml/2ywePA2
Search for "getStack"
This seem to always come from this code:
http://searchfox.org/mozilla-central/rev/f54c1723befe6bcc7229f005217d5c681128fcad/devtools/shared/client/main.js#726
request.stack = getStack();
Which is executed for each RDP request, so it isn't not surprising it easily appear in profiles.
We should do that only when we want to debug devtools and/or when async stack pref is turned on (javascript.options.asyncstackn which is off on release and beta).
`executeSoon` (which can also use the stack saving) only does so for tests or when debug JS modules mode is enabled:
http://searchfox.org/mozilla-central/rev/20e41d4a61a8f5e34c9cf357304b78b3e9bced8a/devtools/shared/DevToolsUtils.js#54-56
That seems like a reasonable model to apply here as well.
Reporter | ||
Comment 2•7 years ago
|
||
Hum --enable-debug-js-modules has to be set manually.
I was more thinking about something automatically turned on for local builds?
It this note really enough to ensure all devtools contributors turn this on?
http://searchfox.org/mozilla-central/source/devtools/docs/getting-started/development-profiles.md#67
But yes, I agree, it should use the same flag!
(In reply to Alexandre Poirot [:ochameau] from comment #2)
> Hum --enable-debug-js-modules has to be set manually.
> I was more thinking about something automatically turned on for local builds?
> It this note really enough to ensure all devtools contributors turn this on?
>
> http://searchfox.org/mozilla-central/source/devtools/docs/getting-started/
> development-profiles.md#67
>
> But yes, I agree, it should use the same flag!
Well, it seems like a similar feature to other things currently controlled by that setting, like:
* assertions
* whether to use dev build of React
* async stacks (at least, `executeSoon`)
I think it's ideal for all such features to be off by default in Nightly (so regular users get the best performance).
As far as how to expose them for local development (and esp. contributors), it's a bit trickier to decide the right default... I think it still makes sense for devs to actively choose to turn it on, since these all affect performance, and it can be misleading if you are trying to profile, for example.
I would suggest using this bug to update RDP requests to check the flag like `executeSoon`... If you want to rethink how the flag works more generally, maybe the new-ish RFC process is a good way to see what others think here.
It might make sense to extract:
```
if (AppConstants.DEBUG_JS_MODULES || flags.testing) {
```
to some helper like `slowDevFeaturesAllowed()` or something, so the same check can be used everywhere this pattern occurs.
Updated•7 years ago
|
status-firefox57:
--- → fix-optional
Priority: -- → P3
Reporter | ||
Comment 4•7 years ago
|
||
DAMP reports a 1.6% win with medium confidence on requestsFinished:
https://treeherder.mozilla.org/perf.html#/comparesubtest?originalProject=mozilla-central&newProject=try&newRevision=a1376934c1e38cd7655a92cd168d17180b69cc16&originalSignature=edaec66500db21d37602c99daa61ac983f21a6ac&newSignature=edaec66500db21d37602c99daa61ac983f21a6ac&framework=1&selectedTimeRange=172800
It is about what profiler reports. Profiler recorded 28ms of `getStack` frames which is around 1% of the overall record on the main process.
(In reply to Alexandre Poirot [:ochameau] from comment #4)
> DAMP reports a 1.6% win with medium confidence on requestsFinished:
> https://treeherder.mozilla.org/perf.html#/
> comparesubtest?originalProject=mozilla-
> central&newProject=try&newRevision=a1376934c1e38cd7655a92cd168d17180b69cc16&o
> riginalSignature=edaec66500db21d37602c99daa61ac983f21a6ac&newSignature=edaec6
> 6500db21d37602c99daa61ac983f21a6ac&framework=1&selectedTimeRange=172800
>
> It is about what profiler reports. Profiler recorded 28ms of `getStack`
> frames which is around 1% of the overall record on the main process.
The DAMP report looks like noise to me... :(
Do you plan to still make a change here?
Does the perf improve if you also remove the `callFunctionWithAsyncStack` bit[1] so that it's a just "regular" function calls instead?
Looks like the Webpack shim for `callFunctionWithAsyncStack`[2] just calls the function directly, so I would only expect a perf change for non-Webpack things.
[1]: http://searchfox.org/mozilla-central/rev/8efd128b48cdae3a6c6862795ce618aa1ca1c0b4/devtools/shared/protocol.js#1344
[2]: http://searchfox.org/mozilla-central/source/devtools/client/shared/webpack/shims/platform-stack-stub.js#16
Flags: needinfo?(poirot.alex)
Reporter | ||
Comment 6•7 years ago
|
||
(In reply to J. Ryan Stinnett [:jryans] (use ni?) from comment #5)
> The DAMP report looks like noise to me... :(
Having only this probe be "medium" and all the others be "low" highlights something.
To me, it means that the win is almost within the noise/variance of this particular test.
> Do you plan to still make a change here?
Yes. I'm just logging what I see being slow.
But then try to focus by impact and bug 1404913 is much more impactful.
> Does the perf improve if you also remove the `callFunctionWithAsyncStack`
> bit[1] so that it's a just "regular" function calls instead?
Hum, interesting. Yes, that is something to look into as well!
> Looks like the Webpack shim for `callFunctionWithAsyncStack`[2] just calls
> the function directly, so I would only expect a perf change for non-Webpack
> things.
But these webpack shims are only used when running in a tab, right?
I hope these are not used when loaded in toolbox!
Flags: needinfo?(poirot.alex)
Comment 7•7 years ago
|
||
comment out getStack in debugger-client
http://searchfox.org/mozilla-central/source/devtools/shared/client/debugger-client.js#560
DAMP result shows
simple.netmonitor.open 530.51 > 516.39 -2.66% (low)
simple.netmonitor.close 56.33 > 53.07 -5.79% (low)
https://treeherder.mozilla.org/perf.html#/comparesubtest?originalProject=mozilla-central&newProject=try&newRevision=8d8b67c62281ed5651293e6d1b689a41899ec47e&originalSignature=edaec66500db21d37602c99daa61ac983f21a6ac&newSignature=edaec66500db21d37602c99daa61ac983f21a6ac&framework=1&selectedTimeRange=172800
The try commit
https://treeherder.mozilla.org/#/jobs?repo=try&revision=8d8b67c62281
Reporter | ||
Comment 8•7 years ago
|
||
(In reply to Fred Lin [:gasolin] from comment #7)
> comment out getStack in debugger-client
> http://searchfox.org/mozilla-central/source/devtools/shared/client/debugger-
> client.js#560
>
> DAMP result shows
>
> simple.netmonitor.open 530.51 > 516.39 -2.66% (low)
> simple.netmonitor.close 56.33 > 53.07 -5.79% (low)
Confidence is low here. It means that the observed improvement is within the typical variance of these tests.
So it is hard to conclude anything really serious.
I hope to improve DAMP in bug 1407826 about that and then be able to firmly say if there is any improvement.
You could try to push to DAMP with bug 1407826's patches to see if the numbers are any better (with higher confidence).
Comment 9•7 years ago
|
||
Here's new try with the damp patch https://treeherder.mozilla.org/#/jobs?repo=try&revision=e8ffed18b97b&selectedJob=142640057
The DAMP looks pretty bad for simple.netmonitor test cases
https://treeherder.mozilla.org/perf.html#/comparesubtest?originalProject=mozilla-central&newProject=try&newRevision=e8ffed18b97b403beabdba22875ba3fd72586647&originalSignature=edaec66500db21d37602c99daa61ac983f21a6ac&newSignature=edaec66500db21d37602c99daa61ac983f21a6ac&framework=1&selectedTimeRange=172800
The patch
https://reviewboard.mozilla.org/r/194564/diff/16#index_header
BTW: after apply the damp patch, the test takes over 5 hrs to get the result (previously within 1~2hr with the artifact build).
Reporter | ||
Comment 10•7 years ago
|
||
(In reply to Fred Lin [:gasolin] from comment #9)
> The DAMP looks pretty bad for simple.netmonitor test cases
> https://treeherder.mozilla.org/perf.html#/
> comparesubtest?originalProject=mozilla-
> central&newProject=try&newRevision=e8ffed18b97b403beabdba22875ba3fd72586647&o
> riginalSignature=edaec66500db21d37602c99daa61ac983f21a6ac&newSignature=edaec6
> 6500db21d37602c99daa61ac983f21a6ac&framework=1&selectedTimeRange=172800
Given that the DAMP fix changes almost all timings, you should not compare against mozilla-central,
but against another try, with only the DAMP fix.
Here is a better compare:
https://treeherder.mozilla.org/perf.html#/comparesubtest?originalProject=try&originalRevision=222618638acc7ccef7c0dfb969747681c959b2a3&newProject=try&newRevision=e8ffed18b97b403beabdba22875ba3fd72586647&originalSignature=edaec66500db21d37602c99daa61ac983f21a6ac&newSignature=edaec66500db21d37602c99daa61ac983f21a6ac&filter=netmonitor&framework=1
It confirms that the win is really small, if there is any.
You should ignore "*.close" tests, they are known to be irrelevant as we do not wait correctly for its full completion.
Then, simple.netmonitor.open and complicated.netmonitor.open are now both under 1% stddev,
which helps identifying regressions over 1%. And nothing is reported here.
The only one that reports something is this one:
complicated.netmonitor.requestsFinished 11,915.51 ± 0.58% > 11,758.94 ± 0.57% -1.31% (med)
So this patch may improve performance but at a very small scale, about 1% or less.
Having said that, if you have a local test case that runs faster with this patch,
it would be interesting to know about it. May be DAMP tests are not covering every scenarios.
Updated•7 years ago
|
Assignee: nobody → odvarko
Status: NEW → ASSIGNED
Updated•7 years ago
|
Assignee: odvarko → nobody
Status: ASSIGNED → NEW
Updated•6 years ago
|
Product: Firefox → DevTools
Updated•2 years ago
|
Severity: normal → S3
You need to log in
before you can comment on or make changes to this bug.
Description
•