Closed Bug 1363957 Opened 8 years ago Closed 6 years ago

Intermittent dom/animation/test/mozilla/test_deferred_start.html | Test timed out. - Test timed out.

Categories

(Core :: DOM: Animation, defect, P5)

defect

Tracking

()

RESOLVED WORKSFORME
Tracking Status
firefox58 --- disabled
firefox59 --- disabled

People

(Reporter: intermittent-bug-filer, Unassigned)

References

Details

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

That will be bug 1361260 to blame, and specifically the added playbackRate test: https://hg.mozilla.org/mozilla-central/rev/fc0edea49a70
This seems to have a pretty low failure rate so I'm leaving it for now. It has only occurred twice in 4~5 days and both on Android. Perhaps it gets stuck waiting for paints?
I added a comment about how I think we should fix this in bug 1366603 comment 36 but I probably should have commented here instead.
Whiteboard: [stockwell needswork]
Waiting for updates from bug 1366603
In the last 7 days, there were 121 failures. They occur on android-4-3-armv7-api16 (debug). A recent log: https://treeherder.mozilla.org/logviewer.html#?repo=mozilla-inbound&job_id=143609495&lineNumber=1792 A relevant part of the log where the test failed: [task 2017-11-10T09:22:02.641Z] 09:22:02 INFO - 66 INFO None67 INFO TEST-START | dom/animation/test/mozilla/test_deferred_start.html 1789 [task 2017-11-10T09:27:17.200Z] 09:27:17 INFO - Buffered messages logged at 09:27:13 1790 [task 2017-11-10T09:27:17.200Z] 09:27:17 INFO - 68 INFO TEST-PASS | dom/animation/test/mozilla/test_deferred_start.html | - : Elided 2 passes or known failures. 1791 [task 2017-11-10T09:27:17.200Z] 09:27:17 INFO - Buffered messages finished 1792 [task 2017-11-10T09:27:17.200Z] 09:27:17 INFO - 69 INFO TEST-UNEXPECTED-FAIL | dom/animation/test/mozilla/test_deferred_start.html | Test timed out. - Test timed out. 1793 [task 2017-11-10T09:27:38.274Z] 09:27:38 INFO - 70 INFO TEST-UNEXPECTED-FAIL | dom/animation/test/mozilla/test_deferred_start.html | Timeout - Timeout: Test runner timed us out. 1794 [task 2017-11-10T09:27:38.275Z] 09:27:38 INFO - 71 INFO TEST-UNEXPECTED-FAIL | dom/animation/test/mozilla/test_deferred_start.html | Starting an animation with a playbackRate starts from the correct point - Starting an animation with a playbackRate starts from the correct point: Test timed out 1795 [task 2017-11-10T09:27:38.276Z] 09:27:38 INFO - 72 INFO TEST-UNEXPECTED-FAIL | dom/animation/test/mozilla/test_deferred_start.html | Finished test - Finished test: Status: 2 1796 [task 2017-11-10T09:27:38.277Z] 09:27:38 INFO - 73 INFO TEST-OK | dom/animation/test/mozilla/test_deferred_start.html | took 339632ms :birtles, can you please take a look?
Flags: needinfo?(bbirtles)
Mantaroh is working on this in bug 1395971.
Flags: needinfo?(bbirtles) → needinfo?(mantaroh)
Pushed by jmaher@mozilla.com: https://hg.mozilla.org/integration/mozilla-inbound/rev/c90922dbea36 Disable dom/animation/test/mozilla/test_deferred_start.html on android/debug and win10 for frequent failures. r=me, a=test-only
this has been disabled, please remember to enable it while working on a patch
Whiteboard: [stockwell disable-recommended] → [stockwell disabled]
Status: NEW → RESOLVED
Closed: 7 years ago
Resolution: --- → FIXED
Target Milestone: --- → mozilla59
Status: RESOLVED → REOPENED
Keywords: leave-open
Resolution: FIXED → ---
I hit this phenomenon on bug 1419226 as well. We can confirm this problem on Android of debug build. It seems like that IsDOMAfterPaintPending() returns true always. A mechanism of this failure is as follow: -------------------------------------------------------------------------------------------------------------- 1) test will check that gecko has a pending paint event. (i.e. calling the isMozAfterPaintPending.) 2) nsPresContext::IsDOMAfterPaintPending() returns true due to pres context has a pending flush of view manager, then pres context queued MozAfterPaint(e.g transaction id is 'X'). 3) Notify invalidation rectangle. (e.g. transaction id is X + 1) 4) Notify invalidation rectangle. (e.g. transaction id is X + 2) 5) Received DidComposite from compositor(transaction id is X + 1), then gecko fired MozAfterPaint with transaction id[X / X+1]. After this step, pres context has pending transaction is [X+2] 6) test will check that gecko has a pending paint event. 7) nsPresContext::IsDOMAfterPaintPending() returns true due to pres context has unfired paint event (i.e. X + 2) 8) Notify invalidation rectangle. (e.g. transaction id is X + 3) 9) Received DidComposite from compositor(transaction id is X + 2), then gecko fired MozAfterPaint with transaction id[X + 2]. After this step, pres context has pending transaction is [X+3] 10) test will check that gecko has a pending paint event. 11) nsPresContext::IsDOMAfterPaintPending returns true due to pres context has unfired paint event (i.e. X + 3) -------------------------------------------------------------------------------------------------------------- The gecko continues these steps. Maybe,, I guess that the delay of DidComposite causes this bug, or calling NotifyInvalidation() twice will cause this bug.
I don't believe Mantaroh is working on this any more: clearing ni.
Flags: needinfo?(mantaroh)
Priority: -- → P5
Closing since the failure hasn't happened for four months.
Status: REOPENED → RESOLVED
Closed: 7 years ago6 years ago
Resolution: --- → WORKSFORME
You need to log in before you can comment on or make changes to this bug.