1300651 - requestAnimationFrame calls back much too soon/often with webvr enabled

Status: RESOLVED FIXED

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

Description

[omgitsraven]

User Agent: Mozilla/5.0 (Windows NT 6.1; Win64; x64; rv:48.0) Gecko/20100101 Firefox/48.0
Build ID: 20160823121617

Steps to reproduce:

Make a simple requestAnimationFrame "loop" (call a function that at some point passes itself to requestAnimationFrame), then observe how many times per second that function is called.

Example here: http://ravenworks.ca/temp/fpstest.html


Actual results:

The function is called every 0.04ms, which is something like 20,000 frames per second.


Expected results:

Something more like 60 frames per second.

Comment 1

[Ben Kelly [:bkelly, not reviewing]]

Can you post your about:support?  I get 60fps on both 48.0.2 and nightly 51 on win10.

Comment 2

[omgitsraven]

Application Basics
------------------

Name: Firefox
Version: 51.0a1
Build ID: 20160905030222
Update Channel: nightly
User Agent: Mozilla/5.0 (Windows NT 6.1; Win64; x64; rv:51.0) Gecko/20100101 Firefox/51.0
OS: Windows_NT 6.1
Multiprocess Windows: 1/1 (Enabled by user)
Safe Mode: false

Crash Reports for the Last 3 Days
---------------------------------

Report ID: bp-d1489a13-5e98-4e32-8c2a-2d3f82160906
Submitted: 1 hour ago

Report ID: bp-b4c5f34f-cb67-486c-991e-6038d2160906
Submitted: 1 hour ago

Report ID: bp-9d74e07c-08ad-4990-aeb5-c48d02160906
Submitted: 1 hour ago

Report ID: bp-3a5bde20-515d-4c37-ac25-0566a2160905
Submitted: 6 hours ago

Report ID: bp-9f1b1450-c7ae-49b0-ba71-38e262160905
Submitted: 6 hours ago

Report ID: bp-96985e27-7479-46cc-b34d-dfa0b2160905
Submitted: 7 hours ago

Report ID: bp-be229740-fb77-4fc9-af3a-44f3d2160905
Submitted: 7 hours ago

Report ID: bp-318074e9-bdb6-4907-b114-d4a992160905
Submitted: 7 hours ago

Report ID: bp-9172d8bb-9c05-4a02-886d-7b2bd2160905
Submitted: 7 hours ago

Report ID: bp-6b2d8ce2-99ef-4b25-bfea-7e0a52160905
Submitted: 8 hours ago

Report ID: bp-bdadbeb1-140a-4ad3-9356-cbe9f2160905
Submitted: 8 hours ago

Report ID: bp-92b26df3-6252-481b-873c-233dd2160905
Submitted: 8 hours ago

Report ID: bp-cc9145ef-7250-460e-87ae-7a5452160905
Submitted: 8 hours ago

Report ID: bp-ede16302-bdf6-4d9a-b46c-1cfe72160905
Submitted: 8 hours ago

All Crash Reports

Extensions
----------

Name: FlyWeb
Version: 1.0.0
Enabled: true
ID: [e-mail]

Name: Mozilla WebVR Plus
Version: 0.5.0
Enabled: true
ID: @mozillawebvrenabler

Name: Multi-process staged rollout
Version: 1.2
Enabled: true
ID: [e-mail]

Name: Pocket
Version: 1.0.4
Enabled: true
ID: [e-mail]

Name: Web Compat
Version: 1.0
Enabled: true
ID: [e-mail]

Graphics
--------

Features
Compositing: Direct3D 11
Asynchronous Pan/Zoom: wheel input enabled; touch input enabled
WebGL Renderer: Google Inc. -- ANGLE (NVIDIA GeForce GTX 970 Direct3D11 vs_5_0 ps_5_0)
WebGL2 Renderer: NVIDIA Corporation -- GeForce GTX 970/PCIe/SSE2
Hardware H264 Decoding: No; D3D9 blacklisted with DLL atiumd64.dll (9.14.10.1080)
Audio Backend: wasapi
Direct2D: true
DirectWrite: true (6.2.9200.17568)
GPU #1
Active: Yes
Description: NVIDIA GeForce GTX 970
Vendor ID: 0x10de
Device ID: 0x13c2
Driver Version: 10.18.13.6881
Driver Date: 7-10-2016
Drivers: nvd3dumx,nvwgf2umx,nvwgf2umx nvd3dum,nvwgf2um,nvwgf2um
Subsys ID: 31711462
RAM: 4096

