browser_ext_devtools_inspectedWindow.js is going to frequently fail when Gecko 57 merges to Beta on 2017-09-20

VERIFIED FIXED in Firefox 57

Status

defect
--
critical
VERIFIED FIXED
2 years ago
Last year

People

(Reporter: RyanVM, Assigned: jdescottes)

Tracking

Trunk
Firefox 57
Dependency tree / graph

Firefox Tracking Flags

(firefox57+ verified)

Details

Attachments

(1 attachment)

Reporter

Description

2 years ago
[Tracking Requested - why for this release]: Frequently failing test on the next merge day.

I won't call this permafail since I'm pretty sure there were *some* green runs, but the failure rate is extremely high nonetheless (intermittently green more than the other way around).

I bisected this down to the range below:
https://hg.mozilla.org/mozilla-central/pushloghtml?fromchange=a2723b650460&tochange=e4b8ea7baeb6

From there, bug 1395262 seems like the most obvious candidate within the range, but I haven't actually verified that. Regardless, can you please take a look, Tom? CCing Luca as well just in case he has any ideas.

https://treeherder.mozilla.org/logviewer.html#?job_id=127609175&repo=try

TEST-PASS | browser/components/extensions/test/browser/test-oop-extensions/browser_ext_devtools_inspectedWindow.js | Got exceptionInfo.value value Error: fake eval exception
	@debugger eval called from moz-extension://b18d9dca-ab60-4f95-aea8-119930c216c9/ - eval code:1:7
 matches /Error: fake eval exception\n.*moz-extension:\/\// - 
Console message: [JavaScript Error: "TypeError: this._urls is null" {file: "resource://gre/modules/commonjs/toolkit/loader.js -> resource://devtools/client/framework/source-map-url-service.js" line: 82}]
Buffered messages finished
TEST-UNEXPECTED-FAIL | browser/components/extensions/test/browser/test-oop-extensions/browser_ext_devtools_inspectedWindow.js | A promise chain failed to handle a rejection: this._urls is null - stack: null
Rejection date: Fri Sep 01 2017 02:30:13 GMT+0000 (UTC) - false == true - JS frame :: resource://testing-common/PromiseTestUtils.jsm :: assertNoUncaughtRejections :: line 265
Stack trace:
    resource://testing-common/PromiseTestUtils.jsm:assertNoUncaughtRejections:265
    chrome://mochikit/content/browser-test.js:Tester_execTest/<:825
    Tester_execTest@chrome://mochikit/content/browser-test.js:794:9
    Tester.prototype.nextTest</<@chrome://mochikit/content/browser-test.js:694:7
    SimpleTest.waitForFocus/waitForFocusInner/focusedOrLoaded/<@chrome://mochikit/content/tests/SimpleTest/SimpleTest.js:795:59
Leaving test bound test_devtools_inspectedWindow_eval

The patch below should be sufficient for reproducing locally or on Try. Let me know if it doesn't work.
https://hg.mozilla.org/try/rev/893117049f14004a416aad09dabe24ea2f5d5ef2
Flags: needinfo?(ttromey)
Assignee

Comment 2

2 years ago
For the record we have a similar intermittent that appeared for scratchpad : https://bugzilla.mozilla.org/show_bug.cgi?id=1395783

I guess the most probable explanation for the failure is related to an async step in the constructor of the SourceMapURLService:

>  this._loadingPromise = threadClient.getSources().then(({sources}) => {
>    // Ignore errors.  Register the sources we got; we can't rely on
>    // an event to arrive if the source actor already existed.
>    for (let source of sources) {
>      this._onSourceUpdated(null, {source});
>    }
>  }, e => {
>    // Also ignore any protocol-based errors.
>  });

If the toolbox is destroyed before threadClient.getSources() finishes, it will trigger the error detected in the test. No idea why this would be more frequent on Beta than on Nightly, and I can't reproduce locally for now.

This code was added by Bug 1396071, that landed on central yesterday: https://hg.mozilla.org/mozilla-central/rev/fcd4aabcec11 
It landed prior to the bisect mentioned above, so it's possible that another changeset increased the intermittent frequency.

