cc: Heuristic for Renderer latency recovery

cc/scheduler/scheduler.cc

 // Copyright 2011 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 "cc/scheduler/scheduler.h"
 
 #include <algorithm>
 
 #include "base/auto_reset.h"
 #include "base/logging.h"
@@ skipping 111 matching lines @@
 
 base::TimeTicks Scheduler::Now() const {
   base::TimeTicks now = gfx::FrameTime::Now();
   TRACE_EVENT1(TRACE_DISABLED_BY_DEFAULT("cc.debug.scheduler.now"),
                "Scheduler::Now",
                "now",
                now);
   return now;
 }
 
+void Scheduler::SetAuthoritativeVSyncInterval(const base::TimeDelta& interval) {
+  authoritative_vsync_interval_ = interval;
+  if (vsync_observer_)
+    vsync_observer_->OnUpdateVSyncParameters(last_vsync_timebase_, interval);
+}
+
 void Scheduler::CommitVSyncParameters(base::TimeTicks timebase,
                                       base::TimeDelta interval) {
+  TRACE_EVENT2("cc", "Scheduler::CommitVSyncParameters", "timebase",
+               (timebase - base::TimeTicks()).InSecondsF(), "interval",
+               interval.InSecondsF());
+
   if (authoritative_vsync_interval_ != base::TimeDelta()) {
     interval = authoritative_vsync_interval_;
   } else if (interval == base::TimeDelta()) {
     // TODO(brianderson): We should not be receiving 0 intervals.
     interval = BeginFrameArgs::DefaultInterval();
   }
 
   last_vsync_timebase_ = timebase;
 
   if (vsync_observer_)
@@ skipping 236 matching lines @@
     BeginImplFrameWithDeadline(adjusted_args);
   }
   return true;
 }
 
 void Scheduler::SetChildrenNeedBeginFrames(bool children_need_begin_frames) {
   state_machine_.SetChildrenNeedBeginFrames(children_need_begin_frames);
   ProcessScheduledActions();
 }
 
-void Scheduler::SetAuthoritativeVSyncInterval(const base::TimeDelta& interval) {
-  authoritative_vsync_interval_ = interval;
-  if (vsync_observer_)
-    vsync_observer_->OnUpdateVSyncParameters(last_vsync_timebase_, interval);
-}
-
 void Scheduler::SetVideoNeedsBeginFrames(bool video_needs_begin_frames) {
   state_machine_.SetVideoNeedsBeginFrames(video_needs_begin_frames);
   ProcessScheduledActions();
 }
 
 void Scheduler::OnDrawForOutputSurface() {
   DCHECK(settings_.using_synchronous_renderer_compositor);
   DCHECK_EQ(state_machine_.begin_impl_frame_state(),
             SchedulerStateMachine::BEGIN_IMPL_FRAME_STATE_IDLE);
   DCHECK(!BeginImplFrameDeadlinePending());
@@ skipping 85 matching lines @@
                args.AsValue(), "main_thread_is_high_latency",
                main_thread_is_in_high_latency_mode);
   TRACE_COUNTER1(TRACE_DISABLED_BY_DEFAULT("cc.debug.scheduler"),
                  "MainThreadLatency", main_thread_is_in_high_latency_mode);
 
   advance_commit_state_task_.Cancel();
 
   begin_impl_frame_args_ = args;
   begin_impl_frame_args_.deadline -= client_->DrawDurationEstimate();
 