Diagnostics
AzureCanvasAccelerated: 0
AzureCanvasBackend: direct2d 1.1
AzureContentBackend: direct2d 1.1
AzureFallbackCanvasBackend: cairo





Important Modified Preferences
------------------------------

accessibility.typeaheadfind.flashBar: 0
browser.cache.disk.capacity: 358400
browser.cache.disk.filesystem_reported: 1
browser.cache.disk.smart_size.first_run: false
browser.cache.frecency_experiment: 3
browser.download.importedFromSqlite: true
browser.places.smartBookmarksVersion: 8
browser.sessionstore.upgradeBackup.latestBuildID: 20160905030222
browser.startup.homepage: about:home
browser.startup.homepage_override.buildID: 20160905030222
browser.startup.homepage_override.mstone: 51.0a1
browser.tabs.crashReporting.email: [e-mail]
browser.tabs.crashReporting.emailMe: true
browser.tabs.crashReporting.includeURL: true
browser.tabs.remote.autostart: true
browser.tabs.remote.autostart.2: false
browser.urlbar.userMadeSearchSuggestionsChoice: true
dom.apps.lastUpdate.buildID: 20160602030220
dom.apps.lastUpdate.mstone: 49.0a1
dom.apps.reset-permissions: true
dom.mozApps.used: true
dom.vr.poseprediction.enabled: true
extensions.lastAppVersion: 51.0a1
gfx.crash-guard.d3d11layers.appVersion: 43.0a1
gfx.crash-guard.d3d11layers.deviceID: 0x13c2
gfx.crash-guard.d3d11layers.driverVersion: 10.18.13.5598
gfx.crash-guard.d3d11layers.feature-d2d: true
gfx.crash-guard.d3d11layers.feature-d3d11: true
gfx.crash-guard.status.d3d11layers: 2
gfx.crash-guard.status.d3d9video: 2
gfx.direct3d.last_used_feature_level_idx: 0
gfx.driver-init.appVersion: 42.0a1
gfx.driver-init.deviceID: 0x13c2
gfx.driver-init.driverVersion: 9.18.13.5306
gfx.driver-init.feature-d2d: true
gfx.driver-init.feature-d3d11: true
gfx.driver-init.status: 2
gfx.vr.mirror-textures: true
media.gmp-eme-adobe.abi: x86_64-msvc-x64
media.gmp-eme-adobe.lastUpdate: 1459908733
media.gmp-eme-adobe.version: 17
media.gmp-gmpopenh264.abi: x86_64-msvc-x64
media.gmp-gmpopenh264.lastUpdate: 1472256589
media.gmp-gmpopenh264.version: 1.6
media.gmp-manager.buildID: 20160905030222
media.gmp-manager.lastCheck: 1473097708
media.gmp-widevinecdm.abi: x86_64-msvc-x64
media.gmp-widevinecdm.lastUpdate: 1472256591
media.gmp-widevinecdm.version: 1.4.8.903
media.gmp.storage.version.observed: 1
media.hardware-video-decoding.failed: false
network.cookie.prefsMigrated: true
network.predictor.cleaned-up: true
places.database.lastMaintenance: 1473041792
places.history.expiration.transient_current_max_pages: 122334
plugin.disable_full_page_plugin_for_types: application/pdf
plugin.importedState: true
privacy.sanitize.migrateClearSavedPwdsOnExit: true
privacy.sanitize.migrateFx3Prefs: true
security.sandbox.content.tempDirSuffix: {2d903a88-4592-499e-8f25-9c7f5141e85a}
services.sync.declinedEngines:
storage.vacuum.last.index: 1
storage.vacuum.last.places.sqlite: 1472257279

Important Locked Preferences
----------------------------

Places Database
---------------

JavaScript
----------

Incremental GC: true

Accessibility
-------------

Activated: false
Prevent Accessibility: 0

Library Versions
----------------

NSPR
Expected minimum version: 4.13 Beta
Version in use: 4.13 Beta

NSS
Expected minimum version: 3.27 Beta
Version in use: 3.27 Beta

NSSSMIME
Expected minimum version: 3.27 Beta
Version in use: 3.27 Beta

NSSSSL
Expected minimum version: 3.27 Beta
Version in use: 3.27 Beta

NSSUTIL
Expected minimum version: 3.27 Beta
Version in use: 3.27 Beta

Experimental Features
---------------------

Sandbox
-------

Content Process Sandbox Level: 2

Comment 3

[Ben Kelly [:bkelly, not reviewing]]

Mason, do you see anything in comment 2 that might suggest vsync would not be working correctly?  I think DOM bases its requestAnimationFrame() stuff on our vsync notifications.

Comment 4

[Ben Kelly [:bkelly, not reviewing]]

Although this crash stack linked from the about:support suggests perhaps refresh tick is being driven by nsITimer instead of vsync??

0 	xul.dll 	mozilla::layers::CanvasClientSharedSurface::UpdateRenderer(mozilla::gfx::IntSizeTyped<mozilla::gfx::UnknownUnits>, mozilla::MaybeOneOf<mozilla::layers::ClientCanvasLayer*, mozilla::layers::AsyncCanvasRenderer*>&) 	gfx/layers/client/CanvasClient.cpp:419
1 	xul.dll 	mozilla::layers::CanvasClientSharedSurface::Update(mozilla::gfx::IntSizeTyped<mozilla::gfx::UnknownUnits>, mozilla::layers::ClientCanvasLayer*) 	gfx/layers/client/CanvasClient.cpp:384
2 	xul.dll 	mozilla::layers::ClientCanvasLayer::RenderLayer() 	gfx/layers/client/ClientCanvasLayer.cpp:135
3 	xul.dll 	mozilla::layers::ClientContainerLayer::RenderLayer() 	gfx/layers/client/ClientContainerLayer.h:62
4 	xul.dll 	mozilla::layers::ClientLayerManager::EndTransactionInternal(void (*)(mozilla::layers::PaintedLayer*, gfxContext*, mozilla::gfx::IntRegionTyped<mozilla::gfx::UnknownUnits> const&, mozilla::gfx::IntRegionTyped<mozilla::gfx::UnknownUnits> const&, mozilla::layers::DrawRegionClip, mozilla::gfx::IntRegionTyped<mozilla::gfx::UnknownUnits> const&, void*), void*, mozilla::layers::LayerManager::EndTransactionFlags) 	gfx/layers/client/ClientLayerManager.cpp:302
5 	xul.dll 	mozilla::layers::ClientLayerManager::EndTransaction(void (*)(mozilla::layers::PaintedLayer*, gfxContext*, mozilla::gfx::IntRegionTyped<mozilla::gfx::UnknownUnits> const&, mozilla::gfx::IntRegionTyped<mozilla::gfx::UnknownUnits> const&, mozilla::layers::DrawRegionClip, mozilla::gfx::IntRegionTyped<mozilla::gfx::UnknownUnits> const&, void*), void*, mozilla::layers::LayerManager::EndTransactionFlags) 	gfx/layers/client/ClientLayerManager.cpp:347
6 	xul.dll 	nsDisplayList::PaintRoot(nsDisplayListBuilder*, nsRenderingContext*, unsigned int) 	layout/base/nsDisplayList.cpp:1938
7 	xul.dll 	nsLayoutUtils::PaintFrame(nsRenderingContext*, nsIFrame*, nsRegion const&, unsigned int, nsDisplayListBuilderMode, nsLayoutUtils::PaintFrameFlags) 	layout/base/nsLayoutUtils.cpp:3605
8 	xul.dll 	PresShell::Paint(nsView*, nsRegion const&, unsigned int) 	layout/base/nsPresShell.cpp:6641
9 	xul.dll 	nsViewManager::ProcessPendingUpdatesPaint(nsIWidget*) 	view/nsViewManager.cpp:484
10 	xul.dll 	nsViewManager::ProcessPendingUpdatesForView(nsView*, bool) 	view/nsViewManager.cpp:415
11 	xul.dll 	nsViewManager::ProcessPendingUpdates() 	view/nsViewManager.cpp:1118
12 	xul.dll 	nsRefreshDriver::Tick(__int64, mozilla::TimeStamp) 	layout/base/nsRefreshDriver.cpp:1898
13 	xul.dll 	mozilla::RefreshDriverTimer::TickDriver(nsRefreshDriver*, __int64, mozilla::TimeStamp) 	layout/base/nsRefreshDriver.cpp:275
14 	xul.dll 	mozilla::RefreshDriverTimer::TickRefreshDrivers(__int64, mozilla::TimeStamp, nsTArray<RefPtr<nsRefreshDriver> >&) 	layout/base/nsRefreshDriver.cpp:247
15 	xul.dll 	mozilla::RefreshDriverTimer::Tick(__int64, mozilla::TimeStamp) 	layout/base/nsRefreshDriver.cpp:266
16 	xul.dll 	mozilla::RefreshDriverTimer::TimerTick(nsITimer*, void*) 	layout/base/nsRefreshDriver.cpp:290
17 	xul.dll 	nsTimerImpl::Fire() 	xpcom/threads/nsTimerImpl.cpp:521
18 	xul.dll 	nsTimerEvent::Run() 	xpcom/threads/TimerThread.cpp:286
19 	xul.dll 	nsThread::ProcessNextEvent(bool, bool*) 	xpcom/threads/nsThread.cpp:1058

