1244225 - Unhandled promise rejections in performance tests

Status: RESOLVED FIXED

(DevTools :: Performance Tools (Profiler/Timeline), defect, P2)

Description

[J. Ryan Stinnett [:jryans] (Use needinfo, replies may be slow)]

Bug 1240804 uncovered a performance test that fails when unhandled promise rejection tracking is used:

devtools/client/performance/test/browser_perf-options-profiler.js

Please note you need to apply the patch in bug 1240804 to see the test failures.

Comment 1

[Victor Porof [:vporof][:vp]]

Triaging. Filter on LULUGUBRIOUSUS.

Comment 2

[Jordan Santell [:jsantell] [@jsantell]]

Browser Chrome Test Summary
	Passed: 2667
	Failed: 1
	Todo: 0
*** End BrowserChrome Test Results ***
The following tests failed:
5223 INFO TEST-UNEXPECTED-FAIL | devtools/client/performance/test/browser_perf-options-profiler.js | A promise chain failed to handle a rejection:  - at resource://gre/modules/commonjs/toolkit/loader.js -> resource://devtools/server/actors/common.js:487 - Error: Wrong state while getting allocations settings:Expected 'attached', but current state is 'detached'.
Stack trace:
expectState/<@resource://gre/modules/commonjs/toolkit/loader.js -> resource://devtools/server/actors/common.js:487:29
exports.PerformanceRecorder<.getConfiguration@resource://gre/modules/commonjs/toolkit/loader.js -> resource://devtools/server/performance/recorder.js:470:23
actorBridge/<@resource://gre/modules/commonjs/toolkit/loader.js -> resource://devtools/server/actors/common.js:507:12
actorProto/</handler@resource://gre/modules/commonjs/toolkit/loader.js -> resource://devtools/server/protocol.js:1013:19
DSC_onPacket@resource://gre/modules/commonjs/toolkit/loader.js -> resource://devtools/server/main.js:1643:15
LocalDebuggerTransport.prototype.send/<@resource://gre/modules/commonjs/toolkit/loader.js -> resource://devtools/shared/transport/transport.js:569:11
exports.makeInfallible/<@resource://gre/modules/commonjs/toolkit/loader.js -> resource://devtools/shared/ThreadSafeDevToolsUtils.js:101:14
DevToolsUtils.executeSoon*executeSoon@resource://gre/modules/commonjs/toolkit/loader.js -> resource://devtools/shared/DevToolsUtils.js:34:11
LocalDebuggerTransport.prototype.send@resource://gre/modules/commonjs/toolkit/loader.js -> resource://devtools/shared/transport/transport.js:562:7
Front<.send/<@resource://gre/modules/commonjs/toolkit/loader.js -> resource://devtools/server/protocol.js:1162:9
Handler.prototype.process@resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:937:23
this.PromiseWalker.walkerLoop@resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:816:7
Promise*this.PromiseWalker.scheduleWalkerLoop@resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:747:11
this.PromiseWalker.schedulePromise@resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:779:7
this.PromiseWalker.completePromise@resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:714:7
DevToolsWorker.prototype.performTask/</listener@resource://devtools/shared/worker/worker.js:94:9
EventListener.handleEvent*DevToolsWorker.prototype.performTask/<@resource://devtools/shared/worker/worker.js:98:5
Promise@resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:388:5
DevToolsWorker.prototype.performTask@resource://devtools/shared/worker/worker.js:78:10
this.CanvasGraphUtils._performTaskInWorker@resource://gre/modules/commonjs/toolkit/loader.js -> resource://devtools/client/shared/widgets/Graphs.js:1369:12
LineGraphWidget.prototype<.setDataFromTimestamps<@resource://gre/modules/commonjs/toolkit/loader.js -> resource://devtools/client/shared/widgets/LineGraphWidget.js:148:15
TaskImpl_run@resource://gre/modules/Task.jsm:319:40
TaskImpl@resource://gre/modules/Task.jsm:280:3
createAsyncFunction/asyncFunction@resource://gre/modules/Task.jsm:254:14
FramerateGraph.prototype<.setPerformanceData@resource://gre/modules/commonjs/toolkit/loader.js -> resource://devtools/client/performance/modules/widgets/graphs.js:116:12
GraphsController.prototype.render<@resource://gre/modules/commonjs/toolkit/loader.js -> resource://devtools/client/performance/modules/widgets/graphs.js:224:13
TaskImpl_run@resource://gre/modules/Task.jsm:319:40
TaskImpl_handleResultValue@resource://gre/modules/Task.jsm:400:7
TaskImpl_run@resource://gre/modules/Task.jsm:327:13
Handler.prototype.process@resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:937:23
this.PromiseWalker.walkerLoop@resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:816:7
Promise*this.PromiseWalker.scheduleWalkerLoop@resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:747:11
this.PromiseWalker.schedulePromise@resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:779:7
Promise.prototype.then@resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:454:5
TaskImpl_handleResultValue@resource://gre/modules/Task.jsm:395:7
TaskImpl_run@resource://gre/modules/Task.jsm:327:13
TaskImpl_handleResultValue@resource://gre/modules/Task.jsm:400:7
TaskImpl_run@resource://gre/modules/Task.jsm:327:13
TaskImpl@resource://gre/modules/Task.jsm:280:3
createAsyncFunction/asyncFunction@resource://gre/modules/Task.jsm:254:14
OverviewView.render<@chrome://devtools/content/performance/views/overview.js:179:11
TaskImpl_run@resource://gre/modules/Task.jsm:319:40
TaskImpl@resource://gre/modules/Task.jsm:280:3
createAsyncFunction/asyncFunction@resource://gre/modules/Task.jsm:254:14
OverviewView._onRecordingTick<@chrome://devtools/content/performance/views/overview.js:191:11
TaskImpl_run@resource://gre/modules/Task.jsm:319:40
TaskImpl@resource://gre/modules/Task.jsm:280:3
createAsyncFunction/asyncFunction@resource://gre/modules/Task.jsm:254:14
setTimeout handler*OverviewView._startPolling@chrome://devtools/content/performance/views/overview.js:243:23
_onRecordingStateChange@chrome://devtools/content/performance/views/overview.js:409:7
EventEmitter_emit@resource://gre/modules/commonjs/toolkit/loader.js -> resource://devtools/shared/event-emitter.js:147:11
PerformanceController.setCurrentRecording@chrome://devtools/content/performance/performance-controller.js:339:7
PerformanceController._onRecordingSelectFromView@chrome://devtools/content/performance/performance-controller.js:370:5
SUITE-END | took 296s

Comment 3

[Jordan Santell [:jsantell] [@jsantell]]

Attachment: 1244225-unhandled-promise-perf.patch

https://treeherder.mozilla.org/#/jobs?repo=try&revision=7e7e19d76679

Comment 4

[Nick Fitzgerald [:fitzgen] [⏰PST; UTC-8]]

Comment on attachment 8716552 [details] [diff] [review]
1244225-unhandled-promise-perf.patch

Review of attachment 8716552 [details] [diff] [review]:
-----------------------------------------------------------------

... I guess ...

Real solution would be to fix whatever race condition you have, but whatever...

Comment 5

[Jordan Santell [:jsantell] [@jsantell]]

So, in `expectState` (devtools/server/actors/common.js), if in an invalid state, we return a rejected promise (resolving to an error) -- this works when the component is hooked into an actor (like memory actor), but when used in the same process (devtools/server/performance/{memory|recorder}.js), we access these synchronous methods without yielding -- having expectState function like this means all methods implemented with this helper should be yielded upon.

That seems like the correct fix, but that I'm sure has many implications, and not sure the right thing to do. Maybe expectState should just throw? Anyways, atleast only memory and promises use this utility.

Comment 6

[Nick Fitzgerald [:fitzgen] [⏰PST; UTC-8]]

Why does it need to yield? The state is a local property to the memory bridge thing.

Comment 7

[Jordan Santell [:jsantell] [@jsantell]]

Because getAllocationSettings returns a rejected promise, its not handled anywhere, hence unhandled promises; unless I'm misunderstanding, we need something to yield or throw that error if that's what you mean, there's no race condition in this case

Comment 8

[Jordan Santell [:jsantell] [@jsantell]]

Attachment: 1244225-unhandled-promise-perf.patch

fitzgen and I discussed that these settings are only valid per-recording, and does not make sense for the memory component to return information about it when it's not attached, so the performance component handles this now. Ideally, the performance component will handle set/get of underlying component state so we don't have to query the individual components, but this is only used in tests anyway.

Comment 9

[Pulsebot]

https://hg.mozilla.org/integration/fx-team/rev/5506056498b0

Comment 10

[Carsten Book [:Tomcat]]

https://hg.mozilla.org/mozilla-central/rev/5506056498b0