cc: Heuristic for Renderer latency recovery

cc/scheduler/scheduler_unittest.cc

Index: cc/scheduler/scheduler_unittest.cc
diff --git a/cc/scheduler/scheduler_unittest.cc b/cc/scheduler/scheduler_unittest.cc
index f8a9d3fc68c2e657e4ee3bbd02a18f9cb07df092..e6d9d8a2db6bf8b35ef6cb9702b1b001318a4c2b 100644
--- a/cc/scheduler/scheduler_unittest.cc
+++ b/cc/scheduler/scheduler_unittest.cc
@@ -150,12 +150,17 @@ class FakeSchedulerClient : public SchedulerClient {
     if (log_anticipated_draw_time_change_)
       PushAction("DidAnticipatedDrawTimeChange");
   }
-  base::TimeDelta DrawDurationEstimate() override { return base::TimeDelta(); }
+
+  // Use really long estimations by default so we don't inadvertently
+  // test latency recovery logic unless a test explicitly wants to.

[mithro-old, 2015/05/27 04:40:14]

These tests should be deterministic, so I'm not sure why we would be getting
transitions where we don't expect? Can you explain what is going on here?

Also, wouldn't the most common case for tests to always have very quick
operations and be operating in low latency mode?

Could we instead add a way to check that the tests never go into the high
latency mode unless explicitly requested?

