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..028539ba1642e9b65298e5749a26b841bc4450e4 100644
--- a/third_party/WebKit/Source/modules/vr/VRDisplay.cpp
+++ b/third_party/WebKit/Source/modules/vr/VRDisplay.cpp
@@ -9,6 +9,7 @@
 #include "core/dom/FrameRequestCallback.h"
 #include "core/dom/ScriptedAnimationController.h"
 #include "core/dom/TaskRunnerHelper.h"
+#include "core/frame/Frame.h"
 #include "core/frame/FrameView.h"
 #include "core/frame/ImageBitmap.h"
 #include "core/frame/UseCounter.h"
@@ -16,6 +17,7 @@
 #include "core/layout/LayoutView.h"
 #include "core/layout/compositing/PaintLayerCompositor.h"
 #include "core/loader/DocumentLoader.h"
+#include "core/page/FocusController.h"
 #include "gpu/command_buffer/client/gles2_interface.h"
 #include "gpu/command_buffer/common/mailbox_holder.h"
 #include "modules/EventTargetModules.h"
@@ -104,8 +106,36 @@ void VRDisplay::Update(const device::mojom::blink::VRDisplayInfoPtr& display) {
   }
 }
 
+bool VRDisplay::IsPresentationFocused() {
+  if (!navigator_vr_)
+    return false;
+
+  if (navigator_vr_->IsFocused())
+    return true;
+
+  auto doc = navigator_vr_->GetDocument();
+  if (!doc)
+    return false;
+
+  // Check if this is an embedded iframe without focus. If a local parent is
+  // focused, continue presenting.
+
+  Frame* frame = doc->GetFrame();
+  for (; frame; frame = frame->Tree().Parent()) {
+    if (!frame->IsLocalFrame())
+      break;
+    auto frame_doc = ToLocalFrame(frame)->GetDocument();
+    if (frame_doc && frame_doc->hasFocus()) {
+      DVLOG(3) << __FUNCTION__ << ": a parent frame is focused";
+      return true;
+    }
+  }
+
+  return false;
+}
+
 bool VRDisplay::getFrameData(VRFrameData* frame_data) {
-  if (!navigator_vr_->IsFocused() || !frame_pose_ || display_blurred_)
+  if (!IsPresentationFocused() || !frame_pose_ || display_blurred_)
     return false;
 
   if (!frame_data)
@@ -130,10 +160,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 +177,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 +192,7 @@ void VRDisplay::OnBlur() {
 }
 
 void VRDisplay::OnFocus() {
+  DVLOG(1) << __FUNCTION__;
   display_blurred_ = false;
   ConnectVSyncProvider();
   navigator_vr_->EnqueueVREvent(VRDisplayEvent::Create(
@@ -178,6 +212,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 +355,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 +433,41 @@ void VRDisplay::BeginPresent() {
     resolver->Resolve();
   }
   OnPresentChange();
+
+  // TODO(klausw,crbug.com/710863): there appear to be cases where an embedded
+  // 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
+  // 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_) {
+    if (doc) {
+      doc->AddConsoleMessage(
+          ConsoleMessage::Create(kRenderingMessageSource, kWarningMessageLevel,
+                                 "Scheduling missing vsync."));

[bajones, 2017/04/27 22:02:46]

Is this something that we feel pages should be architected to avoid? If so I
think the message should be a bit more instructive about how to avoid hitting
this condition, if not then I don't feel it's appropriate to log a warning to
the console for expected behavior and a DVLOG is probably more appropriate.

[klausw, 2017/04/28 18:43:14]

Changed to DVLOG, this was only there for investigating the issue. Sorry about
that.

+    }
+    if (vr_v_sync_provider_.is_bound()) {
+      pending_vsync_ = true;
+      vr_v_sync_provider_->GetVSync(ConvertToBaseCallback(
+          WTF::Bind(&VRDisplay::OnVSync, WrapWeakPersistent(this))));
+    } else {
+      if (doc) {
+        doc->AddConsoleMessage(ConsoleMessage::Create(
+            kRenderingMessageSource, kWarningMessageLevel,
+            "Failed to schedule missing vsync. Not focused?"));
+      }
+    }
+  }
 }
 
 // Need to close service if exists and then free rendering context.
@@ -613,6 +684,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 +753,46 @@ 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_) {
+    LOG(INFO) << __FUNCTION__ << ": rAF fallback saved us! FIXME FIXME";
+  }
+
+  if (!pending_vrdisplay_raf_) {
+    // There wasn't any call to vrDisplay.rAF, so we won't be getting new
+    // frames from now on. TODO(klausw,crbug.com/716087): do something more
+    // useful here.
+    doc->AddConsoleMessage(ConsoleMessage::Create(
+        kRenderingMessageSource, kWarningMessageLevel,
+        "VRDisplay.requestAnimationFrame not called, presentation is broken."));

[bajones, 2017/04/27 22:02:46]

This seems drastic. o_O If the developer calls VRDisplay.requestAnimationFrame
again at some other point outside the rAF they will continue getting new frames,
right? If so, I would expect the warning should read more like "No VR frame
callback scheduled. Presentation will not resume until
VRDisplay.requestAnimationFrame is called."

[klausw, 2017/04/28 18:43:14]

I've changed it to a DVLOG. We should continue discussions here in the bug, IMHO
it shouldn't be legal to stop frame production while waiting for a timeout or
external event. (That's the only way it can resume presenting, right?)

[klausw, 2017/04/28 18:45:08]

To clarify, "the bug" in this context meant crbug.com/716087 as marked in the
TODO comment for identifying unrecoverable presentation issues, it's not one of
those addressed by these patches.

+  }
 }
 
 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 +808,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:
@@ -747,12 +843,16 @@ void VRDisplay::OnVSync(device::mojom::blink::VRPosePtr pose,
 }
 
 void VRDisplay::ConnectVSyncProvider() {
-  if (!navigator_vr_->IsFocused() || vr_v_sync_provider_.is_bound())
+  DVLOG(1) << __FUNCTION__
+           << ": IsPresentationFocused()=" << IsPresentationFocused()
+           << " vr_v_sync_provider_.is_bound()="
+           << vr_v_sync_provider_.is_bound();
+  if (!IsPresentationFocused() || 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))));
@@ -801,6 +901,7 @@ bool VRDisplay::HasPendingActivity() const {
 
 void VRDisplay::FocusChanged() {
   // TODO(mthiesse): Blur/focus the display.
+  DVLOG(1) << __FUNCTION__;
   vr_v_sync_provider_.reset();
   ConnectVSyncProvider();
 }