Estimate draw duration in SchedulerClient

This adds a DrawDurationEstimate method to SchedulerClient. The
implementation of this method (in ThreadProxy) produces an
estimate based on recent draw times.

This also adds UMA stats measuring the duration of each draw and
the amount by which this duration is underestimated or
overestimated.

BUG=243459

Review URL: https://chromiumcodereview.appspot.com/16574002

git-svn-id: svn://svn.chromium.org/chrome/trunk/src@206624 0039d316-1c4b-4281-b951-d872f2087c98

4 files changed, 51 insertions, 2 deletions

diff --git a/cc/scheduler/scheduler.h b/cc/scheduler/scheduler.h
index d8151fa..88d2735 100644
--- a/cc/scheduler/scheduler.h
+++ b/cc/scheduler/scheduler.h
@@ -44,6 +44,7 @@ class SchedulerClient {
   virtual void ScheduledActionBeginOutputSurfaceCreation() = 0;
   virtual void ScheduledActionAcquireLayerTexturesForMainThread() = 0;
   virtual void DidAnticipatedDrawTimeChange(base::TimeTicks time) = 0;
+  virtual base::TimeDelta DrawDurationEstimate() = 0;
 
  protected:
   virtual ~SchedulerClient() {}
diff --git a/cc/scheduler/scheduler_unittest.cc b/cc/scheduler/scheduler_unittest.cc
index bc7d575..dd92eaa 100644
--- a/cc/scheduler/scheduler_unittest.cc
+++ b/cc/scheduler/scheduler_unittest.cc
@@ -115,6 +115,9 @@ class FakeSchedulerClient : public SchedulerClient {
     states_.push_back(scheduler_->StateAsStringForTesting());
   }
   virtual void DidAnticipatedDrawTimeChange(base::TimeTicks) OVERRIDE {}
+  virtual base::TimeDelta DrawDurationEstimate() OVERRIDE {
+    return base::TimeDelta();
+  }
 
  protected:
   bool needs_begin_frame_;
diff --git a/cc/trees/thread_proxy.cc b/cc/trees/thread_proxy.cc
index 274aca9..7b761a2 100644
--- a/cc/trees/thread_proxy.cc
+++ b/cc/trees/thread_proxy.cc
@@ -9,6 +9,7 @@
 #include "base/auto_reset.h"
 #include "base/bind.h"
 #include "base/debug/trace_event.h"
+#include "base/metrics/histogram.h"
 #include "cc/base/thread.h"
 #include "cc/input/input_handler.h"
 #include "cc/output/context_provider.h"
@@ -29,6 +30,10 @@ const double kContextRecreationTickRate = 0.03;
 // Measured in seconds.
 const double kSmoothnessTakesPriorityExpirationDelay = 0.25;
 
+const size_t kDrawDurationHistorySize = 60;
+const double kDrawDurationEstimationPercentile = 100.0;
+const int kDrawDurationEstimatePaddingInMicroseconds = 0;
+
 }  // namespace
 
 namespace cc {
@@ -84,7 +89,8 @@ ThreadProxy::ThreadProxy(LayerTreeHost* layer_tree_host,
           layer_tree_host->settings().using_synchronous_renderer_compositor),
       inside_draw_(false),
       defer_commits_(false),
-      renew_tree_priority_on_impl_thread_pending_(false) {
+      renew_tree_priority_on_impl_thread_pending_(false),
+      draw_duration_history_(kDrawDurationHistorySize) {
   TRACE_EVENT0("cc", "ThreadProxy::ThreadProxy");
   DCHECK(IsMainThread());
   DCHECK(layer_tree_host_);
@@ -907,6 +913,8 @@ ThreadProxy::ScheduledActionDrawAndSwapInternal(bool forced_draw) {
   layer_tree_host_impl_->Animate(monotonic_time, wall_clock_time);
   layer_tree_host_impl_->UpdateBackgroundAnimateTicking(false);
 
+  base::TimeTicks start_time = base::TimeTicks::HighResNow();
+  base::TimeDelta draw_duration_estimate = DrawDurationEstimate();
   base::AutoReset<bool> mark_inside(&inside_draw_, true);
 
   // This method is called on a forced draw, regardless of whether we are able
@@ -978,9 +986,34 @@ ThreadProxy::ScheduledActionDrawAndSwapInternal(bool forced_draw) {
         base::Bind(&ThreadProxy::DidCommitAndDrawFrame, main_thread_weak_ptr_));
   }
 
-  if (draw_frame)
+  if (draw_frame) {
     CheckOutputSurfaceStatusOnImplThread();
 
+    base::TimeDelta draw_duration = base::TimeTicks::HighResNow() - start_time;
+    draw_duration_history_.InsertSample(draw_duration);
+    base::TimeDelta draw_duration_overestimate;
+    base::TimeDelta draw_duration_underestimate;
+    if (draw_duration > draw_duration_estimate)
+      draw_duration_underestimate = draw_duration - draw_duration_estimate;
+    else
+      draw_duration_overestimate = draw_duration_estimate - draw_duration;
+    UMA_HISTOGRAM_CUSTOM_TIMES("Renderer.DrawDuration",
+                               draw_duration,
+                               base::TimeDelta::FromMilliseconds(1),
+                               base::TimeDelta::FromMilliseconds(100),
+                               50);
+    UMA_HISTOGRAM_CUSTOM_TIMES("Renderer.DrawDurationUnderestimate",
+                               draw_duration_underestimate,
+                               base::TimeDelta::FromMilliseconds(1),
+                               base::TimeDelta::FromMilliseconds(100),
+                               50);
+    UMA_HISTOGRAM_CUSTOM_TIMES("Renderer.DrawDurationOverestimate",
+                               draw_duration_overestimate,
+                               base::TimeDelta::FromMilliseconds(1),
+                               base::TimeDelta::FromMilliseconds(100),
+                               50);
+  }
+
   // Update the tile state after drawing.  This prevents manage tiles from
   // being in the critical path for getting things on screen, but still
   // makes sure that tile state is updated on a semi-regular basis.
@@ -1046,6 +1079,14 @@ void ThreadProxy::DidAnticipatedDrawTimeChange(base::TimeTicks time) {
   layer_tree_host_impl_->ResetCurrentFrameTimeForNextFrame();
 }
 
+base::TimeDelta ThreadProxy::DrawDurationEstimate() {
+  base::TimeDelta historical_estimate =
+      draw_duration_history_.Percentile(kDrawDurationEstimationPercentile);
+  base::TimeDelta padding = base::TimeDelta::FromMicroseconds(
+      kDrawDurationEstimatePaddingInMicroseconds);
+  return historical_estimate + padding;
+}
+
 void ThreadProxy::ReadyToFinalizeTextureUpdates() {
   DCHECK(IsImplThread());
   scheduler_on_impl_thread_->FinishCommit();
diff --git a/cc/trees/thread_proxy.h b/cc/trees/thread_proxy.h
index 8013882..db3a502 100644
--- a/cc/trees/thread_proxy.h
+++ b/cc/trees/thread_proxy.h
@@ -13,6 +13,7 @@
 #include "cc/animation/animation_events.h"
 #include "cc/base/completion_event.h"
 #include "cc/resources/resource_update_controller.h"
+#include "cc/scheduler/rolling_time_delta_history.h"
 #include "cc/scheduler/scheduler.h"
 #include "cc/trees/layer_tree_host_impl.h"
 #include "cc/trees/proxy.h"
@@ -101,6 +102,7 @@ class ThreadProxy : public Proxy,
   virtual void ScheduledActionBeginOutputSurfaceCreation() OVERRIDE;
   virtual void ScheduledActionAcquireLayerTexturesForMainThread() OVERRIDE;
   virtual void DidAnticipatedDrawTimeChange(base::TimeTicks time) OVERRIDE;
+  virtual base::TimeDelta DrawDurationEstimate() OVERRIDE;
 
   // ResourceUpdateControllerClient implementation
   virtual void ReadyToFinalizeTextureUpdates() OVERRIDE;
@@ -243,6 +245,8 @@ class ThreadProxy : public Proxy,
   base::TimeTicks smoothness_takes_priority_expiration_time_;
   bool renew_tree_priority_on_impl_thread_pending_;
 
+  RollingTimeDeltaHistory draw_duration_history_;
+
   DISALLOW_COPY_AND_ASSIGN(ThreadProxy);
 };