WebVR: fix initial vsync

third_party/WebKit/Source/modules/vr/VRDisplay.cpp

Index: third_party/WebKit/Source/modules/vr/VRDisplay.cpp
diff --git a/third_party/WebKit/Source/modules/vr/VRDisplay.cpp b/third_party/WebKit/Source/modules/vr/VRDisplay.cpp
index 553622a0dfa064f16522cfd8694dc7834f1abb48..f28db428e7ec2baf68afefddd105b080908dc9b4 100644
--- a/third_party/WebKit/Source/modules/vr/VRDisplay.cpp
+++ b/third_party/WebKit/Source/modules/vr/VRDisplay.cpp
@@ -130,10 +130,11 @@ VREyeParameters* VRDisplay::getEyeParameters(const String& which_eye) {
 }
 
 int VRDisplay::requestAnimationFrame(FrameRequestCallback* callback) {
+  DVLOG(2) << __FUNCTION__;
   Document* doc = this->GetDocument();
   if (!doc)
     return 0;
-  pending_raf_ = true;
+  pending_vrdisplay_raf_ = true;
   if (!vr_v_sync_provider_.is_bound()) {
     ConnectVSyncProvider();
   } else if (!display_blurred_ && !pending_vsync_) {
@@ -146,12 +147,14 @@ int VRDisplay::requestAnimationFrame(FrameRequestCallback* callback) {
 }
 
 void VRDisplay::cancelAnimationFrame(int id) {
+  DVLOG(2) << __FUNCTION__;
   if (!scripted_animation_controller_)
     return;
   scripted_animation_controller_->CancelCallback(id);
 }
 
 void VRDisplay::OnBlur() {
+  DVLOG(1) << __FUNCTION__;
   display_blurred_ = true;
   vr_v_sync_provider_.reset();
   navigator_vr_->EnqueueVREvent(VRDisplayEvent::Create(
@@ -159,6 +162,7 @@ void VRDisplay::OnBlur() {
 }
 
 void VRDisplay::OnFocus() {
+  DVLOG(1) << __FUNCTION__;
   display_blurred_ = false;
   ConnectVSyncProvider();
   navigator_vr_->EnqueueVREvent(VRDisplayEvent::Create(
@@ -178,6 +182,7 @@ void ReportPresentationResult(PresentationResult result) {
 
 ScriptPromise VRDisplay::requestPresent(ScriptState* script_state,
                                         const HeapVector<VRLayer>& layers) {
+  DVLOG(1) << __FUNCTION__;
   ExecutionContext* execution_context = ExecutionContext::From(script_state);
   UseCounter::Count(execution_context, UseCounter::kVRRequestPresent);
   if (!execution_context->IsSecureContext()) {
@@ -320,6 +325,7 @@ void VRDisplay::OnPresentComplete(bool success) {
 }
 
 ScriptPromise VRDisplay::exitPresent(ScriptState* script_state) {
+  DVLOG(1) << __FUNCTION__;
   ScriptPromiseResolver* resolver = ScriptPromiseResolver::Create(script_state);
   ScriptPromise promise = resolver->Promise();
 
@@ -397,6 +403,34 @@ void VRDisplay::BeginPresent() {
     resolver->Resolve();
   }
   OnPresentChange();
+
+  // TODO(klausw,crbug.com/710863): there appear to be cases where an embedded

[mthiesse, 2017/04/28 19:45:06]

If you simply replace all of the code here with:

  if (doc && doc->GetPage()) {
    doc->GetPage()->Animator().ServiceScriptedAnimations(
        WTF::MonotonicallyIncreasingTime());
  }

it seems to fix at least the quake site that was broken. Then you don't need the
rest of the changes here.

+  // iframe has started presenting but isn't focused. To fix this, would need
+  // to switch focus here.
+
+  // Ensure that we get at least one vsync. It's possible that a page may
+  // have started presentation but not used vrDisplay.rAF yet, i.e. if it
+  // uses window.rAF while not yet presenting. It needs to get a chance

[mthiesse, 2017/04/28 19:13:21]

So, why not just fire window.rAF once after presentChange? Why all this
complexity about adding another path to initializing the VSync provider?

Sure, they'll 'miss' one frame, but that's their fault.

Also I'm really really itching to refactor how focus and vsync provider work and
shift everything into the browser, but I'm not being allowed to do so until we
ship :P

[klausw, 2017/04/28 20:23:01]

I'm doing something similar now, and have confirmed that the
MonotonicallyIncreasingTimestamp is compatible via some extra temporary logging:

04-28 13:17:10.490 25461 25476 I chromium: [INFO:VRDisplay.cpp(708)]
ProcessScheduledWindowAnimations: timestamp=211870.831677ms
04-28 13:17:10.490 25461 25476 I chromium: [INFO:VRDisplay.cpp(711)]
ProcessScheduledWindowAnimations: window.rAF fallback successfully scheduled
VRDisplay.rAF
04-28 13:17:10.575 25461 25476 I chromium: [INFO:VRDisplay.cpp(708)]
ProcessScheduledWindowAnimations: timestamp=211870.989914ms

+  // to run its animation loop to avoid getting stuck, and to do so we
+  // need a vsync where we can run pending window.rAF callbacks.
+  if (!vr_v_sync_provider_.is_bound()) {
+    ConnectVSyncProvider();
+  } else if (!display_blurred_ && !pending_vsync_) {
+    pending_vsync_ = true;
+    vr_v_sync_provider_->GetVSync(ConvertToBaseCallback(
+        WTF::Bind(&VRDisplay::OnVSync, WrapWeakPersistent(this))));
+  }
+  if (!pending_vsync_) {
+    DVLOG(1) << __FUNCTION__ << ": scheduling missing vsync";
+    if (vr_v_sync_provider_.is_bound()) {
+      pending_vsync_ = true;
+      vr_v_sync_provider_->GetVSync(ConvertToBaseCallback(
+          WTF::Bind(&VRDisplay::OnVSync, WrapWeakPersistent(this))));
+    } else {
+      DVLOG(1) << __FUNCTION__
+               << ": failed to schedule mising vsync, not focused?";
+    }
+  }
 }
 
 // Need to close service if exists and then free rendering context.
@@ -613,6 +647,7 @@ Document* VRDisplay::GetDocument() {
 }
 
 void VRDisplay::OnPresentChange() {
+  DVLOG(1) << __FUNCTION__ << ": is_presenting_=" << is_presenting_;
   if (is_presenting_ && !is_valid_device_for_presenting_) {
     DVLOG(1) << __FUNCTION__ << ": device not valid, not sending event";
     return;
@@ -681,23 +716,48 @@ void VRDisplay::ProcessScheduledWindowAnimations(double timestamp) {
   auto page = doc->GetPage();
   if (!page)
     return;
+
+  bool had_pending_vrdisplay_raf = pending_vrdisplay_raf_;
   // TODO(klausw): update timestamp based on scheduling delay?
   page->Animator().ServiceScriptedAnimations(timestamp);
+
+  if (had_pending_vrdisplay_raf != pending_vrdisplay_raf_) {
+    DVLOG(1) << __FUNCTION__
+             << ": window.rAF fallback successfully scheduled VRDisplay.rAF";
+  }
+
+  if (!pending_vrdisplay_raf_) {
+    // There wasn't any call to vrDisplay.rAF, so we will not be getting new
+    // frames from now on unless the application schedules one down the road in
+    // reaction to a separate event or timeout. TODO(klausw,crbug.com/716087):
+    // do something more useful here?
+    DVLOG(1) << __FUNCTION__
+             << ": no scheduled VRDisplay.requestAnimationFrame, presentation "
+                "broken?";
+  }
 }
 
 void VRDisplay::ProcessScheduledAnimations(double timestamp) {
+  DVLOG(2) << __FUNCTION__;
   // Check if we still have a valid context, the animation controller
   // or document may have disappeared since we scheduled this.
   Document* doc = this->GetDocument();
-  if (!doc || display_blurred_ || !scripted_animation_controller_)
+  if (!doc || display_blurred_) {
+    DVLOG(2) << __FUNCTION__ << ": early exit, doc=" << doc
+             << " display_blurred_=" << display_blurred_;
     return;
+  }
 
   TRACE_EVENT1("gpu", "VRDisplay::OnVSync", "frame", vr_frame_id_);
 
-  AutoReset<bool> animating(&in_animation_frame_, true);
-  pending_raf_ = false;
-
-  scripted_animation_controller_->ServiceScriptedAnimations(timestamp);
+  if (pending_vrdisplay_raf_ && scripted_animation_controller_) {
+    // Run the callback, making sure that in_animation_frame_ is only
+    // true for the vrDisplay rAF and not for a legacy window rAF
+    // that may be called later.
+    AutoReset<bool> animating(&in_animation_frame_, true);
+    pending_vrdisplay_raf_ = false;
+    scripted_animation_controller_->ServiceScriptedAnimations(timestamp);
+  }
 
   // For GVR, we shut down normal vsync processing during VR presentation.
   // Trigger any callbacks on window.rAF manually so that they run after
@@ -713,6 +773,7 @@ void VRDisplay::OnVSync(device::mojom::blink::VRPosePtr pose,
                         mojo::common::mojom::blink::TimeDeltaPtr time,
                         int16_t frame_id,
                         device::mojom::blink::VRVSyncProvider::Status error) {
+  DVLOG(2) << __FUNCTION__;
   v_sync_connection_failed_ = false;
   switch (error) {
     case device::mojom::blink::VRVSyncProvider::Status::SUCCESS:
@@ -752,7 +813,7 @@ void VRDisplay::ConnectVSyncProvider() {
   display_->GetVRVSyncProvider(mojo::MakeRequest(&vr_v_sync_provider_));
   vr_v_sync_provider_.set_connection_error_handler(ConvertToBaseCallback(
       WTF::Bind(&VRDisplay::OnVSyncConnectionError, WrapWeakPersistent(this))));
-  if (pending_raf_ && !display_blurred_) {
+  if (pending_vrdisplay_raf_ && !display_blurred_) {
     pending_vsync_ = true;
     vr_v_sync_provider_->GetVSync(ConvertToBaseCallback(
         WTF::Bind(&VRDisplay::OnVSync, WrapWeakPersistent(this))));
@@ -801,6 +862,7 @@ bool VRDisplay::HasPendingActivity() const {
 
 void VRDisplay::FocusChanged() {
   // TODO(mthiesse): Blur/focus the display.
+  DVLOG(1) << __FUNCTION__;
   vr_v_sync_provider_.reset();
   ConnectVSyncProvider();
 }