Closed Bug 1582946 Opened 5 years ago Closed 5 years ago

Perma browser_deck_has_out_of_process_iframe.js | Uncaught exception - OperationError: The operation failed for an operation-specific reason, when Gecko 71 merges to Beta on 2019-10-14

Categories

(Core :: Layout, defect)

Product:
Core
Component:
Layout
Type:
defect
Priority:
Not set
Severity:
normal

Tracking

()

Status:
VERIFIED FIXED
Milestone:
mozilla71
Tracking Flags:
Tracking Status
firefox-esr60 --- unaffected
firefox-esr68 --- unaffected
firefox69 --- unaffected
firefox70 --- unaffected
firefox71 + verified

People

(Reporter: noemi_erli, Assigned: hiro)

References

(Regression)

Details

(Keywords: regression)

Attachments

(1 file)

Bug 1582946 - Skip whole test cases in browser_deck_has_out_of_process_iframe.js if fission.autostart pref is locked. r?surkov
47 bytes, text/x-phabricator-request
Details | Review

[Tracking Requested - why for this release]:

Central as beta simulation:
https://treeherder.mozilla.org/#/jobs?repo=try&resultStatus=testfailed%2Cbusted%2Cexception%2Cretry%2Cusercancel%2Crunnable&revision=15522f57933ab94ad5066dc6fd76c7c5a361c3be&selectedJob=267806662

Failure log: https://treeherder.mozilla.org/logviewer.html#/jobs?job_id=267806662&repo=try&lineNumber=2137

