Index: cc/scheduler/compositor_timing_history.cc |
diff --git a/cc/scheduler/compositor_timing_history.cc b/cc/scheduler/compositor_timing_history.cc |
index e82356baeb412e8c427415134fef4dbb55b449d4..d21696dca6ae3afb3894babbe4cbfb3e222ab411 100644 |
--- a/cc/scheduler/compositor_timing_history.cc |
+++ b/cc/scheduler/compositor_timing_history.cc |
@@ -14,6 +14,14 @@ class CompositorTimingHistory::UMAReporter { |
public: |
virtual ~UMAReporter() {} |
+ // Throughput measurements |
+ virtual void AddBeginMainFrameIntervalCritical(base::TimeDelta interval) = 0; |
+ virtual void AddBeginMainFrameIntervalNotCritical( |
+ base::TimeDelta interval) = 0; |
+ virtual void AddCommitInterval(base::TimeDelta interval) = 0; |
+ virtual void AddDrawInterval(base::TimeDelta interval) = 0; |
+ |
+ // Latency measurements |
virtual void AddBeginMainFrameToCommitDuration(base::TimeDelta duration, |
base::TimeDelta estimate, |
bool affects_estimate) = 0; |
@@ -130,6 +138,26 @@ class RendererUMAReporter : public CompositorTimingHistory::UMAReporter { |
public: |
~RendererUMAReporter() override {} |
+ void AddBeginMainFrameIntervalCritical(base::TimeDelta interval) override { |
+ UMA_HISTOGRAM_CUSTOM_TIMES_MICROS( |
+ "Scheduling.Renderer.BeginMainFrameIntervalCritical", interval); |
+ } |
+ |
+ void AddBeginMainFrameIntervalNotCritical(base::TimeDelta interval) override { |
+ UMA_HISTOGRAM_CUSTOM_TIMES_MICROS( |
+ "Scheduling.Renderer.BeginMainFrameIntervalNotCritical", interval); |
+ } |
+ |
+ void AddCommitInterval(base::TimeDelta interval) override { |
+ UMA_HISTOGRAM_CUSTOM_TIMES_MICROS("Scheduling.Renderer.CommitInterval", |
+ interval); |
+ } |
+ |
+ void AddDrawInterval(base::TimeDelta interval) override { |
+ UMA_HISTOGRAM_CUSTOM_TIMES_MICROS("Scheduling.Renderer.DrawInterval", |
+ interval); |
+ } |
+ |
void AddBeginMainFrameToCommitDuration(base::TimeDelta duration, |
base::TimeDelta estimate, |
bool affects_estimate) override { |
@@ -191,6 +219,26 @@ class BrowserUMAReporter : public CompositorTimingHistory::UMAReporter { |
public: |
~BrowserUMAReporter() override {} |
+ void AddBeginMainFrameIntervalCritical(base::TimeDelta interval) override { |
+ UMA_HISTOGRAM_CUSTOM_TIMES_MICROS( |
+ "Scheduling.Browser.BeginMainFrameIntervalCritical", interval); |
+ } |
+ |
+ void AddBeginMainFrameIntervalNotCritical(base::TimeDelta interval) override { |
+ UMA_HISTOGRAM_CUSTOM_TIMES_MICROS( |
+ "Scheduling.Browser.BeginMainFrameIntervalNotCritical", interval); |
+ } |
+ |
+ void AddCommitInterval(base::TimeDelta interval) override { |
+ UMA_HISTOGRAM_CUSTOM_TIMES_MICROS("Scheduling.Browser.CommitInterval", |
+ interval); |
+ } |
+ |
+ void AddDrawInterval(base::TimeDelta interval) override { |
+ UMA_HISTOGRAM_CUSTOM_TIMES_MICROS("Scheduling.Browser.DrawInterval", |
+ interval); |
+ } |
+ |
void AddBeginMainFrameToCommitDuration(base::TimeDelta duration, |
base::TimeDelta estimate, |
bool affects_estimate) override { |
@@ -251,6 +299,11 @@ class BrowserUMAReporter : public CompositorTimingHistory::UMAReporter { |
class NullUMAReporter : public CompositorTimingHistory::UMAReporter { |
public: |
~NullUMAReporter() override {} |
+ void AddBeginMainFrameIntervalCritical(base::TimeDelta interval) override {} |
+ void AddBeginMainFrameIntervalNotCritical(base::TimeDelta interval) override { |
+ } |
+ void AddCommitInterval(base::TimeDelta interval) override {} |
+ void AddDrawInterval(base::TimeDelta interval) override {} |
void AddBeginMainFrameToCommitDuration(base::TimeDelta duration, |
base::TimeDelta estimate, |
bool affects_estimate) override {} |
@@ -283,6 +336,10 @@ CompositorTimingHistory::CompositorTimingHistory( |
UMACategory uma_category, |
RenderingStatsInstrumentation* rendering_stats_instrumentation) |
: enabled_(false), |
+ did_send_begin_main_frame_(false), |
+ begin_main_frame_needed_continuously_(false), |
+ begin_main_frame_committing_continuously_(false), |
+ compositor_drawing_continuously_(false), |
begin_main_frame_sent_to_commit_duration_history_(kDurationHistorySize), |
begin_main_frame_queue_duration_critical_history_(kDurationHistorySize), |
begin_main_frame_queue_duration_not_critical_history_( |
@@ -338,6 +395,28 @@ void CompositorTimingHistory::SetRecordingEnabled(bool enabled) { |
enabled_ = enabled; |
} |
+void CompositorTimingHistory::SetBeginMainFrameNeededContinuously(bool active) { |
+ if (active == begin_main_frame_needed_continuously_) |
+ return; |
+ begin_main_frame_end_time_prev_ = base::TimeTicks(); |
+ begin_main_frame_needed_continuously_ = active; |
+} |
+ |
+void CompositorTimingHistory::SetBeginMainFrameCommittingContinuously( |
+ bool active) { |
+ if (active == begin_main_frame_committing_continuously_) |
+ return; |
+ new_active_tree_draw_end_time_prev_ = base::TimeTicks(); |
+ begin_main_frame_committing_continuously_ = active; |
+} |
+ |
+void CompositorTimingHistory::SetCompositorDrawingContinuously(bool active) { |
+ if (active == compositor_drawing_continuously_) |
+ return; |
+ draw_end_time_prev_ = base::TimeTicks(); |
+ compositor_drawing_continuously_ = active; |
+} |
+ |
base::TimeDelta |
CompositorTimingHistory::BeginMainFrameToCommitDurationEstimate() const { |
return begin_main_frame_sent_to_commit_duration_history_.Percentile( |
@@ -382,10 +461,40 @@ base::TimeDelta CompositorTimingHistory::DrawDurationEstimate() const { |
return draw_duration_history_.Percentile(kDrawEstimationPercentile); |
} |
+void CompositorTimingHistory::WillBeginImplFrame( |
+ bool new_active_tree_is_likely) { |
+ // The check for whether a BeginMainFrame was sent anytime between two |
+ // BeginImplFrames protects us from not detecting a fast main thread that |
+ // does all it's work and goes idle in between BeginImplFrames. |
+ // For example, this may happen if an animation is being driven with |
+ // setInterval(17) or if input events just happen to arrive in the |
+ // middle of every frame. |
+ if (!new_active_tree_is_likely && !did_send_begin_main_frame_) { |
+ SetBeginMainFrameNeededContinuously(false); |
+ SetBeginMainFrameCommittingContinuously(false); |
+ } |
+ |
+ did_send_begin_main_frame_ = false; |
+} |
+ |
+void CompositorTimingHistory::WillFinishImplFrame(bool needs_redraw) { |
+ if (!needs_redraw) |
+ SetCompositorDrawingContinuously(false); |
+} |
+ |
+void CompositorTimingHistory::BeginImplFrameNotExpectedSoon() { |
+ SetBeginMainFrameNeededContinuously(false); |
+ SetBeginMainFrameCommittingContinuously(false); |
+ SetCompositorDrawingContinuously(false); |
+} |
+ |
void CompositorTimingHistory::WillBeginMainFrame(bool on_critical_path) { |
DCHECK_EQ(base::TimeTicks(), begin_main_frame_sent_time_); |
begin_main_frame_on_critical_path_ = on_critical_path; |
begin_main_frame_sent_time_ = Now(); |
+ |
+ did_send_begin_main_frame_ = true; |
+ SetBeginMainFrameNeededContinuously(true); |
} |
void CompositorTimingHistory::BeginMainFrameStarted( |
@@ -396,13 +505,19 @@ void CompositorTimingHistory::BeginMainFrameStarted( |
} |
void CompositorTimingHistory::BeginMainFrameAborted() { |
- DidCommit(); |
+ SetBeginMainFrameCommittingContinuously(false); |
+ DidBeginMainFrame(); |
} |
void CompositorTimingHistory::DidCommit() { |
+ SetBeginMainFrameCommittingContinuously(true); |
+ DidBeginMainFrame(); |
+} |
+ |
+void CompositorTimingHistory::DidBeginMainFrame() { |
DCHECK_NE(base::TimeTicks(), begin_main_frame_sent_time_); |
- commit_time_ = Now(); |
+ begin_main_frame_end_time_ = Now(); |
// If the BeginMainFrame start time isn't know, assume it was immediate |
// for scheduling purposes, but don't report it for UMA to avoid skewing |
@@ -413,11 +528,11 @@ void CompositorTimingHistory::DidCommit() { |
begin_main_frame_start_time_ = begin_main_frame_sent_time_; |
base::TimeDelta begin_main_frame_sent_to_commit_duration = |
- commit_time_ - begin_main_frame_sent_time_; |
+ begin_main_frame_end_time_ - begin_main_frame_sent_time_; |
base::TimeDelta begin_main_frame_queue_duration = |
begin_main_frame_start_time_ - begin_main_frame_sent_time_; |
base::TimeDelta begin_main_frame_start_to_commit_duration = |
- commit_time_ - begin_main_frame_start_time_; |
+ begin_main_frame_end_time_ - begin_main_frame_start_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 |
@@ -458,34 +573,46 @@ void CompositorTimingHistory::DidCommit() { |
begin_main_frame_start_to_commit_duration); |
} |
+ if (begin_main_frame_needed_continuously_) { |
+ if (!begin_main_frame_end_time_prev_.is_null()) { |
+ base::TimeDelta commit_interval = |
+ begin_main_frame_end_time_ - begin_main_frame_end_time_prev_; |
+ if (begin_main_frame_on_critical_path_) |
+ uma_reporter_->AddBeginMainFrameIntervalCritical(commit_interval); |
+ else |
+ uma_reporter_->AddBeginMainFrameIntervalNotCritical(commit_interval); |
+ } |
+ begin_main_frame_end_time_prev_ = begin_main_frame_end_time_; |
+ } |
+ |
begin_main_frame_sent_time_ = base::TimeTicks(); |
begin_main_frame_start_time_ = base::TimeTicks(); |
} |
void CompositorTimingHistory::WillPrepareTiles() { |
- DCHECK_EQ(base::TimeTicks(), start_prepare_tiles_time_); |
- start_prepare_tiles_time_ = Now(); |
+ DCHECK_EQ(base::TimeTicks(), prepare_tiles_start_time_); |
+ prepare_tiles_start_time_ = Now(); |
} |
void CompositorTimingHistory::DidPrepareTiles() { |
- DCHECK_NE(base::TimeTicks(), start_prepare_tiles_time_); |
+ DCHECK_NE(base::TimeTicks(), prepare_tiles_start_time_); |
- base::TimeDelta prepare_tiles_duration = Now() - start_prepare_tiles_time_; |
+ base::TimeDelta prepare_tiles_duration = Now() - prepare_tiles_start_time_; |
uma_reporter_->AddPrepareTilesDuration( |
prepare_tiles_duration, PrepareTilesDurationEstimate(), enabled_); |
if (enabled_) |
prepare_tiles_duration_history_.InsertSample(prepare_tiles_duration); |
- start_prepare_tiles_time_ = base::TimeTicks(); |
+ prepare_tiles_start_time_ = base::TimeTicks(); |
} |
void CompositorTimingHistory::ReadyToActivate() { |
// We only care about the first ready to activate signal |
// after a commit. |
- if (commit_time_ == base::TimeTicks()) |
+ if (begin_main_frame_end_time_ == base::TimeTicks()) |
return; |
- base::TimeDelta time_since_commit = Now() - commit_time_; |
+ base::TimeDelta time_since_commit = Now() - begin_main_frame_end_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 |
@@ -503,34 +630,35 @@ void CompositorTimingHistory::ReadyToActivate() { |
time_since_commit); |
} |
- commit_time_ = base::TimeTicks(); |
+ begin_main_frame_end_time_ = base::TimeTicks(); |
} |
void CompositorTimingHistory::WillActivate() { |
- DCHECK_EQ(base::TimeTicks(), start_activate_time_); |
- start_activate_time_ = Now(); |
+ DCHECK_EQ(base::TimeTicks(), activate_start_time_); |
+ activate_start_time_ = Now(); |
} |
void CompositorTimingHistory::DidActivate() { |
- DCHECK_NE(base::TimeTicks(), start_activate_time_); |
- base::TimeDelta activate_duration = Now() - start_activate_time_; |
+ DCHECK_NE(base::TimeTicks(), activate_start_time_); |
+ base::TimeDelta activate_duration = Now() - activate_start_time_; |
uma_reporter_->AddActivateDuration(activate_duration, |
ActivateDurationEstimate(), enabled_); |
if (enabled_) |
activate_duration_history_.InsertSample(activate_duration); |
- start_activate_time_ = base::TimeTicks(); |
+ activate_start_time_ = base::TimeTicks(); |
} |
void CompositorTimingHistory::WillDraw() { |
- DCHECK_EQ(base::TimeTicks(), start_draw_time_); |
- start_draw_time_ = Now(); |
+ DCHECK_EQ(base::TimeTicks(), draw_start_time_); |
+ draw_start_time_ = Now(); |
} |
-void CompositorTimingHistory::DidDraw() { |
- DCHECK_NE(base::TimeTicks(), start_draw_time_); |
- base::TimeDelta draw_duration = Now() - start_draw_time_; |
+void CompositorTimingHistory::DidDraw(bool used_new_active_tree) { |
+ DCHECK_NE(base::TimeTicks(), draw_start_time_); |
+ base::TimeTicks draw_end_time = Now(); |
+ base::TimeDelta draw_duration = draw_end_time - draw_start_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 |
@@ -545,7 +673,23 @@ void CompositorTimingHistory::DidDraw() { |
draw_duration_history_.InsertSample(draw_duration); |
} |
- start_draw_time_ = base::TimeTicks(); |
+ SetCompositorDrawingContinuously(true); |
+ if (!draw_end_time_prev_.is_null()) { |
+ base::TimeDelta draw_interval = draw_end_time - draw_end_time_prev_; |
+ uma_reporter_->AddDrawInterval(draw_interval); |
+ } |
+ draw_end_time_prev_ = draw_end_time; |
+ |
+ if (begin_main_frame_committing_continuously_ && used_new_active_tree) { |
+ if (!new_active_tree_draw_end_time_prev_.is_null()) { |
+ base::TimeDelta draw_interval = |
+ draw_end_time - new_active_tree_draw_end_time_prev_; |
+ uma_reporter_->AddCommitInterval(draw_interval); |
+ } |
+ new_active_tree_draw_end_time_prev_ = draw_end_time; |
+ } |
+ |
+ draw_start_time_ = base::TimeTicks(); |
} |
void CompositorTimingHistory::DidSwapBuffers() { |