Comment 5

[omgitsraven]

It might be worth mentioning, a lot of those crashes were in VR mode, although the bug occurs even if I have not used WebVR whatsoever since launching Nightly.

Comment 6

[Mason Chang [Inactive] [:mchang]]

Yeah the fact that it's a timer is weird and so is VR. VR does some else thing outside of vsync to schedule things. Can you please try a clean profile and see if you still have the same problems? Thanks!

Comment 7

[omgitsraven]

Good call -- clean profile gives me 60 fps; and in my usual (nightly) profile, turning off the "Mozilla WebVR Plus" plugin (and relaunching) gives me 60 fps. Sorry I didn't think to try that before now.

Comment 8

[Ben Kelly [:bkelly, not reviewing]]

Vlad, can you take a look at this webvr issue?

Comment 9

[Andrew Overholt [:overholt]]

Maybe Kip would be able to take a look?

Comment 10

[:kip (Kearwood Gilbert)]

Prior to the WebVR 1.0 implementation, we recommended that users testing WebVR set layout.frane_rate to 0, effectively disabling vsync.  The WebVR add-on also set preferences to this effect.

Now with the dedicated VR rendering path implemented, this is no longer required and we are instructing users to reset their profiles if they set such preferences in the past.

Perhaps this is the root of the issue?

Comment 11

[omgitsraven]

I definitely had the WebVR add-on installed, so that sounds like a reasonable cause.

Does this mean hat "Mozilla WebVR Plus" should no longer be installed for Nightly WebVR users? (Maybe the plugin's description should be updated to reflect that?)

Comment 12

[Andrew Overholt [:overholt]]

(for comment 11)

Comment 13

[:kip (Kearwood Gilbert)]

(In reply to omgitsraven from comment #11)
> I definitely had the WebVR add-on installed, so that sounds like a
> reasonable cause.
> 
> Does this mean hat "Mozilla WebVR Plus" should no longer be installed for
> Nightly WebVR users? (Maybe the plugin's description should be updated to
> reflect that?)

Yes, Mozilla WebVR Plus currently provides no advantages to WebVR nightly users.  We could either update the add-on to no longer set the prefs or perhaps reverse them.

We have plans to enable WebVR in release with Firefox 51 using Test Pilot initially.

The add-on is intended to be later used for VR specific developer tools; however, this would ideally be a system add-on.

I will NI :cvan, who may have some insight into disabling or updating the add-on..

Comment 14

[:kip (Kearwood Gilbert)]

I'd suggest that we push an update to the add-on to reverse the layout.frame_rate pref to the default of -1.

Comment 15

[Christopher Van Wiemeersch [:cvan]]

(In reply to :kip (Kearwood Gilbert) from comment #14)
> I'd suggest that we push an update to the add-on to reverse the
> layout.frame_rate pref to the default of -1.

Done. In addons.mozilla.org review queue.

Comment 16

[Hsin-Yi Tsai (she/her) [:hsinyi]]

(In reply to Christopher Van Wiemeersch [:cvan] from comment #15)
> (In reply to :kip (Kearwood Gilbert) from comment #14)
> > I'd suggest that we push an update to the add-on to reverse the
> > layout.frame_rate pref to the default of -1.
> 
> Done. In addons.mozilla.org review queue.

Hi Christopher, could you kindly give the update on the addon review status so far? Has this issue been fixed?  Thank you.

Comment 17

[Christopher Van Wiemeersch [:cvan]]

(In reply to Hsin-Yi Tsai [:hsinyi] from comment #16)
> (In reply to Christopher Van Wiemeersch [:cvan] from comment #15)
> > (In reply to :kip (Kearwood Gilbert) from comment #14)
> > > I'd suggest that we push an update to the add-on to reverse the
> > > layout.frame_rate pref to the default of -1.
> > 
> > Done. In addons.mozilla.org review queue.
> 
> Hi Christopher, could you kindly give the update on the addon review status
> so far? Has this issue been fixed?  Thank you.

Yes, this was both fixed in the add-on/extension and the updated version approved back in October 2016 (see https://addons.mozilla.org/en-us/firefox/addon/mozilla-webvr-enabler/versions/).

As such, I'm closing this bug.

omgitsraven: Though you shouldn't, if you're able to reproduce this bug still, feel free to comment, and I can reopen this bug.

Thanks, everyone.