Closed Bug 1698698 Opened 1 year ago Closed 11 months ago

Intermittent dom/tests/mochitest/pointerlock/test_pointerlock_xorigin_iframe.html | Test timed out.

Categories

(Core :: DOM: Core & HTML, defect)

defect

Tracking

()

RESOLVED FIXED
Tracking Status
firefox-esr78 --- unaffected
firefox86 --- unaffected
firefox87 --- unaffected
firefox88 --- wontfix
firefox89 --- disabled
firefox90 --- wontfix
firefox91 --- fixed

People

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

References

(Regression)

Details

(Keywords: intermittent-failure, regression, Whiteboard: [retriggered][stockwell disabled][stockwell needswork:owner])

Attachments

(3 files)

[task 2021-03-16T04:06:59.439Z] 04:06:59     INFO - TEST-PASS | dom/tests/mochitest/pointerlock/test_pointerlock_xorigin_iframe.html | got pointerlockchange - "pointerlockchange" == "pointerlockchange" 
[task 2021-03-16T04:06:59.439Z] 04:06:59     INFO - wait for mousemove event
[task 2021-03-16T04:06:59.439Z] 04:06:59     INFO - Buffered messages finished
[task 2021-03-16T04:06:59.439Z] 04:06:59     INFO - TEST-UNEXPECTED-FAIL | dom/tests/mochitest/pointerlock/test_pointerlock_xorigin_iframe.html | Test timed out. 
[task 2021-03-16T04:06:59.439Z] 04:06:59     INFO -     SimpleTest.ok@SimpleTest/SimpleTest.js:417:16
[task 2021-03-16T04:06:59.439Z] 04:06:59     INFO -     reportError@SimpleTest/TestRunner.js:147:24
[task 2021-03-16T04:06:59.439Z] 04:06:59     INFO -     TestRunner._checkForHangs@SimpleTest/TestRunner.js:170:18
Flags: needinfo?(echen)
Summary: Intermittent [TV] dom/tests/mochitest/pointerlock/test_pointerlock_xorigin_iframe.html | Test timed out. → Intermittent dom/tests/mochitest/pointerlock/test_pointerlock_xorigin_iframe.html | Test timed out.

The test set test.events.async.enabled to true to make event routed to APZ, maybe the intermittent is from the test tries to send the mouse event before the APZ get stable.

Duplicate of this bug: 1667873
Whiteboard: [retriggered][stockwell needswork:owner]
Assignee: nobody → malexandru
Status: NEW → ASSIGNED
Assignee: malexandru → nobody
Status: ASSIGNED → NEW
Assignee: nobody → malexandru
Status: NEW → ASSIGNED
Pushed by nbeleuzu@mozilla.com:
https://hg.mozilla.org/integration/autoland/rev/7d4e7000d946
Disable test_pointerlock_xorigin_iframe on Linux and Win7 for frequent failures. r=edgar,intermittent-reviewers,ahal
Status: ASSIGNED → RESOLVED
Closed: 1 year ago
Resolution: --- → FIXED
Target Milestone: --- → 89 Branch
Status: RESOLVED → REOPENED
Keywords: leave-open
Resolution: FIXED → ---
Whiteboard: [retriggered][stockwell disable-recommended] → [retriggered][stockwell disabled]
Target Milestone: 89 Branch → ---
Assignee: malexandru → nobody

There have been a total of 92 failures in the past 7 days, mostly on:

windows10-64/qr-debug/opt/asan
macosx1015-64-qr opt/debug
linux1804-64-qr opt
android-em-7-0-x86_64-qr debug/opt

Recent failure log:

