Closed Bug 1577642 Opened 5 months ago Closed 5 months ago

Intermittent /html/webappapis/animation-frames/same-dispatch-time.html | requestAnimationFrame will timestamp events in the same queue with the same time - assert_equals: expected 65.5 but got 65.52

Categories

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

defect

Tracking

()

RESOLVED FIXED
mozilla71
Tracking Status
firefox-esr60 --- unaffected
firefox-esr68 --- unaffected
firefox69 --- unaffected
firefox70 --- fixed
firefox71 --- fixed

People

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

References

(Regression)

Details

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

Attachments

(1 file)

Filed by: nerli [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer.html#?job_id=264126287&repo=autoland
Full log: https://queue.taskcluster.net/v1/task/Uk2d_PFuRLmyJCB0r01Rjg/runs/0/artifacts/public/logs/live_backing.log


[task 2019-08-29T21:11:18.434Z] 21:11:18 INFO - TEST-START | /html/webappapis/animation-frames/same-dispatch-time.html
[task 2019-08-29T21:11:18.437Z] 21:11:18 INFO - Closing window 36
[task 2019-08-29T21:11:18.990Z] 21:11:18 INFO -
[task 2019-08-29T21:11:18.990Z] 21:11:18 INFO - TEST-UNEXPECTED-FAIL | /html/webappapis/animation-frames/same-dispatch-time.html | requestAnimationFrame will timestamp events in the same queue with the same time - assert_equals: expected 65.5 but got 65.52
[task 2019-08-29T21:11:18.990Z] 21:11:18 INFO - @http://web-platform.test:8000/html/webappapis/animation-frames/same-dispatch-time.html:25:24
[task 2019-08-29T21:11:18.990Z] 21:11:18 INFO - Test.prototype.step@http://web-platform.test:8000/resources/testharness.js:1611:25
[task 2019-08-29T21:11:18.990Z] 21:11:18 INFO - Test.prototype.step_func/<@http://web-platform.test:8000/resources/testharness.js:1635:35
[task 2019-08-29T21:11:18.990Z] 21:11:18 INFO - FrameRequestCallback*@http://web-platform.test:8000/html/webappapis/animation-frames/same-dispatch-time.html:21:30
[task 2019-08-29T21:11:18.990Z] 21:11:18 INFO - Test.prototype.step@http://web-platform.test:8000/resources/testharness.js:1611:25
[task 2019-08-29T21:11:18.990Z] 21:11:18 INFO - async_test@http://web-platform.test:8000/resources/testharness.js:576:22
[task 2019-08-29T21:11:18.990Z] 21:11:18 INFO - @http://web-platform.test:8000/html/webappapis/animation-frames/same-dispatch-time.html:12:17
[task 2019-08-29T21:11:18.990Z] 21:11:18 INFO - TEST-OK | /html/webappapis/animation-frames/same-dispatch-time.html | took 521ms
[task 2019-08-29T21:11:18.990Z] 21:11:18 INFO - PID 2505 | 1567113078960 Marionette INFO Stopped listening on port 50264
[task 2019-08-29T21:11:19.579Z] 21:11:19 INFO - Browser exited with return code 0
[task 2019-08-29T21:11:19.579Z] 21:11:19 INFO - PROCESS LEAKS None
[task 2019-08-29T21:11:19.580Z] 21:11:19 INFO - Closing logging queue
[task 2019-08-29T21:11:19.580Z] 21:11:19 INFO - queue closed
[task 2019-08-29T21:11:19.584Z] 21:11:19 INFO - Setting up ssl
[task 2019-08-29T21:11:19.631Z] 21:11:19 INFO - certutil |
[task 2019-08-29T21:11:19.657Z] 21:11:19 INFO - certutil |
[task 2019-08-29T21:11:19.682Z] 21:11:19 INFO - certutil |
[task 2019-08-29T21:11:19.682Z] 21:11:19 INFO - Certificate Nickname Trust Attributes
[task 2019-08-29T21:11:19.682Z] 21:11:19 INFO - SSL,S/MIME,JAR/XPI
[task 2019-08-29T21:11:19.682Z] 21:11:19 INFO -
[task 2019-08-29T21:11:19.682Z] 21:11:19 INFO - web-platform-tests CT,,
[task 2019-08-29T21:11:19.682Z] 21:11:19 INFO -
[task 2019-08-29T21:11:19.703Z] 21:11:19 INFO - Application command: /Users/cltbld/tasks/task_1567112263/build/application/Firefox Nightly.app/Contents/MacOS/firefox --marionette about:blank -foreground -profile /var/folders/72/xvs3v_s16pv64g5kbkvljct0000017/T/tmp3nUcVU.mozrunner
[task 2019-08-29T21:11:19.712Z] 21:11:19 INFO - Starting runner
[task 2019-08-29T21:11:20.343Z] 21:11:20 INFO - PID 2521 | 1567113080320 addons.webextension.screenshots@mozilla.org WARN Loading extension 'screenshots@mozilla.org': Reading manifest: Invalid extension permission: mozillaAddons
[task 2019-08-29T21:11:20.344Z] 21:11:20 INFO - PID 2521 | 1567113080320 addons.webextension.screenshots@mozilla.org WARN Loading extension 'screenshots@mozilla.org': Reading manifest: Invalid extension permission: telemetry
[task 2019-08-29T21:11:20.344Z] 21:11:20 INFO - PID 2521 | 1567113080320 addons.webextension.screenshots@mozilla.org WARN Loading extension 'screenshots@mozilla.org': Reading manifest: Invalid extension permission: resource://pdf.js/
[task 2019-08-29T21:11:20.344Z] 21:11:20 INFO - PID 2521 | 1567113080320 addons.webextension.screenshots@mozilla.org WARN Loading extension 'screenshots@mozilla.org': Reading manifest: Invalid extension permission: about:reader*
[task 2019-08-29T21:11:22.490Z] 21:11:22 INFO - PID 2521 | 1567113082467 Marionette INFO Listening on port 50264

Hi Tom, this seems to be from Bug 1573793, can you please take a look?

There are 22 total failures since the bug was filed, the 29th of August.

Recent failure log: https://treeherder.mozilla.org/logviewer.html#/jobs?job_id=264394478&repo=mozilla-inbound&lineNumber=7336

Flags: needinfo?(tom)
Regressed by: 1573793
Whiteboard: [stockwell needswork:owner]

I think you mean https://github.com/web-platform-tests/wpt/pull/18750 / Bug 1577243

This looks like we're calling Reduce more than once....

Regressed by: 1577243
No longer regressed by: 1573793

When we had it in the loop, we would continually reduce it, which held the
possibility of bumping it down an epoch due to double imprecision. Now
we only reduce it once, using all rAF callbacks get the same timestamp.

Ah I see it.

Assignee: nobody → tom
Status: NEW → ASSIGNED
Flags: needinfo?(tom)
Pushed by tritter@mozilla.com:
https://hg.mozilla.org/integration/autoland/rev/a45c5b31080b
Move the timestamp rounding outside of the loop so it's only reduced once r=birtles
Status: ASSIGNED → RESOLVED
Closed: 5 months ago
Resolution: --- → FIXED
Target Milestone: --- → mozilla71

Please nominate this for Beta approval when you get a chance.

Comment on attachment 9090159 [details]
Bug 1577642 - Move the timestamp rounding outside of the loop so it's only reduced once r?birtles

Beta/Release Uplift Approval Request

  • User impact if declined: Beta's gonna have intermittents
  • Is this code covered by automated tests?: Yes
  • Has the fix been verified in Nightly?: Yes
  • Needs manual test from QE?: No
  • If yes, steps to reproduce:
  • List of other uplifts needed: None
  • Risk to taking this patch: Low
  • Why is the change risky/not risky? (and alternatives if risky): It's a pretty simple change
  • String changes made/needed:
Flags: needinfo?(tom)
Attachment #9090159 - Flags: approval-mozilla-beta?

Comment on attachment 9090159 [details]
Bug 1577642 - Move the timestamp rounding outside of the loop so it's only reduced once r?birtles

Fix for intermittent test failures, let's uplift for beta 5.

Attachment #9090159 - Flags: approval-mozilla-beta? → approval-mozilla-beta+
You need to log in before you can comment on or make changes to this bug.