Closed Bug 1694238 Opened 4 years ago Closed 1 month ago

Intermittent mozilla/tests/focus/focus-next-tick-before-iframe-loaded-different-site.html | Check result - assert_equals: Check verdict expected "PASS" but got "FAIL missing onfocus"

Categories

(Core :: DOM: UI Events & Focus Handling, defect, P5)

defect

Tracking

()

RESOLVED INCOMPLETE
Tracking Status
firefox-esr78 --- unaffected
firefox86 --- unaffected
firefox87 --- unaffected
firefox88 --- wontfix

People

(Reporter: intermittent-bug-filer, Unassigned)

References

(Regression)

Details

(Keywords: intermittent-failure, regression, Whiteboard: [retriggered][stockwell unknown])

Attachments

(2 files)

Filed by: malexandru [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer?job_id=330778291&repo=autoland
Full log: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/X8c3HFMJTTuqfAaV5H82Pg/runs/0/artifacts/public/logs/live_backing.log


[task 2021-02-22T18:54:12.162Z] 18:54:12     INFO - TEST-OK | /_mozilla/focus/focus-before-iframe-loaded-same-site.html | took 121ms
[task 2021-02-22T18:54:12.164Z] 18:54:12     INFO - TEST-START | /_mozilla/focus/focus-next-tick-before-iframe-loaded-different-site.html
[task 2021-02-22T18:54:12.164Z] 18:54:12     INFO - Closing window 8589934629
[task 2021-02-22T18:54:12.197Z] 18:54:12     INFO - PID 1092 | JavaScript error: resource://specialpowers/AppTestDelegateParent.jsm, line 10: NS_ERROR_NOT_AVAILABLE:
[task 2021-02-22T18:54:12.197Z] 18:54:12     INFO - PID 1092 | JavaScript error: resource://specialpowers/AppTestDelegateParent.jsm, line 10: NS_ERROR_NOT_AVAILABLE:
[task 2021-02-22T18:54:12.248Z] 18:54:12     INFO - PID 1092 | JavaScript error: resource://specialpowers/AppTestDelegateParent.jsm, line 10: NS_ERROR_NOT_AVAILABLE:
[task 2021-02-22T18:54:12.250Z] 18:54:12     INFO - PID 1092 | JavaScript error: resource://specialpowers/AppTestDelegateParent.jsm, line 10: NS_ERROR_NOT_AVAILABLE:
[task 2021-02-22T18:54:12.263Z] 18:54:12     INFO - PID 1092 | JavaScript error: resource://specialpowers/AppTestDelegateParent.jsm, line 10: NS_ERROR_NOT_AVAILABLE:
[task 2021-02-22T18:54:12.301Z] 18:54:12     INFO - PID 1092 | JavaScript error: resource://specialpowers/AppTestDelegateParent.jsm, line 10: NS_ERROR_NOT_AVAILABLE:
[task 2021-02-22T18:54:12.303Z] 18:54:12     INFO - PID 1092 | JavaScript error: resource://specialpowers/AppTestDelegateParent.jsm, line 10: NS_ERROR_NOT_AVAILABLE:
[task 2021-02-22T18:54:12.304Z] 18:54:12     INFO - PID 1092 | JavaScript error: resource://specialpowers/AppTestDelegateParent.jsm, line 10: NS_ERROR_NOT_AVAILABLE:
[task 2021-02-22T18:54:14.324Z] 18:54:14     INFO - 
[task 2021-02-22T18:54:14.324Z] 18:54:14     INFO - TEST-UNEXPECTED-FAIL | /_mozilla/focus/focus-next-tick-before-iframe-loaded-different-site.html | Check result - assert_equals: Check verdict expected "PASS" but got "FAIL missing onfocus"
[task 2021-02-22T18:54:14.324Z] 18:54:14     INFO - window.onmessage/<@http://web-platform.test:8000/_mozilla/focus/focus-next-tick-before-iframe-loaded-different-site.html:10:22
[task 2021-02-22T18:54:14.324Z] 18:54:14     INFO - Test.prototype.step@http://web-platform.test:8000/resources/testharness.js:2092:25
[task 2021-02-22T18:54:14.324Z] 18:54:14     INFO - test@http://web-platform.test:8000/resources/testharness.js:566:30
[task 2021-02-22T18:54:14.324Z] 18:54:14     INFO - window.onmessage@http://web-platform.test:8000/_mozilla/focus/focus-next-tick-before-iframe-loaded-different-site.html:9:9
[task 2021-02-22T18:54:14.325Z] 18:54:14     INFO - TEST-OK | /_mozilla/focus/focus-next-tick-before-iframe-loaded-different-site.html | took 2160ms
[task 2021-02-22T18:54:14.330Z] 18:54:14     INFO - PID 1092 | 1614020054329	Marionette	INFO	Stopped listening on port 53168
[task 2021-02-22T18:54:14.733Z] 18:54:14     INFO - Browser exited with return code 0
[task 2021-02-22T18:54:14.734Z] 18:54:14     INFO - PROCESS LEAKS None
[task 2021-02-22T18:54:14.737Z] 18:54:14     INFO - Closing logging queue
[task 2021-02-22T18:54:14.737Z] 18:54:14     INFO - queue closed
[task 2021-02-22T18:54:14.802Z] 18:54:14     INFO - Application command: C:\Users\task_1614017881\build\application\firefox\firefox.exe -marionette about:blank --wait-for-browser -profile C:\Users\task_1614017881\AppData\Local\Temp\tmpl628nbdx
[task 2021-02-22T18:54:14.804Z] 18:54:14     INFO - PID 7620 | console.warn: SearchSettings: "get: No settings file exists, new profile?" (new Error("", "(unknown module)"))
[task 2021-02-22T18:54:14.805Z] 18:54:14     INFO - PID 7620 | 1614020050910	Marionette	INFO	Listening on port 53198
[task 2021-02-22T18:54:14.806Z] 18:54:14     INFO - Starting runner
[task 2021-02-22T18:54:15.707Z] 18:54:15     INFO - Installing extension from C:\Users\task_1614017881\build\tests\extensions\specialpowers@mozilla.org.xpi
[task 2021-02-22T18:54:15.887Z] 18:54:15     INFO - PID 7620 | JavaScript error: resource://specialpowers/AppTestDelegateParent.jsm, line 10: NS_ERROR_NOT_AVAILABLE:
[task 2021-02-22T18:54:15.890Z] 18:54:15     INFO - PID 7620 | JavaScript error: resource://specialpowers/AppTestDelegateParent.jsm, line 10: NS_ERROR_NOT_AVAILABLE:
[task 2021-02-22T18:54:15.916Z] 18:54:15     INFO - TEST-START | /_mozilla/focus/focus-next-tick-before-iframe-loaded-same-site.html```
Component: web-platform-tests → DOM: UI Events & Focus Handling
Flags: needinfo?(hsivonen)
Product: Testing → Core

Hard to say from this if the focus event is occasionally really missing of if the virtual machine occasionally stalls so that the wall clock advances two seconds without the browser making much progress.

Whiteboard: [retriggered][stockwell needswork:owner]

Update:

There have been 32 failures within the last 7 days:

  • 1 failure on Linux 18.04 x64 opt
  • 7 failures on Linux 18.04 x64 WebRender opt
  • 12 failures on Linux 18.04 x64 WebRender Shippable opt
  • 2 failures on OS X 10.14 WebRender opt
  • 7 failures on Windows 10 x64 WebRender opt
  • 3 failures on Windows 10 x64 WebRender Shippable opt

Recent failure log: https://treeherder.mozilla.org/logviewer?job_id=331408404&repo=autoland&lineNumber=12422

[task 2021-02-27T00:23:24.099Z] 00:23:24     INFO - TEST-START | /_mozilla/focus/focus-next-tick-before-iframe-loaded-different-site.html
[task 2021-02-27T00:23:24.104Z] 00:23:24     INFO - Closing window 6442450981
[task 2021-02-27T00:23:24.161Z] 00:23:24     INFO - PID 17615 | JavaScript error: resource://specialpowers/AppTestDelegateParent.jsm, line 10: NS_ERROR_NOT_AVAILABLE:
[task 2021-02-27T00:23:24.172Z] 00:23:24     INFO - PID 17615 | JavaScript error: resource://specialpowers/AppTestDelegateParent.jsm, line 10: NS_ERROR_NOT_AVAILABLE:
[task 2021-02-27T00:23:24.260Z] 00:23:24     INFO - PID 17615 | JavaScript error: resource://specialpowers/AppTestDelegateParent.jsm, line 10: NS_ERROR_NOT_AVAILABLE:
[task 2021-02-27T00:23:24.262Z] 00:23:24     INFO - PID 17615 | JavaScript error: resource://specialpowers/AppTestDelegateParent.jsm, line 10: NS_ERROR_NOT_AVAILABLE:
[task 2021-02-27T00:23:24.287Z] 00:23:24     INFO - PID 17615 | JavaScript error: resource://specialpowers/AppTestDelegateParent.jsm, line 10: NS_ERROR_NOT_AVAILABLE:
[task 2021-02-27T00:23:24.336Z] 00:23:24     INFO - PID 17615 | JavaScript error: resource://specialpowers/AppTestDelegateParent.jsm, line 10: NS_ERROR_NOT_AVAILABLE:
[task 2021-02-27T00:23:24.339Z] 00:23:24     INFO - PID 17615 | JavaScript error: resource://specialpowers/AppTestDelegateParent.jsm, line 10: NS_ERROR_NOT_AVAILABLE:
[task 2021-02-27T00:23:24.342Z] 00:23:24     INFO - PID 17615 | JavaScript error: resource://specialpowers/AppTestDelegateParent.jsm, line 10: NS_ERROR_NOT_AVAILABLE:
[task 2021-02-27T00:23:26.375Z] 00:23:26     INFO - 
[task 2021-02-27T00:23:26.375Z] 00:23:26     INFO - TEST-UNEXPECTED-FAIL | /_mozilla/focus/focus-next-tick-before-iframe-loaded-different-site.html | Check result - assert_equals: Check verdict expected "PASS" but got "FAIL missing onfocus"
[task 2021-02-27T00:23:26.375Z] 00:23:26     INFO - window.onmessage/<@http://web-platform.test:8000/_mozilla/focus/focus-next-tick-before-iframe-loaded-different-site.html:10:22
[task 2021-02-27T00:23:26.375Z] 00:23:26     INFO - Test.prototype.step@http://web-platform.test:8000/resources/testharness.js:2092:25
[task 2021-02-27T00:23:26.375Z] 00:23:26     INFO - test@http://web-platform.test:8000/resources/testharness.js:566:30
[task 2021-02-27T00:23:26.375Z] 00:23:26     INFO - window.onmessage@http://web-platform.test:8000/_mozilla/focus/focus-next-tick-before-iframe-loaded-different-site.html:9:9
[task 2021-02-27T00:23:26.375Z] 00:23:26     INFO - TEST-OK | /_mozilla/focus/focus-next-tick-before-iframe-loaded-different-site.html | took 2274ms
See Also: → 1694300
See Also: → 1694528

In the opt case, this is in wpt3.

In the Linux debug case, this is in wpt11.

There have been 47 total failures in the last 7 days.
Recent log.

Affected platforms are:

  • linux1804-64-qr debug & opt / linux1804-64-shippable-qr
  • windows10-64-qr opt / windows10-64-shippable-qr
  • windows7-32 opt / windows7-32-shippable
Assignee: nobody → apavel
Status: NEW → ASSIGNED
Assignee: apavel → nobody
Status: ASSIGNED → NEW
Keywords: leave-open
Pushed by apavel@mozilla.com: https://hg.mozilla.org/integration/autoland/rev/242d6966b003 add test expectations r=intermittent-reviewers,jmaher DONTBUILD
Attachment #9211186 - Attachment description: Bug 1694238 - add test expectations r?#intermittent-reviewers → Bug 1694238- correct expectation r=Aryx
Has Regression Range: --- → yes

There are 42 total failures in the last 7 days on

[task 2022-01-25T17:30:51.991Z] 17:30:51     INFO - TEST-START | /_mozilla/focus/focus-next-tick-before-iframe-loaded-different-site.html
[task 2022-01-25T17:30:51.996Z] 17:30:51     INFO - Closing window 659a971e-9682-45cf-b7e3-9fdc49cd0065
[task 2022-01-25T17:30:52.195Z] 17:30:52     INFO - PID 4712 | [Child 4304, Main Thread] WARNING: NS_ENSURE_TRUE(rootFrame) failed: file /builds/worker/checkouts/gecko/dom/base/nsGlobalWindowOuter.cpp:4235
[task 2022-01-25T17:30:52.433Z] 17:30:52     INFO - PID 4712 | ### XPCOM_MEM_BLOAT_LOG defined -- logging bloat/leaks to C:\Users\task_164312910875303\AppData\Local\Temp\tmpnukx3jyi\runtests_leaks_8128_tab_pid5600.log
[task 2022-01-25T17:30:52.442Z] 17:30:52     INFO - PID 4712 | [5600, Main Thread] WARNING: XPCOM_MEM_BLOAT_LOG is set, disabling native allocations.: file /builds/worker/checkouts/gecko/tools/profiler/core/platform.cpp:254
[task 2022-01-25T17:30:52.502Z] 17:30:52     INFO - PID 4712 | ### XPCOM_MEM_BLOAT_LOG defined -- logging bloat/leaks to C:\Users\task_164312910875303\AppData\Local\Temp\tmpnukx3jyi\runtests_leaks_8128_tab_pid2732.log
[task 2022-01-25T17:30:52.509Z] 17:30:52     INFO - PID 4712 | [2732, Main Thread] WARNING: XPCOM_MEM_BLOAT_LOG is set, disabling native allocations.: file /builds/worker/checkouts/gecko/tools/profiler/core/platform.cpp:254
[task 2022-01-25T17:30:58.474Z] 17:30:58     INFO - PID 4712 | ###!!! [Parent][PCompositorManagerParent] Error: RunMessage(msgname=PCompositorBridge::Msg___delete__) Channel closing: too late to send/recv, messages will be lost
[task 2022-01-25T17:30:58.483Z] 17:30:58     INFO - PID 4712 | [Child 1420, Main Thread] WARNING: IPC message 'PIdleScheduler::Msg_StartedGC' discarded: actor cannot send: file /builds/worker/checkouts/gecko/ipc/glue/ProtocolUtils.cpp:528
[task 2022-01-25T17:30:58.492Z] 17:30:58     INFO - PID 4712 | [Child 1420, Main Thread] WARNING: IPC message 'PIdleScheduler::Msg_DoneGC' discarded: actor cannot send: file /builds/worker/checkouts/gecko/ipc/glue/ProtocolUtils.cpp:528
[task 2022-01-25T17:30:58.504Z] 17:30:58     INFO - 
[task 2022-01-25T17:30:58.504Z] 17:30:58     INFO - TEST-UNEXPECTED-FAIL | /_mozilla/focus/focus-next-tick-before-iframe-loaded-different-site.html | Check result - assert_equals: Check verdict expected "PASS" but got "FAIL missing onfocus"
[task 2022-01-25T17:30:58.505Z] 17:30:58     INFO - window.onmessage/<@http://web-platform.test:8000/_mozilla/focus/focus-next-tick-before-iframe-loaded-different-site.html:10:22
[task 2022-01-25T17:30:58.505Z] 17:30:58     INFO - Test.prototype.step@http://web-platform.test:8000/resources/testharness.js:2534:25
[task 2022-01-25T17:30:58.505Z] 17:30:58     INFO - test@http://web-platform.test:8000/resources/testharness.js:572:30
[task 2022-01-25T17:30:58.505Z] 17:30:58     INFO - window.onmessage@http://web-platform.test:8000/_mozilla/focus/focus-next-tick-before-iframe-loaded-different-site.html:9:9
[task 2022-01-25T17:30:58.505Z] 17:30:58     INFO - TEST-OK | /_mozilla/focus/focus-next-tick-before-iframe-loaded-different-site.html | took 6524ms

Hsin-Yi, can you please take a look?

Flags: needinfo?(htsai)
Whiteboard: [retriggered][stockwell unknown] → [retriggered][stockwell needswork:owner]

We enabled web-platform tests for all platforms and variants last week, see https://bugzilla.mozilla.org/show_bug.cgi?id=1750841
The increase of intermittent failures may be due to that? Keep NI to investigate ...

Hi Andrew, can you please take a look at this? It looks to me that the failure increases were related with test migration to fission. I wonder if changing the annotation is the first sensible thing to do. Thanks!

Flags: needinfo?(htsai) → needinfo?(continuation)

It looks like this test was added by Henri in bug 1663931, to test some kind of issue with focus and Fission.

It looks like it was set to ignore failures on Linux and Windows opt not long after the test was added:
https://hg.mozilla.org/mozilla-central/rev/242d6966b003e5921ee40ebd760ee36648e39166

My guess would be that this test is just really flakey and we weren't running this on OSX or Win debug before bug 1750841.

So yes, it seems like this test should just be set to be ignore failures on OSX (opt and debug) and Win debug, which I assume is the same as ignoring failures everywhere, until Henri can get a chance to investigate it.

Flags: needinfo?(continuation)
Pushed by amccreight@mozilla.com: https://hg.mozilla.org/integration/autoland/rev/105fd53de10e Ignore failures in focus-next-tick-before-iframe-loaded-different-site.html. r=intermittent-reviewers,jmaher
Flags: needinfo?(hsivonen)
Status: NEW → RESOLVED
Closed: 1 month ago
Resolution: --- → INCOMPLETE
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Created:
Updated:
Size: