VrShellGl: add ProcessWebVrFrame, refactor VSync logic

The WebVR frame lifecycle transition from "animating" to "processing" was
confusing due to use of deferred SubmitFrame. Add a new ProcessWebVrCall at
the end of SubmitFrame that can be deferred if needed. A frame counts as
"animating" until that executes.

Refactor VSync logic. WebVrCanAnimateFrame checks if all necessary resources
are available. All the places that provide resources call
WebVrTryStartAnimatingFrame which runs SendVSyncNow if CanAnimateFrame returns
true.

Resources include pending_vsync_ and get_vsync_callback_ along with the
ShouldSkipVSync heuristics and the ui_->CanSendWebVrVSync() check. It should be
generally equivalent, but with reduced wait time if not VSync aligned since it
now reschedules after webvr_deferred_start_processing_ becomes false instead of
waiting for the next OnVSync.

Change-Id: I32f920d3147b0032037b03f72b18df6cf7195751
Reviewed-on: https://chromium-review.googlesource.com/985652
Commit-Queue: Klaus Weidner <klausw@chromium.org>
Reviewed-by: Michael Thiessen <mthiesse@chromium.org>
Reviewed-by: Bill Orr <billorr@chromium.org>
Cr-Commit-Position: refs/heads/master@{#547821}

chrome/browser/android/vr/vr_shell_gl.cc

@@ -336,18 +336,18 @@ void VrShellGl::InitializeGl(gfx::AcceleratedWidget window) {
     OnVSync(base::TimeTicks::Now());
 }
 
-bool VrShellGl::WebVrCanSubmitFrame() {
+bool VrShellGl::WebVrCanProcessFrame() {
   return mailbox_bridge_ready_ && !webvr_frame_processing_;
 }
 
-void VrShellGl::WebVrTryDeferredSubmit() {
-  if (!webvr_deferred_mojo_submit_ || !WebVrCanSubmitFrame())
+void VrShellGl::WebVrTryDeferredProcessing() {
+  if (!webvr_deferred_start_processing_ || !WebVrCanProcessFrame())
     return;
 
   DVLOG(2) << "Running deferred SubmitFrame";
   // Run synchronously, not via PostTask, to ensure we don't
   // get a new SendVSync scheduling in between.
-  base::ResetAndReturn(&webvr_deferred_mojo_submit_).Run();
+  base::ResetAndReturn(&webvr_deferred_start_processing_).Run();
 }
 
 void VrShellGl::OnGpuProcessConnectionReady() {
@@ -355,7 +355,7 @@ void VrShellGl::OnGpuProcessConnectionReady() {
   mailbox_bridge_ready_ = true;
   // We might have a deferred submit that was waiting for
   // mailbox_bridge_ready_.
-  WebVrTryDeferredSubmit();
+  WebVrTryDeferredProcessing();
 }
 
 void VrShellGl::CreateOrResizeWebVRSurface(const gfx::Size& size) {
@@ -402,26 +402,13 @@ void VrShellGl::SubmitFrame(int16_t frame_index,
   if (!submit_client_.get())
     return;
 
-  if (!WebVrCanSubmitFrame()) {
-    DVLOG(2) << "Deferring SubmitFrame, not ready";
-    DCHECK(!webvr_deferred_mojo_submit_);
-    webvr_deferred_mojo_submit_ =
-        base::BindOnce(&VrShellGl::SubmitFrame, weak_ptr_factory_.GetWeakPtr(),
-                       frame_index, mailbox, time_waited);
-    return;
-  }
-
   if (frame_index < 0 ||
       !webvr_frame_oustanding_[frame_index % kPoseRingBufferSize]) {
     mojo::ReportBadMessage("SubmitFrame called with an invalid frame_index");
     binding_.Close();
     return;
   }
-  webvr_frame_processing_ = true;
-  OnNewWebVRFrame();
 
-  webvr_time_js_submit_[frame_index % kPoseRingBufferSize] =
-      base::TimeTicks::Now();
 
   // The JavaScript wait time is supplied externally and not trustworthy. Clamp
   // to a reasonable range to avoid math errors.
@@ -433,6 +420,27 @@ void VrShellGl::SubmitFrame(int16_t frame_index,
   TRACE_COUNTER1("gpu", "WebVR JS wait (ms)",
                  webvr_js_wait_time_.GetAverage().InMilliseconds());
 
+  webvr_time_js_submit_[frame_index % kPoseRingBufferSize] =
+      base::TimeTicks::Now();
+
+  if (WebVrCanProcessFrame()) {
+    ProcessWebVrFrame(frame_index, mailbox);
+  } else {
+    DVLOG(2) << "Deferring processing frame, not ready";
+    DCHECK(!webvr_deferred_start_processing_);
+    webvr_deferred_start_processing_ =
+        base::BindOnce(&VrShellGl::ProcessWebVrFrame,
+                       weak_ptr_factory_.GetWeakPtr(), frame_index, mailbox);
+  }
+}
+
+void VrShellGl::ProcessWebVrFrame(int16_t frame_index,
+                                  const gpu::MailboxHolder& mailbox) {
+  TRACE_EVENT0("gpu", __FUNCTION__);
+  // Transition frame from "animating" to "processing" state.
+  webvr_frame_processing_ = true;
+  OnNewWebVRFrame();
+
   // Swapping twice on a Surface without calling updateTexImage in
   // between can lose frames, so don't draw+swap if we already have
   // a pending frame we haven't consumed yet.
@@ -454,6 +462,10 @@ void VrShellGl::SubmitFrame(int16_t frame_index,
     // OnWebVRFrameAvailable where we'd normally report that.
     submit_client_->OnSubmitFrameRendered();
   }
+
+  // Unblock the next animating frame in case it was waiting for this
+  // one to start processing.
+  WebVrTryStartAnimatingFrame(false);
 }
 
 void VrShellGl::SubmitFrameWithTextureHandle(
@@ -1357,9 +1369,6 @@ void VrShellGl::DrawFrameSubmitNow(int16_t frame_index,
     // but the logic is a bit complicated.
     if (frame_index >= 0) {
       webvr_frame_processing_ = false;
-      // If we have a waiting submit that arrived while processing this one,
-      // handle it now.
-      WebVrTryDeferredSubmit();
     }
   }
 
@@ -1368,6 +1377,13 @@ void VrShellGl::DrawFrameSubmitNow(int16_t frame_index,
   vr_ui_fps_meter_.AddFrame(base::TimeTicks::Now());
   DVLOG(1) << "fps: " << vr_ui_fps_meter_.GetFPS();
   TRACE_COUNTER1("gpu", "VR UI FPS", vr_ui_fps_meter_.GetFPS());
+
+  if (ShouldDrawWebVr()) {
+    // We finished processing a frame, this may make pending WebVR
+    // work eligible to proceed.
+    WebVrTryDeferredProcessing();
+    WebVrTryStartAnimatingFrame(false);
+  }
 }
 
 bool VrShellGl::ShouldDrawWebVr() {
@@ -1434,8 +1450,10 @@ void VrShellGl::SetWebVrMode(bool enabled) {
     ClosePresentationBindings();
     // Ensure that re-entering VR later gets a fresh start by clearing out the
     // current session's animating and processing frame state.
-    webvr_deferred_mojo_submit_.Reset();
+    webvr_frame_oustanding_.assign(kPoseRingBufferSize, false);
+    webvr_deferred_start_processing_.Reset();
     webvr_frame_processing_ = false;
+    last_ui_allows_sending_webvr_vsync_ = false;
   }
 }
 
@@ -1457,6 +1475,78 @@ base::WeakPtr<BrowserUiInterface> VrShellGl::GetBrowserUiWeakPtr() {
   return ui_->GetBrowserUiWeakPtr();
 }
 
+bool VrShellGl::WebVrCanAnimateFrame(bool is_from_onvsync) {
+  // This check needs to be first to ensure that we start the WebVR
+  // first-frame timeout on presentation start.
+  bool can_send_webvr_vsync = ui_->CanSendWebVrVSync();
+  if (!last_ui_allows_sending_webvr_vsync_ && can_send_webvr_vsync) {
+    // We will start sending vsync to the WebVR page, so schedule the incoming
+    // frame timeout.
+    ScheduleOrCancelWebVrFrameTimeout();
+  }
+  last_ui_allows_sending_webvr_vsync_ = can_send_webvr_vsync;
+  if (!can_send_webvr_vsync) {
+    DVLOG(2) << __FUNCTION__ << ": waiting for can_send_webvr_vsync";
+    return false;
+  }
+
+  // If we want to send vsync-aligned frames, we only allow animation to start
+  // when called from OnVSync, so if we're called from somewhere else we can
+  // skip all the other checks. Legacy Cardboard mode (not surfaceless) doesn't
+  // use vsync aligned frames, and there's a flag to disable it for surfaceless
+  // mode.
+  if (surfaceless_rendering_ && webvr_vsync_align_ && !is_from_onvsync) {
+    DVLOG(3) << __FUNCTION__ << ": waiting for onvsync (vsync aligned)";
+    return false;
+  }
+
+  if (get_vsync_callback_.is_null()) {
+    DVLOG(2) << __FUNCTION__ << ": waiting for get_vsync_callback_";
+    return false;
+  }
+
+  if (!pending_vsync_) {
+    DVLOG(2) << __FUNCTION__ << ": waiting for pending_vsync (too fast)";
+    return false;
+  }
+
+  // If the previous frame deferred starting processing, that frame is still
+  // considered the current animating frame, so we must wait for that to
+  // transition to processing before sending the next VSync. Don't check
+  // WebVrCanProcessFrame() here - we intentionally want to allow the first
+  // VSync to go out before mailbox_bridge_ready_ becomes true. The first
+  // SubmitFrame will be deferred if needed.
+  if (webvr_deferred_start_processing_) {
+    DVLOG(2) << __FUNCTION__
+             << ": waiting for previous frame to start processing";
+    return false;
+  }
+
+  // Keep the heuristic tests last since they update a trace counter, they
+  // should only be run if the remaining criteria are already met. There's no
+  // corresponding WebVrTryStartAnimating call for this, the retries happen
+  // via OnVSync.
+  bool still_rendering = WebVrHasSlowRenderingFrame();
+  bool overstuffed = WebVrHasOverstuffedBuffers();
+  TRACE_COUNTER2("gpu", "WebVR frame skip", "still rendering", still_rendering,
+                 "overstuffed", overstuffed);
+  if (still_rendering || overstuffed) {
+    DVLOG(2) << __FUNCTION__ << ": waiting for backlogged frames,"
+             << " still_rendering=" << still_rendering
+             << " overstuffed=" << overstuffed;
+    return false;
+  }
+
+  DVLOG(2) << __FUNCTION__ << ": ready to animate frame";
+  return true;
+}
+
+void VrShellGl::WebVrTryStartAnimatingFrame(bool is_from_onvsync) {
+  if (WebVrCanAnimateFrame(is_from_onvsync)) {
+    SendVSync();
+  }
+}
+
 void VrShellGl::OnVSync(base::TimeTicks frame_time) {
   TRACE_EVENT0("gpu", "VrShellGl::OnVSync");
   // Create a synthetic VSync trace event for the reported last-VSync time. Use
@@ -1476,25 +1566,10 @@ void VrShellGl::OnVSync(base::TimeTicks frame_time) {
   vsync_helper_.RequestVSync(
       base::BindRepeating(&VrShellGl::OnVSync, base::Unretained(this)));
 
-  bool can_send_webvr_vsync = ui_->CanSendWebVrVSync();
-  if (!last_should_send_webvr_vsync_ && can_send_webvr_vsync) {
-    // We will start sending vsync to the WebVR page, so schedule the first
-    // frame timeout.
-    ScheduleOrCancelWebVrFrameTimeout();
-  }
-  last_should_send_webvr_vsync_ = can_send_webvr_vsync;
+  pending_vsync_ = true;
+  pending_time_ = frame_time;
+  WebVrTryStartAnimatingFrame(true);
 
-  // Process WebVR presenting VSync (VRDisplay rAF).
-  if (!callback_.is_null() && can_send_webvr_vsync) {
-    // A callback was stored by GetVSync. Use it now for sending a VSync.
-    SendVSync(frame_time, base::ResetAndReturn(&callback_));
-  } else {
-    // We don't have a callback yet. Mark that there's a pending VSync
-    // to indicate that the next GetVSync is allowed to call SendVSync
-    // immediately.
-    pending_vsync_ = true;
-    pending_time_ = frame_time;
-  }
   if (ShouldDrawWebVr()) {
     // When drawing WebVR, controller input doesn't need to be synchronized with
     // rendering as WebVR uses the gamepad api. To ensure we always handle input
@@ -1509,22 +1584,15 @@ void VrShellGl::OnVSync(base::TimeTicks frame_time) {
 }
 
 void VrShellGl::GetVSync(GetVSyncCallback callback) {
-  // In surfaceless (reprojecting) rendering, stay locked
-  // to vsync intervals. Otherwise, for legacy Cardboard mode,
-  // run requested animation frames now if it missed a vsync.
-  if ((surfaceless_rendering_ && webvr_vsync_align_) || !pending_vsync_ ||
-      !ui_->CanSendWebVrVSync()) {
-    if (!callback_.is_null()) {
-      mojo::ReportBadMessage(
-          "Requested VSync before waiting for response to previous request.");
-      ClosePresentationBindings();
-      return;
-    }
-    callback_ = std::move(callback);
+  TRACE_EVENT0("gpu", __FUNCTION__);
+  if (!get_vsync_callback_.is_null()) {
+    mojo::ReportBadMessage(
+        "Requested VSync before waiting for response to previous request.");
+    ClosePresentationBindings();
     return;
   }
-  pending_vsync_ = false;
-  SendVSync(pending_time_, std::move(callback));
+  get_vsync_callback_ = std::move(callback);
+  WebVrTryStartAnimatingFrame(false);
 }
 
 void VrShellGl::ForceExitVr() {
@@ -1597,15 +1665,7 @@ base::TimeDelta VrShellGl::GetPredictedFrameTime() {
   return expected_frame_time;
 }
 
-bool VrShellGl::ShouldSkipVSync() {
-  // If we appear to be backlogged, don't send additional VSyncs. Don't check
-  // WebVrCanSubmit() here - we intentionally want to allow the first VSync to
-  // go out before mailbox_bridge_ready_ becomes true. The first SubmitFrame
-  // will be deferred if needed, and we'll throttle here to avoid requesting
-  // more frames until that's done.
-  if (webvr_deferred_mojo_submit_)
-    return true;
-
+bool VrShellGl::WebVrHasSlowRenderingFrame() {
   // Disable heuristic for traditional render path where we submit completed
   // frames.
   if (!webvr_use_gpu_fence_)
@@ -1621,7 +1681,6 @@ bool VrShellGl::ShouldSkipVSync() {
   // Also, AddWebVrRenderTimeEstimate zeroes the submit time once the rendered
   // frame is complete. In all of those cases, we don't need to wait for render
   // completion.
-  bool still_rendering = false;
   int16_t prev_idx =
       (next_frame_index_ + kPoseRingBufferSize - 2) % kPoseRingBufferSize;
   base::TimeTicks prev_js_submit = webvr_time_js_submit_[prev_idx];
@@ -1641,34 +1700,38 @@ bool VrShellGl::ShouldSkipVSync() {
     // this VSync if we'd arrive a full VSync interval early.
     if (mean_js_time - mean_js_wait + frame_interval <
         prev_render_time_left + frame_interval * 3 / 4) {
-      still_rendering = true;
+      return true;
     }
   }
+  return false;
+}
+
+bool VrShellGl::WebVrHasOverstuffedBuffers() {
+  base::TimeDelta frame_interval = vsync_helper_.DisplayVSyncInterval();
+  base::TimeDelta mean_render_time =
+      webvr_render_time_.GetAverageOrDefault(frame_interval);
 
-  bool overstuffed = false;
   if (webvr_unstuff_ratelimit_frames_ > 0) {
     --webvr_unstuff_ratelimit_frames_;
   } else if (webvr_acquire_time_.GetAverage() >= kWebVrSlowAcquireThreshold &&
              mean_render_time < frame_interval) {
-    overstuffed = true;
+    // This is a fast app with average render time less than the frame
+    // interval. If GVR acquire is slow, that means its internal swap chain was
+    // already full when we tried to give it the next frame. We can skip a
+    // SendVSync to drain one frame from the GVR queue. That should reduce
+    // latency by one frame.
     webvr_unstuff_ratelimit_frames_ = kWebVrUnstuffMaxDropRate;
+    return true;
   }
-  TRACE_COUNTER2("gpu", "WebVR frame skip", "still rendering", still_rendering,
-                 "overstuffed", overstuffed);
-
-  return still_rendering | overstuffed;
+  return false;
 }
 
-void VrShellGl::SendVSync(base::TimeTicks time, GetVSyncCallback callback) {
-  // There must not be a stored callback at this point, callers should use
-  // ResetAndReturn to clear it before calling this method.
-  DCHECK(!callback_);
+void VrShellGl::SendVSync() {
+  DCHECK(!get_vsync_callback_.is_null());
+  DCHECK(pending_vsync_);
 
-  if (ShouldSkipVSync()) {
-    callback_ = std::move(callback);
-    DVLOG(2) << __FUNCTION__ << ": ShouldSkipVSync()=true";
-    return;
-  }
+  // Mark the VSync as consumed.
+  pending_vsync_ = false;
 
   // next_frame_index_ is an uint8_t that generates a wrapping 0.255 frame
   // number. We store it in an int16_t to match mojo APIs, and to avoid it
@@ -1706,19 +1769,19 @@ void VrShellGl::SendVSync(base::TimeTicks time, GetVSyncCallback callback) {
   // frame.
   webvr_time_js_submit_[frame_index % kPoseRingBufferSize] = base::TimeTicks();
 
-  std::move(callback).Run(
-      std::move(pose), time - base::TimeTicks(), frame_index,
-      device::mojom::VRPresentationProvider::VSyncStatus::SUCCESS);
+  base::ResetAndReturn(&get_vsync_callback_)
+      .Run(std::move(pose), pending_time_ - base::TimeTicks(), frame_index,
+           device::mojom::VRPresentationProvider::VSyncStatus::SUCCESS);
 }
 
 void VrShellGl::ClosePresentationBindings() {
   webvr_frame_timeout_.Cancel();
   submit_client_.reset();
-  if (!callback_.is_null()) {
+  if (!get_vsync_callback_.is_null()) {
     // When this Presentation provider is going away we have to respond to
     // pending callbacks, so instead of providing a VSync, tell the requester
     // the connection is closing.
-    base::ResetAndReturn(&callback_)
+    base::ResetAndReturn(&get_vsync_callback_)
         .Run(nullptr, base::TimeDelta(), -1,
              device::mojom::VRPresentationProvider::VSyncStatus::CLOSING);
   }

chrome/browser/android/vr/vr_shell_gl.h

@@ -189,16 +189,32 @@ class VrShellGl : public device::mojom::VRPresentationProvider {
 
   void ForceExitVr();
 
-  bool ShouldSkipVSync();
-  void SendVSync(base::TimeTicks time, GetVSyncCallback callback);
-
-  // Checks if we're in a valid state for submitting a frame. Invalid states
-  // include mailbox_bridge_ready_ being false, or overlapping processing
-  // frames.
-  bool WebVrCanSubmitFrame();
-  // Call this after state changes that could result in WebVrCanSubmitFrame
+  // Sends a GetVSync response to the presentation client.
+  void SendVSync();
+
+  // Heuristics to avoid excessive backlogged frames.
+  bool WebVrHasSlowRenderingFrame();
+  bool WebVrHasOverstuffedBuffers();
+
+  // Checks if we're in a valid state for starting animation of a new frame.
+  // Invalid states include a previous animating frame that's not complete
+  // yet (including deferred processing not having started yet), or timing
+  // heuristics indicating that it should be retried later.
+  bool WebVrCanAnimateFrame(bool is_from_onvsync);
+  // Call this after state changes that could result in WebVrCanAnimateFrame
   // becoming true.
-  void WebVrTryDeferredSubmit();
+  void WebVrTryStartAnimatingFrame(bool is_from_onvsync);
+
+  // Checks if we're in a valid state for processing the current animating
+  // frame. Invalid states include mailbox_bridge_ready_ being false, or an
+  // already existing processing frame that's not done yet.
+  bool WebVrCanProcessFrame();
+  // Call this after state changes that could result in WebVrCanProcessFrame
+  // becoming true.
+  void WebVrTryDeferredProcessing();
+  // Transition a frame from animating to processing.
+  void ProcessWebVrFrame(int16_t frame_index,
+                         const gpu::MailboxHolder& mailbox);
 
   void ClosePresentationBindings();
 
@@ -280,16 +296,16 @@ class VrShellGl : public device::mojom::VRPresentationProvider {
   scoped_refptr<base::SingleThreadTaskRunner> task_runner_;
 
   // Attributes tracking WebVR rAF/VSync animation loop state. Blink schedules
-  // a callback using the GetVSync mojo call, and the callback is either passed
-  // to SendVSync immediately, or deferred until the next OnVSync call.
+  // a callback using the GetVSync mojo call which is stored in
+  // get_vsync_callback_. The callback is executed by SendVSync once
+  // WebVrCanAnimateFrame returns true.
   //
-  // pending_vsync_ is set to true in OnVSync if there is no current
-  // outstanding callback, and this means that a future GetVSync is permitted
-  // to execute SendVSync immediately. If it is false, GetVSync must store the
-  // pending callback in callback_ for later execution.
+  // pending_vsync_ is set to true in OnVSync and false in SendVSync. It
+  // throttles animation to no faster than the VSync rate. The pending_time_ is
+  // updated in OnVSync and used as the rAF animation timer in SendVSync.
   base::TimeTicks pending_time_;
   bool pending_vsync_ = false;
-  GetVSyncCallback callback_;
+  GetVSyncCallback get_vsync_callback_;
 
   mojo::Binding<device::mojom::VRPresentationProvider> binding_;
   device::mojom::VRSubmitFrameClientPtr submit_client_;
@@ -349,9 +365,9 @@ class VrShellGl : public device::mojom::VRPresentationProvider {
   // for that timespan.
   bool webvr_frame_processing_ = false;
 
-  // If we receive a new SubmitFrame when we're not ready, save it for
-  // later execution.
-  base::OnceClosure webvr_deferred_mojo_submit_;
+  // If we receive a new SubmitFrame when we're not ready, defer start of
+  // processing for later.
+  base::OnceClosure webvr_deferred_start_processing_;
 
   std::vector<gvr::BufferSpec> specs_;
 
@@ -363,7 +379,10 @@ class VrShellGl : public device::mojom::VRPresentationProvider {
   std::unique_ptr<VrDialog> vr_dialog_;
   bool showing_vr_dialog_ = false;
 
-  bool last_should_send_webvr_vsync_ = false;
+  // Used by WebVrCanAnimateFrame() to detect when ui_->CanSendWebVrVSync()
+  // transitions from false to true, as part of starting the incoming frame
+  // timeout.
+  bool last_ui_allows_sending_webvr_vsync_ = false;
 
   base::WeakPtrFactory<VrShellGl> weak_ptr_factory_;