Closed Bug 1561092 Opened 4 months ago Closed 2 months ago

Intermittent devtools/client/debugger/test/mochitest/browser_dbg-wasm-sourcemaps.js | A promise chain failed to handle a rejection: Error: Parser: source sourceURL-http://example.com/browser/devtools/client/debugger/test/mochitest/examples/doc-wa

Categories

(DevTools :: Debugger, defect, P5)

defect

Tracking

(firefox-esr60 unaffected, firefox-esr68 unaffected, firefox68 unaffected, firefox69 wontfix, firefox70 fixed)

RESOLVED FIXED
Firefox 70
Tracking Status
firefox-esr60 --- unaffected
firefox-esr68 --- unaffected
firefox68 --- unaffected
firefox69 --- wontfix
firefox70 --- fixed

People

(Reporter: intermittent-bug-filer, Assigned: jlast)

References

(Blocks 1 open bug, Regression)

Details

(Keywords: intermittent-failure, regression, Whiteboard: [debugger-mvp] [stockwell disabled])

Attachments

(3 files, 1 obsolete file)

Filed by: ccoroiu [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer.html#?job_id=253166758&repo=autoland
Full log: https://queue.taskcluster.net/v1/task/JDXNQ6psQ_6_EKn-eIx4nw/runs/0/artifacts/public/logs/live_backing.log
Reftest URL: https://hg.mozilla.org/mozilla-central/raw-file/tip/layout/tools/reftest/reftest-analyzer.xhtml#logurl=https://queue.taskcluster.net/v1/task/JDXNQ6psQ_6_EKn-eIx4nw/runs/0/artifacts/public/logs/live_backing.log&only_show_unexpected=1


[task 2019-06-24T19:25:02.090Z] 19:25:02 INFO - TEST-PASS | devtools/client/debugger/test/mochitest/browser_dbg-wasm-sourcemaps.js | It shall be fib.c source -
[task 2019-06-24T19:25:02.091Z] 19:25:02 INFO - Buffered messages finished
[task 2019-06-24T19:25:02.094Z] 19:25:02 INFO - TEST-UNEXPECTED-FAIL | devtools/client/debugger/test/mochitest/browser_dbg-wasm-sourcemaps.js | A promise chain failed to handle a rejection: Error: Parser: source sourceURL-http://example.com/browser/devtools/client/debugger/test/mochitest/examples/doc-wasm-sourcemaps.html was not provided. - stack: setInScopeLines/<@resource://devtools/client/debugger/src/actions/ast/setInScopeLines.js:57:5
[task 2019-06-24T19:25:02.095Z] 19:25:02 INFO - asyncthunk/</</<@resource://devtools/client/debugger/src/actions/utils/middleware/thunk.js:21:45
[task 2019-06-24T19:25:02.095Z] 19:25:02 INFO - dispatch@resource://devtools/client/shared/vendor/redux.js:755:18
[task 2019-06-24T19:25:02.095Z] 19:25:02 INFO - selectLocation/<@resource://devtools/client/debugger/src/actions/sources/select.js:147:5
[task 2019-06-24T19:25:02.095Z] 19:25:02 INFO - async
thunk/</</<@resource://devtools/client/debugger/src/actions/utils/middleware/thunk.js:21:45
[task 2019-06-24T19:25:02.096Z] 19:25:02 INFO - dispatch@resource://devtools/client/shared/vendor/redux.js:755:18
[task 2019-06-24T19:25:02.097Z] 19:25:02 INFO - checkSelectedSource/<@resource://devtools/client/debugger/src/actions/sources/newSources.js:148:13
[task 2019-06-24T19:25:02.097Z] 19:25:02 INFO - thunk/</</<@resource://devtools/client/debugger/src/actions/utils/middleware/thunk.js:21:45
[task 2019-06-24T19:25:02.097Z] 19:25:02 INFO - dispatch@resource://devtools/client/shared/vendor/redux.js:755:18
[task 2019-06-24T19:25:02.098Z] 19:25:02 INFO - checkNewSources/<@resource://devtools/client/debugger/src/actions/sources/newSources.js:333:7
[task 2019-06-24T19:25:02.098Z] 19:25:02 INFO - thunk/</</<@resource://devtools/client/debugger/src/actions/utils/middleware/thunk.js:21:45
[task 2019-06-24T19:25:02.099Z] 19:25:02 INFO - dispatch@resource://devtools/client/shared/vendor/redux.js:755:18
[task 2019-06-24T19:25:02.099Z] 19:25:02 INFO - newOriginalSources/<@resource://devtools/client/debugger/src/actions/sources/newSources.js:238:11
[task 2019-06-24T19:25:02.101Z] 19:25:02 INFO - thunk/</</<@resource://devtools/client/debugger/src/actions/utils/middleware/thunk.js:21:45
[task 2019-06-24T19:25:02.101Z] 19:25:02 INFO - dispatch@resource://devtools/client/shared/vendor/redux.js:755:18
[task 2019-06-24T19:25:02.101Z] 19:25:02 INFO - newQueuedSources/<@resource://devtools/client/debugger/src/actions/sources/newSources.js:210:13
[task 2019-06-24T19:25:02.101Z] 19:25:02 INFO - thunk/</</<@resource://devtools/client/debugger/src/actions/utils/middleware/thunk.js:21:45
[task 2019-06-24T19:25:02.101Z] 19:25:02 INFO - bindActionCreator/<@resource://devtools/client/shared/vendor/redux.js:644:12
[task 2019-06-24T19:25:02.101Z] 19:25:02 INFO - dispatchNewSources@resource://devtools/client/debugger/src/utils/source-queue.js:19:23
[task 2019-06-24T19:25:02.102Z] 19:25:02 INFO - invokeFunc@resource://devtools/client/shared/vendor/lodash.js:10350:23
[task 2019-06-24T19:25:02.103Z] 19:25:02 INFO - leadingEdge@resource://devtools/client/shared/vendor/lodash.js:10360:26
[task 2019-06-24T19:25:02.103Z] 19:25:02 INFO - debounced@resource://devtools/client/shared/vendor/lodash.js:10425:20
[task 2019-06-24T19:25:02.104Z] 19:25:02 INFO - queueSources@resource://devtools/client/debugger/src/utils/source-queue.js:36:7
[task 2019-06-24T19:25:02.105Z] 19:25:02 INFO - loadSourceMaps/</sourceList<@resource://devtools/client/debugger/src/actions/sources/newSources.js:43:31
[task 2019-06-24T19:25:02.105Z] 19:25:02 INFO - Async*loadSourceMaps/<@resource://devtools/client/debugger/src/actions/sources/newSources.js:41:52
[task 2019-06-24T19:25:02.106Z] 19:25:02 INFO - thunk/</</<@resource://devtools/client/debugger/src/actions/utils/middleware/thunk.js:21:45
[task 2019-06-24T19:25:02.107Z] 19:25:02 INFO - dispatch@resource://devtools/client/shared/vendor/redux.js:755:18
[task 2019-06-24T19:25:02.107Z] 19:25:02 INFO - checkNewSources/<@resource://devtools/client/debugger/src/actions/sources/newSources.js:337:5
[task 2019-06-24T19:25:02.108Z] 19:25:02 INFO - thunk/</</<@resource://devtools/client/debugger/src/actions/utils/middleware/thunk.js:21:45
[task 2019-06-24T19:25:02.109Z] 19:25:02 INFO - dispatch@resource://devtools/client/shared/vendor/redux.js:755:18
[task 2019-06-24T19:25:02.109Z] 19:25:02 INFO - newGeneratedSources/<@resource://devtools/client/debugger/src/actions/sources/newSources.js:318:11
[task 2019-06-24T19:25:02.109Z] 19:25:02 INFO - thunk/</</<@resource://devtools/client/debugger/src/actions/utils/middleware/thunk.js:21:45
[task 2019-06-24T19:25:02.110Z] 19:25:02 INFO - dispatch@resource://devtools/client/shared/vendor/redux.js:755:18
[task 2019-06-24T19:25:02.111Z] 19:25:02 INFO - newQueuedSources/<@resource://devtools/client/debugger/src/actions/sources/newSources.js:207:13
[task 2019-06-24T19:25:02.111Z] 19:25:02 INFO - thunk/</</<@resource://devtools/client/debugger/src/actions/utils/middleware/thunk.js:21:45
[task 2019-06-24T19:25:02.111Z] 19:25:02 INFO - bindActionCreator/<@resource://devtools/client/shared/vendor/redux.js:644:12
[task 2019-06-24T19:25:02.112Z] 19:25:02 INFO - dispatchNewSources@resource://devtools/client/debugger/src/utils/source-queue.js:19:23
[task 2019-06-24T19:25:02.112Z] 19:25:02 INFO - invokeFunc@resource://devtools/client/shared/vendor/lodash.js:10350:23
[task 2019-06-24T19:25:02.113Z] 19:25:02 INFO - leadingEdge@resource://devtools/client/shared/vendor/lodash.js:10360:26
[task 2019-06-24T19:25:02.114Z] 19:25:02 INFO - debounced@resource://devtools/client/shared/vendor/lodash.js:10425:20
[task 2019-06-24T19:25:02.114Z] 19:25:02 INFO - queue@resource://devtools/client/debugger/src/utils/source-queue.js:31:5
[task 2019-06-24T19:25:02.114Z] 19:25:02 INFO - newSource@resource://devtools/client/debugger/src/client/firefox/events.js:81:25

Component: General → Debugger
Flags: needinfo?(ydelendik)
Whiteboard: [stockwell needswork]
Summary: Intermittent [tier 2] devtools/client/debugger/test/mochitest/browser_dbg-wasm-sourcemaps.js | A promise chain failed to handle a rejection: Error: Parser: source sourceURL-http://example.com/browser/devtools/client/debugger/test/mochitest/examples/doc-wa → Intermittent devtools/client/debugger/test/mochitest/browser_dbg-wasm-sourcemaps.js | A promise chain failed to handle a rejection: Error: Parser: source sourceURL-http://example.com/browser/devtools/client/debugger/test/mochitest/examples/doc-wa
Regressed by: 1560631

Joel can we backout here?

Flags: needinfo?(jmaher)

I'll be working on it tomorrow. Feel free to disable in the meantime.

I would say yes, lets backout- when we find a root cause and it is within 3 days of landing when you identify it, ask real quick about a backout. If it is longer than 3 days, needinfo and wait 2 business days.

This specific bug would have been a candidate for a quick backout, and also we had a long period of needinfo (could be holiday, but still landing code right before holiday isn't ideal).

I am glad to hear that :jlast will be looking into this and will look forward to a fix soon- if there isn't a fix or pending review by July 4th please disable

Flags: needinfo?(jmaher)
Whiteboard: [stockwell disable-recommended] → [stockwell needswork:owner]

Hi David, could you take a look at the patch here? Failure rate is very high.

Thank you.

Flags: needinfo?(dwalsh)
Pushed by csabou@mozilla.com:
https://hg.mozilla.org/integration/autoland/rev/109fab16fdda
Fix intermittent browser_dbg-wasm-sourcemaps test. r=davidwalsh

Push with failures: https://treeherder.mozilla.org/#/jobs?repo=autoland&group_state=expanded&resultStatus=testfailed%2Cbusted%2Cexception&revision=109fab16fddacbe16a28a8cb9ed8182378fdfef6&selectedJob=255204487

Failure log: https://treeherder.mozilla.org/logviewer.html#/jobs?job_id=255204487&repo=autoland&lineNumber=90

Backout link: https://hg.mozilla.org/integration/autoland/rev/49dbe87c01da133fbe2109cb6c37403add2c3149

[task 2019-07-08T05:45:42.597Z] TEST START | Flow
[task 2019-07-08T05:46:02.570Z] Error ------------------------------------------------------------------------- src/actions/ast/setInScopeLines.js:73:35
[task 2019-07-08T05:46:02.570Z]
[task 2019-07-08T05:46:02.570Z] Cannot call hasSourceActor with location.sourceId bound to id because string [1] is incompatible with
[task 2019-07-08T05:46:02.570Z] SourceActorId [2].
[task 2019-07-08T05:46:02.570Z]
[task 2019-07-08T05:46:02.570Z] src/actions/ast/setInScopeLines.js:73:35
[task 2019-07-08T05:46:02.570Z] 73| !hasSourceActor(getState(), location.sourceId)
[task 2019-07-08T05:46:02.570Z] ^^^^^^^^^^^^^^^^^
[task 2019-07-08T05:46:02.570Z]
[task 2019-07-08T05:46:02.570Z] References:
[task 2019-07-08T05:46:02.570Z] src/types.js:87:14
[task 2019-07-08T05:46:02.570Z] 87| +sourceId: SourceId,
[task 2019-07-08T05:46:02.570Z] ^^^^^^^^ [1]
[task 2019-07-08T05:46:02.570Z] src/reducers/source-actors.js:95:7
[task 2019-07-08T05:46:02.570Z] 95| id: SourceActorId
[task 2019-07-08T05:46:02.570Z] ^^^^^^^^^^^^^ [2]
[task 2019-07-08T05:46:02.570Z]
[task 2019-07-08T05:46:02.570Z]
[task 2019-07-08T05:46:02.570Z]
[task 2019-07-08T05:46:02.570Z] Found 1 error
[task 2019-07-08T05:46:02.570Z]
[task 2019-07-08T05:46:19.669Z] TEST-UNEXPECTED-FAIL flow | Cannot call hasSourceActor with location.sourceId bound to id because string [1] is incompatible with SourceActorId [2].
[task 2019-07-08T05:46:19.669Z] TEST START | Eslint
[task 2019-07-08T05:47:04.762Z] yarn run v1.9.4
[task 2019-07-08T05:47:04.763Z] $ eslint .js "src/**/.js" "packages//src/**/.js" --fix

[task 2019-07-08T05:49:02.887Z] PASS test src/components/shared/tests/Badge.spec.js
[task 2019-07-08T05:49:02.887Z]
[task 2019-07-08T05:49:02.887Z] Summary of all failing tests
[task 2019-07-08T05:49:02.887Z] FAIL src/actions/ast/tests/setInScopeLines.spec.js (21.396s)
[task 2019-07-08T05:49:02.887Z] ● getInScopeLine › with selected line
[task 2019-07-08T05:49:02.887Z]
[task 2019-07-08T05:49:02.887Z] Timeout - Async callback was not invoked within the 20000ms timeout specified by jest.setTimeout.
[task 2019-07-08T05:49:02.887Z]
[task 2019-07-08T05:49:02.887Z] 34 |
[task 2019-07-08T05:49:02.887Z] 35 | describe("getInScopeLine", () => {
[task 2019-07-08T05:49:02.887Z] > 36 | it("with selected line", async () => {
[task 2019-07-08T05:49:02.887Z] | ^
[task 2019-07-08T05:49:02.887Z] 37 | const store = createStore(threadClient);
[task 2019-07-08T05:49:02.887Z] 38 | const { dispatch, getState } = store;
[task 2019-07-08T05:49:02.887Z] 39 | const source = makeMockSource("scopes.js", "scopes.js");
[task 2019-07-08T05:49:02.887Z]
[task 2019-07-08T05:49:02.888Z] at Spec (node_modules/jest-jasmine2/build/jasmine/Spec.js:85:20)
[task 2019-07-08T05:49:02.888Z] at Suite.Object.<anonymous>.describe (src/actions/ast/tests/setInScopeLines.spec.js:36:3)
[task 2019-07-08T05:49:02.888Z] at Object.<anonymous> (src/actions/ast/tests/setInScopeLines.spec.js:35:1)
[task 2019-07-08T05:49:02.888Z]
[task 2019-07-08T05:49:02.888Z]
[task 2019-07-08T05:49:02.888Z] Test Suites: 1 failed, 204 passed, 205 total
[task 2019-07-08T05:49:02.888Z] Tests: 1 failed, 8 skipped, 1735 passed, 1744 total
[task 2019-07-08T05:49:02.888Z] Snapshots: 439 passed, 439 total
[task 2019-07-08T05:49:02.888Z] Time: 115.827s
[task 2019-07-08T05:49:02.888Z] Ran all test suites in 5 projects.
[task 2019-07-08T05:49:02.888Z] error Command failed with exit code 1.
[task 2019-07-08T05:49:02.888Z] TEST-UNEXPECTED-FAIL jest | ● getInScopeLine › with selected line
[task 2019-07-08T05:49:02.889Z] TEST START | Stylelint

Flags: needinfo?(jlaster)

The patch that was pushed with changeset 109fab16fdda and backed out also makes browser_dbg-preview-frame.js time out:

https://treeherder.mozilla.org/logviewer.html#/jobs?job_id=255207796&repo=autoland&lineNumber=7343

07:15:44 INFO - TEST-INFO | started process screencapture
07:15:44 INFO - TEST-INFO | screencapture: exit 0
07:15:44 INFO - Buffered messages logged at 07:14:59
07:15:44 INFO - Entering test bound
07:15:44 INFO - Console message: [JavaScript Error: "uncaught exception: Object" {file: "resource://testing-common/PromiseTestUtils.jsm" line: 112}]
07:15:44 INFO - Adding a new tab with URL: http://example.com/browser/devtools/client/debugger/test/mochitest/examples/doc-script-switching.html
07:15:44 INFO - Tab added and finished loading
07:15:44 INFO - Opening the toolbox
07:15:44 INFO - Buffered messages logged at 07:15:00
07:15:44 INFO - Toolbox opened and focused
07:15:44 INFO - TEST-PASS | devtools/client/debugger/test/mochitest/browser_dbg-preview-frame.js | Call stack is hidden -
07:15:44 INFO - Invoking in tab: firstCall()
07:15:44 INFO - Waiting for state change: paused
07:15:44 INFO - Finished waiting for state change: paused
07:15:44 INFO - Finished waiting for state change: paused
07:15:44 INFO - Waiting for state change: selected source
07:15:44 INFO - Finished waiting for state change: selected source
07:15:44 INFO - Preview a variable in the second frame
07:15:44 INFO - Waiting for state change:
07:15:44 INFO - Buffered messages finished
07:15:44 INFO - TEST-UNEXPECTED-FAIL | devtools/client/debugger/test/mochitest/browser_dbg-preview-frame.js | Test timed out -
07:15:44 INFO - Removing tab.
07:15:44 INFO - Waiting for event: 'TabClose' on [object XULElement].
07:15:44 INFO - Got event: 'TabClose' on [object XULElement].
07:15:44 INFO - Tab removed and finished closing
07:15:44 INFO - GECKO(1716) | MEMORY STAT | vsize 7997MB | residentFast 644MB | heapAllocated 158MB
07:15:44 INFO - TEST-OK | devtools/client/debugger/test/mochitest/browser_dbg-preview-frame.js | took 45351ms
07:15:44 INFO - checking window state
07:15:44 INFO - GECKO(1716) | JavaScript error: resource://testing-common/PromiseTestUtils.jsm, line 112: uncaught exception: Object
07:15:44 INFO - TEST-START | devtools/client/debugger/test/mochitest/browser_dbg-preview-module.js

Pushed by jlaster@mozilla.com:
https://hg.mozilla.org/integration/autoland/rev/cefe8197e4ce
Fix intermittent browser_dbg-wasm-sourcemaps test.
Status: NEW → RESOLVED
Closed: 3 months ago
Resolution: --- → FIXED
Target Milestone: --- → Firefox 70
Assignee: nobody → jlaster

This still happens even after the fix has landed: https://treeherder.mozilla.org/#/jobs?repo=autoland&resultStatus=success%2Ctestfailed%2Cbusted%2Cexception&searchStr=windows%2C7%2Cdebug%2Cmochitests%2Ctest-windows7-32%2Fdebug-mochitest-devtools-chrome-e10s-5%2Cm%28dt5%29&fromchange=58fced48cd5dcf0f87c1d8345e011f6961af78cf&selectedJob=255440484

Failure log: https://treeherder.mozilla.org/logviewer.html#/jobs?job_id=255440484&repo=autoland&lineNumber=60909

INFO - TEST-UNEXPECTED-FAIL | devtools/client/debugger/test/mochitest/browser_dbg-wasm-sourcemaps.js | A promise chain failed to handle a rejection: Error: Parser: source sourceURL-http://example.com/browser/devtools/client/debugger/test/mochitest/examples/doc-wasm-sourcemaps.html was not provided. - stack: setInScopeLines/<@resource://devtools/client/debugger/src/actions/ast/setInScopeLines.js:59:5

Status: RESOLVED → REOPENED
Resolution: FIXED → ---
Target Milestone: Firefox 70 → ---
Duplicate of this bug: 1564385
Attachment #9075817 - Attachment is obsolete: true
Attachment #9077008 - Attachment description: Bug 1561092 - disabled browser_dbg-wasm-sourcemaps.js on win and linux r=jmaher → Bug 1561092 - disabled browser_dbg-wasm-sourcemaps.js on win and linux debug r=jmaher
Pushed by apavel@mozilla.com:
https://hg.mozilla.org/integration/autoland/rev/26592a2a32aa
disabled browser_dbg-wasm-sourcemaps.js on win and linux debug r=jmaher
Keywords: leave-open
Whiteboard: [stockwell disable-recommended] → [stockwell disabled]

The test was skipped but looks like disabling this test led to a spike in other test failures in bug 1559760 and bug 1559761: devtools/client/debugger/test/mochitest/browser_dbg-console-link.js and devtools/client/debugger/test/mochitest/browser_dbg-windowless-workers-early-breakpoint.js that both had 0 zero failures before this landed.
https://treeherder.mozilla.org/#/jobs?repo=autoland&searchStr=windows%2C7%2Cdebug%2Cmochitests%2Ctest-windows7-32%2Fdebug-mochitest-devtools-chrome-e10s&tochange=26592a2a32aaebbb33bd03042b6c283775b99745&fromchange=ee059061515f19c66cbc1466108d2cf0e05de0bd&group_state=expanded&selectedJob=255786454
Joel, any ideas on what to do here? I fear that disabling the other two tests would lead to other failing.

Flags: needinfo?(jmaher)
Regressions: 1559761
Regressions: 1559760

Andrea, would it be possible to re-enable this test as i pushed a fix for the test on monday? perhaps this will improve the other tests that started failing...

Flags: needinfo?(jlaster)
Flags: needinfo?(csabou)
Flags: needinfo?(apavel)

I think what :jlast said would be a good next step.

Flags: needinfo?(jmaher)

Backed out changeset 26592a2a32aa (bug 1561092) reverting disabling because of bug 1559760 and bug 1559761

I reverted Andreea's changes with this backout, we should see a decrease in failures.

Backout:
https://hg.mozilla.org/integration/autoland/rev/956e97b8354d666aa441eef42c21c88f2fbf775d

Flags: needinfo?(csabou)
Flags: needinfo?(apavel)
Flags: needinfo?(dwalsh)
Blocks: dbg-70
Whiteboard: [stockwell disabled] → [debugger-mvp] [stockwell disabled]
Pushed by jlaster@mozilla.com:
https://hg.mozilla.org/integration/autoland/rev/9e5591144e2e
browser_dbg-wasm-sourcemaps.js. r=davidwalsh
Status: REOPENED → RESOLVED
Closed: 3 months ago2 months ago
Resolution: --- → FIXED

Jason, can we safely backport this to Beta to fix the oranges there?

Flags: needinfo?(ydelendik) → needinfo?(jlaster)
Target Milestone: --- → Firefox 70
Flags: needinfo?(jlaster)
You need to log in before you can comment on or make changes to this bug.