WebVR: fix initial vsync

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

 // Copyright 2016 The Chromium Authors. All rights reserved.
 // Use of this source code is governed by a BSD-style license that can be
 // found in the LICENSE file.
 
 #include "modules/vr/VRDisplay.h"
 
 #include "core/css/StylePropertySet.h"
 #include "core/dom/DOMException.h"
 #include "core/dom/FrameRequestCallback.h"
 #include "core/dom/ScriptedAnimationController.h"
@@ skipping 112 matching lines @@
     case kVREyeLeft:
       return eye_parameters_left_;
     case kVREyeRight:
       return eye_parameters_right_;
     default:
       return nullptr;
   }
 }
 
 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_) {
     pending_vsync_ = true;
     vr_v_sync_provider_->GetVSync(ConvertToBaseCallback(
         WTF::Bind(&VRDisplay::OnVSync, WrapWeakPersistent(this))));
   }
   callback->use_legacy_time_base_ = false;
   return EnsureScriptedAnimationController(doc).RegisterCallback(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(
       EventTypeNames::vrdisplayblur, true, false, this, ""));
 }
 
 void VRDisplay::OnFocus() {
+  DVLOG(1) << __FUNCTION__;
   display_blurred_ = false;
   ConnectVSyncProvider();
   navigator_vr_->EnqueueVREvent(VRDisplayEvent::Create(
       EventTypeNames::vrdisplayfocus, true, false, this, ""));
 }
 
 void ReportPresentationResult(PresentationResult result) {
   // Note that this is called twice for each call to requestPresent -
   // one to declare that requestPresent was called, and one for the
   // result.
   DEFINE_STATIC_LOCAL(
       EnumerationHistogram, vr_presentation_result_histogram,
       ("VRDisplayPresentResult",
        static_cast<int>(PresentationResult::kPresentationResultMax)));
   vr_presentation_result_histogram.Count(static_cast<int>(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()) {
     UseCounter::Count(execution_context,
                       UseCounter::kVRRequestPresentInsecureOrigin);
   }
 
   ReportPresentationResult(PresentationResult::kRequested);
 
   ScriptPromiseResolver* resolver = ScriptPromiseResolver::Create(script_state);
@@ skipping 122 matching lines @@
         kNotAllowedError, "Presentation request was denied.");
 
     while (!pending_present_resolvers_.IsEmpty()) {
       ScriptPromiseResolver* resolver = pending_present_resolvers_.TakeFirst();
       resolver->Reject(exception);
     }
   }
 }
 
 ScriptPromise VRDisplay::exitPresent(ScriptState* script_state) {
+  DVLOG(1) << __FUNCTION__;
   ScriptPromiseResolver* resolver = ScriptPromiseResolver::Create(script_state);
   ScriptPromise promise = resolver->Promise();
 
   if (!is_presenting_) {
     // Can't stop presenting if we're not presenting.
     DOMException* exception = DOMException::Create(
         kInvalidStateError, "VRDisplay is not presenting.");
     resolver->Reject(exception);
     return promise;
   }
@@ skipping 57 matching lines @@
   is_presenting_ = true;
   ReportPresentationResult(PresentationResult::kSuccess);
 
   UpdateLayerBounds();
 
   while (!pending_present_resolvers_.IsEmpty()) {
     ScriptPromiseResolver* resolver = pending_present_resolvers_.TakeFirst();
     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.
 void VRDisplay::ForceExitPresent() {
   if (display_) {
     display_->ExitPresent();
   }
   StopPresenting();
 }
 
@@ skipping 196 matching lines @@
 
 void VRDisplay::OnSubmitFrameRendered() {
   pending_previous_frame_render_ = false;
 }
 
 Document* VRDisplay::GetDocument() {
   return navigator_vr_->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;
   }
   navigator_vr_->EnqueueVREvent(VRDisplayEvent::Create(
       EventTypeNames::vrdisplaypresentchange, true, false, this, ""));
 }
 
 void VRDisplay::OnChanged(device::mojom::blink::VRDisplayInfoPtr display) {
   Update(display);
@@ skipping 48 matching lines @@
 }
 
 void VRDisplay::ProcessScheduledWindowAnimations(double timestamp) {
   TRACE_EVENT1("gpu", "VRDisplay::window.rAF", "frame", vr_frame_id_);
   auto doc = navigator_vr_->GetDocument();
   if (!doc)
     return;
   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
   // completing the vrDisplay.rAF processing.
   if (is_presenting_ && !capabilities_->hasExternalDisplay()) {
     Platform::Current()->CurrentThread()->GetWebTaskRunner()->PostTask(
         BLINK_FROM_HERE, WTF::Bind(&VRDisplay::ProcessScheduledWindowAnimations,
                                    WrapWeakPersistent(this), timestamp));
   }
 }
 
 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:
       break;
     case device::mojom::blink::VRVSyncProvider::Status::CLOSING:
       return;
   }
   pending_vsync_ = false;
 
   WTF::TimeDelta time_delta =
@@ skipping 19 matching lines @@
       WTF::Bind(&VRDisplay::ProcessScheduledAnimations,
                 WrapWeakPersistent(this), timebase_ + time_delta.InSecondsF()));
 }
 
 void VRDisplay::ConnectVSyncProvider() {
   if (!navigator_vr_->IsFocused() || vr_v_sync_provider_.is_bound())
     return;
   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))));
   }
 }
 
 void VRDisplay::OnVSyncConnectionError() {
   vr_v_sync_provider_.reset();
   if (v_sync_connection_failed_)
     return;
@@ skipping 28 matching lines @@
 }
 
 bool VRDisplay::HasPendingActivity() const {
   // Prevent V8 from garbage collecting the wrapper object if there are
   // event listeners attached to it.
   return GetExecutionContext() && HasEventListeners();
 }
 
 void VRDisplay::FocusChanged() {
   // TODO(mthiesse): Blur/focus the display.
+  DVLOG(1) << __FUNCTION__;
   vr_v_sync_provider_.reset();
   ConnectVSyncProvider();
 }
 
 DEFINE_TRACE(VRDisplay) {
   EventTargetWithInlineData::Trace(visitor);
   ContextLifecycleObserver::Trace(visitor);
   visitor->Trace(navigator_vr_);
   visitor->Trace(capabilities_);
   visitor->Trace(stage_parameters_);
   visitor->Trace(eye_parameters_left_);
   visitor->Trace(eye_parameters_right_);
   visitor->Trace(layer_);
   visitor->Trace(rendering_context_);
   visitor->Trace(scripted_animation_controller_);
   visitor->Trace(pending_present_resolvers_);
 }
 
 }  // namespace blink