Closed Bug 1475782 Opened 6 years ago Closed 6 years ago

Intermittent devtools/client/inspector/fonts/test/browser_fontinspector_editor-font-size-conversion.js | A promise chain failed to handle a rejection: Connection closed, pending request to server1.conn2.child1/pagestyle29, type getComputed failed

Categories

(DevTools :: Inspector, defect, P2)

Product:
DevTools
Component:
Inspector
Type:
defect

Tracking

(firefox63 fixed)

Status:
RESOLVED FIXED
Milestone:
Firefox 63
Tracking Flags:
Tracking Status
firefox63 --- fixed

People

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

References

Details

(Keywords: intermittent-failure, Whiteboard: [retriggered][TV-bf fail:fail][TV-bf TODO][stockwell needswork])

Attachments

(2 files)

Bug 1475782 - Fix for intermittent test failures on Font Editor unit conversion.
59 bytes, text/x-review-board-request
pbro
: review+
Details
Bug 1475782 - Return promises from Rule mutation methods and catch errors in font editor.
59 bytes, text/x-review-board-request
pbro
: review+
Details 
Filed by: btara [at] mozilla.com

https://treeherder.mozilla.org/logviewer.html#?job_id=188181222&repo=mozilla-inbound

https://queue.taskcluster.net/v1/task/Ql6UKJIRTAKstU-tcsPwLw/runs/0/artifacts/public/logs/live_backing.log

08:30:25     INFO -  123 INFO TEST-PASS | devtools/client/inspector/fonts/test/browser_fontinspector_editor-font-size-conversion.js | Font size on inline style is 1em -
08:30:25     INFO -  124 INFO Leaving test bound
08:30:25     INFO -  125 INFO Console message: [JavaScript Error: "Error: Connection closed, pending request to server1.conn2.child1/pagestyle29, type getComputed failed
08:30:25     INFO -  Request stack:
08:30:25     INFO -  request@resource://devtools/shared/base-loader.js -> resource://devtools/shared/protocol.js:1346:14
08:30:25     INFO -  generateRequestMethods/</frontProto[name]@resource://devtools/shared/base-loader.js -> resource://devtools/shared/protocol.js:1500:14
08:30:25     INFO -  refreshFontEditor@resource://devtools/shared/base-loader.js -> resource://devtools/client/inspector/fonts/fonts.js:862:36
08:30:25     INFO -  async*onRulePropertyUpdated@resource://devtools/shared/base-loader.js -> resource://devtools/client/inspector/fonts/fonts.js:759:13
08:30:25     INFO -  async*exports.debounce/</timer<@resource://devtools/shared/base-loader.js -> resource://devtools/shared/debounce.js:30:7
08:30:25     INFO -  notify@resource://gre/modules/Timer.jsm:44:7
08:30:25     INFO -  " {file: "resource://devtools/shared/base-loader.js -> resource://devtools/shared/protocol.js" line: 1289}]
08:30:25     INFO -  Buffered messages logged at 08:30:25
08:30:25     INFO -  126 INFO Removing tab.
08:30:25     INFO -  127 INFO Waiting for event: 'TabClose' on [object XULElement].
08:30:25     INFO -  128 INFO Got event: 'TabClose' on [object XULElement].
08:30:25     INFO -  129 INFO Tab removed and finished closing
08:30:25     INFO -  Buffered messages finished
08:30:25    ERROR -  130 INFO TEST-UNEXPECTED-FAIL | devtools/client/inspector/fonts/test/browser_fontinspector_editor-font-size-conversion.js | A promise chain failed to handle a rejection: Connection closed, pending request to server1.conn2.child1/pagestyle29, type getComputed failed
08:30:25     INFO -  Request stack:
08:30:25     INFO -  request@resource://devtools/shared/base-loader.js -> resource://devtools/shared/protocol.js:1346:14
08:30:25     INFO -  generateRequestMethods/</frontProto[name]@resource://devtools/shared/base-loader.js -> resource://devtools/shared/protocol.js:1500:14
08:30:25     INFO -  refreshFontEditor@resource://devtools/shared/base-loader.js -> resource://devtools/client/inspector/fonts/fonts.js:862:36
08:30:25     INFO -  async*onRulePropertyUpdated@resource://devtools/shared/base-loader.js -> resource://devtools/client/inspector/fonts/fonts.js:759:13
08:30:25     INFO -  async*exports.debounce/</timer<@resource://devtools/shared/base-loader.js -> resource://devtools/shared/debounce.js:30:7
08:30:25     INFO -  notify@resource://gre/modules/Timer.jsm:44:7
08:30:25     INFO -   - stack: destroy@resource://devtools/shared/base-loader.js -> resource://devtools/shared/protocol.js:1289:23
08:30:25     INFO -  destroy@resource://devtools/shared/base-loader.js -> resource://devtools/shared/fronts/styles.js:39:5
08:30:25     INFO -  destroy@resource://devtools/shared/base-loader.js -> resource://devtools/shared/protocol.js:928:9
08:30:25     INFO -  destroy@resource://devtools/shared/base-loader.js -> resource://devtools/shared/protocol.js:1291:5
08:30:25     INFO -  destroy@resource://devtools/shared/base-loader.js -> resource://devtools/shared/fronts/inspector.js:472:5
08:30:25     INFO -  destroyInspector/this._destroyingInspector<@resource://devtools/shared/base-loader.js -> resource://devtools/client/framework/toolbox.js:2797:13
08:30:25     INFO -  Async*destroyInspector@resource://devtools/shared/base-loader.js -> resource://devtools/client/framework/toolbox.js:2781:40
08:30:25     INFO -  destroy@resource://devtools/shared/base-loader.js -> resource://devtools/client/framework/toolbox.js:2924:22
08:30:25     INFO -  closeToolbox@resource://devtools/shared/base-loader.js -> resource://devtools/client/framework/devtools.js:590:11
08:30:25     INFO -  async*closeTabAndToolbox@chrome://mochitests/content/browser/devtools/client/shared/test/shared-head.js:456:11
08:30:25     INFO -  async*cleanup@chrome://mochitests/content/browser/devtools/client/shared/test/shared-head.js:139:11
08:30:25     INFO -  async*nextTest@chrome://mochikit/content/browser-test.js:704:30
08:30:25     INFO -  async*testScope/test_finish/<@chrome://mochikit/content/browser-test.js:1397:11
08:30:25     INFO -  run@chrome://mochikit/content/browser-test.js:1334:9
08:30:25     INFO -  Rejection date: Sat Jul 14 2018 08:30:24 GMT+0000 (Coordinated Universal Time) - false == true - JS frame :: resource://testing-common/PromiseTestUtils.jsm :: assertNoUncaughtRejections :: line 257
08:30:25     INFO -  Stack trace:
08:30:25     INFO -  resource://testing-common/PromiseTestUtils.jsm:assertNoUncaughtRejections:257
08:30:25     INFO -  chrome://mochikit/content/browser-test.js:nextTest:745
08:30:25     INFO -  chrome://mochikit/content/browser-test.js:testScope/test_finish/<:1397
08:30:25     INFO -  chrome://mochikit/content/browser-test.js:run:1334
08:30:25     INFO -  GECKO(3816) | MEMORY STAT | vsize 2000MB | vsizeMaxContiguous 130967534MB | residentFast 356MB | heapAllocated 141MB
08:30:25     INFO -  131 INFO TEST-OK | devtools/client/inspector/fonts/test/browser_fontinspector_editor-font-size-conversion.js | took 5648ms
08:30:25     INFO -  GECKO(3816) | ++DOCSHELL 0000012E19249000 == 3 [pid = 4840] [id = {2f36af80-2335-4976-921b-c8989e43b208}]
08:30:25     INFO -  GECKO(3816) | ++DOMWINDOW == 6 (0000012E1921A600) [pid = 4840] [serial = 11] [outer = 0000000000000000]
08:30:25     INFO -  132 INFO checking window state
08:30:25     INFO -  GECKO(3816) | ++DOMWINDOW == 7 (0000012E20895C00) [pid = 4840] [serial = 12] [outer = 0000012E1921A600]
Whiteboard: [retriggered] → [retriggered][TV-bf fail:fail][TV-bf TODO]
Assignee: nobody → rcaliman
Status: NEW → ASSIGNED
Component: Inspector → Font Inspector
Priority: P5 → P2
Over the last 7 days there are 41 failures on this bug. These happen on windows7-32-msvc, windows10-64, osx-10-10, linux64-ccov, linux64.

Here is the most recent log example: [task 2018-07-16T11:09:35.622Z] 11:09:35     INFO - TEST-UNEXPECTED-FAIL | devtools/client/inspector/fonts/test/browser_fontinspector_editor-font-size-conversion.js | A promise chain failed to handle a rejection: Connection closed, pending request to server1.conn2.child1/pagestyle29, type getComputed failed
Flags: needinfo?(rcaliman)
See Also: → 1476095
See Also: → 1475979
This intermittent failure occurs after introducing the patch for Bug 1459898. The cause is likely a debounced call getComputed (which lives on the actor) that does not handle the case when the actor is disconnected. I'm on it, attempting a fix. 

If I can't find the root cause today, I will temporarily disable this test: 
devtools/client/inspector/fonts/test/browser_fontinspector_editor-font-size-conversion.js
Flags: needinfo?(rcaliman)
This does look to be related to bug 1475065 as it didn't fail in 20 retriggers on the previous push and failed 3 times in 20 retriggers when that landed (see comment 7).

With that said, we will see what Razvan comes up with.
Flags: needinfo?(jmaher)
Whiteboard: [retriggered][TV-bf fail:fail][TV-bf TODO] → [retriggered][TV-bf fail:fail][TV-bf TODO][stockwell needswork]
Attachment #8992721 - Flags: review?(pbrosset)
Comment on attachment 8992721 [details]
Bug 1475782 - Fix for intermittent test failures on Font Editor unit conversion.

https://reviewboard.mozilla.org/r/257580/#review264584

I re-triggered a lot of runs from your try push: https://treeherder.mozilla.org/#/jobs?repo=try&revision=14cabcfb7695500fa7754a21ca25a3f8c388b6aa
your fix does seem to do the trick, but as discussed on slack, I think wrapping the problematic await in a try catch and then checking for what happened in the catch is probably how we want to go about this.

::: devtools/client/inspector/fonts/fonts.js:857
(Diff revision 1)
>      this.nodeComputedStyle = await this.pageStyle.getComputed(node, {
>        filterProperties: FONT_PROPERTIES
> -    });
> +    }).catch(console.error);