[task 2021-04-28T11:17:30.294Z] 11:17:30     INFO - TEST-UNEXPECTED-FAIL | dom/tests/mochitest/pointerlock/test_pointerlock_xorigin_iframe.html | Test timed out. - 
[task 2021-04-28T11:17:31.187Z] 11:17:31     INFO - GECKO(2724) | MEMORY STAT | vsize 19405920MB | vsizeMaxContiguous 68359513MB | residentFast 579MB
[task 2021-04-28T11:17:31.208Z] 11:17:31     INFO - TEST-OK | dom/tests/mochitest/pointerlock/test_pointerlock_xorigin_iframe.html | took 307401ms
[task 2021-04-28T11:17:34.217Z] 11:17:34     INFO - Error: Unable to restore focus, expect failures and timeouts.```

Backfills point to bug 1706794 as recent regressor for this very frequent failure.

Flags: needinfo?(sefeng)
Regressed by: 1706794
Has Regression Range: --- → yes

Since the status are different for nightly and release, what's the status for beta?
For more information, please visit auto_nag documentation.

I haven't been able to reproduce it locally, although I do have a theory since the test is related to input tasks.

After bug 1706794, input events may not be run if there's no pending vsync, I'd assume the timeout is related to this, and we probably need to add some requestAnimationFrame to the test to fix it. This should fix the recent frequent failures.

Pushed by abutkovits@mozilla.com:
https://hg.mozilla.org/integration/autoland/rev/4c0cd663b3f4
disable test_pointerlock_xorigin_iframe.html on Win, Android_64, Mac_64_WR for frequent failures. r=intermittent-reviewers,jmaher DONTBUILD

Shouldn't be an issue on Firefox 89 since the pref was disabled in bug 1705392.

There are 31 total failures in the last 7 days on

[task 2021-06-28T17:44:13.064Z] 17:44:13 INFO - TEST-START | dom/tests/mochitest/pointerlock/test_pointerlock_xorigin_iframe.html
[task 2021-06-28T17:44:13.383Z] 17:44:13 INFO - GECKO(7248) | [POINTERLOCK] Starting file_pointerlock_xorigin_iframe.html
[task 2021-06-28T17:44:15.100Z] 17:44:15 INFO - GECKO(7248) | [POINTERLOCK] Finishing file_pointerlock_xorigin_iframe.html
[task 2021-06-28T17:44:16.876Z] 17:44:16 INFO - GECKO(7248) | [POINTERLOCK] Starting file_pointerlock_xorigin_iframe_no_user_gesture.html
[task 2021-06-28T17:44:17.046Z] 17:44:17 INFO - GECKO(7248) | WaitUntilApzStable: flushed APZ repaints in parent proc, waiting for callback...
[task 2021-06-28T17:44:17.048Z] 17:44:17 INFO - GECKO(7248) | WaitUntilApzStable: APZ flush done in parent proc
[task 2021-06-28T17:44:17.049Z] 17:44:17 INFO - GECKO(7248) | WaitUntilApzStable: got apz-flush-done in child proc
[task 2021-06-28T17:44:17.051Z] 17:44:17 INFO - GECKO(7248) | WaitUntilApzStable: done promiseFocus
[task 2021-06-28T17:44:17.076Z] 17:44:17 INFO - GECKO(7248) | WaitUntilApzStable: done promiseAllPaintsDone
[task 2021-06-28T17:44:17.078Z] 17:44:17 INFO - GECKO(7248) | PromiseApzRepaintsFlushed: Flushed APZ repaints, waiting for callback...
[task 2021-06-28T17:44:17.093Z] 17:44:17 INFO - GECKO(7248) | PromiseApzRepaintsFlushed: APZ flush done
[task 2021-06-28T17:44:17.095Z] 17:44:17 INFO - GECKO(7248) | WaitUntilApzStable: all done
[task 2021-06-28T17:44:17.221Z] 17:44:17 INFO - GECKO(7248) | WaitUntilApzStable: flushed APZ repaints in parent proc, waiting for callback...
[task 2021-06-28T17:44:17.272Z] 17:44:17 INFO - GECKO(7248) | WaitUntilApzStable: APZ flush done in parent proc
[task 2021-06-28T17:44:17.274Z] 17:44:17 INFO - GECKO(7248) | WaitUntilApzStable: got apz-flush-done in child proc
[task 2021-06-28T17:44:17.434Z] 17:44:17 INFO - GECKO(7248) | WaitUntilApzStable: done promiseFocus
[task 2021-06-28T17:44:17.469Z] 17:44:17 INFO - GECKO(7248) | WaitUntilApzStable: done promiseAllPaintsDone
[task 2021-06-28T17:44:17.471Z] 17:44:17 INFO - GECKO(7248) | PromiseApzRepaintsFlushed: Flushed APZ repaints, waiting for callback...
[task 2021-06-28T17:44:17.516Z] 17:44:17 INFO - GECKO(7248) | PromiseApzRepaintsFlushed: APZ flush done
[task 2021-06-28T17:44:17.517Z] 17:44:17 INFO - GECKO(7248) | WaitUntilApzStable: all done
[task 2021-06-28T17:44:17.541Z] 17:44:17 INFO - GECKO(7248) | [POINTERLOCK] Finishing file_pointerlock_xorigin_iframe_no_user_gesture.html
[task 2021-06-28T17:44:17.934Z] 17:44:17 INFO - GECKO(7248) | [POINTERLOCK] Starting file_pointerlock_xorigin_iframe_not_focused.html
[task 2021-06-28T17:49:27.636Z] 17:49:27 INFO - TEST-INFO | started process screentopng
[task 2021-06-28T17:49:27.771Z] 17:49:27 INFO - TEST-INFO | screentopng: exit 0
[task 2021-06-28T17:49:27.771Z] 17:49:27 INFO - Buffered messages logged at 17:44:13
[task 2021-06-28T17:49:27.772Z] 17:49:27 INFO - must wait for load
[task 2021-06-28T17:49:27.773Z] 17:49:27 INFO - Testing file_pointerlock_xorigin_iframe.html
[task 2021-06-28T17:49:27.773Z] 17:49:27 INFO - file_pointerlock_xorigin_iframe.html: must wait for focus
[task 2021-06-28T17:49:27.774Z] 17:49:27 INFO - TEST-PASS | dom/tests/mochitest/pointerlock/test_pointerlock_xorigin_iframe.html | file_pointerlock_xorigin_iframe.html: got pointerlockchange
[task 2021-06-28T17:49:27.775Z] 17:49:27 INFO - TEST-PASS | dom/tests/mochitest/pointerlock/test_pointerlock_xorigin_iframe.html | file_pointerlock_xorigin_iframe.html: target pointer locked
[task 2021-06-28T17:49:27.776Z] 17:49:27 INFO - file_pointerlock_xorigin_iframe.html: Got mousemove
[task 2021-06-28T17:49:27.777Z] 17:49:27 INFO - TEST-PASS | dom/tests/mochitest/pointerlock/test_pointerlock_xorigin_iframe.html | file_pointerlock_xorigin_iframe.html: has movementX
[task 2021-06-28T17:49:27.778Z] 17:49:27 INFO - TEST-PASS | dom/tests/mochitest/pointerlock/test_pointerlock_xorigin_iframe.html | file_pointerlock_xorigin_iframe.html: has movementY
[task 2021-06-28T17:49:27.779Z] 17:49:27 INFO - TEST-PASS | dom/tests/mochitest/pointerlock/test_pointerlock_xorigin_iframe.html | file_pointerlock_xorigin_iframe.html: event.target
[task 2021-06-28T17:49:27.780Z] 17:49:27 INFO - Buffered messages logged at 17:44:15
[task 2021-06-28T17:49:27.780Z] 17:49:27 INFO - request pointer lock in xorigin iframe
[task 2021-06-28T17:49:27.781Z] 17:49:27 INFO - TEST-PASS | dom/tests/mochitest/pointerlock/test_pointerlock_xorigin_iframe.html | got pointerlockerror - "pointerlockerror" == "pointerlockerror"
[task 2021-06-28T17:49:27.782Z] 17:49:27 INFO - TEST-PASS | dom/tests/mochitest/pointerlock/test_pointerlock_xorigin_iframe.html | file_pointerlock_xorigin_iframe.html: got pointerlockchange
[task 2021-06-28T17:49:27.783Z] 17:49:27 INFO - TEST-PASS | dom/tests/mochitest/pointerlock/test_pointerlock_xorigin_iframe.html | file_pointerlock_xorigin_iframe.html: pointer unlocked
[task 2021-06-28T17:49:27.784Z] 17:49:27 INFO - must wait for focus
[task 2021-06-28T17:49:27.785Z] 17:49:27 INFO - Testing file_pointerlock_xorigin_iframe_no_user_gesture.html
[task 2021-06-28T17:49:27.785Z] 17:49:27 INFO - Buffered messages logged at 17:44:16
[task 2021-06-28T17:49:27.786Z] 17:49:27 INFO - file_pointerlock_xorigin_iframe_no_user_gesture.html: must wait for focus
[task 2021-06-28T17:49:27.787Z] 17:49:27 INFO - Buffered messages logged at 17:44:17
[task 2021-06-28T17:49:27.788Z] 17:49:27 INFO - TEST-PASS | dom/tests/mochitest/pointerlock/test_pointerlock_xorigin_iframe.html | file_pointerlock_xorigin_iframe_no_user_gesture.html: got pointerlockerror
[task 2021-06-28T17:49:27.789Z] 17:49:27 INFO - TEST-PASS | dom/tests/mochitest/pointerlock/test_pointerlock_xorigin_iframe.html | file_pointerlock_xorigin_iframe_no_user_gesture.html: target pointer locked
[task 2021-06-28T17:49:27.789Z] 17:49:27 INFO - file_pointerlock_xorigin_iframe_no_user_gesture.html: test sending mouse event to iframe
[task 2021-06-28T17:49:27.790Z] 17:49:27 INFO - file_pointerlock_xorigin_iframe_no_user_gesture.html: test sending mouse event to another window
[task 2021-06-28T17:49:27.791Z] 17:49:27 INFO - file_pointerlock_xorigin_iframe_no_user_gesture.html: win onload
[task 2021-06-28T17:49:27.792Z] 17:49:27 INFO - file_pointerlock_xorigin_iframe_no_user_gesture.html: must wait for focus
[task 2021-06-28T17:49:27.793Z] 17:49:27 INFO - must wait for focus
[task 2021-06-28T17:49:27.793Z] 17:49:27 INFO - Testing file_pointerlock_xorigin_iframe_not_focused.html
[task 2021-06-28T17:49:27.794Z] 17:49:27 INFO - file_pointerlock_xorigin_iframe_not_focused.html: must wait for focus
[task 2021-06-28T17:49:27.794Z] 17:49:27 INFO - Buffered messages logged at 17:44:18
[task 2021-06-28T17:49:27.794Z] 17:49:27 INFO - file_pointerlock_xorigin_iframe_not_focused.html: Put the focus on top-level document
[task 2021-06-28T17:49:27.794Z] 17:49:27 INFO - request pointer lock in xorigin iframe
[task 2021-06-28T17:49:27.794Z] 17:49:27 INFO - Buffered messages logged at 17:44:19
[task 2021-06-28T17:49:27.794Z] 17:49:27 INFO - TEST-PASS | dom/tests/mochitest/pointerlock/test_pointerlock_xorigin_iframe.html | got pointerlockchange - "pointerlockchange" == "pointerlockchange"
[task 2021-06-28T17:49:27.794Z] 17:49:27 INFO - wait for mousemove event
[task 2021-06-28T17:49:27.794Z] 17:49:27 INFO - Buffered messages finished
[task 2021-06-28T17:49:27.795Z] 17:49:27 INFO - TEST-UNEXPECTED-FAIL | dom/tests/mochitest/pointerlock/test_pointerlock_xorigin_iframe.html | Test timed out. -
[task 2021-06-28T17:49:28.641Z] 17:49:28 INFO - GECKO(7248) | MEMORY STAT | vsize 2546MB | residentFast 112MB | heapAllocated 8MB
[task 2021-06-28T17:49:28.646Z] 17:49:28 INFO - TEST-OK | dom/tests/mochitest/pointerlock/test_pointerlock_xorigin_iframe.html | took 315581ms
[task 2021-06-28T17:49:31.650Z] 17:49:31 INFO - Error: Unable to restore focus, expect failures and timeouts.

Whiteboard: [retriggered][stockwell disabled] → [retriggered][stockwell disabled][stockwell needswork:owner]

Hi Sean, are you still working on this?

Flags: needinfo?(sefeng)
Flags: needinfo?(sefeng)

No, I am not, I have not been actively working on this.

Flags: needinfo?(sefeng)

Hi Jens, can you assign someone to take a look?

Flags: needinfo?(jstutte)

I will take a look.

Assignee: nobody → echen
Flags: needinfo?(jstutte)
Flags: needinfo?(echen)

It is not guaranteed that the task scheduled by SepcialPowers.spawn would be run
before the asynchronous synthesized mouse event. So rewrite the test to ensure
the event listener is ready on remote iframe before starting test.

Attachment #9231868 - Attachment description: WIP: Bug 1698698 - Ensure event listener is registered on remote iframe before synthesizing mouse event; → Bug 1698698 - Ensure event listener is registered on remote iframe before synthesizing mouse event;
Pushed by echen@mozilla.com:
https://hg.mozilla.org/integration/autoland/rev/911545677d2b
Ensure event listener is registered on remote iframe before synthesizing mouse event; r=masayuki
Status: REOPENED → RESOLVED
Closed: 1 year ago11 months ago
Keywords: leave-open
Resolution: --- → FIXED
You need to log in before you can comment on or make changes to this bug.