STR: - Open a google doc - Open Console, log window and expand it - Wait, maybe click Continue in Slow Script Dialog (shows react.js) - Close Console ER: Closing fast as 1000 unicorns AR: 3s hang Profile failed to symbolicate, so I attached a screenshot. Ever happens in react.js, probably removing elements (could this be done after the console closed?): perform < batchedUpdates < batchedUpdates < dispatchEvent < bound

Another test case with a big object that doesn't require opening a google doc is at Bug 1392180

Steps to reproduce 1. evaluate : Array(10000).fill("p").reduce((res, _, i)=> { res["item_" + i] = i; return res; }, {}) 2. expand the object 3. close the consoel when the properties are shown Profile: https://perfht.ml/2hO8v3K

Here is a profile where I removed the clearOutput part: https://perfht.ml/2gcjwZa And … it's worse :) So here it seems that a long time is spent on restyle, probably because of the "border as background" issue. We have a bug to get rid of that, so maybe it will help here. One other thing might be to do an `consoleOutput.innerHTML = ""` so we bypass React unmounting. If we do that, we need to make sure actors get released on the server when we destroy the console.

(In reply to Nicolas Chevobbe [:nchevobbe] from comment #3) > One other thing might be to do an `consoleOutput.innerHTML = ""` so we > bypass React unmounting. > If we do that, we need to make sure actors get released on the server when > we destroy the console. It'd be worth taking a profile to check if innerHTML fixes the performance issue, to see if it's worth looking into the server actor removal bit

I put up a patch where I clear the hud outputNode (with `innerHTML = ""`), and it shows a clear improvement: Without the patch (~3500ms) : https://perfht.ml/2i0TIDa With the patch (~500ms) : https://perfht.ml/2hWzU3I I guess now we should add a DAMP test covering this test case so we don't regress for this specific behavior.

Comment on attachment 8916520 [details] Bug 1405070 - Bypass React to clear console on destroy; https://reviewboard.mozilla.org/r/187650/#review193308 Strange that it's still slow even when just not clearing the output, but it definitely seems to do the trick! Have you confirmed that the server takes care of releasing appropriate actors when the console is closed?

Yes, all the actors pools are being cleared, so we're good here. By checking that I see that we are creating 2 actors for each logged message, one of them not being released when we clear the output (with console.clear or the clear button). I need to check what is going on here (it's visible without my patch, so unrelated). I will proceed with this patch and add a DAMP test to acknowledge the perf win as well as to prevent any regression on this.

I put up a patch with a DAMP test for this specific case. This is showing some good results: - Linux: https://treeherder.mozilla.org/perf.html#/comparesubtest?originalProject=try&originalRevision=a54cb255776ace9dfe066a3615c9fded7477d53d&newProject=try&newRevision=bce50f4d409a5e417c35d9d6d8071ead555e767a&originalSignature=edaec66500db21d37602c99daa61ac983f21a6ac&newSignature=edaec66500db21d37602c99daa61ac983f21a6ac&showOnlyImportant=1&framework=1 - osx: https://treeherder.mozilla.org/perf.html#/comparesubtest?originalProject=try&originalRevision=a54cb255776ace9dfe066a3615c9fded7477d53d&newProject=try&newRevision=bce50f4d409a5e417c35d9d6d8071ead555e767a&originalSignature=9663a154caf9b713fb951c8db24518c7e0ceddce&newSignature=9663a154caf9b713fb951c8db24518c7e0ceddce&showOnlyImportant=1&framework=1 - windows: 10 https://treeherder.mozilla.org/perf.html#/comparesubtest?originalProject=try&originalRevision=a54cb255776ace9dfe066a3615c9fded7477d53d&newProject=try&newRevision=bce50f4d409a5e417c35d9d6d8071ead555e767a&originalSignature=f687ee347bcbdc55828148af029908049de69b7f&newSignature=f687ee347bcbdc55828148af029908049de69b7f&showOnlyImportant=1&framework=1 - windows 7 https://treeherder.mozilla.org/perf.html#/comparesubtest?originalProject=try&originalRevision=a54cb255776ace9dfe066a3615c9fded7477d53d&newProject=try&newRevision=bce50f4d409a5e417c35d9d6d8071ead555e767a&originalSignature=63c652b34bd8fcf3623be048bdd3104906f70f02&newSignature=63c652b34bd8fcf3623be048bdd3104906f70f02&showOnlyImportant=1&framework=1 there are other side effects, depending on the platforms, not sure what to do with them. Also I think my test crashed DAMP a few time (https://treeherder.mozilla.org/#/jobs?repo=try&revision=a54cb255776ace9dfe066a3615c9fded7477d53d&filter-resultStatus=testfailed&filter-resultStatus=busted&filter-resultStatus=exception&filter-resultStatus=retry&filter-resultStatus=usercancel&filter-resultStatus=running&filter-resultStatus=pending&filter-resultStatus=runnable&selectedJob=136171323), not sure why

(In reply to Nicolas Chevobbe [:nchevobbe] from comment #11) > Also I think my test crashed DAMP a few time > (https://treeherder.mozilla.org/#/ > jobs?repo=try&revision=a54cb255776ace9dfe066a3615c9fded7477d53d&filter- > resultStatus=testfailed&filter-resultStatus=busted&filter- > resultStatus=exception&filter-resultStatus=retry&filter- > resultStatus=usercancel&filter-resultStatus=running&filter- > resultStatus=pending&filter-resultStatus=runnable&selectedJob=136171323), > not sure why Looks like maybe Bug 1406564

Comment on attachment 8917406 [details] Bug 1405070 - Add a DAMP test for console shutdown after expanding a large object; . https://reviewboard.mozilla.org/r/188404/#review193648 ::: testing/talos/talos/tests/devtools/addon/content/damp.js:271 (Diff revision 1) > + let webconsole = toolbox.getPanel("webconsole"); > + > + // Resolve once the last message has been received. > + let onMessageReceived = new Promise(resolve => { > + function receiveMessages(e, messages) { > + for (let m of messages) { Instead of looping here, should it be `resolve(messages[0])`? ::: testing/talos/talos/tests/devtools/addon/content/damp.js:295 (Diff revision 1) > + > + // Kick off the logging > + messageManager.sendAsyncMessage("do-dir"); > + > + yield onMessageReceived; > + const tree = webconsole.hud.ui.outputNode.querySelector(".dir.message .tree"); Would it be easy to emit an event from the webconsole for once properties are fetched / rendered? If so, we could skip the onMessageReceived code and this mutation observer. If not, don't worry about it. ::: testing/talos/talos/tests/devtools/addon/content/damp.js:309 (Diff revision 1) > + observer.observe(tree, { > + childList: true > + }); > + }); > + } > + While we are here we could go ahead and add another probe that measures time to receive / expand the message. Something like: ``` let start = performance.now(); yield onMessageReceived; .... this._results.push({ name: "console.objectexpand", value: performance.now() - start, }); yield this.closeToolboxAndLog("console.closeafterdir"); ``` If you think this makes sense, we could also rename the test from `consoleCloseAfterDir` to `consoleObjectExpansion` and replace `this.closeToolboxAndLog("console.closeafterdir")` with `this.closeToolboxAndLog("console.objectexpanded")` or similar. This means we'd end up with two new measuments in the test: `console.objectexpand` and `console.objectexpanded.close.DAMP`

Comment on attachment 8917406 [details] Bug 1405070 - Add a DAMP test for console shutdown after expanding a large object; . https://reviewboard.mozilla.org/r/188404/#review193648 > Instead of looping here, should it be `resolve(messages[0])`? `messages` is a set so we can't access elements that way. We could do `[...messages][0]` I guess. > Would it be easy to emit an event from the webconsole for once properties are fetched / rendered? If so, we could skip the onMessageReceived code and this mutation observer. If not, don't worry about it. we can't at the moment. everything happens in the object inspector itself and the console can't hook to this. jason was thinking of something to make the OI accessible for consumers, but that's not ready yet. > While we are here we could go ahead and add another probe that measures time to receive / expand the message. Something like: > > ``` > let start = performance.now(); > yield onMessageReceived; > > .... > > this._results.push({ > name: "console.objectexpand", > value: performance.now() - start, > }); > yield this.closeToolboxAndLog("console.closeafterdir"); > ``` > > If you think this makes sense, we could also rename the test from `consoleCloseAfterDir` to `consoleObjectExpansion` and replace `this.closeToolboxAndLog("console.closeafterdir")` with `this.closeToolboxAndLog("console.objectexpanded")` or similar. This means we'd end up with two new measuments in the test: `console.objectexpand` and `console.objectexpanded.close.DAMP` it would be nice indeed. Here we would have to use console.log and then click on the node instead of relying on console.dir I think (to only measure "fetching + tree rendering" time).

(In reply to Nicolas Chevobbe [:nchevobbe] from comment #14) > > If you think this makes sense, we could also rename the test from `consoleCloseAfterDir` to `consoleObjectExpansion` and replace `this.closeToolboxAndLog("console.closeafterdir")` with `this.closeToolboxAndLog("console.objectexpanded")` or similar. This means we'd end up with two new measuments in the test: `console.objectexpand` and `console.objectexpanded.close.DAMP` > > it would be nice indeed. Here we would have to use console.log and then > click on the node instead of relying on console.dir I think (to only measure > "fetching + tree rendering" time). I think it'd be fine to measure both fetching and tree rendering together - that's the total time the user has to wait for the message to be functional

(In reply to Nicolas Chevobbe [:nchevobbe] from comment #14) > Comment on attachment 8917406 [details] > Bug 1405070 - Add a DAMP test for console shutdown after expanding a large > object; . > > https://reviewboard.mozilla.org/r/188404/#review193648 > > > Instead of looping here, should it be `resolve(messages[0])`? > > `messages` is a set so we can't access elements that way. We could do > `[...messages][0]` I guess. > > > Would it be easy to emit an event from the webconsole for once properties are fetched / rendered? If so, we could skip the onMessageReceived code and this mutation observer. If not, don't worry about it. > > we can't at the moment. everything happens in the object inspector itself > and the console can't hook to this. > jason was thinking of something to make the OI accessible for consumers, but > that's not ready yet. OK, let's leave things as is then for both of these comments

Comment on attachment 8917406 [details] Bug 1405070 - Add a DAMP test for console shutdown after expanding a large object; . https://reviewboard.mozilla.org/r/188404/#review194218 Works for me, thanks! The expanded time is closer to 1 sec now so more in line with other subtests

Pushed by nchevobbe@mozilla.com: https://hg.mozilla.org/integration/autoland/rev/3df81d9d8337 Add a DAMP test for console shutdown after expanding a large object; r=bgrins. https://hg.mozilla.org/integration/autoland/rev/1cb834c19806 Bypass React to clear console on destroy; r=bgrins

https://hg.mozilla.org/mozilla-central/rev/3df81d9d8337 https://hg.mozilla.org/mozilla-central/rev/1cb834c19806