+  base::TimeDelta DrawDurationEstimate() override {
+    return base::TimeDelta::FromHours(1);
+  }
   base::TimeDelta BeginMainFrameToCommitDurationEstimate() override {
-    return base::TimeDelta();
+    return base::TimeDelta::FromHours(1);
   }
   base::TimeDelta CommitToActivateDurationEstimate() override {
-    return base::TimeDelta();
+    return base::TimeDelta::FromHours(1);
   }
 
   void SendBeginFramesToChildren(const BeginFrameArgs& args) override {
@@ -203,9 +208,9 @@ class FakeSchedulerClient : public SchedulerClient {
   TestScheduler* scheduler_;
 };
 
-class SchedulerClientWithFixedEstimates : public FakeSchedulerClient {
+class SchedulerClientWithCustomEstimates : public FakeSchedulerClient {

[mithro-old, 2015/05/27 04:40:14]

Is there any reason we don't just make this part of FakeSchedulerClient?

  public:
-  SchedulerClientWithFixedEstimates(
+  SchedulerClientWithCustomEstimates(
       base::TimeDelta draw_duration,
       base::TimeDelta begin_main_frame_to_commit_duration,
       base::TimeDelta commit_to_activate_duration)
@@ -222,7 +227,7 @@ class SchedulerClientWithFixedEstimates : public FakeSchedulerClient {
     return commit_to_activate_duration_;
   }
 
- private:
+ public:
   base::TimeDelta draw_duration_;
   base::TimeDelta begin_main_frame_to_commit_duration_;
   base::TimeDelta commit_to_activate_duration_;
@@ -420,6 +425,12 @@ class SchedulerTest : public testing::Test {
       int64 commit_to_activate_estimate_in_ms,
       bool impl_latency_takes_priority,
       bool should_send_begin_main_frame);
+  void SwapIsHighLatency(int64 draw_estimate_in_ms,
+                         int64 begin_main_frame_to_commit_estimate_in_ms,
+                         int64 commit_to_activate_estimate_in_ms,
+                         bool has_impl_side_updates,
+                         bool swap_ack_before_deadline,
+                         bool should_draw_and_swap_in_high_latency);
   void BeginFramesNotFromClient(bool use_external_begin_frame_source,
                                 bool throttle_frame_production);
   void BeginFramesNotFromClient_SwapThrottled(
@@ -486,8 +497,8 @@ TEST_F(SchedulerTest, SendBeginFramesToChildrenWithoutCommit) {
 
 TEST_F(SchedulerTest, SendBeginFramesToChildrenDeadlineNotAdjusted) {
   // Set up client with specified estimates.
-  SchedulerClientWithFixedEstimates* client =
-      new SchedulerClientWithFixedEstimates(
+  SchedulerClientWithCustomEstimates* client =
+      new SchedulerClientWithCustomEstimates(

[mithro-old, 2015/05/27 04:40:15]

It might be worth adding a comment which says which value is for which. Really
wish that C++ had keyword arguments like Python.

           base::TimeDelta::FromMilliseconds(1),
           base::TimeDelta::FromMilliseconds(2),
           base::TimeDelta::FromMilliseconds(4));
@@ -1318,8 +1329,8 @@ void SchedulerTest::MainFrameInHighLatencyMode(
     bool impl_latency_takes_priority,
     bool should_send_begin_main_frame) {
   // Set up client with specified estimates (draw duration is set to 1).
-  SchedulerClientWithFixedEstimates* client =
-      new SchedulerClientWithFixedEstimates(
+  SchedulerClientWithCustomEstimates* client =
+      new SchedulerClientWithCustomEstimates(
           base::TimeDelta::FromMilliseconds(1),
           base::TimeDelta::FromMilliseconds(
               begin_main_frame_to_commit_estimate_in_ms),
@@ -1357,29 +1368,255 @@ void SchedulerTest::MainFrameInHighLatencyMode(
 TEST_F(SchedulerTest,
        SkipMainFrameIfHighLatencyAndCanCommitAndActivateBeforeDeadline) {
   // Set up client so that estimates indicate that we can commit and activate
-  // before the deadline (~8ms by default).
+  // before the deadline (~11ms by default).
   EXPECT_SCOPED(MainFrameInHighLatencyMode(1, 1, false, false));
 }
 
 TEST_F(SchedulerTest, NotSkipMainFrameIfHighLatencyAndCanCommitTooLong) {
   // Set up client so that estimates indicate that the commit cannot finish
-  // before the deadline (~8ms by default).
+  // before the deadline (~11ms by default).
   EXPECT_SCOPED(MainFrameInHighLatencyMode(10, 1, false, true));
 }
 
 TEST_F(SchedulerTest, NotSkipMainFrameIfHighLatencyAndCanActivateTooLong) {
   // Set up client so that estimates indicate that the activate cannot finish
-  // before the deadline (~8ms by default).
+  // before the deadline (~11ms by default).
   EXPECT_SCOPED(MainFrameInHighLatencyMode(1, 10, false, true));
 }
 
 TEST_F(SchedulerTest, NotSkipMainFrameInPreferImplLatencyMode) {
   // Set up client so that estimates indicate that we can commit and activate
-  // before the deadline (~8ms by default), but also enable impl latency takes
+  // before the deadline (~11ms by default), but also enable impl latency takes
   // priority mode.
   EXPECT_SCOPED(MainFrameInHighLatencyMode(1, 1, true, true));
 }
 
+void SchedulerTest::SwapIsHighLatency(
+    int64 draw_estimate_in_ms,
+    int64 begin_main_frame_to_commit_estimate_in_ms,
+    int64 commit_to_activate_estimate_in_ms,
+    bool has_impl_side_updates,
+    bool swap_ack_before_deadline,
+    bool should_draw_and_swap_in_high_latency) {
+  // Set up client with specified estimates.
+  SchedulerClientWithCustomEstimates* client =
+      new SchedulerClientWithCustomEstimates(
+          base::TimeDelta::FromMilliseconds(draw_estimate_in_ms),
+          base::TimeDelta::FromMilliseconds(
+              begin_main_frame_to_commit_estimate_in_ms),
+          base::TimeDelta::FromMilliseconds(commit_to_activate_estimate_in_ms));
+
+  scheduler_settings_.use_external_begin_frame_source = true;
+  SetUpScheduler(make_scoped_ptr(client).Pass(), true);
+
+  // To get into a high latency state, this test disables automatic swap acks.
+  scheduler_->SetMaxSwapsPending(1);
+  client_->SetAutomaticSwapAck(false);
+
+  // Draw and swap for first BeginFrame
+  client->Reset();
+  scheduler_->SetNeedsCommit();
+  if (has_impl_side_updates)
+    scheduler_->SetNeedsRedraw();
+  EXPECT_FALSE(scheduler_->MainThreadIsInHighLatencyMode());
+  EXPECT_SCOPED(AdvanceFrame());
+  scheduler_->NotifyBeginMainFrameStarted();
+  scheduler_->NotifyReadyToCommit();
+  EXPECT_FALSE(scheduler_->MainThreadIsInHighLatencyMode());
+  task_runner().RunPendingTasks();  // Run posted deadline.
+  EXPECT_TRUE(client->HasAction("ScheduledActionDrawAndSwapIfPossible"));
+
+  // Not calling scheduler_->DidSwapBuffersComplete() until after next frame
+  // puts impl thread in high latency mode.
+  client->Reset();
+  scheduler_->SetNeedsCommit();
+  if (has_impl_side_updates)
+    scheduler_->SetNeedsRedraw();
+  EXPECT_FALSE(scheduler_->MainThreadIsInHighLatencyMode());
+  if (should_draw_and_swap_in_high_latency) {

[mithro-old, 2015/05/27 04:40:14]

Instead of using if statements here, does it make more sense to split this into
multiple functions?

Being explicit in tests makes them easier to understand and work with.

+    AdvanceFrame();
+  } else {
+    // Don't use AdvanceFrame since we expect the the Scheduler to
+    // skip the BeginImplFrame.

[mithro-old, 2015/05/27 04:40:15]

I feel like there isn't enough checks in this section of the if statement.

+    SendNextBeginFrame();
+    EXPECT_FALSE(client->HasAction("WillBeginImplFrame"));
+    EXPECT_FALSE(scheduler_->BeginImplFrameDeadlinePending());
+  }
+  EXPECT_FALSE(scheduler_->MainThreadIsInHighLatencyMode());
+
+  if (should_draw_and_swap_in_high_latency) {
+    DCHECK(swap_ack_before_deadline);
+    scheduler_->DidSwapBuffersComplete();
+    scheduler_->NotifyBeginMainFrameStarted();
+    scheduler_->NotifyReadyToCommit();
+    task_runner().RunPendingTasks();  // Run posted deadline.

[mithro-old, 2015/05/27 04:40:14]

Please run tasks until a condition is met rather than just randomly running any
pending tasks.

+  } else if (swap_ack_before_deadline) {
+    scheduler_->DidSwapBuffersComplete();
+    task_runner().RunPendingTasks();  // Run posted deadline.
+  } else {
+    task_runner().RunPendingTasks();  // Run posted deadline.
+    scheduler_->DidSwapBuffersComplete();
+  }
+
+  // Verify that we recovered immediately if we were supposed to.
+  EXPECT_EQ(should_draw_and_swap_in_high_latency,
+            client->HasAction("ScheduledActionDrawAndSwapIfPossible"));
+  if (should_draw_and_swap_in_high_latency)
+    scheduler_->DidSwapBuffersComplete();
+
+  // Verify that we:
+  // 1) Don't skip two frames in a row.
+  // 2) Continue normal operation if we didn't skip a frame.
+  // 3) Make forward progress even when we aren't expecting another swap ack.
+  client->Reset();
+  EXPECT_FALSE(scheduler_->MainThreadIsInHighLatencyMode());
+  scheduler_->SetNeedsCommit();
+  if (has_impl_side_updates)
+    scheduler_->SetNeedsRedraw();
+  EXPECT_SCOPED(AdvanceFrame());
+  scheduler_->NotifyBeginMainFrameStarted();
+  scheduler_->NotifyReadyToCommit();
+  task_runner().RunPendingTasks();  // Run posted deadline.
+  EXPECT_TRUE(client->HasAction("ScheduledActionDrawAndSwapIfPossible"));
+}
+
+TEST_F(SchedulerTest,
+       SkipSwapIfHighLatencyAndCanDrawBeforeDeadline_SwapAckThenDeadline) {
+  // Set up client so that estimates indicate that we can commit and activate
+  // before the deadline (~11ms by default).
+  EXPECT_SCOPED(SwapIsHighLatency(1, 1, 1, true, true, false));

[mithro-old, 2015/05/27 04:40:15]

It's really hard to understand how the values (1,1,1,true,true,false) end up
testing SkipSwapIfHighLatencyAndCanDrawBeforeDeadline_SwapAckThenDeadline. 

After re-reading the code the 5th time, I'm still unsure your test is actually
correct. This makes me feel like the splitting up of SwapIsHighLatency into
multiple steps you explicitly call here is a good idea.

The big difference between MainFrameInHighLatencyMode code above (that I assume
you based this section on) and this section is that; the checks / code in
MainFrameInHighLatencyMode are not dependent on the passed in arguments. This
means you are not continually going "okay which side of this if statement are we
taking" and "does this side of the if statement match what I'm actually trying
to test".

+}
+
+TEST_F(SchedulerTest,
+       SkipSwapIfHighLatencyAndCanDrawBeforeDeadline_DeadlineThenSwapAck) {
+  // Set up client so that estimates indicate that we can commit and activate
+  // before the deadline (~11ms by default).
+  EXPECT_SCOPED(SwapIsHighLatency(1, 1, 1, true, false, false));
+}
+
+TEST_F(SchedulerTest, NotSkipSwapIfHighLatencyAndCanDrawTooLong) {
+  // Set up client so that estimates indicate that the commit cannot finish
+  // before the deadline (~11ms by default).
+  EXPECT_SCOPED(SwapIsHighLatency(20, 1, 1, true, true, true));
+}
+
+TEST_F(SchedulerTest, NotSkipSwapIfHighLatencyAndCanActivateTooLong) {
+  // Set up client so that estimates indicate that the activate cannot finish
+  // before the deadline (~11ms by default).
+  EXPECT_SCOPED(SwapIsHighLatency(1, 8, 8, false, true, true));
+}
+
+TEST_F(SchedulerTest, MainAndSwapInHighLatencyMode) {
+  // Set up client with custom estimates.
+  // This test starts off with expensive estimates to prevent latency recovery
+  // initially, the lowers the estimates to enable it once both the main
+  // and impl threads are in a high latency mode.
+  auto fast_duration = base::TimeDelta::FromMilliseconds(1);
+  auto slow_duration = base::TimeDelta::FromMilliseconds(10);

[mithro-old, 2015/05/27 04:40:15]

10ms it a slow estimate?

+  SchedulerClientWithCustomEstimates* client =
+      new SchedulerClientWithCustomEstimates(slow_duration, slow_duration,
+                                             slow_duration);
+
+  scheduler_settings_.use_external_begin_frame_source = true;
+  SetUpScheduler(make_scoped_ptr(client).Pass(), true);
+
+  // To get into a high latency state, this test disables automatic swap acks.
+  scheduler_->SetMaxSwapsPending(1);
+  client_->SetAutomaticSwapAck(false);
+
+  // Impl thread hits deadline before commit finishes to make
+  // MainThreadIsInHighLatencyMode true
+  client->Reset();
+  scheduler_->SetNeedsCommit();
+  EXPECT_FALSE(scheduler_->MainThreadIsInHighLatencyMode());
+  EXPECT_SCOPED(AdvanceFrame());
+  EXPECT_FALSE(scheduler_->MainThreadIsInHighLatencyMode());
+  task_runner().RunPendingTasks();  // Run posted deadline.
+  EXPECT_TRUE(scheduler_->MainThreadIsInHighLatencyMode());
+  scheduler_->NotifyBeginMainFrameStarted();
+  scheduler_->NotifyReadyToCommit();
+  EXPECT_TRUE(scheduler_->MainThreadIsInHighLatencyMode());
+  EXPECT_TRUE(client->HasAction("WillBeginImplFrame"));
+  EXPECT_TRUE(client->HasAction("ScheduledActionSendBeginMainFrame"));
+
+  // Draw and swap for first commit, start second commit.
+  client->Reset();
+  scheduler_->SetNeedsCommit();
+  EXPECT_TRUE(scheduler_->MainThreadIsInHighLatencyMode());
+  EXPECT_SCOPED(AdvanceFrame());
+  EXPECT_TRUE(scheduler_->MainThreadIsInHighLatencyMode());
+  task_runner().RunPendingTasks();  // Run posted deadline.
+  scheduler_->NotifyBeginMainFrameStarted();
+  scheduler_->NotifyReadyToCommit();
+  EXPECT_TRUE(client->HasAction("WillBeginImplFrame"));
+  EXPECT_TRUE(client->HasAction("ScheduledActionSendBeginMainFrame"));
+  EXPECT_TRUE(client->HasAction("ScheduledActionDrawAndSwapIfPossible"));
+
+  // Don't call scheduler_->DidSwapBuffersComplete() until after next frame
+  // to put the impl thread in a high latency mode.
+  client->Reset();
+  scheduler_->SetNeedsCommit();
+  EXPECT_TRUE(scheduler_->MainThreadIsInHighLatencyMode());
+  EXPECT_SCOPED(AdvanceFrame());
+  EXPECT_TRUE(scheduler_->MainThreadIsInHighLatencyMode());
+  task_runner().RunPendingTasks();  // Run posted deadline.
+  scheduler_->DidSwapBuffersComplete();
+  EXPECT_TRUE(client->HasAction("WillBeginImplFrame"));
+  // Note: BeginMainFrame and BeginImplFrame are skipped here because
+  // of backpressure, not because of latency recovery.
+  EXPECT_FALSE(client->HasAction("ScheduledActionSendBeginMainFrame"));
+  EXPECT_FALSE(client->HasAction("ScheduledActionDrawAndSwapIfPossible"));
+
+  // Lower estimates so that the scheduler will attempt latency recovery.

[mithro-old, 2015/05/27 04:40:15]

How would this happen in the "real" world?

+  client->begin_main_frame_to_commit_duration_ = fast_duration;
+  client->commit_to_activate_duration_ = fast_duration;
+  client->draw_duration_ = fast_duration;
+
+  // Now that both threads are in a high latency mode, make sure we

[mithro-old, 2015/05/27 04:40:14]

I think you should have checks here which verify your precondition mentioned in
the comment, IE

EXPECT_TRUE(scheduler_->MainThreadIsInHighLatencyMode());

+  // skip the BeginMainFrame, then the BeginImplFrame, but not both
+  // at the same time.
+
+  // Verify we skip BeginMainFrame first.
+  client->Reset();
+  EXPECT_TRUE(scheduler_->NeedsCommit());  // Previous commit still outstanding.
+  EXPECT_TRUE(scheduler_->MainThreadIsInHighLatencyMode());
+  SendNextBeginFrame();
+  task_runner().RunPendingTasks();  // Run posted deadline.

[mithro-old, 2015/05/27 04:40:15]

RunPendingTasks is the devil.... What are you actually running tasks to achieve?

+  EXPECT_FALSE(scheduler_->MainThreadIsInHighLatencyMode());
+  EXPECT_TRUE(client->HasAction("WillBeginImplFrame"));
+  EXPECT_FALSE(client->HasAction("ScheduledActionSendBeginMainFrame"));
+  EXPECT_TRUE(client->HasAction("ScheduledActionDrawAndSwapIfPossible"));
+
+  // Verify we skip the DrawAndSwap second.
+  client->Reset();
+  EXPECT_TRUE(scheduler_->NeedsCommit());  // Previous commit still outstanding.
+  EXPECT_FALSE(scheduler_->MainThreadIsInHighLatencyMode());
+  SendNextBeginFrame();
+  task_runner().RunPendingTasks();  // Run posted deadline.

[mithro-old, 2015/05/27 04:40:14]

....

+  EXPECT_FALSE(scheduler_->MainThreadIsInHighLatencyMode());
+  scheduler_->DidSwapBuffersComplete();
+  EXPECT_FALSE(scheduler_->MainThreadIsInHighLatencyMode());
+  EXPECT_FALSE(client->HasAction("WillBeginImplFrame"));
+  EXPECT_FALSE(client->HasAction("ScheduledActionSendBeginMainFrame"));
+  EXPECT_FALSE(client->HasAction("ScheduledActionDrawAndSwapIfPossible"));
+
+  // Then verify we operate in a low latency mode.
+  client->Reset();
+  EXPECT_TRUE(scheduler_->NeedsCommit());  // Previous commit still outstanding.
+  EXPECT_FALSE(scheduler_->MainThreadIsInHighLatencyMode());
+  SendNextBeginFrame();
+  EXPECT_FALSE(scheduler_->MainThreadIsInHighLatencyMode());
+  scheduler_->NotifyBeginMainFrameStarted();
+  scheduler_->NotifyReadyToCommit();
+  task_runner().RunPendingTasks();  // Run posted deadline.
+  EXPECT_FALSE(scheduler_->MainThreadIsInHighLatencyMode());
+  scheduler_->DidSwapBuffersComplete();
+  EXPECT_FALSE(scheduler_->MainThreadIsInHighLatencyMode());
+  EXPECT_TRUE(client->HasAction("WillBeginImplFrame"));
+  EXPECT_TRUE(client->HasAction("ScheduledActionSendBeginMainFrame"));
+  EXPECT_TRUE(client->HasAction("ScheduledActionDrawAndSwapIfPossible"));
+}
+
 TEST_F(SchedulerTest,
        Deadlock_NotifyReadyToCommitMakesProgressWhileSwapTrottled) {
   // NPAPI plugins on Windows block the Browser UI thread on the Renderer main
@@ -1390,8 +1627,8 @@ TEST_F(SchedulerTest,
 
   // Since we are simulating a long commit, set up a client with draw duration
   // estimates that prevent skipping main frames to get to low latency mode.
-  SchedulerClientWithFixedEstimates* client =
-      new SchedulerClientWithFixedEstimates(
+  SchedulerClientWithCustomEstimates* client =
+      new SchedulerClientWithCustomEstimates(
           base::TimeDelta::FromMilliseconds(1),
           base::TimeDelta::FromMilliseconds(32),
           base::TimeDelta::FromMilliseconds(32));
@@ -1456,8 +1693,8 @@ TEST_F(
 
   // Since we are simulating a long commit, set up a client with draw duration
   // estimates that prevent skipping main frames to get to low latency mode.
-  SchedulerClientWithFixedEstimates* client =
-      new SchedulerClientWithFixedEstimates(
+  SchedulerClientWithCustomEstimates* client =
+      new SchedulerClientWithCustomEstimates(
           base::TimeDelta::FromMilliseconds(1),
           base::TimeDelta::FromMilliseconds(32),
           base::TimeDelta::FromMilliseconds(32));
@@ -1534,8 +1771,8 @@ TEST_F(SchedulerTest,
 
   // Since we are simulating a long commit, set up a client with draw duration
   // estimates that prevent skipping main frames to get to low latency mode.
-  SchedulerClientWithFixedEstimates* client =
-      new SchedulerClientWithFixedEstimates(
+  SchedulerClientWithCustomEstimates* client =
+      new SchedulerClientWithCustomEstimates(
           base::TimeDelta::FromMilliseconds(1),
           base::TimeDelta::FromMilliseconds(32),
           base::TimeDelta::FromMilliseconds(32));
@@ -1621,8 +1858,8 @@ TEST_F(
 
   // Since we are simulating a long commit, set up a client with draw duration
   // estimates that prevent skipping main frames to get to low latency mode.
-  SchedulerClientWithFixedEstimates* client =
-      new SchedulerClientWithFixedEstimates(
+  SchedulerClientWithCustomEstimates* client =
+      new SchedulerClientWithCustomEstimates(
           base::TimeDelta::FromMilliseconds(1),
           base::TimeDelta::FromMilliseconds(32),
           base::TimeDelta::FromMilliseconds(32));