diff options
author | dominikg@chromium.org <dominikg@chromium.org@0039d316-1c4b-4281-b951-d872f2087c98> | 2014-07-21 15:08:06 +0000 |
---|---|---|
committer | dominikg@chromium.org <dominikg@chromium.org@0039d316-1c4b-4281-b951-d872f2087c98> | 2014-07-21 15:08:06 +0000 |
commit | dfb6e5ee242f8d672ba1ffb3ca39b06be5ce1332 (patch) | |
tree | 563d684ce17240697ad5ec8b0bff64c24873c131 | |
parent | c1b7d3524c10d8405d95bc13d12ae196b1de8300 (diff) | |
download | chromium_src-dfb6e5ee242f8d672ba1ffb3ca39b06be5ce1332.zip chromium_src-dfb6e5ee242f8d672ba1ffb3ca39b06be5ce1332.tar.gz chromium_src-dfb6e5ee242f8d672ba1ffb3ca39b06be5ce1332.tar.bz2 |
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
-rw-r--r-- | cc/cc_tests.gyp | 1 | ||||
-rw-r--r-- | cc/debug/benchmark_instrumentation.cc | 6 | ||||
-rw-r--r-- | cc/debug/benchmark_instrumentation.h | 6 | ||||
-rw-r--r-- | cc/debug/rendering_stats.cc | 80 | ||||
-rw-r--r-- | cc/debug/rendering_stats.h | 80 | ||||
-rw-r--r-- | cc/debug/rendering_stats_instrumentation.cc | 46 | ||||
-rw-r--r-- | cc/debug/rendering_stats_instrumentation.h | 20 | ||||
-rw-r--r-- | cc/debug/rendering_stats_unittest.cc | 67 | ||||
-rw-r--r-- | cc/trees/proxy_timing_history.cc | 71 | ||||
-rw-r--r-- | cc/trees/proxy_timing_history.h | 12 | ||||
-rw-r--r-- | cc/trees/thread_proxy.cc | 41 | ||||
-rw-r--r-- | cc/trees/thread_proxy.h | 5 |
12 files changed, 345 insertions, 90 deletions
diff --git a/cc/cc_tests.gyp b/cc/cc_tests.gyp index 763bda9..a58342c 100644 --- a/cc/cc_tests.gyp +++ b/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', diff --git a/cc/debug/benchmark_instrumentation.cc b/cc/debug/benchmark_instrumentation.cc index 8d197b9..adc969b 100644 --- a/cc/debug/benchmark_instrumentation.cc +++ b/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, diff --git a/cc/debug/benchmark_instrumentation.h b/cc/debug/benchmark_instrumentation.h index 59d6751..3a6b03d8 100644 --- a/cc/debug/benchmark_instrumentation.h +++ b/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 diff --git a/cc/debug/rendering_stats.cc b/cc/debug/rendering_stats.cc index 3e123b66..47bc7c7 100644 --- a/cc/debug/rendering_stats.cc +++ b/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) { diff --git a/cc/debug/rendering_stats.h b/cc/debug/rendering_stats.h index bd3b7c7..a6edff1 100644 --- a/cc/debug/rendering_stats.h +++ b/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; diff --git a/cc/debug/rendering_stats_instrumentation.cc b/cc/debug/rendering_stats_instrumentation.cc index 9655241..01499d2 100644 --- a/cc/debug/rendering_stats_instrumentation.cc +++ b/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 diff --git a/cc/debug/rendering_stats_instrumentation.h b/cc/debug/rendering_stats_instrumentation.h index 6640131..208c1a3 100644 --- a/cc/debug/rendering_stats_instrumentation.h +++ b/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_; diff --git a/cc/debug/rendering_stats_unittest.cc b/cc/debug/rendering_stats_unittest.cc new file mode 100644 index 0000000..ea0276c --- /dev/null +++ b/cc/debug/rendering_stats_unittest.cc @@ -0,0 +1,67 @@ +// 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 diff --git a/cc/trees/proxy_timing_history.cc b/cc/trees/proxy_timing_history.cc index 6c45f71..9020ad5 100644 --- a/cc/trees/proxy_timing_history.cc +++ b/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 diff --git a/cc/trees/proxy_timing_history.h b/cc/trees/proxy_timing_history.h index 9230e8a..aa213b6 100644 --- a/cc/trees/proxy_timing_history.h +++ b/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 diff --git a/cc/trees/thread_proxy.cc b/cc/trees/thread_proxy.cc index e505e18..0726432 100644 --- a/cc/trees/thread_proxy.cc +++ b/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; diff --git a/cc/trees/thread_proxy.h b/cc/trees/thread_proxy.h index dd21c00..a28068e 100644 --- a/cc/trees/thread_proxy.h +++ b/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; |