Add duration estimation data to RenderingStats.

The deadline scheduler in the Chrome compositor relies on runtime estimations of
various stages in the rendering pipeline. This patch adds the actual and
estimated runtimes of these stages to RenderingStats so they will be available
in tracing output. This will allow us to tune the estimators.

BUG=243459

Review URL: https://codereview.chromium.org/363003002

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

cc/cc_tests.gyp

@@ -23,6 +23,7 @@
       'base/unique_notifier_unittest.cc',
       'base/util_unittest.cc',
       'debug/micro_benchmark_controller_unittest.cc',
+      'debug/rendering_stats_unittest.cc',
       'input/top_controls_manager_unittest.cc',
       'layers/content_layer_unittest.cc',
       'layers/contents_scaling_layer_unittest.cc',

cc/debug/benchmark_instrumentation.cc

@@ -12,14 +12,16 @@ namespace benchmark_instrumentation {
 // tools/perf/measurements/rendering_stats.py accordingly.
 // The benchmarks search for events and their arguments by name.
 
-void IssueMainThreadRenderingStatsEvent(const MainThreadRenderingStats& stats) {
+void IssueMainThreadRenderingStatsEvent(
+    const RenderingStats::MainThreadRenderingStats& stats) {
   TRACE_EVENT_INSTANT1("benchmark",
                        "BenchmarkInstrumentation::MainThreadRenderingStats",
                        TRACE_EVENT_SCOPE_THREAD,
                        "data", stats.AsTraceableData());
 }
 
-void IssueImplThreadRenderingStatsEvent(const ImplThreadRenderingStats& stats) {
+void IssueImplThreadRenderingStatsEvent(
+    const RenderingStats::ImplThreadRenderingStats& stats) {
   TRACE_EVENT_INSTANT1("benchmark",
                        "BenchmarkInstrumentation::ImplThreadRenderingStats",
                        TRACE_EVENT_SCOPE_THREAD,

cc/debug/benchmark_instrumentation.h

@@ -41,8 +41,10 @@ class ScopedBeginFrameTask {
   DISALLOW_COPY_AND_ASSIGN(ScopedBeginFrameTask);
 };
 
-void IssueMainThreadRenderingStatsEvent(const MainThreadRenderingStats& stats);
-void IssueImplThreadRenderingStatsEvent(const ImplThreadRenderingStats& stats);
+void IssueMainThreadRenderingStatsEvent(
+    const RenderingStats::MainThreadRenderingStats& stats);
+void IssueImplThreadRenderingStatsEvent(
+    const RenderingStats::ImplThreadRenderingStats& stats);
 
 }  // namespace benchmark_instrumentation
 }  // namespace cc

cc/debug/rendering_stats.cc

@@ -2,18 +2,43 @@
 // Use of this source code is governed by a BSD-style license that can be
 // found in the LICENSE file.
 
-#include "base/values.h"
 #include "cc/debug/rendering_stats.h"
 
 namespace cc {
 
-MainThreadRenderingStats::MainThreadRenderingStats()
-    : frame_count(0),
-      painted_pixel_count(0),
-      recorded_pixel_count(0) {}
+RenderingStats::TimeDeltaList::TimeDeltaList() {
+}
+
+RenderingStats::TimeDeltaList::~TimeDeltaList() {
+}
+
+void RenderingStats::TimeDeltaList::Append(base::TimeDelta value) {
+  values.push_back(value);
+}
+
+scoped_ptr<base::ListValue>
+RenderingStats::TimeDeltaList::AsListValueInMilliseconds() const {
+  scoped_ptr<base::ListValue> list_value(new base::ListValue);
+  std::list<base::TimeDelta>::const_iterator iter;
+  for (iter = values.begin(); iter != values.end(); ++iter) {
+    list_value->AppendDouble(iter->InMillisecondsF());
+  }
+  return list_value.Pass();
+}
+
+void RenderingStats::TimeDeltaList::Add(const TimeDeltaList& other) {
+  values.insert(values.end(), other.values.begin(), other.values.end());
+}
+
+RenderingStats::MainThreadRenderingStats::MainThreadRenderingStats()
+    : frame_count(0), painted_pixel_count(0), recorded_pixel_count(0) {
+}
+
+RenderingStats::MainThreadRenderingStats::~MainThreadRenderingStats() {
+}
 
 scoped_refptr<base::debug::ConvertableToTraceFormat>
-MainThreadRenderingStats::AsTraceableData() const {
+RenderingStats::MainThreadRenderingStats::AsTraceableData() const {
   scoped_ptr<base::DictionaryValue> record_data(new base::DictionaryValue());
   record_data->SetInteger("frame_count", frame_count);
   record_data->SetDouble("paint_time", paint_time.InSecondsF());
@@ -23,7 +48,8 @@ MainThreadRenderingStats::AsTraceableData() const {
   return TracedValue::FromValue(record_data.release());
 }
 
-void MainThreadRenderingStats::Add(const MainThreadRenderingStats& other) {
+void RenderingStats::MainThreadRenderingStats::Add(
+    const MainThreadRenderingStats& other) {
   frame_count += other.frame_count;
   paint_time += other.paint_time;
   painted_pixel_count += other.painted_pixel_count;
@@ -31,15 +57,18 @@ void MainThreadRenderingStats::Add(const MainThreadRenderingStats& other) {
   recorded_pixel_count += other.recorded_pixel_count;
 }
 
-ImplThreadRenderingStats::ImplThreadRenderingStats()
+RenderingStats::ImplThreadRenderingStats::ImplThreadRenderingStats()
     : frame_count(0),
       rasterized_pixel_count(0),
       visible_content_area(0),
       approximated_visible_content_area(0) {
 }
 
+RenderingStats::ImplThreadRenderingStats::~ImplThreadRenderingStats() {
+}
+
 scoped_refptr<base::debug::ConvertableToTraceFormat>
-ImplThreadRenderingStats::AsTraceableData() const {
+RenderingStats::ImplThreadRenderingStats::AsTraceableData() const {
   scoped_ptr<base::DictionaryValue> record_data(new base::DictionaryValue());
   record_data->SetInteger("frame_count", frame_count);
   record_data->SetDouble("rasterize_time", rasterize_time.InSecondsF());
@@ -47,16 +76,47 @@ ImplThreadRenderingStats::AsTraceableData() const {
   record_data->SetInteger("visible_content_area", visible_content_area);
   record_data->SetInteger("approximated_visible_content_area",
                           approximated_visible_content_area);
+  record_data->Set("draw_duration_ms",
+                   draw_duration.AsListValueInMilliseconds().release());
+  record_data->Set(
+      "draw_duration_estimate_ms",
+      draw_duration_estimate.AsListValueInMilliseconds().release());
+  record_data->Set(
+      "begin_main_frame_to_commit_duration_ms",
+      begin_main_frame_to_commit_duration.AsListValueInMilliseconds()
+          .release());
+  record_data->Set(
+      "begin_main_frame_to_commit_duration_estimate_ms",
+      begin_main_frame_to_commit_duration_estimate.AsListValueInMilliseconds()
+          .release());
+  record_data->Set(
+      "commit_to_activate_duration_ms",
+      commit_to_activate_duration.AsListValueInMilliseconds().release());
+  record_data->Set(
+      "commit_to_activate_duration_estimate_ms",
+      commit_to_activate_duration_estimate.AsListValueInMilliseconds()
+          .release());
   return TracedValue::FromValue(record_data.release());
 }
 
-void ImplThreadRenderingStats::Add(const ImplThreadRenderingStats& other) {
+void RenderingStats::ImplThreadRenderingStats::Add(
+    const ImplThreadRenderingStats& other) {
   frame_count += other.frame_count;
   rasterize_time += other.rasterize_time;
   analysis_time += other.analysis_time;
   rasterized_pixel_count += other.rasterized_pixel_count;
   visible_content_area += other.visible_content_area;
   approximated_visible_content_area += other.approximated_visible_content_area;
+
+  draw_duration.Add(other.draw_duration);
+  draw_duration_estimate.Add(other.draw_duration_estimate);
+  begin_main_frame_to_commit_duration.Add(
+      other.begin_main_frame_to_commit_duration);
+  begin_main_frame_to_commit_duration_estimate.Add(
+      other.begin_main_frame_to_commit_duration_estimate);
+  commit_to_activate_duration.Add(other.commit_to_activate_duration);
+  commit_to_activate_duration_estimate.Add(
+      other.commit_to_activate_duration_estimate);
 }
 
 void RenderingStats::Add(const RenderingStats& other) {

cc/debug/rendering_stats.h

@@ -5,45 +5,73 @@
 #ifndef CC_DEBUG_RENDERING_STATS_H_
 #define CC_DEBUG_RENDERING_STATS_H_
 
+#include <list>
+
 #include "base/basictypes.h"
 #include "base/time/time.h"
+#include "base/values.h"
 #include "cc/base/cc_export.h"
 #include "cc/debug/traced_value.h"
 
 namespace cc {
 
-struct CC_EXPORT MainThreadRenderingStats {
-  // Note: when adding new members, please remember to update EnumerateFields
-  // and Add in rendering_stats.cc.
+struct CC_EXPORT RenderingStats {
+  // Stores a sequence of TimeDelta objects.
+  class CC_EXPORT TimeDeltaList {
+   public:
+    TimeDeltaList();
+    ~TimeDeltaList();
 
-  int64 frame_count;
-  base::TimeDelta paint_time;
-  int64 painted_pixel_count;
-  base::TimeDelta record_time;
-  int64 recorded_pixel_count;
+    void Append(base::TimeDelta value);
+    scoped_ptr<base::ListValue> AsListValueInMilliseconds() const;
+    void Add(const TimeDeltaList& other);
 
-  MainThreadRenderingStats();
-  scoped_refptr<base::debug::ConvertableToTraceFormat> AsTraceableData() const;
-  void Add(const MainThreadRenderingStats& other);
-};
+   private:
+    std::list<base::TimeDelta> values;
+  };
 
-struct CC_EXPORT ImplThreadRenderingStats {
-  // Note: when adding new members, please remember to update EnumerateFields
-  // and Add in rendering_stats.cc.
+  struct CC_EXPORT MainThreadRenderingStats {
+    // Note: when adding new members, please remember to update Add in
+    // rendering_stats.cc.
 
-  int64 frame_count;
-  base::TimeDelta rasterize_time;
-  base::TimeDelta analysis_time;
-  int64 rasterized_pixel_count;
-  int64 visible_content_area;
-  int64 approximated_visible_content_area;
+    int64 frame_count;
+    base::TimeDelta paint_time;
+    int64 painted_pixel_count;
+    base::TimeDelta record_time;
+    int64 recorded_pixel_count;
 
-  ImplThreadRenderingStats();
-  scoped_refptr<base::debug::ConvertableToTraceFormat> AsTraceableData() const;
-  void Add(const ImplThreadRenderingStats& other);
-};
+    MainThreadRenderingStats();
+    ~MainThreadRenderingStats();
+    scoped_refptr<base::debug::ConvertableToTraceFormat> AsTraceableData()
+        const;
+    void Add(const MainThreadRenderingStats& other);
+  };
+
+  struct CC_EXPORT ImplThreadRenderingStats {
+    // Note: when adding new members, please remember to update Add in
+    // rendering_stats.cc.
+
+    int64 frame_count;
+    base::TimeDelta rasterize_time;
+    base::TimeDelta analysis_time;
+    int64 rasterized_pixel_count;
+    int64 visible_content_area;
+    int64 approximated_visible_content_area;
+
+    TimeDeltaList draw_duration;
+    TimeDeltaList draw_duration_estimate;
+    TimeDeltaList begin_main_frame_to_commit_duration;
+    TimeDeltaList begin_main_frame_to_commit_duration_estimate;
+    TimeDeltaList commit_to_activate_duration;
+    TimeDeltaList commit_to_activate_duration_estimate;
+
+    ImplThreadRenderingStats();
+    ~ImplThreadRenderingStats();
+    scoped_refptr<base::debug::ConvertableToTraceFormat> AsTraceableData()
+        const;
+    void Add(const ImplThreadRenderingStats& other);
+  };
 
-struct CC_EXPORT RenderingStats {
   MainThreadRenderingStats main_stats;
   ImplThreadRenderingStats impl_stats;
 

cc/debug/rendering_stats_instrumentation.cc

@@ -18,13 +18,13 @@ RenderingStatsInstrumentation::RenderingStatsInstrumentation()
 
 RenderingStatsInstrumentation::~RenderingStatsInstrumentation() {}
 
-MainThreadRenderingStats
+RenderingStats::MainThreadRenderingStats
 RenderingStatsInstrumentation::main_thread_rendering_stats() {
   base::AutoLock scoped_lock(lock_);
   return main_thread_rendering_stats_;
 }
 
-ImplThreadRenderingStats
+RenderingStats::ImplThreadRenderingStats
 RenderingStatsInstrumentation::impl_thread_rendering_stats() {
   base::AutoLock scoped_lock(lock_);
   return impl_thread_rendering_stats_;
@@ -43,13 +43,13 @@ RenderingStats RenderingStatsInstrumentation::GetRenderingStats() {
 void RenderingStatsInstrumentation::AccumulateAndClearMainThreadStats() {
   base::AutoLock scoped_lock(lock_);
   main_thread_rendering_stats_accu_.Add(main_thread_rendering_stats_);
-  main_thread_rendering_stats_ = MainThreadRenderingStats();
+  main_thread_rendering_stats_ = RenderingStats::MainThreadRenderingStats();
 }
 
 void RenderingStatsInstrumentation::AccumulateAndClearImplThreadStats() {
   base::AutoLock scoped_lock(lock_);
   impl_thread_rendering_stats_accu_.Add(impl_thread_rendering_stats_);
-  impl_thread_rendering_stats_ = ImplThreadRenderingStats();
+  impl_thread_rendering_stats_ = RenderingStats::ImplThreadRenderingStats();
 }
 
 base::TimeTicks RenderingStatsInstrumentation::StartRecording() const {
@@ -139,4 +139,42 @@ void RenderingStatsInstrumentation::AddApproximatedVisibleContentArea(
   impl_thread_rendering_stats_.approximated_visible_content_area += area;
 }
 
+void RenderingStatsInstrumentation::AddDrawDuration(
+    base::TimeDelta draw_duration,
+    base::TimeDelta draw_duration_estimate) {
+  if (!record_rendering_stats_)
+    return;
+
+  base::AutoLock scoped_lock(lock_);
+  impl_thread_rendering_stats_.draw_duration.Append(draw_duration);
+  impl_thread_rendering_stats_.draw_duration_estimate.Append(
+      draw_duration_estimate);
+}
+
+void RenderingStatsInstrumentation::AddBeginMainFrameToCommitDuration(
+    base::TimeDelta begin_main_frame_to_commit_duration,
+    base::TimeDelta begin_main_frame_to_commit_duration_estimate) {
+  if (!record_rendering_stats_)
+    return;
+
+  base::AutoLock scoped_lock(lock_);
+  impl_thread_rendering_stats_.begin_main_frame_to_commit_duration.Append(
+      begin_main_frame_to_commit_duration);
+  impl_thread_rendering_stats_.begin_main_frame_to_commit_duration_estimate
+      .Append(begin_main_frame_to_commit_duration_estimate);
+}
+
+void RenderingStatsInstrumentation::AddCommitToActivateDuration(
+    base::TimeDelta commit_to_activate_duration,
+    base::TimeDelta commit_to_activate_duration_estimate) {
+  if (!record_rendering_stats_)
+    return;
+
+  base::AutoLock scoped_lock(lock_);
+  impl_thread_rendering_stats_.commit_to_activate_duration.Append(
+      commit_to_activate_duration);
+  impl_thread_rendering_stats_.commit_to_activate_duration_estimate.Append(
+      commit_to_activate_duration_estimate);
+}
+
 }  // namespace cc

cc/debug/rendering_stats_instrumentation.h

@@ -19,10 +19,10 @@ class CC_EXPORT RenderingStatsInstrumentation {
   virtual ~RenderingStatsInstrumentation();
 
   // Return copy of current main thread rendering stats.
-  MainThreadRenderingStats main_thread_rendering_stats();
+  RenderingStats::MainThreadRenderingStats main_thread_rendering_stats();
 
   // Return copy of current impl thread rendering stats.
-  ImplThreadRenderingStats impl_thread_rendering_stats();
+  RenderingStats::ImplThreadRenderingStats impl_thread_rendering_stats();
 
   // Return the accumulated, combined rendering stats.
   RenderingStats GetRenderingStats();
@@ -54,15 +54,23 @@ class CC_EXPORT RenderingStatsInstrumentation {
   void AddAnalysis(base::TimeDelta duration, int64 pixels);
   void AddVisibleContentArea(int64 area);
   void AddApproximatedVisibleContentArea(int64 area);
+  void AddDrawDuration(base::TimeDelta draw_duration,
+                       base::TimeDelta draw_duration_estimate);
+  void AddBeginMainFrameToCommitDuration(
+      base::TimeDelta begin_main_frame_to_commit_duration,
+      base::TimeDelta begin_main_frame_to_commit_duration_estimate);
+  void AddCommitToActivateDuration(
+      base::TimeDelta commit_to_activate_duration,
+      base::TimeDelta commit_to_activate_duration_estimate);
 
  protected:
   RenderingStatsInstrumentation();
 
  private:
-  MainThreadRenderingStats main_thread_rendering_stats_;
-  MainThreadRenderingStats main_thread_rendering_stats_accu_;
-  ImplThreadRenderingStats impl_thread_rendering_stats_;
-  ImplThreadRenderingStats impl_thread_rendering_stats_accu_;
+  RenderingStats::MainThreadRenderingStats main_thread_rendering_stats_;
+  RenderingStats::MainThreadRenderingStats main_thread_rendering_stats_accu_;
+  RenderingStats::ImplThreadRenderingStats impl_thread_rendering_stats_;
+  RenderingStats::ImplThreadRenderingStats impl_thread_rendering_stats_accu_;
 
   bool record_rendering_stats_;
 

cc/debug/rendering_stats_unittest.cc

+// Copyright 2014 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 "base/time/time.h"
+#include "base/values.h"
+#include "cc/debug/rendering_stats.h"
+#include "testing/gtest/include/gtest/gtest.h"
+
+namespace cc {
+namespace {
+
+void CompareDoubleValue(const base::ListValue& list_value,
+                        int index,
+                        double expected_value) {
+  double value;
+  EXPECT_TRUE(list_value.GetDouble(index, &value));
+  EXPECT_EQ(expected_value, value);
+}
+
+TEST(RenderingStatsTest, TimeDeltaListEmpty) {
+  RenderingStats::TimeDeltaList time_delta_list;
+  scoped_ptr<base::ListValue> list_value =
+      time_delta_list.AsListValueInMilliseconds();
+  EXPECT_TRUE(list_value->empty());
+  EXPECT_EQ(0ul, list_value->GetSize());
+}
+
+TEST(RenderingStatsTest, TimeDeltaListNonEmpty) {
+  RenderingStats::TimeDeltaList time_delta_list;
+  time_delta_list.Append(base::TimeDelta::FromMilliseconds(234));
+  time_delta_list.Append(base::TimeDelta::FromMilliseconds(827));
+
+  scoped_ptr<base::ListValue> list_value =
+      time_delta_list.AsListValueInMilliseconds();
+  EXPECT_FALSE(list_value->empty());
+  EXPECT_EQ(2ul, list_value->GetSize());
+
+  CompareDoubleValue(*list_value.get(), 0, 234);
+  CompareDoubleValue(*list_value.get(), 1, 827);
+}
+
+TEST(RenderingStatsTest, TimeDeltaListAdd) {
+  RenderingStats::TimeDeltaList time_delta_list_a;
+  time_delta_list_a.Append(base::TimeDelta::FromMilliseconds(810));
+  time_delta_list_a.Append(base::TimeDelta::FromMilliseconds(32));
+
+  RenderingStats::TimeDeltaList time_delta_list_b;
+  time_delta_list_b.Append(base::TimeDelta::FromMilliseconds(43));
+  time_delta_list_b.Append(base::TimeDelta::FromMilliseconds(938));
+  time_delta_list_b.Append(base::TimeDelta::FromMilliseconds(2));
+
+  time_delta_list_a.Add(time_delta_list_b);
+  scoped_ptr<base::ListValue> list_value =
+      time_delta_list_a.AsListValueInMilliseconds();
+  EXPECT_FALSE(list_value->empty());
+  EXPECT_EQ(5ul, list_value->GetSize());
+
+  CompareDoubleValue(*list_value.get(), 0, 810);
+  CompareDoubleValue(*list_value.get(), 1, 32);
+  CompareDoubleValue(*list_value.get(), 2, 43);
+  CompareDoubleValue(*list_value.get(), 3, 938);
+  CompareDoubleValue(*list_value.get(), 4, 2);
+}
+
+}  // namespace
+}  // namespace cc

cc/trees/proxy_timing_history.cc

@@ -4,6 +4,8 @@
 
 #include "cc/trees/proxy_timing_history.h"
 
+#include "base/metrics/histogram.h"
+
 const size_t kDurationHistorySize = 60;
 const double kCommitAndActivationDurationEstimationPercentile = 50.0;
 const double kDrawDurationEstimationPercentile = 100.0;
@@ -11,10 +13,13 @@ const int kDrawDurationEstimatePaddingInMicroseconds = 0;
 
 namespace cc {
 
-ProxyTimingHistory::ProxyTimingHistory()
+ProxyTimingHistory::ProxyTimingHistory(
+    RenderingStatsInstrumentation* rendering_stats_instrumentation)
     : draw_duration_history_(kDurationHistorySize),
       begin_main_frame_to_commit_duration_history_(kDurationHistorySize),
-      commit_to_activate_duration_history_(kDurationHistorySize) {}
+      commit_to_activate_duration_history_(kDurationHistorySize),
+      rendering_stats_instrumentation_(rendering_stats_instrumentation) {
+}
 
 ProxyTimingHistory::~ProxyTimingHistory() {}
 
@@ -43,24 +48,78 @@ void ProxyTimingHistory::DidBeginMainFrame() {
 
 void ProxyTimingHistory::DidCommit() {
   commit_complete_time_ = base::TimeTicks::HighResNow();
+  base::TimeDelta begin_main_frame_to_commit_duration =
+      commit_complete_time_ - begin_main_frame_sent_time_;
+
+  // Before adding the new data point to the timing history, see what we would
+  // have predicted for this frame. This allows us to keep track of the accuracy
+  // of our predictions.
+  rendering_stats_instrumentation_->AddBeginMainFrameToCommitDuration(
+      begin_main_frame_to_commit_duration,
+      BeginMainFrameToCommitDurationEstimate());
+
   begin_main_frame_to_commit_duration_history_.InsertSample(
-      commit_complete_time_ - begin_main_frame_sent_time_);
+      begin_main_frame_to_commit_duration);
 }
 
 void ProxyTimingHistory::DidActivateSyncTree() {
+  base::TimeDelta commit_to_activate_duration =
+      base::TimeTicks::HighResNow() - commit_complete_time_;
+
+  // Before adding the new data point to the timing history, see what we would
+  // have predicted for this frame. This allows us to keep track of the accuracy
+  // of our predictions.
+  rendering_stats_instrumentation_->AddCommitToActivateDuration(
+      commit_to_activate_duration, CommitToActivateDurationEstimate());
+
   commit_to_activate_duration_history_.InsertSample(
-      base::TimeTicks::HighResNow() - commit_complete_time_);
+      commit_to_activate_duration);
 }
 
 void ProxyTimingHistory::DidStartDrawing() {
   start_draw_time_ = base::TimeTicks::HighResNow();
 }
 
-base::TimeDelta ProxyTimingHistory::DidFinishDrawing() {
+void ProxyTimingHistory::DidFinishDrawing() {
   base::TimeDelta draw_duration =
       base::TimeTicks::HighResNow() - start_draw_time_;
+
+  // Before adding the new data point to the timing history, see what we would
+  // have predicted for this frame. This allows us to keep track of the accuracy
+  // of our predictions.
+  base::TimeDelta draw_duration_estimate = DrawDurationEstimate();
+  rendering_stats_instrumentation_->AddDrawDuration(draw_duration,
+                                                    draw_duration_estimate);
+
+  AddDrawDurationUMA(draw_duration, draw_duration_estimate);
+
   draw_duration_history_.InsertSample(draw_duration);
-  return draw_duration;
+}
+
+void ProxyTimingHistory::AddDrawDurationUMA(
+    base::TimeDelta draw_duration,
+    base::TimeDelta draw_duration_estimate) {
+  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);
 }
 
 }  // namespace cc

cc/trees/proxy_timing_history.h

@@ -6,12 +6,14 @@
 #define CC_TREES_PROXY_TIMING_HISTORY_H_
 
 #include "cc/base/rolling_time_delta_history.h"
+#include "cc/debug/rendering_stats_instrumentation.h"
 
 namespace cc {
 
 class ProxyTimingHistory {
  public:
-  ProxyTimingHistory();
+  explicit ProxyTimingHistory(
+      RenderingStatsInstrumentation* rendering_stats_instrumentation);
   ~ProxyTimingHistory();
 
   base::TimeDelta DrawDurationEstimate() const;
@@ -22,10 +24,12 @@ class ProxyTimingHistory {
   void DidCommit();
   void DidActivateSyncTree();
   void DidStartDrawing();
-  // Returns draw duration.
-  base::TimeDelta DidFinishDrawing();
+  void DidFinishDrawing();
 
  protected:
+  void AddDrawDurationUMA(base::TimeDelta draw_duration,
+                          base::TimeDelta draw_duration_estimate);
+
   RollingTimeDeltaHistory draw_duration_history_;
   RollingTimeDeltaHistory begin_main_frame_to_commit_duration_history_;
   RollingTimeDeltaHistory commit_to_activate_duration_history_;
@@ -33,6 +37,8 @@ class ProxyTimingHistory {
   base::TimeTicks begin_main_frame_sent_time_;
   base::TimeTicks commit_complete_time_;
   base::TimeTicks start_draw_time_;
+
+  RenderingStatsInstrumentation* rendering_stats_instrumentation_;
 };
 
 }  // namespace cc

cc/trees/thread_proxy.cc

@@ -11,7 +11,6 @@
 #include "base/bind.h"
 #include "base/debug/trace_event.h"
 #include "base/debug/trace_event_synthetic_delay.h"
-#include "base/metrics/histogram.h"
 #include "cc/base/swap_promise.h"
 #include "cc/debug/benchmark_instrumentation.h"
 #include "cc/debug/devtools_instrumentation.h"
@@ -78,7 +77,10 @@ ThreadProxy::ThreadProxy(
     : Proxy(main_task_runner, impl_task_runner),
       main_thread_only_vars_unsafe_(this, layer_tree_host->id()),
       main_thread_or_blocked_vars_unsafe_(layer_tree_host),
-      compositor_thread_vars_unsafe_(this, layer_tree_host->id()) {
+      compositor_thread_vars_unsafe_(
+          this,
+          layer_tree_host->id(),
+          layer_tree_host->rendering_stats_instrumentation()) {
   TRACE_EVENT0("cc", "ThreadProxy::ThreadProxy");
   DCHECK(IsMainThread());
   DCHECK(this->layer_tree_host());
@@ -111,8 +113,10 @@ ThreadProxy::MainThreadOrBlockedMainThread::contents_texture_manager() {
   return layer_tree_host->contents_texture_manager();
 }
 
-ThreadProxy::CompositorThreadOnly::CompositorThreadOnly(ThreadProxy* proxy,
-                                                        int layer_tree_host_id)
+ThreadProxy::CompositorThreadOnly::CompositorThreadOnly(
+    ThreadProxy* proxy,
+    int layer_tree_host_id,
+    RenderingStatsInstrumentation* rendering_stats_instrumentation)
     : layer_tree_host_id(layer_tree_host_id),
       contents_texture_manager(NULL),
       commit_completion_event(NULL),
@@ -127,6 +131,7 @@ ThreadProxy::CompositorThreadOnly::CompositorThreadOnly(ThreadProxy* proxy,
           base::Bind(&ThreadProxy::RenewTreePriority, base::Unretained(proxy)),
           base::TimeDelta::FromMilliseconds(
               kSmoothnessTakesPriorityExpirationDelay * 1000)),
+      timing_history(rendering_stats_instrumentation),
       weak_factory(proxy) {
 }
 
@@ -1053,7 +1058,6 @@ DrawResult ThreadProxy::DrawSwapInternal(bool forced_draw) {
   DCHECK(impl().layer_tree_host_impl.get());
 
   impl().timing_history.DidStartDrawing();
-  base::TimeDelta draw_duration_estimate = DrawDurationEstimate();
   base::AutoReset<bool> mark_inside(&impl().inside_draw, true);
 
   if (impl().did_commit_after_animating) {
@@ -1129,31 +1133,8 @@ DrawResult ThreadProxy::DrawSwapInternal(bool forced_draw) {
   if (draw_frame)
     CheckOutputSurfaceStatusOnImplThread();
 
-  if (result == DRAW_SUCCESS) {
-    base::TimeDelta draw_duration = impl().timing_history.DidFinishDrawing();
-
-    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);
-  }
+  if (result == DRAW_SUCCESS)
+    impl().timing_history.DidFinishDrawing();
 
   DCHECK_NE(INVALID_RESULT, result);
   return result;

cc/trees/thread_proxy.h

@@ -97,7 +97,10 @@ class CC_EXPORT ThreadProxy : public Proxy,
   struct ReadbackRequest;
 
   struct CompositorThreadOnly {
-    CompositorThreadOnly(ThreadProxy* proxy, int layer_tree_host_id);
+    CompositorThreadOnly(
+        ThreadProxy* proxy,
+        int layer_tree_host_id,
+        RenderingStatsInstrumentation* rendering_stats_instrumentation);
     ~CompositorThreadOnly();
 
     const int layer_tree_host_id;