-  if (!state_machine_.impl_latency_takes_priority() &&
-      main_thread_is_in_high_latency_mode &&
-      CanCommitAndActivateBeforeDeadline()) {
+  BeginImplFrame();
+  // Decide if we want skip any actions before we ProcessScheduledActions
+  // so that they take effect immediately rather than with a 1 frame delay.
+  // Prioritize skipping the main thread's latency first so we can keep the
+  // main and impl threads synchronized. Then skip an impl frame if it makes
+  // sense. This avoids skipping both at the same time to avoid strange
+  // interactions/oscillations since ShouldRecoverImplLatency() depends on
+  // whether the main thread is in a high latency mode or not.
+  if (ShouldRecoverMainLatency()) {
+    TRACE_EVENT_INSTANT1("cc", "SkipBeginMainFrameToReduceLatency",
+                         TRACE_EVENT_SCOPE_THREAD, "state", AsValue());
     state_machine_.SetSkipNextBeginMainFrameToReduceLatency();
+  } else if (ShouldRecoverImplLatency()) {
+    TRACE_EVENT_INSTANT1("cc", "SkipNextSwapToReduceLatency",
+                         TRACE_EVENT_SCOPE_THREAD, "state", AsValue());
+    state_machine_.SetSkipNextSwapToReduceLatency();

[sunnyps, 2015/05/21 23:42:23]

Can we call FinishImplFrame here instead of going through the BeginImplFrame
cycle? That will allows us to get rid of the state tracking code in the state
machine.

[brianderson, 2015/05/22 01:12:53]

That's a good idea. I'll give it a try!

   }
-
-  BeginImplFrame();
+  ProcessScheduledActions();

[sunnyps, 2015/05/21 23:42:23]

Any particular reason for splitting ProcessScheduledActions out of
BeginImplFrame?

[brianderson, 2015/05/22 01:12:53]

SchedulerStateMachine::OnBeginImplFrame resets the skip_next_... variables. Let
me see if there's another way of doing this - it may not be needed if calling
FinishImplFrame works.

 
   // The deadline will be scheduled in ProcessScheduledActions.
   state_machine_.OnBeginImplFrameDeadlinePending();
   ProcessScheduledActions();
 }
 
 void Scheduler::BeginImplFrameSynchronous(const BeginFrameArgs& args) {
   TRACE_EVENT1("cc,benchmark", "Scheduler::BeginImplFrame", "args",
                args.AsValue());
   begin_impl_frame_args_ = args;
   BeginImplFrame();
+  ProcessScheduledActions();
+
   FinishImplFrame();
 }
 
 void Scheduler::FinishImplFrame() {
   state_machine_.OnBeginImplFrameIdle();
   ProcessScheduledActions();
 
   client_->DidFinishImplFrame();
   frame_source_->DidFinishFrame(begin_retro_frame_args_.size());
 }
 
 // BeginImplFrame starts a compositor frame that will wait up until a deadline
 // for a BeginMainFrame+activation to complete before it times out and draws
 // any asynchronous animation and scroll/pinch updates.
 void Scheduler::BeginImplFrame() {
   DCHECK_EQ(state_machine_.begin_impl_frame_state(),
             SchedulerStateMachine::BEGIN_IMPL_FRAME_STATE_IDLE);
   DCHECK(!BeginImplFrameDeadlinePending());
   DCHECK(state_machine_.HasInitializedOutputSurface());
   DCHECK(advance_commit_state_task_.IsCancelled());
 
   state_machine_.OnBeginImplFrame();
   devtools_instrumentation::DidBeginFrame(layer_tree_host_id_);
   client_->WillBeginImplFrame(begin_impl_frame_args_);
-
-  ProcessScheduledActions();
 }
 
 void Scheduler::ScheduleBeginImplFrameDeadline() {
   // The synchronous compositor does not post a deadline task.
   DCHECK(!settings_.using_synchronous_renderer_compositor);
 
   begin_impl_frame_deadline_task_.Cancel();
   begin_impl_frame_deadline_task_.Reset(begin_impl_frame_deadline_closure_);
 
   begin_impl_frame_deadline_mode_ =
       state_machine_.CurrentBeginImplFrameDeadlineMode();
-
   base::TimeTicks deadline;
   switch (begin_impl_frame_deadline_mode_) {
     case SchedulerStateMachine::BEGIN_IMPL_FRAME_DEADLINE_MODE_NONE:
       // No deadline.
       return;
     case SchedulerStateMachine::BEGIN_IMPL_FRAME_DEADLINE_MODE_IMMEDIATE:
       // We are ready to draw a new active tree immediately.
       // We don't use Now() here because it's somewhat expensive to call.
       deadline = base::TimeTicks();
       break;
@@ skipping 197 matching lines @@
   state->SetInteger("begin_retro_frame_args_", begin_retro_frame_args_.size());
   state->SetBoolean("begin_retro_frame_task_",
                     !begin_retro_frame_task_.IsCancelled());
   state->SetBoolean("begin_impl_frame_deadline_task_",
                     !begin_impl_frame_deadline_task_.IsCancelled());
   state->SetBoolean("advance_commit_state_task_",
                     !advance_commit_state_task_.IsCancelled());
   state->BeginDictionary("begin_impl_frame_args");
   begin_impl_frame_args_.AsValueInto(state);
   state->EndDictionary();
+  state->SetString("begin_impl_frame_deadline_mode_",
+                   SchedulerStateMachine::BeginImplFrameDeadlineModeToString(
+                       begin_impl_frame_deadline_mode_));
 
   base::TimeTicks now = Now();
   base::TimeTicks frame_time = begin_impl_frame_args_.frame_time;
   base::TimeTicks deadline = begin_impl_frame_args_.deadline;
   base::TimeDelta interval = begin_impl_frame_args_.interval;
   state->BeginDictionary("major_timestamps_in_ms");
   state->SetDouble("0_interval", interval.InMillisecondsF());
   state->SetDouble("1_now_to_deadline", (deadline - now).InMillisecondsF());
   state->SetDouble("2_frame_time_to_now", (now - frame_time).InMillisecondsF());
   state->SetDouble("3_frame_time_to_deadline",
@@ skipping 12 matching lines @@
                    client_->DrawDurationEstimate().InMillisecondsF());
   state->SetDouble(
       "begin_main_frame_to_commit_duration_estimate_ms",
       client_->BeginMainFrameToCommitDurationEstimate().InMillisecondsF());
   state->SetDouble(
       "commit_to_activate_duration_estimate_ms",
       client_->CommitToActivateDurationEstimate().InMillisecondsF());
   state->EndDictionary();
 }
 
+bool Scheduler::ShouldRecoverMainLatency() const {
+  TRACE_EVENT0("cc", "ShouldRecoverMainLatency");
+  if (!state_machine_.MainThreadIsInHighLatencyMode())
+    return false;
+
+  if (state_machine_.impl_latency_takes_priority())
+    return false;
+
+  return CanCommitAndActivateBeforeDeadline();
+}
+
+bool Scheduler::ShouldRecoverImplLatency() const {
+  TRACE_EVENT1("cc", "ShouldRecoverImplLatency",
+               "swaps_are_likely_high_latency",
+               state_machine_.swaps_are_likely_high_latency());
+  if (!state_machine_.swaps_are_likely_high_latency())

[sunnyps, 2015/05/21 23:42:22]

When is swaps_are_likely_high_latency != pending_swaps >= max_pending_swaps? 

[brianderson, 2015/05/22 01:12:53]

When the swap ack for a BeginImplFrame(1) comes back after the deadline of the
next BeginImplFrame(2).

In that case though, we wouldn't have done anything in the BeginImplFrame(2) and
shouldn't need to skip the next swap in BeginImplFrame(3).

I'll try to simplify the logic.

+    return false;
+
+  bool frame_time_is_before_deadline =

[sunnyps, 2015/05/21 23:42:23]

Maybe we shouldn't adjust the deadline in begin_impl_frame_args_? So that we can
compare DrawDurationEstimate with the real deadline here? It's a little unclear
what's happening here because the deadline already has DrawDurationEstimate
adjusted.

[brianderson, 2015/05/22 01:12:53]

Are you saying the logic would be easier to follow that way? Or is there also
something wrong with this comparison?

I like how the deadline is adjusted by DrawDurationEstimate for tracing purposes
- it's easy to see how much time is left before the deadline.

+      begin_impl_frame_args_.frame_time < begin_impl_frame_args_.deadline;
+
+  auto next_begin_impl_frame_deadline_mode =

[sunnyps, 2015/05/21 23:42:23]

nit: Let's not use auto here.

[brianderson, 2015/05/22 01:12:53]

Done.

+      state_machine_.CurrentBeginImplFrameDeadlineMode();
+  switch (next_begin_impl_frame_deadline_mode) {
+    case SchedulerStateMachine::BEGIN_IMPL_FRAME_DEADLINE_MODE_NONE:
+      return false;
+    case SchedulerStateMachine::BEGIN_IMPL_FRAME_DEADLINE_MODE_IMMEDIATE:
+      return frame_time_is_before_deadline;
+    case SchedulerStateMachine::BEGIN_IMPL_FRAME_DEADLINE_MODE_REGULAR:
+      return frame_time_is_before_deadline;
+    case SchedulerStateMachine::BEGIN_IMPL_FRAME_DEADLINE_MODE_LATE:
+      return CanCommitAndActivateBeforeDeadline();
+    case SchedulerStateMachine::
+        BEGIN_IMPL_FRAME_DEADLINE_MODE_BLOCKED_ON_READY_TO_DRAW:
+      return false;
+  }
+  NOTREACHED();
+  return false;
+}
+
 bool Scheduler::CanCommitAndActivateBeforeDeadline() const {
   // Check if the main thread computation and commit can be finished before the
   // impl thread's deadline.
   base::TimeTicks estimated_draw_time =
       begin_impl_frame_args_.frame_time +
       client_->BeginMainFrameToCommitDurationEstimate() +
       client_->CommitToActivateDurationEstimate();
 
-  TRACE_EVENT2(
-      TRACE_DISABLED_BY_DEFAULT("cc.debug.scheduler"),
-      "CanCommitAndActivateBeforeDeadline",
-      "time_left_after_drawing_ms",
-      (begin_impl_frame_args_.deadline - estimated_draw_time).InMillisecondsF(),
-      "state",
-      AsValue());
-
   return estimated_draw_time < begin_impl_frame_args_.deadline;
 }
 
 bool Scheduler::IsBeginMainFrameSentOrStarted() const {
   return (state_machine_.commit_state() ==
               SchedulerStateMachine::COMMIT_STATE_BEGIN_MAIN_FRAME_SENT ||
           state_machine_.commit_state() ==
               SchedulerStateMachine::COMMIT_STATE_BEGIN_MAIN_FRAME_STARTED);
 }
 
 }  // namespace cc