cc: Measure compositor timing with finer granularity

cc/scheduler/scheduler_unittest.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 <string>
 #include <vector>
 
 #include "base/logging.h"
@@ skipping 109 matching lines @@
 
       if (automatic_swap_ack_)
         scheduler_->DidSwapBuffersComplete();
     }
     return result;
   }
   DrawResult ScheduledActionDrawAndSwapForced() override {
     PushAction("ScheduledActionDrawAndSwapForced");
     return DRAW_SUCCESS;
   }
-  void ScheduledActionCommit() override { PushAction("ScheduledActionCommit"); }
+  void ScheduledActionCommit() override {

[mithro-old, 2015/06/30 07:55:49]

Why didn't any tests previously depend on this happening!?

[brianderson, 2015/06/30 17:35:15]

I added Scheduler::DidCommit as part of this patch, so it's more clear when the
commit actually finished. (The LTHI can do extra work after the commit that the
Scheduler isn't aware of.)

+    PushAction("ScheduledActionCommit");
+    scheduler_->DidCommit();
+  }
   void ScheduledActionActivateSyncTree() override {
     PushAction("ScheduledActionActivateSyncTree");
   }
   void ScheduledActionBeginOutputSurfaceCreation() override {
     PushAction("ScheduledActionBeginOutputSurfaceCreation");
   }
   void ScheduledActionPrepareTiles() override {
     PushAction("ScheduledActionPrepareTiles");
+    scheduler_->WillPrepareTiles();
+    scheduler_->DidPrepareTiles();
   }
   void ScheduledActionInvalidateOutputSurface() override {
     actions_.push_back("ScheduledActionInvalidateOutputSurface");
     states_.push_back(scheduler_->AsValue());
   }
 
   void SendBeginFramesToChildren(const BeginFrameArgs& args) override {
     begin_frame_args_sent_to_children_ = args;
   }
 
@@ skipping 298 matching lines @@
 }
 
 TEST_F(SchedulerTest, SendBeginFramesToChildrenDeadlineNotAdjusted) {
   // Set up client with specified estimates.
   scheduler_settings_.use_external_begin_frame_source = true;
   SetUpScheduler(true);
   fake_compositor_timing_history_->SetDrawDurationEstimate(
       base::TimeDelta::FromMilliseconds(1));
   fake_compositor_timing_history_->SetBeginMainFrameToCommitDurationEstimate(
       base::TimeDelta::FromMilliseconds(2));
-  fake_compositor_timing_history_->SetCommitToActivateDurationEstimate(
+  fake_compositor_timing_history_->SetCommitToReadyToActivateDurationEstimate(
       base::TimeDelta::FromMilliseconds(4));
 
   EXPECT_FALSE(client_->needs_begin_frames());
   scheduler_->SetChildrenNeedBeginFrames(true);
   EXPECT_SINGLE_ACTION("SetNeedsBeginFrames(true)", client_);
   EXPECT_TRUE(client_->needs_begin_frames());
 
   client_->Reset();
 
   BeginFrameArgs frame_args =
@@ skipping 235 matching lines @@
   task_runner().RunPendingTasks();  // Run posted deadline.
   EXPECT_FALSE(client_->needs_begin_frames());
   client_->Reset();
 }
 
 class SchedulerClientThatsetNeedsDrawInsideDraw : public FakeSchedulerClient {
  public:
   SchedulerClientThatsetNeedsDrawInsideDraw()
       : FakeSchedulerClient(), request_redraws_(false) {}
 
-  void ScheduledActionSendBeginMainFrame() override {}
-
   void SetRequestRedrawsInsideDraw(bool enable) { request_redraws_ = enable; }
 
   DrawResult ScheduledActionDrawAndSwapIfPossible() override {
     // Only SetNeedsRedraw the first time this is called
     if (request_redraws_) {
       scheduler_->SetNeedsRedraw();
     }
     return FakeSchedulerClient::ScheduledActionDrawAndSwapIfPossible();
   }
 
   DrawResult ScheduledActionDrawAndSwapForced() override {
     NOTREACHED();
     return DRAW_SUCCESS;
   }
 
-  void ScheduledActionCommit() override {}
-
  private:
   bool request_redraws_;
 };
 
 // Tests for two different situations:
 // 1. the scheduler dropping SetNeedsRedraw requests that happen inside
 //    a ScheduledActionDrawAndSwap
 // 2. the scheduler drawing twice inside a single tick
 TEST_F(SchedulerTest, RequestRedrawInsideDraw) {
   SchedulerClientThatsetNeedsDrawInsideDraw* client =
@@ skipping 74 matching lines @@
   EXPECT_TRUE(scheduler_->CommitPending());
   EXPECT_FALSE(scheduler_->RedrawPending());
   EXPECT_TRUE(client->needs_begin_frames());
 }
 
 class SchedulerClientThatSetNeedsCommitInsideDraw : public FakeSchedulerClient {
  public:
   SchedulerClientThatSetNeedsCommitInsideDraw()
       : set_needs_commit_on_next_draw_(false) {}
 
-  void ScheduledActionSendBeginMainFrame() override {}
   DrawResult ScheduledActionDrawAndSwapIfPossible() override {
     // Only SetNeedsCommit the first time this is called
     if (set_needs_commit_on_next_draw_) {
       scheduler_->SetNeedsCommit();
       set_needs_commit_on_next_draw_ = false;
     }
     return FakeSchedulerClient::ScheduledActionDrawAndSwapIfPossible();
   }
 
   DrawResult ScheduledActionDrawAndSwapForced() override {
     NOTREACHED();
     return DRAW_SUCCESS;
   }
 
-  void ScheduledActionCommit() override {}
-
   void SetNeedsCommitOnNextDraw() { set_needs_commit_on_next_draw_ = true; }
 
  private:
   bool set_needs_commit_on_next_draw_;
 };
 
 // Tests for the scheduler infinite-looping on SetNeedsCommit requests that
 // happen inside a ScheduledActionDrawAndSwap
 TEST_F(SchedulerTest, RequestCommitInsideDraw) {
   SchedulerClientThatSetNeedsCommitInsideDraw* client =
@@ skipping 231 matching lines @@
   // again.
   scheduler_->SetNeedsPrepareTiles();
   scheduler_->SetNeedsRedraw();
   client_->Reset();
   EXPECT_SCOPED(AdvanceFrame());
   EXPECT_ACTION("WillBeginImplFrame", client_, 0, 2);
   EXPECT_ACTION("ScheduledActionAnimate", client_, 1, 2);
   EXPECT_TRUE(scheduler_->BeginImplFrameDeadlinePending());
 
   EXPECT_TRUE(scheduler_->PrepareTilesPending());
+  scheduler_->WillPrepareTiles();
   scheduler_->DidPrepareTiles();  // An explicit PrepareTiles.
   EXPECT_FALSE(scheduler_->PrepareTilesPending());
 
   client_->Reset();
   task_runner().RunPendingTasks();  // Run posted deadline.
   EXPECT_EQ(1, client_->num_draws());
   EXPECT_TRUE(client_->HasAction("ScheduledActionDrawAndSwapIfPossible"));
   EXPECT_FALSE(client_->HasAction("ScheduledActionPrepareTiles"));
   EXPECT_FALSE(scheduler_->RedrawPending());
   EXPECT_FALSE(scheduler_->PrepareTilesPending());
@@ skipping 11 matching lines @@
   client_->Reset();
   task_runner().RunPendingTasks();  // Run posted deadline.
   EXPECT_EQ(1, client_->num_draws());
   EXPECT_TRUE(client_->HasAction("ScheduledActionDrawAndSwapIfPossible"));
   EXPECT_TRUE(client_->HasAction("ScheduledActionPrepareTiles"));
   EXPECT_LT(client_->ActionIndex("ScheduledActionDrawAndSwapIfPossible"),
             client_->ActionIndex("ScheduledActionPrepareTiles"));
   EXPECT_FALSE(scheduler_->RedrawPending());
   EXPECT_FALSE(scheduler_->PrepareTilesPending());
   EXPECT_FALSE(scheduler_->BeginImplFrameDeadlinePending());
-  scheduler_->DidPrepareTiles();  // Corresponds to ScheduledActionPrepareTiles
 
   // If we get another DidPrepareTiles within the same frame, we should
   // not PrepareTiles on the next frame.
+  scheduler_->WillPrepareTiles();
   scheduler_->DidPrepareTiles();  // An explicit PrepareTiles.
   scheduler_->SetNeedsPrepareTiles();
   scheduler_->SetNeedsRedraw();
   client_->Reset();
   EXPECT_SCOPED(AdvanceFrame());
   EXPECT_ACTION("WillBeginImplFrame", client_, 0, 2);
   EXPECT_ACTION("ScheduledActionAnimate", client_, 1, 2);
   EXPECT_TRUE(scheduler_->BeginImplFrameDeadlinePending());
 
   EXPECT_TRUE(scheduler_->PrepareTilesPending());
 
   client_->Reset();
   task_runner().RunPendingTasks();  // Run posted deadline.
   EXPECT_EQ(1, client_->num_draws());
   EXPECT_TRUE(client_->HasAction("ScheduledActionDrawAndSwapIfPossible"));
   EXPECT_FALSE(client_->HasAction("ScheduledActionPrepareTiles"));
   EXPECT_FALSE(scheduler_->RedrawPending());
   EXPECT_FALSE(scheduler_->BeginImplFrameDeadlinePending());
 
   // If we get another DidPrepareTiles, we should not PrepareTiles on the next
   // frame. This verifies we don't alternate calling PrepareTiles once and
   // twice.
   EXPECT_TRUE(scheduler_->PrepareTilesPending());
+  scheduler_->WillPrepareTiles();
   scheduler_->DidPrepareTiles();  // An explicit PrepareTiles.
   EXPECT_FALSE(scheduler_->PrepareTilesPending());
   scheduler_->SetNeedsPrepareTiles();
   scheduler_->SetNeedsRedraw();
   client_->Reset();
   EXPECT_SCOPED(AdvanceFrame());
   EXPECT_ACTION("WillBeginImplFrame", client_, 0, 2);
   EXPECT_ACTION("ScheduledActionAnimate", client_, 1, 2);
   EXPECT_TRUE(scheduler_->BeginImplFrameDeadlinePending());
 
@@ skipping 19 matching lines @@
   client_->Reset();
   task_runner().RunPendingTasks();  // Run posted deadline.
   EXPECT_EQ(1, client_->num_draws());
   EXPECT_TRUE(client_->HasAction("ScheduledActionDrawAndSwapIfPossible"));
   EXPECT_TRUE(client_->HasAction("ScheduledActionPrepareTiles"));
   EXPECT_LT(client_->ActionIndex("ScheduledActionDrawAndSwapIfPossible"),
             client_->ActionIndex("ScheduledActionPrepareTiles"));
   EXPECT_FALSE(scheduler_->RedrawPending());
   EXPECT_FALSE(scheduler_->PrepareTilesPending());
   EXPECT_FALSE(scheduler_->BeginImplFrameDeadlinePending());
-  scheduler_->DidPrepareTiles();  // Corresponds to ScheduledActionPrepareTiles
 }
 
 TEST_F(SchedulerTest, TriggerBeginFrameDeadlineEarly) {
   SchedulerClientNeedsPrepareTilesInDraw* client =
       new SchedulerClientNeedsPrepareTilesInDraw;
   scheduler_settings_.use_external_begin_frame_source = true;
   SetUpScheduler(make_scoped_ptr(client).Pass(), true);
 
   scheduler_->SetNeedsRedraw();
   EXPECT_SCOPED(AdvanceFrame());
@@ skipping 93 matching lines @@
     bool impl_latency_takes_priority,
     bool should_send_begin_main_frame) {
   scheduler_settings_.use_external_begin_frame_source = true;
   SetUpScheduler(true);
 
   fake_compositor_timing_history_->SetDrawDurationEstimate(
       base::TimeDelta::FromMilliseconds(1));
   fake_compositor_timing_history_->SetBeginMainFrameToCommitDurationEstimate(
       base::TimeDelta::FromMilliseconds(
           begin_main_frame_to_commit_estimate_in_ms));
-  fake_compositor_timing_history_->SetCommitToActivateDurationEstimate(
+  fake_compositor_timing_history_->SetCommitToReadyToActivateDurationEstimate(
       base::TimeDelta::FromMilliseconds(commit_to_activate_estimate_in_ms));
 
   scheduler_->SetImplLatencyTakesPriority(impl_latency_takes_priority);
 
   // Impl thread hits deadline before commit finishes.
   scheduler_->SetNeedsCommit();
   EXPECT_FALSE(scheduler_->MainThreadIsInHighLatencyMode());
   EXPECT_SCOPED(AdvanceFrame());
   EXPECT_FALSE(scheduler_->MainThreadIsInHighLatencyMode());
   task_runner().RunPendingTasks();  // Run posted deadline.
@@ skipping 51 matching lines @@
   // 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.
   scheduler_settings_.use_external_begin_frame_source = true;
   scheduler_settings_.main_frame_while_swap_throttled_enabled = true;
   SetUpScheduler(true);
 
   fake_compositor_timing_history_->SetDrawDurationEstimate(
       base::TimeDelta::FromMilliseconds(1));
   fake_compositor_timing_history_->SetBeginMainFrameToCommitDurationEstimate(
       base::TimeDelta::FromMilliseconds(32));
-  fake_compositor_timing_history_->SetCommitToActivateDurationEstimate(
+  fake_compositor_timing_history_->SetCommitToReadyToActivateDurationEstimate(
       base::TimeDelta::FromMilliseconds(32));
 
   // Disables automatic swap acks so this test can force swap ack throttling
   // to simulate a blocked Browser ui thread.
   scheduler_->SetMaxSwapsPending(1);
   client_->SetAutomaticSwapAck(false);
 
   // Get a new active tree in main-thread high latency mode and put us
   // in a swap throttled state.
   client_->Reset();
@@ skipping 59 matching lines @@
   // estimates that prevent skipping main frames to get to low latency mode.
   scheduler_settings_.use_external_begin_frame_source = true;
   scheduler_settings_.main_frame_while_swap_throttled_enabled = true;
   scheduler_settings_.main_frame_before_activation_enabled = true;
   SetUpScheduler(true);
 
   fake_compositor_timing_history_->SetDrawDurationEstimate(
       base::TimeDelta::FromMilliseconds(1));
   fake_compositor_timing_history_->SetBeginMainFrameToCommitDurationEstimate(
       base::TimeDelta::FromMilliseconds(32));
-  fake_compositor_timing_history_->SetCommitToActivateDurationEstimate(
+  fake_compositor_timing_history_->SetCommitToReadyToActivateDurationEstimate(
       base::TimeDelta::FromMilliseconds(32));
 
   // Disables automatic swap acks so this test can force swap ack throttling
   // to simulate a blocked Browser ui thread.
   scheduler_->SetMaxSwapsPending(1);
   client_->SetAutomaticSwapAck(false);
 
   // Start a new commit in main-thread high latency mode and hold off on
   // activation.
   client_->Reset();
@@ skipping 67 matching lines @@
   // estimates that prevent skipping main frames to get to low latency mode.
   scheduler_settings_.use_external_begin_frame_source = true;
   scheduler_settings_.main_frame_while_swap_throttled_enabled = true;
   scheduler_settings_.main_frame_before_activation_enabled = true;
   SetUpScheduler(true);
 
   fake_compositor_timing_history_->SetDrawDurationEstimate(
       base::TimeDelta::FromMilliseconds(1));
   fake_compositor_timing_history_->SetBeginMainFrameToCommitDurationEstimate(
       base::TimeDelta::FromMilliseconds(32));
-  fake_compositor_timing_history_->SetCommitToActivateDurationEstimate(
+  fake_compositor_timing_history_->SetCommitToReadyToActivateDurationEstimate(
       base::TimeDelta::FromMilliseconds(32));
 
   // Disables automatic swap acks so this test can force swap ack throttling
   // to simulate a blocked Browser ui thread.
   scheduler_->SetMaxSwapsPending(1);
   client_->SetAutomaticSwapAck(false);
 
   // Start a new commit in main-thread high latency mode and hold off on
   // activation.
   client_->Reset();
@@ skipping 1289 matching lines @@
 
 class SchedulerClientSetNeedsPrepareTilesOnDraw : public FakeSchedulerClient {
  public:
   SchedulerClientSetNeedsPrepareTilesOnDraw() : FakeSchedulerClient() {}
 
  protected:
   DrawResult ScheduledActionDrawAndSwapIfPossible() override {
     scheduler_->SetNeedsPrepareTiles();
     return FakeSchedulerClient::ScheduledActionDrawAndSwapIfPossible();
   }
-
-  void ScheduledActionPrepareTiles() override {
-    FakeSchedulerClient::ScheduledActionPrepareTiles();
-    scheduler_->DidPrepareTiles();
-  }
 };
 
 TEST_F(SchedulerTest, SynchronousCompositorPrepareTilesOnDraw) {
   scheduler_settings_.using_synchronous_renderer_compositor = true;
   scheduler_settings_.use_external_begin_frame_source = true;
 
   scoped_ptr<FakeSchedulerClient> client =
       make_scoped_ptr(new SchedulerClientSetNeedsPrepareTilesOnDraw);
   SetUpScheduler(client.Pass(), true);
 
@@ skipping 90 matching lines @@
   scheduler_->SetImplLatencyTakesPriority(true);
   scheduler_->SetChildrenNeedBeginFrames(true);
 
   EXPECT_SCOPED(AdvanceFrame());
   EXPECT_TRUE(client_->begin_frame_is_sent_to_children());
   EXPECT_FALSE(client_->begin_frame_args_sent_to_children().on_critical_path);
 }
 
 }  // namespace
 }  // namespace cc