[task 2019-09-21T12:58:13.925Z] 12:58:13 INFO - TEST-START | accessible/tests/browser/states/browser_deck_has_out_of_process_iframe.js
[task 2019-09-21T12:58:13.961Z] 12:58:13 INFO - GECKO(1156) | ++DOCSHELL 0x7f4320dd5800 == 7 [pid = 1156] [id = {f889365e-feca-4607-b03d-8bb35036892e}]
[task 2019-09-21T12:58:13.962Z] 12:58:13 INFO - GECKO(1156) | ++DOMWINDOW == 15 (0x7f43250eb6a0) [pid = 1156] [serial = 15] [outer = (nil)]
[task 2019-09-21T12:58:13.963Z] 12:58:13 INFO - GECKO(1156) | ++DOMWINDOW == 16 (0x7f431e3bc800) [pid = 1156] [serial = 16] [outer = 0x7f43250eb6a0]
[task 2019-09-21T12:58:13.999Z] 12:58:13 INFO - GECKO(1156) | [Parent 1156, Main Thread] WARNING: Attempting to get a displayport from a content with no primary frame!: file /builds/worker/workspace/build/src/layout/base/nsLayoutUtils.cpp, line 767
[task 2019-09-21T12:58:14.000Z] 12:58:14 INFO - GECKO(1156) | [Parent 1156, Main Thread] WARNING: g_type_add_interface_static: assertion 'g_type_parent (interface_type) == G_TYPE_INTERFACE' failed: 'glib warning', file /builds/worker/workspace/build/src/toolkit/xre/nsSigHandlers.cpp, line 135
[task 2019-09-21T12:58:14.001Z] 12:58:14 INFO - GECKO(1156) | (firefox:1156): GLib-GObject-CRITICAL **: g_type_add_interface_static: assertion 'g_type_parent (interface_type) == G_TYPE_INTERFACE' failed
[task 2019-09-21T12:58:14.001Z] 12:58:14 INFO - GECKO(1156) | [Parent 1156, Main Thread] WARNING: g_type_add_interface_static: assertion 'g_type_parent (interface_type) == G_TYPE_INTERFACE' failed: 'glib warning', file /builds/worker/workspace/build/src/toolkit/xre/nsSigHandlers.cpp, line 135
[task 2019-09-21T12:58:14.002Z] 12:58:14 INFO - GECKO(1156) | (firefox:1156): GLib-GObject-CRITICAL **: g_type_add_interface_static: assertion 'g_type_parent (interface_type) == G_TYPE_INTERFACE' failed
[task 2019-09-21T12:58:14.002Z] 12:58:14 INFO - GECKO(1156) | [Parent 1156, Main Thread] WARNING: NS_ENSURE_SUCCESS(rv, rv) failed with result 0x80004005: file /builds/worker/workspace/build/src/dom/base/ThirdPartyUtil.cpp, line 416
[task 2019-09-21T12:58:14.118Z] 12:58:14 INFO - GECKO(1156) | ++DOCSHELL 0x7f4323504000 == 8 [pid = 1156] [id = {62dea52a-476e-4fb3-9203-6b756df3a7aa}]
[task 2019-09-21T12:58:14.120Z] 12:58:14 INFO - GECKO(1156) | ++DOMWINDOW == 17 (0x7f43250eb880) [pid = 1156] [serial = 17] [outer = (nil)]
[task 2019-09-21T12:58:14.160Z] 12:58:14 INFO - GECKO(1156) | ++DOCSHELL 0x7f4323519800 == 9 [pid = 1156] [id = {c51518f6-a07f-4d13-9e00-4b357dd75f84}]
[task 2019-09-21T12:58:14.161Z] 12:58:14 INFO - GECKO(1156) | ++DOMWINDOW == 18 (0x7f43250eba60) [pid = 1156] [serial = 18] [outer = (nil)]
[task 2019-09-21T12:58:14.203Z] 12:58:14 INFO - GECKO(1156) | [Parent 1156, Main Thread] WARNING: '!mWindow->GetCurrentInnerWindow()', file /builds/worker/workspace/build/src/dom/ipc/nsQueryActor.h, line 20
[task 2019-09-21T12:58:14.204Z] 12:58:14 INFO - GECKO(1156) | ++DOMWINDOW == 19 (0x7f4327560c00) [pid = 1156] [serial = 19] [outer = 0x7f43250eb880]
[task 2019-09-21T12:58:14.212Z] 12:58:14 INFO - GECKO(1156) | [Parent 1156, Main Thread] WARNING: '!mWindow->GetCurrentInnerWindow()', file /builds/worker/workspace/build/src/dom/ipc/nsQueryActor.h, line 20
[task 2019-09-21T12:58:14.213Z] 12:58:14 INFO - GECKO(1156) | ++DOMWINDOW == 20 (0x7f4327562400) [pid = 1156] [serial = 20] [outer = 0x7f43250eba60]
[task 2019-09-21T12:58:14.331Z] 12:58:14 INFO - GECKO(1156) | ### XPCOM_MEM_BLOAT_LOG defined -- logging bloat/leaks to /tmp/tmpgcS1p1.mozrunner/runtests_leaks_tab_pid1319.log
[task 2019-09-21T12:58:14.476Z] 12:58:14 INFO - GECKO(1156) | Couldn't convert chrome URL: chrome://branding/locale/brand.properties
[task 2019-09-21T12:58:14.626Z] 12:58:14 INFO - GECKO(1156) | [WARN audio_thread_priority::rt_linux] Could not make thread real-time.
[task 2019-09-21T12:58:14.626Z] 12:58:14 INFO - GECKO(1156) | [WARN audioipc_client] Could not promote audio threads to real-time during initialization.
[task 2019-09-21T12:58:14.644Z] 12:58:14 INFO - GECKO(1156) | ++DOCSHELL 0x7f38bc2ab000 == 1 [pid = 1319] [id = {76a390dc-f11c-4662-9693-a01151e6bddb}]
[task 2019-09-21T12:58:14.671Z] 12:58:14 INFO - GECKO(1156) | [Parent 1156, Main Thread] WARNING: Ignoring duplicate observer.: file /builds/worker/workspace/build/src/modules/libpref/Preferences.cpp, line 2696
[task 2019-09-21T12:58:14.692Z] 12:58:14 INFO - GECKO(1156) | ++DOMWINDOW == 1 (0x7f38bd2d4f20) [pid = 1319] [serial = 1] [outer = (nil)]
[task 2019-09-21T12:58:14.693Z] 12:58:14 INFO - GECKO(1156) | [Parent 1156, Main Thread] WARNING: g_type_add_interface_static: assertion 'g_type_parent (interface_type) == G_TYPE_INTERFACE' failed: 'glib warning', file /builds/worker/workspace/build/src/toolkit/xre/nsSigHandlers.cpp, line 135
[task 2019-09-21T12:58:14.694Z] 12:58:14 INFO - GECKO(1156) | (firefox:1156): GLib-GObject-CRITICAL **: g_type_add_interface_static: assertion 'g_type_parent (interface_type) == G_TYPE_INTERFACE' failed
[task 2019-09-21T12:58:14.694Z] 12:58:14 INFO - GECKO(1156) | ++DOMWINDOW == 2 (0x7f38bc22b800) [pid = 1319] [serial = 2] [outer = 0x7f38bd2d4f20]
[task 2019-09-21T12:58:14.750Z] 12:58:14 INFO - GECKO(1156) | ++DOCSHELL 0x7efd79734800 == 3 [pid = 1232] [id = {617bfff1-65be-492e-8d38-9019e6a7e67c}]
[task 2019-09-21T12:58:14.751Z] 12:58:14 INFO - GECKO(1156) | ++DOMWINDOW == 8 (0x7efd797bb980) [pid = 1232] [serial = 8] [outer = (nil)]
[task 2019-09-21T12:58:14.752Z] 12:58:14 INFO - GECKO(1156) | ++DOMWINDOW == 9 (0x7efd797ddc00) [pid = 1232] [serial = 9] [outer = 0x7efd797bb980]
[task 2019-09-21T12:58:14.828Z] 12:58:14 INFO - GECKO(1156) | ++DOMWINDOW == 10 (0x7efd797e3000) [pid = 1232] [serial = 10] [outer = 0x7efd797bb980]
[task 2019-09-21T12:58:14.848Z] 12:58:14 INFO - GECKO(1156) | ++DOMWINDOW == 3 (0x7f38bcb74c00) [pid = 1319] [serial = 3] [outer = 0x7f38bd2d4f20]
[task 2019-09-21T12:58:14.985Z] 12:58:14 INFO - GECKO(1156) | ### XPCOM_MEM_BLOAT_LOG defined -- logging bloat/leaks to /tmp/tmpgcS1p1.mozrunner/runtests_leaks_tab_pid1344.log
[task 2019-09-21T12:58:15.122Z] 12:58:15 INFO - GECKO(1156) | Couldn't convert chrome URL: chrome://branding/locale/brand.properties
[task 2019-09-21T12:58:15.264Z] 12:58:15 INFO - GECKO(1156) | [WARN audio_thread_priority::rt_linux] Could not make thread real-time.
[task 2019-09-21T12:58:15.265Z] 12:58:15 INFO - GECKO(1156) | [WARN audioipc_client] Could not promote audio threads to real-time during initialization.
[task 2019-09-21T12:58:15.281Z] 12:58:15 INFO - GECKO(1156) | ++DOCSHELL 0x7f495a1ac000 == 1 [pid = 1344] [id = {3488b4c8-0cb0-4771-977e-dd32622c04ac}]
[task 2019-09-21T12:58:15.342Z] 12:58:15 INFO - GECKO(1156) | ++DOMWINDOW == 1 (0x7f495b181f20) [pid = 1344] [serial = 1] [outer = (nil)]
[task 2019-09-21T12:58:15.342Z] 12:58:15 INFO - GECKO(1156) | ++DOMWINDOW == 2 (0x7f495a12bc00) [pid = 1344] [serial = 2] [outer = 0x7f495b181f20]
[task 2019-09-21T12:58:15.747Z] 12:58:15 INFO - GECKO(1156) | ++DOMWINDOW == 3 (0x7f495a9a5400) [pid = 1344] [serial = 3] [outer = 0x7f495b181f20]
[task 2019-09-21T12:58:15.823Z] 12:58:15 INFO - GECKO(1156) | ++DOCSHELL 0x7f4959cac000 == 2 [pid = 1344] [id = {47f8948d-b62e-4c7a-b4cf-fbe4647f4310}]
[task 2019-09-21T12:58:15.823Z] 12:58:15 INFO - GECKO(1156) | ++DOMWINDOW == 4 (0x7f495b182100) [pid = 1344] [serial = 4] [outer = (nil)]
[task 2019-09-21T12:58:15.824Z] 12:58:15 INFO - GECKO(1156) | [Child 1344, Main Thread] WARNING: '!mWindow->GetCurrentInnerWindow()', file /builds/worker/workspace/build/src/dom/ipc/nsQueryActor.h, line 20
[task 2019-09-21T12:58:15.825Z] 12:58:15 INFO - GECKO(1156) | ++DOMWINDOW == 5 (0x7f495a15e800) [pid = 1344] [serial = 5] [outer = 0x7f495b182100]
[task 2019-09-21T12:58:15.840Z] 12:58:15 INFO - GECKO(1156) | ++DOCSHELL 0x7f4959cad000 == 3 [pid = 1344] [id = {e85b121b-d2a8-4e79-978d-29f2668605dc}]
[task 2019-09-21T12:58:15.841Z] 12:58:15 INFO - GECKO(1156) | ++DOMWINDOW == 6 (0x7f495b1822e0) [pid = 1344] [serial = 6] [outer = (nil)]
[task 2019-09-21T12:58:15.842Z] 12:58:15 INFO - GECKO(1156) | [Child 1344, Main Thread] WARNING: '!mWindow->GetCurrentInnerWindow()', file /builds/worker/workspace/build/src/dom/ipc/nsQueryActor.h, line 20
[task 2019-09-21T12:58:15.843Z] 12:58:15 INFO - GECKO(1156) | ++DOMWINDOW == 7 (0x7f495a161000) [pid = 1344] [serial = 7] [outer = 0x7f495b1822e0]
[task 2019-09-21T12:58:16.274Z] 12:58:16 INFO - GECKO(1156) | ++DOMWINDOW == 8 (0x7f495aa8e000) [pid = 1344] [serial = 8] [outer = 0x7f495b182100]
[task 2019-09-21T12:58:16.450Z] 12:58:16 INFO - GECKO(1156) | ### XPCOM_MEM_BLOAT_LOG defined -- logging bloat/leaks to /tmp/tmpgcS1p1.mozrunner/runtests_leaks_tab_pid1373.log
[task 2019-09-21T12:58:16.527Z] 12:58:16 INFO - GECKO(1156) | ++DOMWINDOW == 9 (0x7f495aa92800) [pid = 1344] [serial = 9] [outer = 0x7f495b1822e0]
[task 2019-09-21T12:58:16.643Z] 12:58:16 INFO - GECKO(1156) | Couldn't convert chrome URL: chrome://branding/locale/brand.properties
[task 2019-09-21T12:58:16.745Z] 12:58:16 INFO - GECKO(1156) | --DOMWINDOW == 8 (0x7f495a12bc00) [pid = 1344] [serial = 2] [outer = (nil)] [url = about:blank]
[task 2019-09-21T12:58:16.773Z] 12:58:16 INFO - GECKO(1156) | [WARN audio_thread_priority::rt_linux] Could not make thread real-time.
[task 2019-09-21T12:58:16.774Z] 12:58:16 INFO - GECKO(1156) | [WARN audioipc_client] Could not promote audio threads to real-time during initialization.
[task 2019-09-21T12:58:16.809Z] 12:58:16 INFO - GECKO(1156) | JavaScript error: chrome://mochitests/content/browser/accessible/tests/browser/states/head.js, line 55: TypeError: acc.getAccessibleFor(...) is null
[task 2019-09-21T12:58:16.809Z] 12:58:16 INFO - GECKO(1156) | JavaScript error: , line 0: NS_ERROR_UNEXPECTED
[task 2019-09-21T12:58:16.810Z] 12:58:16 INFO - GECKO(1156) | JavaScript error: , line 0: OperationError: The operation failed for an operation-specific reason
[task 2019-09-21T12:58:16.914Z] 12:58:16 INFO - TEST-INFO | started process screentopng
[task 2019-09-21T12:58:17.421Z] 12:58:17 INFO - TEST-INFO | screentopng: exit 0
[task 2019-09-21T12:58:17.422Z] 12:58:17 INFO - Buffered messages logged at 12:58:13
[task 2019-09-21T12:58:17.422Z] 12:58:17 INFO - Entering test bound
[task 2019-09-21T12:58:17.422Z] 12:58:17 INFO - Buffered messages logged at 12:58:16
[task 2019-09-21T12:58:17.423Z] 12:58:17 INFO - TEST-PASS | accessible/tests/browser/states/browser_deck_has_out_of_process_iframe.js | 0 == 0 -
[task 2019-09-21T12:58:17.423Z] 12:58:17 INFO - TEST-PASS | accessible/tests/browser/states/browser_deck_has_out_of_process_iframe.js | true == true -
[task 2019-09-21T12:58:17.423Z] 12:58:17 INFO - Console message: [JavaScript Error: "TypeError: acc.getAccessibleFor(...) is null" {file: "chrome://mochitests/content/browser/accessible/tests/browser/states/head.js" line: 55}]
[task 2019-09-21T12:58:17.427Z] 12:58:17 INFO - Console message: [JavaScript Error: "NS_ERROR_UNEXPECTED"]
[task 2019-09-21T12:58:17.427Z] 12:58:17 INFO - Console message: [JavaScript Error: "OperationError: The operation failed for an operation-specific reason"]
[task 2019-09-21T12:58:17.427Z] 12:58:17 INFO - Buffered messages finished
[task 2019-09-21T12:58:17.428Z] 12:58:17 INFO - TEST-UNEXPECTED-FAIL | accessible/tests/browser/states/browser_deck_has_out_of_process_iframe.js | Uncaught exception - OperationError: The operation failed for an operation-specific reason
[task 2019-09-21T12:58:17.428Z] 12:58:17 INFO - Not taking screenshot here: see the one that was previously logged
[task 2019-09-21T12:58:17.428Z] 12:58:17 INFO - TEST-UNEXPECTED-FAIL | accessible/tests/browser/states/browser_deck_has_out_of_process_iframe.js | A promise chain failed to handle a rejection: The operation failed for an operation-specific reason - stack: (No stack available.)
[task 2019-09-21T12:58:17.429Z] 12:58:17 INFO - Rejection date: Sat Sep 21 2019 12:58:16 GMT+0000 (Coordinated Universal Time) - false == true - JS frame :: resource://testing-common/PromiseTestUtils.jsm :: assertNoUncaughtRejections :: line 265
[task 2019-09-21T12:58:17.429Z] 12:58:17 INFO - Stack trace:
[task 2019-09-21T12:58:17.430Z] 12:58:17 INFO - resource://testing-common/PromiseTestUtils.jsm:assertNoUncaughtRejections:265
[task 2019-09-21T12:58:17.431Z] 12:58:17 INFO - chrome://mochikit/content/browser-test.js:Tester_execTest/<:1381
[task 2019-09-21T12:58:17.431Z] 12:58:17 INFO - Leaving test bound
[task 2019-09-21T12:58:17.432Z] 12:58:17 INFO - GECKO(1156) | ###!!! [Parent][RunMessage] Error: Channel closing: too late to send/recv, messages will be lost
[task 2019-09-21T12:58:17.433Z] 12:58:17 INFO - GECKO(1156) | ###!!! [Parent][RunMessage] Error: Channel closing: too late to send/recv, messages will be lost
[task 2019-09-21T12:58:17.436Z] 12:58:17 INFO - GECKO(1156) | ###!!! [Parent][RunMessage] Error: Channel closing: too late to send/recv, messages will be lost
[task 2019-09-21T12:58:17.437Z] 12:58:17 INFO - GECKO(1156) | ###!!! [Parent][RunMessage] Error: Channel closing: too late to send/recv, messages will be lost
[task 2019-09-21T12:58:17.438Z] 12:58:17 INFO - GECKO(1156) | ###!!! [Parent][RunMessage] Error: Channel closing: too late to send/recv, messages will be lost
[task 2019-09-21T12:58:17.439Z] 12:58:17 INFO - GECKO(1156) | ###!!! [Parent][RunMessage] Error: Channel closing: too late to send/recv, messages will be lost
[task 2019-09-21T12:58:17.440Z] 12:58:17 INFO - GECKO(1156) | --DOCSHELL 0x7f4959cac000 == 2 [pid = 1344] [id = {47f8948d-b62e-4c7a-b4cf-fbe4647f4310}] [url = http://example.org/browser/accessible/tests/browser/states/target.html]
[task 2019-09-21T12:58:17.442Z] 12:58:17 INFO - GECKO(1156) | --DOCSHELL 0x7f4959cad000 == 1 [pid = 1344] [id = {e85b121b-d2a8-4e79-978d-29f2668605dc}] [url = http://example.org/browser/accessible/tests/browser/states/target.html]
[task 2019-09-21T12:58:17.443Z] 12:58:17 INFO - GECKO(1156) | MEMORY STAT vsizeMaxContiguous not supported in this build configuration.
[task 2019-09-21T12:58:17.444Z] 12:58:17 INFO - GECKO(1156) | MEMORY STAT | vsize 2854MB | residentFast 374MB | heapAllocated 155MB

Flags: needinfo?(hikezoe.birchill)
Assignee: nobody → hikezoe.birchill
Status: NEW → ASSIGNED
Flags: needinfo?(hikezoe.birchill)

It seems to me this is caused by an underlying issue in accessibility stuff in fission world.

What I've known so far are;

  1. The test in question fails at the check when the first iframe was hidden.
  2. getAccesibleFor the target element fails because, at that moment, mNodeToAccessibleMap has been already cleared in DocAccessible::Shutdown()
  3. The DocAccessible::Shutdown is called from NotificationController::WillRefresh
  4. It seems to me that the code just before calling Shutdown doesn't work properly in fission

:surkov, can you please take a look at this? Though I don't quite understand why the failure happens in beta merge simulation and Windows with WebRender (bug 1582775), but it seems to me that the failure should happen on other platforms. (Note that I am fine with disabling the test for now)

Flags: needinfo?(surkov.alexander)

Do you what exactly fails: FindContentForSubDocument or GetAccessible(ownerContent) https://searchfox.org/mozilla-central/rev/e3fc8f8970491aef14d3212b2d052942f4d29818/accessible/base/NotificationController.cpp#764-773?

Unfortunately I know a little about fission a11y, so not sure how FindContentForSubDocument works when it comes to iframe docs living in another process, but if it doesn't fail on Nightly, then it has to work somehow, and perhaps the problem is somewhere else.

Jamie, I saw a lot of fission a11y work happened lately, could you think of anything landed recently that may mitigate the problem on trunk?

Flags: needinfo?(surkov.alexander) → needinfo?(jteh)

(In reply to alexander :surkov (:asurkov) from comment #2)

Do you what exactly fails: FindContentForSubDocument or GetAccessible(ownerContent) https://searchfox.org/mozilla-central/rev/e3fc8f8970491aef14d3212b2d052942f4d29818/accessible/base/NotificationController.cpp#764-773?

The GetAccessible(ownerContent) returned nullptr last time I debugged. ownerContent was a valid pointer at that time.

(In reply to Hiroyuki Ikezoe (:hiro) from comment #3)

(In reply to alexander :surkov (:asurkov) from comment #2)

Do you what exactly fails: FindContentForSubDocument or GetAccessible(ownerContent) https://searchfox.org/mozilla-central/rev/e3fc8f8970491aef14d3212b2d052942f4d29818/accessible/base/NotificationController.cpp#764-773?

The GetAccessible(ownerContent) returned nullptr last time I debugged. ownerContent was a valid pointer at that time.

Hmm, I am reading the code in question again, it's bit odd because childDoc->DocumentNode() should live in an out-of-process, IIUC the code.

I noticed that nsCoreUtils::IsRootDocument for the out-of-process document returns true on the bare m-c (it's wrong though), whereas the function returns false with the beta-merge simulation patch. Presumably there are some differences in doc shell tree. So it seems the test in question has been accidentally passing on m-c.

See Also: → 1573625

I just noticed that fission.autostart pref is locked on beta/release channels so that even if we enable the pref explicitly, we are still running the test in non-fission world. (This fact noticed us that some kind of accessibility stuff inside deck frames doesn't work in the first place).

I will add a check whether the pref is locked or not, and if it's locked I am going to skip the whole test there.

Flags: needinfo?(jteh)
Pushed by hikezoe.birchill@mozilla.com:
https://hg.mozilla.org/integration/autoland/rev/39ac5d9d1794
Skip whole test cases in browser_deck_has_out_of_process_iframe.js if fission.autostart pref is locked. r=surkov

https://hg.mozilla.org/mozilla-central/rev/39ac5d9d1794

Status: ASSIGNED → RESOLVED
Closed: 5 years ago
status-firefox71: affected → fixed
Resolution: --- → FIXED
Target Milestone: --- → mozilla71
Status: RESOLVED → VERIFIED
status-firefox71: fixed → verified
See Also: → 1588266
Has Regression Range: --- → yes
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Creator:
Created:
Updated:
Size: