Closed Bug 1708697 Opened 7 months ago Closed 1 month ago

Intermittent gfx/layers/apz/test/mochitest/browser_test_autoscrolling_in_extension_popup_window.js | Test timed out -

Categories

(Core :: Panning and Zooming, defect, P5)

defect

Tracking

()

RESOLVED FIXED
95 Branch
Tracking Status
firefox95 --- fixed

People

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

References

Details

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

Attachments

(5 files)

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


[task 2021-04-30T13:09:40.132Z] 13:09:40     INFO - TEST-START | gfx/layers/apz/test/mochitest/browser_test_autoscrolling_in_extension_popup_window.js
[task 2021-04-30T13:09:40.319Z] 13:09:40     INFO - GECKO(6063) | Flushed APZ repaints, waiting for callback...
[task 2021-04-30T13:09:40.326Z] 13:09:40     INFO - GECKO(6063) | APZ flush done
[task 2021-04-30T13:09:40.327Z] 13:09:40     INFO - GECKO(6063) | Waits for a MozAfterPaint event
[task 2021-04-30T13:09:40.333Z] 13:09:40     INFO - GECKO(6063) | Got a MozAfterPaint event
[task 2021-04-30T13:09:40.344Z] 13:09:40     INFO - GECKO(6063) | Flushed APZ repaints, waiting for callback...
[task 2021-04-30T13:09:40.347Z] 13:09:40     INFO - GECKO(6063) | APZ flush done
[task 2021-04-30T13:09:40.348Z] 13:09:40     INFO - GECKO(6063) | Waits for a MozAfterPaint event
[task 2021-04-30T13:09:40.364Z] 13:09:40     INFO - GECKO(6063) | Got a MozAfterPaint event
[task 2021-04-30T13:10:25.159Z] 13:10:25     INFO - TEST-INFO | started process screentopng
[task 2021-04-30T13:10:25.531Z] 13:10:25     INFO - TEST-INFO | screentopng: exit 0
[task 2021-04-30T13:10:25.532Z] 13:10:25     INFO - Buffered messages logged at 13:09:40
[task 2021-04-30T13:10:25.532Z] 13:10:25     INFO - Entering test bound 
[task 2021-04-30T13:10:25.533Z] 13:10:25     INFO - Extension loaded
[task 2021-04-30T13:10:25.534Z] 13:10:25     INFO - TEST-PASS | gfx/layers/apz/test/mochitest/browser_test_autoscrolling_in_extension_popup_window.js | Expect widget not to be overflowed - true == true - 
[task 2021-04-30T13:10:25.534Z] 13:10:25     INFO - TEST-PASS | gfx/layers/apz/test/mochitest/browser_test_autoscrolling_in_extension_popup_window.js | undefined assertion name - 
[task 2021-04-30T13:10:25.535Z] 13:10:25     INFO - Buffered messages finished
[task 2021-04-30T13:10:25.536Z] 13:10:25     INFO - TEST-UNEXPECTED-FAIL | gfx/layers/apz/test/mochitest/browser_test_autoscrolling_in_extension_popup_window.js | Test timed out - 
[task 2021-04-30T13:10:25.538Z] 13:10:25     INFO - Not taking screenshot here: see the one that was previously logged
[task 2021-04-30T13:10:25.538Z] 13:10:25     INFO - TEST-UNEXPECTED-FAIL | gfx/layers/apz/test/mochitest/browser_test_autoscrolling_in_extension_popup_window.js | Extension left running at test shutdown - 
[task 2021-04-30T13:10:25.538Z] 13:10:25     INFO - Stack trace:
[task 2021-04-30T13:10:25.539Z] 13:10:25     INFO - chrome://mochikit/content/browser-test.js:test_ok:1341
[task 2021-04-30T13:10:25.539Z] 13:10:25     INFO - chrome://mochikit/content/tests/SimpleTest/ExtensionTestUtils.js:ExtensionTestUtils.loadExtension/<:117
[task 2021-04-30T13:10:25.539Z] 13:10:25     INFO - chrome://mochikit/content/browser-test.js:nextTest:571
[task 2021-04-30T13:10:25.539Z] 13:10:25     INFO - Not taking screenshot here: see the one that was previously logged
[task 2021-04-30T13:10:25.539Z] 13:10:25     INFO - TEST-UNEXPECTED-FAIL | gfx/layers/apz/test/mochitest/browser_test_autoscrolling_in_extension_popup_window.js | Uncaught exception received from previously timed out test - AbortError: Actor 'SpecialPowers' destroyed before query 'Spawn' was resolved```

There have been 37 total failures in the last 7 days (recent failure log).
Affected platforms are:

  • linux1804-64-asan-qr
  • linux1804-64-qr debug & opt
  • linux1804-64-shippable-qr

Botond, could you please redirect this to someone who can take a look?

Flags: needinfo?(botond)
Whiteboard: [stockwell needswork]

Redirecting to Hiro as the author of the test

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

To be honest I don't understand what happens in the failure case because I can't reproduce the failure locally, but I did two speculative change;

  1. Use SpecialPowers.pushPrefEnv instead of setBoolPref in browser_test_animations_without_apz_sampler.js which runs just before browser_test_autoscrolling_in_extension_popup_window.js
  2. Setup a scroll event listener before triggering an autoscroll operation to avoid a race condition where the event listener misses scroll events caused by the autoscroll operation
Keywords: leave-open
Pushed by hikezoe.birchill@mozilla.com:
https://hg.mozilla.org/integration/autoland/rev/983d3fb0fbdb
Use SpecialPowers.pushPrefEnv instead of setBoolPref. r=tnikkel
https://hg.mozilla.org/integration/autoland/rev/d58c49c82efa
Setup a scroll event listener before triggering an autoscroll operation. r=tnikkel

As far as I can tell there are three possible race conditions in the test.

  1. The start mouse position of autoscrolling is out side of the popup window, we need to move the mouse cursor position first
  2. SpecialPowers.spawn without awaiting the return value doesn't seem to reliably setup the event listener for scroll events before we do send native mouse events
  3. flushApzRepaintsInPopup waits a MozAfterPaint event, but for this test case it wouldn't be sufficient, we need to do the same thing, waiting all pending MozAfterPaints, flushing "apz-repaints-flushed and waiting for it, and waiting all pending MozAfterPaints events again, that's what promiseApzFlushedRepaints does

With these fixes, this test didn't failed on multiple retriggers.

If we start autoscrolling without moving the mouse position into the content
area, we do sample with undesirable scroll deltas in
AutoscrollAnimation::DoSample since the initial mouse position is outside of the
popup window.

Note that to make sure an event listener mousemove events is set in the popup
content before causing a mousemove event from the browser parent process we need
to add the event listener in the extension's popup context in the first place.
That's because not awaiting a SpecialPowers.spawn() with an addEventListener
call in the spawned context doesn't ensure the script in the spawned context
runs. We will do the same manner for a scroll event in the next change.

And rename the function to promiseApzFlushedRepaintsInPopup since now the
funciton does the same thing what promiseApzFlushedRepaints does.

Depends on D129365

Keywords: leave-open
Pushed by hikezoe.birchill@mozilla.com:
https://hg.mozilla.org/integration/autoland/rev/d62fa53c8c66
Make sure a mousemove event has been received in the popup content before starting autoscrolling. r=tnikkel
https://hg.mozilla.org/integration/autoland/rev/02140dff12b1
Make sure a scroll event was fired in the same manner as we did for a mousemove event in the previous commit. r=tnikkel
https://hg.mozilla.org/integration/autoland/rev/27ba91f03d6b
Make sure all pending paints have been done in flushApzRepaintsInPopup. r=tnikkel
Status: ASSIGNED → RESOLVED
Closed: 1 month ago
Resolution: --- → FIXED
Target Milestone: --- → 95 Branch

Looks like this failure still keeps happening M-swr-fis runs (it's tier-2 though now).

See Also: → 1740713
You need to log in before you can comment on or make changes to this bug.