protocol.js Request.write duplicates its template object and all request arguments on every request

RESOLVED FIXED in Firefox 61

Status

defect
RESOLVED FIXED
Last year
27 days ago

People

(Reporter: ochameau, Assigned: ochameau)

Tracking

(Blocks 1 bug)

unspecified
Firefox 61
Dependency tree / graph

Firefox Tracking Flags

(firefox61 fixed)

Details

(Whiteboard: dt-fission)

Attachments

(1 attachment)

https://searchfox.org/mozilla-central/rev/a30a60eadcff99d2a043241955d215dbeccad876/devtools/shared/protocol.js#655-664
  write: function(fnArgs, ctx) {
    let str = JSON.stringify(this.template, (key, value) => {

This usage of JSON.stringify here ends up duplicating `this.template` as well as all arguments on each request call. This function easily appears in perf-html profiles.

But when I try simplifying this method, I get very surprising results:
https://treeherder.mozilla.org/perf.html#/comparesubtest?originalProject=try&originalRevision=25eed4c2659907a966c9836c1f2617a7b7510a38&newProject=try&newRevision=00c6547659b2c290531bcbc5860ff17a6703e85c&originalSignature=f79b6a4f1f8f53326d3056f6c8008c0ff4de0a94&newSignature=f79b6a4f1f8f53326d3056f6c8008c0ff4de0a94&showOnlyConfident=1&framework=1
While it speeds up a lot the benchmark from bug 1454580, it regresses various other subtests.
I don't understand as the new implementation should just be faster in any possible way. As for Response.write, I'm removing the nested feature and throw explicit error message. It was only used in tests.

I must be missing something...
Here is a first profile with this patch:
https://perfht.ml/2F0bXhD

And another one without:
https://perfht.ml/2qGVT08

If I filter to see only protocol.js, I only see a very small difference with
resource://devtools/server/actors/inspector/node.js's form method.
But that looks unrelated to protocol.js as it doesn't end up calling it.

Otherwise it is hard to see any meaningful difference with the rest of the profile :/
I'm getting the same results with all my current performance patches landed:
https://treeherder.mozilla.org/perf.html#/comparesubtest?originalProject=try&originalRevision=8d31ce9cf9e59aef2cdaec4fdc685275ae8dbb57&newProject=try&newRevision=d6d016897618a3a4ef7409d15aab8d63e901810f&originalSignature=f79b6a4f1f8f53326d3056f6c8008c0ff4de0a94&newSignature=f79b6a4f1f8f53326d3056f6c8008c0ff4de0a94&showOnlyImportant=1&framework=1

I found one different in test output, but that makes no sense to me.
An exception currenctly happens when running debugger tests, and the stack includes one additional frame *with* the patch.

We go from:
console.warn: "iterable.length has been deprecated, use iterable.size or iterable.count(). This warning will become a silent error in a future version. get@resource://devtools/shared/base-loader.js -> resource://devtools/client/shared/vendor/immutable.js:4667:21\nremoveBreakpoints/onBreakpointsCleared<@chrome://damp/content/tests/debugger/debugger-helpers.js:249:15\nwaitForState/<@chrome://damp/content/tests/debugger/debugger-helpers.js:24:9\nwaitForState@chrome://damp/content/tests/debugger/debugger-helpers.js:20:10\nremoveBreakpoints@chrome://damp/content/tests/debugger/debugger-helpers.js:247:33\nasync*pauseDebuggerAndLog@chrome://damp/content/tests/debugger/custom.js:52:9\nasync*module.exports@chrome://damp/content/tests/debugger/custom.js:29:9\nasync*_runNextTest@chrome://damp/content/damp.js:244:19\ntestTeardown@chrome://damp/content/damp.js:198:5\nasync*exports.testTeardown@chrome://damp/content/tests/head.js:48:10\nmodule.exports@chrome://damp/content/tests/inspector/custom.js:23:9\nasync*_runNextTest@chrome://damp/content/damp.js:244:19\ntestTeardown@chrome://damp/content/damp.js:198:5\nasync*exports.testTeardown@chrome://damp/content/tests/head.js:48:10\nmodule.exports@chrome://damp/content/tests/webconsole/custom.js:23:9\nasync*_runNextTest@chrome://damp/content/damp.js:244:19\ntestTeardown@chrome://damp/content/damp.js:198:5\nasync*exports.testTeardown@chrome://damp/content/tests/head.js:48:10\nmodule.exports@chrome://damp/content/tests/memory/complicated.js:22:9\nasync*_runNextTest@chrome://damp/content/damp.js:244:19\ntestTeardown@chrome://damp/content/damp.js:198:5\nasync*exports.testTeardown@chrome://damp/content/tests/head.js:48:10\nmodule.exports@chrome://damp/content/tests/netmonitor/complicated.js:25:9\nasync*_runNextTest@chrome://damp/content/damp.js:244:19\ntestTeardown@chrome://damp/content/damp.js:198:5\nasync*exports.testTeardown@chrome://damp/content/tests/head.js:48:10\nmodule.exports@chrome://damp/content/tests/performance/complicated.js:15:9\nasync*_runNextTest@chrome://damp/content/damp.js:244:19\ntestTeardown@chrome://damp/content/damp.js:198:5\nasync*exports.testTeardown@chrome://damp/content/tests/head.js:48:10\nmodule.exports@chrome://damp/content/tests/styleeditor/complicated.js:15:9\n"

to:
console.warn: "iterable.length has been deprecated, use iterable.size or iterable.count(). This warning will become a silent error in a future version. get@resource://devtools/shared/base-loader.js -> resource://devtools/client/shared/vendor/immutable.js:4667:21\nremoveBreakpoints/onBreakpointsCleared<@chrome://damp/content/tests/debugger/debugger-helpers.js:249:15\nwaitForState/<@chrome://damp/content/tests/debugger/debugger-helpers.js:24:9\nwaitForState@chrome://damp/content/tests/debugger/debugger-helpers.js:20:10\nremoveBreakpoints@chrome://damp/content/tests/debugger/debugger-helpers.js:247:33\nasync*pauseDebuggerAndLog@chrome://damp/content/tests/debugger/custom.js:52:9\nasync*module.exports@chrome://damp/content/tests/debugger/custom.js:29:9\nasync*_runNextTest@chrome://damp/content/damp.js:244:19\ntestTeardown@chrome://damp/content/damp.js:198:5\nasync*exports.testTeardown@chrome://damp/content/tests/head.js:48:10\nmodule.exports@chrome://damp/content/tests/inspector/custom.js:23:9\nasync*_runNextTest@chrome://damp/content/damp.js:244:19\ntestTeardown@chrome://damp/content/damp.js:198:5\nasync*exports.testTeardown@chrome://damp/content/tests/head.js:48:10\nmodule.exports@chrome://damp/content/tests/webconsole/custom.js:23:9\nasync*_runNextTest@chrome://damp/content/damp.js:244:19\ntestTeardown@chrome://damp/content/damp.js:198:5\nasync*exports.testTeardown@chrome://damp/content/tests/head.js:48:10\nmodule.exports@chrome://damp/content/tests/memory/complicated.js:22:9\nasync*_runNextTest@chrome://damp/content/damp.js:244:19\ntestTeardown@chrome://damp/content/damp.js:198:5\nasync*exports.testTeardown@chrome://damp/content/tests/head.js:48:10\nmodule.exports@chrome://damp/content/tests/netmonitor/complicated.js:25:9\nasync*_runNextTest@chrome://damp/content/damp.js:244:19\ntestTeardown@chrome://damp/content/damp.js:198:5\nasync*exports.testTeardown@chrome://damp/content/tests/head.js:48:10\nmodule.exports@chrome://damp/content/tests/performance/complicated.js:15:9\nasync*_runNextTest@chrome://damp/content/damp.js:244:19\ntestTeardown@chrome://damp/content/damp.js:198:5\nasync*exports.testTeardown@chrome://damp/content/tests/head.js:48:10\nmodule.exports@chrome://damp/content/tests/styleeditor/complicated.js:15:9\nasync*_runNextTest@chrome://damp/content/damp.js:244:19\n"

See the additional "async*_runNextTest@chrome://damp/content/damp.js:244:19" frame at the very end.
But this code shouldn't change anything to stacks...
Hmm, I am not sure what suggest here either...  The only thing I could think was what if looping over template keys in some cases encountered more keys than stringify would have, but I assume that's not actually possible. :/
Assignee

Updated

Last year
Assignee: nobody → poirot.alex
Comment hidden (mozreview-request)

Comment 9

Last year
mozreview-review
Comment on attachment 8969095 [details]
Bug 1454899 - Prevent request arguments duplication on each request call.

https://reviewboard.mozilla.org/r/237568/#review245890

Looks good to me!  Seems like you solved the perf mystery.
Attachment #8969095 - Flags: review?(jryans) → review+

Comment 10

Last year
Pushed by apoirot@mozilla.com:
https://hg.mozilla.org/integration/autoland/rev/7e9c01aef284
Prevent request arguments duplication on each request call. r=jryans

Comment 11

Last year
bugherder
https://hg.mozilla.org/mozilla-central/rev/7e9c01aef284
Status: NEW → RESOLVED
Closed: Last year
Resolution: --- → FIXED
Target Milestone: --- → Firefox 61
Assignee

Updated

Last year
Blocks: dt-pjs

Updated

Last year
Product: Firefox → DevTools
Assignee

Updated

8 months ago
Whiteboard: dt-fission
You need to log in before you can comment on or make changes to this bug.