I attached a patch here that should avoid the failure, but we should really try to understand why this fails particularly on beta (if anyone can repro locally and make progress feel free to discard my patch). Try at https://treeherder.mozilla.org/#/jobs?repo=try&revision=aa04831d330ea3b383eb443c2edc4c0e67bc94e1
Assignee

Comment 3

2 years ago
My previous try push was probably a bit bad, here is another one based on : https://hg.mozilla.org/try/rev/4a8fb30e31ab51f9d4cc546b038180041966d8cf

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

No failure for browser_ext_devtools_inspectedWindow.js spotted so far.
Reporter

Comment 4

2 years ago
Comment on attachment 8903831 [details]
Bug 1396071 - check if SourceMapURLService has been destroyed after async call;

I included it with my Try runs last night and it looks good there too.
Attachment #8903831 - Flags: feedback+

Comment 5

2 years ago
mozreview-review
Comment on attachment 8903831 [details]
Bug 1396071 - check if SourceMapURLService has been destroyed after async call;

https://reviewboard.mozilla.org/r/175598/#review181276

r+ with the comment addressed.  Thank you very much for doing this.

::: devtools/client/framework/source-map-url-service.js:40
(Diff revision 1)
>  
>    Services.prefs.addObserver(SOURCE_MAP_PREF, this._onPrefChanged);
>  
>    // Start fetching the sources now.
>    this._loadingPromise = threadClient.getSources().then(({sources}) => {
> +    if (this._destroyed) {

Elsewhere, `this._urls` is used as a sentinel for "destroyed":

https://dxr.mozilla.org/mozilla-central/rev/632e42dca494ec3d90b70325d9c359f80cb3f38a/devtools/client/framework/source-map-url-service.js#105

So I don't think a new flag is needed.

I think it's fine to land this though I do wonder what is going on.  Is it just a normal race?  Or is the service being started unnecessarily at some spot?
Attachment #8903831 - Flags: review?(ttromey) → review+
Assignee

Updated

2 years ago
Assignee: nobody → jdescottes
Status: NEW → ASSIGNED
Comment hidden (mozreview-request)
Assignee

Comment 7

2 years ago
mozreview-review-reply
Comment on attachment 8903831 [details]
Bug 1396071 - check if SourceMapURLService has been destroyed after async call;

https://reviewboard.mozilla.org/r/175598/#review181276

> Elsewhere, `this._urls` is used as a sentinel for "destroyed":
> 
> https://dxr.mozilla.org/mozilla-central/rev/632e42dca494ec3d90b70325d9c359f80cb3f38a/devtools/client/framework/source-map-url-service.js#105
> 
> So I don't think a new flag is needed.
> 
> I think it's fine to land this though I do wonder what is going on.  Is it just a normal race?  Or is the service being started unnecessarily at some spot?

Thanks for the review! Good point about using this._urls. I also moved the guard inside of the _onSourceUpdated method, it's also more consistent with the rest of the file.

Regarding the increased frequency on Beta I have no idea how to explain that. The only thing I can think of is that the old console is being used instead of the new console on Beta. But as I said I can't reproduce locally for now :(
Clearing NI.
Flags: needinfo?(ttromey)
Reporter

Comment 9

2 years ago
Comment on attachment 8903831 [details]
Bug 1396071 - check if SourceMapURLService has been destroyed after async call;

Looks good on Try!
Attachment #8903831 - Flags: feedback+

Comment 10

2 years ago
Pushed by jdescottes@mozilla.com:
https://hg.mozilla.org/integration/autoland/rev/4ef59b77d1cb
check if SourceMapURLService has been destroyed after async call;r=tromey

Comment 11

2 years ago
bugherder
https://hg.mozilla.org/mozilla-central/rev/4ef59b77d1cb
Status: ASSIGNED → RESOLVED
Closed: 2 years ago
Resolution: --- → FIXED
Target Milestone: --- → Firefox 57
Reporter

Updated

2 years ago
Status: RESOLVED → VERIFIED

Updated

Last year
Product: Firefox → DevTools
You need to log in before you can comment on or make changes to this bug.