Reading the logs for this specific test failure (which is confusing because the same test also fails with a different signature `setRuleText`, but here let's focus on `getComputed`), it seems to me that right here is the place where it fails.

What I would do here instead of adding a `catch` handler is wrap this in a try catch and bail out silently if we notice we're destroyed already:

```
try {
  this.nodeComputedStyle = await this.pageStyle.getComputed(...);
} catch (e) {
  // Because getComputed is async, there is a chance the font editor was
  // destroyed while we were waiting. If that happened, just bail out
  // silently.
  if (!this.document) {
    return;
  }
  throw e;
}
```

More code, but also more explicit about why we catch errors.
Attachment #8992721 - Flags: review?(pbrosset)
See Also: → 1476394
See Also: → 1476535
I disabled the test in Bug 1476535 until I find a solution to all the issues it causes.
Comment on attachment 8992721 [details]
Bug 1475782 - Fix for intermittent test failures on Font Editor unit conversion.

https://reviewboard.mozilla.org/r/257580/#review264696
Attachment #8992721 - Flags: review?(pbrosset) → review+
rcaliman: Do you want this patch to be landed? If yes, please add a checkin-needed tag in the keywords section. Thank you.
Flags: needinfo?(rcaliman)
I disabled the offending test while I'm trying out different solutions. 

The attached patch is only a partial solution so I don't intend to land it as-is. I will follow-up with another one.
Flags: needinfo?(rcaliman)
Comment on attachment 8993648 [details]
Bug 1475782 - Return promises from Rule mutation methods and catch errors in font editor.

https://reviewboard.mozilla.org/r/258330/#review265396

::: devtools/client/inspector/rules/models/text-property.js:125
(Diff revision 1)
> -    this.rule.setPropertyValue(this, value, priority);
> -    this.updateEditor();
> +    return this.rule.setPropertyValue(this, value, priority)
> +      .then(() => this.updateEditor());

This change looks good I think, but you're changing the timing of things slightly here. Maybe it's going to be fine, but if not (and rule-view tests are quite delicate things when it comes to timing :) ) then feel free to change it back so updateEditor does not wait for the promise to resolve, yet we still return the promise itself (which you could simply store in a variable).
Attachment #8993648 - Flags: review?(pbrosset) → review+
:rcaliman I see there is also pbro's patch, could you please take a look?
Flags: needinfo?(rcaliman)
:ccoroiu

I completely replaced the contents of the failing test with a different approach in Bug 1477261 which landed yesterday. I expect this simplified test won't trigger intermittent failures. 

I want to wait a few days to see if the failure signature for that changed test file changes (i.e. new intermittent).

The patches attached to this bug are improvements to the code that _should have_ solved the original intermittent failing test, but didn't. I still want to land them because they're good improvements, but after confirming that the original cause for failing has gone away.

This is on my radar to land later this week.
Flags: needinfo?(rcaliman)
Pushed by rcaliman@mozilla.com:
https://hg.mozilla.org/integration/autoland/rev/ee31ecee4727
Fix for intermittent test failures on Font Editor unit conversion. r=pbro
https://hg.mozilla.org/integration/autoland/rev/b4468a68fdf9
Return promises from Rule mutation methods and catch errors in font editor. r=pbro
https://hg.mozilla.org/mozilla-central/rev/ee31ecee4727
https://hg.mozilla.org/mozilla-central/rev/b4468a68fdf9
Status: ASSIGNED → RESOLVED
Closed: 6 years ago
status-firefox63: --- → fixed
Resolution: --- → FIXED
Target Milestone: --- → Firefox 63
Component: Inspector: Fonts → Inspector
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Creator:
Created:
Updated:
Size: