Closed Bug 1277834 Opened 7 years ago Closed 7 years ago

Intermittent browser_toolbox_window_reload_target.js | A promise chain failed to handle a rejection: - at resource://gre/modules/commonjs/toolkit/loader.js -> resource://devtools/client/inspector/breadcrumbs.js:757 - TypeError: this.nodeHierarchy[this.cur

Categories

(DevTools :: Inspector, defect, P2)

Product:
DevTools
Component:
Inspector
Type:
defect

Tracking

(firefox48 unaffected, firefox49 wontfix, firefox50 wontfix, firefox51 fixed)

Status:
RESOLVED FIXED
Milestone:
Firefox 51
Tracking Flags:
Tracking Status
firefox48 --- unaffected
firefox49 --- wontfix
firefox50 --- wontfix
firefox51 --- fixed

People

(Reporter: cbook, Assigned: pbro)

References

(
URL
)

Details

(Keywords: intermittent-failure)

Attachments

(2 files)

Bug 1277834 - Silence inspector warnings and add promise rejection handlers;
58 bytes, text/x-review-board-request
jdescottes
: review+
Details
Bug 1277834 - Add missing promise rejection handler to breadcrumbs;
58 bytes, text/x-review-board-request
jdescottes
: review+
Details 
https://treeherder.mozilla.org/logviewer.html#?job_id=29399375&repo=mozilla-inbound#L2489

 08:04:45 INFO - 209 INFO TEST-UNEXPECTED-FAIL | devtools/client/framework/test/browser_toolbox_window_reload_target.js | A promise chain failed to handle a rejection: - at resource://gre/modules/commonjs/toolkit/loader.js -> resource://devtools/client/inspector/breadcrumbs.js:757 - TypeError: this.nodeHierarchy[this.currentIndex] is undefined
Inspector bug triage (filter on CLIMBING SHOES).
Priority: -- → P3
This looks pretty frequent. Can we please bump the priority on it? Maybe bug 1241019 while we're at it? :)
Flags: needinfo?(pbrosset)
Thanks Ryan, this should indeed really be a P1.
I had seen this test failing often but thought it was a devtools framework thing (it's a toolbox test), but it's instead an inspector problem, which is definitely on my radar. I'll make sure it gets worked on.
Flags: needinfo?(pbrosset)
Priority: P3 → P1
Assignee: nobody → pbrosset
Status: NEW → ASSIGNED
Honza: feel free to delegate the review if you've not worked with this code too much. But I figured that you've been doing a lot of inspector-related work lately.

The part 1 is about silencing warnings we've had for a long time in the inspector and that don't serve any purpose. They were logged when an error occurred after the panel was destroyed, which is expected. So now, we just bail out silently. This avoids creating confusing logs during tests.
It also adds a missing promise rejection to avoid huge stack traces in the logs too.

And part 2 is the actual fix for this bug: the test fails with an unhandled promise rejection, which I easily spotted in breadcrumbs.js.
Attachment #8772731 - Flags: review?(odvarko) → review?(jdescottes)
Attachment #8772732 - Flags: review?(odvarko) → review?(jdescottes)
Attachment #8772732 - Flags: review?(jdescottes)
Comment on attachment 8772732 [details]
Bug 1277834 - Add missing promise rejection handler to breadcrumbs;

https://reviewboard.mozilla.org/r/65502/#review62974

I can still reproduce the test failure locally on Unbuntu, so I relaunched a bunch of jobs on your try run to see how it goes.

The failure is this.nodeHierarchy[this.currentIndex] is undefined. If the issue was related to the destroy of the breadcrumbs, I think the error should be "this.nodeHierarchy is null" (since this.nodeHierarchy is set to null in the destroy method of the breadcrumbs).

Let's wait for the outcome of the tests for now.
Comment on attachment 8772731 [details]
Bug 1277834 - Silence inspector warnings and add promise rejection handlers;

https://reviewboard.mozilla.org/r/65500/#review62958

Looks good thanks!

I thought the idea was to wait on proper events in tests rather than swallowing errors in catch handlers?
I'm ok with this though, I think this increases the implementation's robustness and will decrease test complexity.

::: devtools/client/inspector/inspector-panel.js:267
(Diff revision 1)
> +      // Only log the rejection as an error if the panel hasn't been destroyed in the
> +      // meantime. We expect rejections when the panel is destroyed while requests are
> +      // still being processed.
> +      if (!this._panelDestroyer) {
> +        console.error(e);
> +      }

Around ~6 lines of trivial code duplicated 4 times in inspector-panel and 5 times in markup.js. This is most likely not what you want to read when you lookup those methods.

Maybe each class could have its own private method to cleanup this a bit.

  _catchPromiseError: function (e) {
    // Only log the rejection errors if the panel hasn't been destroyed in the meantime.
    if (!this._panelDestroyer) {
      console.error(e);
    }
  },

::: devtools/client/inspector/inspector-panel.js:634
(Diff revision 1)
>      // of the selected node so it can be restored after reload of the same page
>      if (this.canGetUniqueSelector &&
>          this.selection.isElementNode()) {
>        selection.getUniqueSelector().then(selector => {
>          this.selectionCssSelector = selector;
>        }).then(null, e => {

Not related to your changeset, but do you know if the pattern used here brings any value:

.then(success).then(null, failure)

instead of simply .then(success, failure) ?
Attachment #8772731 - Flags: review?(jdescottes) → review+
Comment on attachment 8772732 [details]
Bug 1277834 - Add missing promise rejection handler to breadcrumbs;

https://reviewboard.mozilla.org/r/65502/#review63010

Ok, 0 failures on try on ~10 runs, so let's give this a shot. (https://treeherder.mozilla.org/#/jobs?repo=try&revision=ec7b6795cad7&group_state=expanded)
Maybe my local tests hit an extremely rare intermittent that happened to have the same error message.
(I still don't understand the correlation between the fix and the error message, so I'll keep an eye on the test :) )
(In reply to Julian Descottes [:jdescottes] from comment #16)
> The failure is this.nodeHierarchy[this.currentIndex] is undefined. If the
> issue was related to the destroy of the breadcrumbs, I think the error
> should be "this.nodeHierarchy is null" (since this.nodeHierarchy is set to
> null in the destroy method of the breadcrumbs).
Yeah, true. I'm not entirely sure what happens. But looking at the error message (unhandled promise rejection), it could really only come from one place: the waitForTick promise in the update method.
We call the scroll method in the handler, and that tries to access this.nodeHierarchy[this.currentIndex].
So my assumption was that during the test, the current inspector selection changed before the promise resolved, and so the this.nodeHierarchy array didn't have the same number of items anymore.

Thanks for retriggering jobs on linux!

(In reply to Julian Descottes [:jdescottes] from comment #17)
> 
> ::: devtools/client/inspector/inspector-panel.js:267
> (Diff revision 1)
> > +      // Only log the rejection as an error if the panel hasn't been destroyed in the
> > +      // meantime. We expect rejections when the panel is destroyed while requests are
> > +      // still being processed.
> > +      if (!this._panelDestroyer) {
> > +        console.error(e);
> > +      }
> 
> Around ~6 lines of trivial code duplicated 4 times in inspector-panel and 5
> times in markup.js. This is most likely not what you want to read when you
> lookup those methods.
> 
> Maybe each class could have its own private method to cleanup this a bit.
> 
>   _catchPromiseError: function (e) {
>     // Only log the rejection errors if the panel hasn't been destroyed in
> the meantime.
>     if (!this._panelDestroyer) {
>       console.error(e);
>     }
>   },
Good point! I'll make that change.

> ::: devtools/client/inspector/inspector-panel.js:634
> (Diff revision 1)
> >      // of the selected node so it can be restored after reload of the same page
> >      if (this.canGetUniqueSelector &&
> >          this.selection.isElementNode()) {
> >        selection.getUniqueSelector().then(selector => {
> >          this.selectionCssSelector = selector;
> >        }).then(null, e => {
> 
> Not related to your changeset, but do you know if the pattern used here
> brings any value:
> 
> .then(success).then(null, failure)
> 
> instead of simply .then(success, failure) ?
Right, there's no difference at all in this case.
But there are other cases where it makes a difference:

function p1() {
  return Promise.resolve("p1 resolved");
}

function p2() {
  return Promise.reject("p2 rejected");
}

p1().then(() => p2(), e => console.error(e));

Here we're not catching the rejection from p2. We'd only catch the one from p1 if it rejected.
So this would work better:

p1().then(() => p2()).then(null, e => console.error(e));
or simply:
p1().then(() => p2()).catch(e => console.error(e));
Comment on attachment 8772731 [details]
Bug 1277834 - Silence inspector warnings and add promise rejection handlers;

Review request updated; see interdiff: https://reviewboard.mozilla.org/r/65500/diff/1-2/
Comment on attachment 8772732 [details]
Bug 1277834 - Add missing promise rejection handler to breadcrumbs;

Review request updated; see interdiff: https://reviewboard.mozilla.org/r/65502/diff/1-2/
Pushed by pbrosset@mozilla.com:
https://hg.mozilla.org/integration/autoland/rev/91c303acd4a3
Silence inspector warnings and add promise rejection handlers; r=jdescottes
https://hg.mozilla.org/integration/autoland/rev/2ce848f8b804
Add missing promise rejection handler to breadcrumbs; r=jdescottes
https://hg.mozilla.org/mozilla-central/rev/91c303acd4a3
https://hg.mozilla.org/mozilla-central/rev/2ce848f8b804
Status: ASSIGNED → RESOLVED
Closed: 7 years ago
status-firefox50: --- → fixed
Resolution: --- → FIXED
Target Milestone: --- → Firefox 50
This affects 49 as well. Can we please get a rebased patch (at least part 1 doesn't apply cleanly) and an approval request?
status-firefox48: --- → unaffected
status-firefox49: --- → affected
Flags: needinfo?(jdescottes)
Looking at the recent failures, the current patch does not fix the intermittent. 
I don't think it is worth rebasing and uplifting just yet.
Flags: needinfo?(jdescottes)
Status: RESOLVED → REOPENED
status-firefox50: fixed → affected
Resolution: FIXED → ---
Target Milestone: Firefox 50 → ---
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1277834&startday=2016-07-01&endday=2016-08-22&tree=all shows that since August 7th, this test doesn't fail much anymore.

So indeed, the fix that I had done (and that landed on July 22nd) didn't fix the issue, but something that landed around August 7th must have.

The only thing I see that landed around that date which could have had an impact is bug 1267365. Especially this change: http://hg.mozilla.org/integration/fx-team/diff/1646172ac6e7/devtools/client/inspector/breadcrumbs.js
which changed waitForTick to setTimeout.

Anyway, adjusting the priority to reflect the failure frequency.
Priority: P1 → P2
Status: REOPENED → RESOLVED
Closed: 7 years ago → 7 years ago
Resolution: --- → FIXED
Target Milestone: --- → Firefox 51
Product: Firefox → DevTools
You need to log in before you can comment on or make changes to this bug.