cc: Fix best-effort sync scroll regression.

Considers the BeginMainFrame fast if it responds before
the next BeginImplFrame, rather than by the deadline.

To prevent estimates from getting stuck because the
scheduler never sends a certain type of BeginMainFrame
(critical or non critical), this patch also changes
estimates to reflect the following two assumptions:

1) Critical BeginMainFrames will be fast if new
   BeginMainFrames of any type are fast.
2) Non critical BeginMainFrames will be slow if new
   BeginMainFrames of any type are slow.

BUG=582749
CQ_INCLUDE_TRYBOTS=tryserver.blink:linux_blink_rel

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

Cr-Commit-Position: refs/heads/master@{#373975}

4 files changed, 166 insertions, 20 deletions

diff --git a/cc/scheduler/compositor_timing_history.cc b/cc/scheduler/compositor_timing_history.cc
index f3ac067..f546062 100644
--- a/cc/scheduler/compositor_timing_history.cc
+++ b/cc/scheduler/compositor_timing_history.cc
@@ -60,6 +60,7 @@ namespace {
 // TODO(brianderson): Fine tune the percentiles below.
 const size_t kDurationHistorySize = 60;
 const double kBeginMainFrameToCommitEstimationPercentile = 90.0;
+const double kBeginMainFrameQueueDurationEstimationPercentile = 90.0;
 const double kBeginMainFrameQueueDurationCriticalEstimationPercentile = 90.0;
 const double kBeginMainFrameQueueDurationNotCriticalEstimationPercentile = 90.0;
 const double kBeginMainFrameStartToCommitEstimationPercentile = 90.0;
@@ -344,6 +345,7 @@ CompositorTimingHistory::CompositorTimingHistory(
       begin_main_frame_committing_continuously_(false),
       compositor_drawing_continuously_(false),
       begin_main_frame_sent_to_commit_duration_history_(kDurationHistorySize),
+      begin_main_frame_queue_duration_history_(kDurationHistorySize),
       begin_main_frame_queue_duration_critical_history_(kDurationHistorySize),
       begin_main_frame_queue_duration_not_critical_history_(
           kDurationHistorySize),
@@ -428,15 +430,27 @@ CompositorTimingHistory::BeginMainFrameToCommitDurationEstimate() const {
 
 base::TimeDelta
 CompositorTimingHistory::BeginMainFrameQueueDurationCriticalEstimate() const {
-  return begin_main_frame_queue_duration_critical_history_.Percentile(
-      kBeginMainFrameQueueDurationCriticalEstimationPercentile);
+  base::TimeDelta all = begin_main_frame_queue_duration_history_.Percentile(
+      kBeginMainFrameQueueDurationEstimationPercentile);
+  base::TimeDelta critical =
+      begin_main_frame_queue_duration_critical_history_.Percentile(
+          kBeginMainFrameQueueDurationCriticalEstimationPercentile);
+  // Return the min since critical BeginMainFrames are likely fast if
+  // the non critical ones are.
+  return std::min(critical, all);
 }
 
 base::TimeDelta
 CompositorTimingHistory::BeginMainFrameQueueDurationNotCriticalEstimate()
     const {
-  return begin_main_frame_queue_duration_not_critical_history_.Percentile(
-      kBeginMainFrameQueueDurationNotCriticalEstimationPercentile);
+  base::TimeDelta all = begin_main_frame_queue_duration_history_.Percentile(
+      kBeginMainFrameQueueDurationEstimationPercentile);
+  base::TimeDelta not_critical =
+      begin_main_frame_queue_duration_not_critical_history_.Percentile(
+          kBeginMainFrameQueueDurationNotCriticalEstimationPercentile);
+  // Return the max since, non critical BeginMainFrames are likely slow if
+  // the critical ones are.
+  return std::max(not_critical, all);
 }
 
 base::TimeDelta
@@ -565,6 +579,8 @@ void CompositorTimingHistory::DidBeginMainFrame() {
   if (enabled_) {
     begin_main_frame_sent_to_commit_duration_history_.InsertSample(
         begin_main_frame_sent_to_commit_duration);
+    begin_main_frame_queue_duration_history_.InsertSample(
+        begin_main_frame_queue_duration);
     if (begin_main_frame_on_critical_path_) {
       begin_main_frame_queue_duration_critical_history_.InsertSample(
           begin_main_frame_queue_duration);
diff --git a/cc/scheduler/compositor_timing_history.h b/cc/scheduler/compositor_timing_history.h
index b64dc056..11dfc00 100644
--- a/cc/scheduler/compositor_timing_history.h
+++ b/cc/scheduler/compositor_timing_history.h
@@ -91,6 +91,7 @@ class CC_EXPORT CompositorTimingHistory {
   base::TimeTicks draw_end_time_prev_;
 
   RollingTimeDeltaHistory begin_main_frame_sent_to_commit_duration_history_;
+  RollingTimeDeltaHistory begin_main_frame_queue_duration_history_;
   RollingTimeDeltaHistory begin_main_frame_queue_duration_critical_history_;
   RollingTimeDeltaHistory begin_main_frame_queue_duration_not_critical_history_;
   RollingTimeDeltaHistory begin_main_frame_start_to_commit_duration_history_;
diff --git a/cc/scheduler/compositor_timing_history_unittest.cc b/cc/scheduler/compositor_timing_history_unittest.cc
index 2cbc8a8..900367f 100644
--- a/cc/scheduler/compositor_timing_history_unittest.cc
+++ b/cc/scheduler/compositor_timing_history_unittest.cc
@@ -51,9 +51,11 @@ base::TimeTicks TestCompositorTimingHistory::Now() const {
   return test_->Now();
 }
 
-TEST_F(CompositorTimingHistoryTest, AllSequentialCommit_Critical) {
+TEST_F(CompositorTimingHistoryTest, AllSequential_Commit) {
   base::TimeDelta one_second = base::TimeDelta::FromSeconds(1);
 
+  // Critical BeginMainFrames are faster than non critical ones,
+  // as expected.
   base::TimeDelta begin_main_frame_queue_duration =
       base::TimeDelta::FromMilliseconds(1);
   base::TimeDelta begin_main_frame_start_to_commit_duration =
@@ -89,8 +91,9 @@ TEST_F(CompositorTimingHistoryTest, AllSequentialCommit_Critical) {
 
   EXPECT_EQ(begin_main_frame_queue_duration,
             timing_history_.BeginMainFrameQueueDurationCriticalEstimate());
-  EXPECT_EQ(base::TimeDelta(),
+  EXPECT_EQ(begin_main_frame_queue_duration,
             timing_history_.BeginMainFrameQueueDurationNotCriticalEstimate());
+
   EXPECT_EQ(begin_main_frame_start_to_commit_duration,
             timing_history_.BeginMainFrameStartToCommitDurationEstimate());
 
@@ -108,8 +111,7 @@ TEST_F(CompositorTimingHistoryTest, AllSequentialCommit_Critical) {
   EXPECT_EQ(draw_duration, timing_history_.DrawDurationEstimate());
 }
 
-TEST_F(CompositorTimingHistoryTest,
-       AllSequentialBeginMainFrameAborted_NotCritical) {
+TEST_F(CompositorTimingHistoryTest, AllSequential_BeginMainFrameAborted) {
   base::TimeDelta one_second = base::TimeDelta::FromSeconds(1);
 
   base::TimeDelta begin_main_frame_queue_duration =
@@ -124,7 +126,7 @@ TEST_F(CompositorTimingHistoryTest,
   base::TimeDelta activate_duration = base::TimeDelta::FromMilliseconds(4);
   base::TimeDelta draw_duration = base::TimeDelta::FromMilliseconds(5);
 
-  timing_history_.WillBeginMainFrame(false);
+  timing_history_.WillBeginMainFrame(true);
   AdvanceNowBy(begin_main_frame_queue_duration);
   timing_history_.BeginMainFrameStarted(Now());
   AdvanceNowBy(begin_main_frame_start_to_commit_duration);
@@ -146,10 +148,11 @@ TEST_F(CompositorTimingHistoryTest,
   AdvanceNowBy(draw_duration);
   timing_history_.DidDraw(true);
 
-  EXPECT_EQ(base::TimeDelta(),
+  EXPECT_EQ(begin_main_frame_queue_duration,
             timing_history_.BeginMainFrameQueueDurationCriticalEstimate());
   EXPECT_EQ(begin_main_frame_queue_duration,
             timing_history_.BeginMainFrameQueueDurationNotCriticalEstimate());
+
   EXPECT_EQ(begin_main_frame_start_to_commit_duration,
             timing_history_.BeginMainFrameStartToCommitDurationEstimate());
 
@@ -167,5 +170,132 @@ TEST_F(CompositorTimingHistoryTest,
   EXPECT_EQ(draw_duration, timing_history_.DrawDurationEstimate());
 }
 
+TEST_F(CompositorTimingHistoryTest, BeginMainFrame_CriticalFaster) {
+  // Critical BeginMainFrames are faster than non critical ones.
+  base::TimeDelta begin_main_frame_queue_duration_critical =
+      base::TimeDelta::FromMilliseconds(1);
+  base::TimeDelta begin_main_frame_queue_duration_not_critical =
+      base::TimeDelta::FromMilliseconds(2);
+  base::TimeDelta begin_main_frame_start_to_commit_duration =
+      base::TimeDelta::FromMilliseconds(1);
+
+  timing_history_.WillBeginMainFrame(true);
+  AdvanceNowBy(begin_main_frame_queue_duration_critical);
+  timing_history_.BeginMainFrameStarted(Now());
+  AdvanceNowBy(begin_main_frame_start_to_commit_duration);
+  timing_history_.BeginMainFrameAborted();
+
+  timing_history_.WillBeginMainFrame(false);
+  AdvanceNowBy(begin_main_frame_queue_duration_not_critical);
+  timing_history_.BeginMainFrameStarted(Now());
+  AdvanceNowBy(begin_main_frame_start_to_commit_duration);
+  timing_history_.BeginMainFrameAborted();
+
+  // Since the critical BeginMainFrames are faster than non critical ones,
+  // the expectations are straightforward.
+  EXPECT_EQ(begin_main_frame_queue_duration_critical,
+            timing_history_.BeginMainFrameQueueDurationCriticalEstimate());
+  EXPECT_EQ(begin_main_frame_queue_duration_not_critical,
+            timing_history_.BeginMainFrameQueueDurationNotCriticalEstimate());
+  EXPECT_EQ(begin_main_frame_start_to_commit_duration,
+            timing_history_.BeginMainFrameStartToCommitDurationEstimate());
+
+  base::TimeDelta begin_main_frame_to_commit_duration_expected_ =
+      begin_main_frame_queue_duration_not_critical +
+      begin_main_frame_start_to_commit_duration;
+  EXPECT_EQ(begin_main_frame_to_commit_duration_expected_,
+            timing_history_.BeginMainFrameToCommitDurationEstimate());
+}
+
+TEST_F(CompositorTimingHistoryTest, BeginMainFrames_OldCriticalSlower) {
+  // Critical BeginMainFrames are slower than non critical ones,
+  // which is unexpected, but could occur if one type of frame
+  // hasn't been sent for a significant amount of time.
+  base::TimeDelta begin_main_frame_queue_duration_critical =
+      base::TimeDelta::FromMilliseconds(2);
+  base::TimeDelta begin_main_frame_queue_duration_not_critical =
+      base::TimeDelta::FromMilliseconds(1);
+  base::TimeDelta begin_main_frame_start_to_commit_duration =
+      base::TimeDelta::FromMilliseconds(1);
+
+  // A single critical frame that is slow.
+  timing_history_.WillBeginMainFrame(true);
+  AdvanceNowBy(begin_main_frame_queue_duration_critical);
+  timing_history_.BeginMainFrameStarted(Now());
+  AdvanceNowBy(begin_main_frame_start_to_commit_duration);
+  // BeginMainFrameAborted counts as a commit complete.
+  timing_history_.BeginMainFrameAborted();
+
+  // A bunch of faster non critical frames that are newer.
+  for (int i = 0; i < 100; i++) {
+    timing_history_.WillBeginMainFrame(false);
+    AdvanceNowBy(begin_main_frame_queue_duration_not_critical);
+    timing_history_.BeginMainFrameStarted(Now());
+    AdvanceNowBy(begin_main_frame_start_to_commit_duration);
+    // BeginMainFrameAborted counts as a commit complete.
+    timing_history_.BeginMainFrameAborted();
+  }
+
+  // Recent fast non critical BeginMainFrames should result in the
+  // critical estimate also being fast.
+  EXPECT_EQ(begin_main_frame_queue_duration_not_critical,
+            timing_history_.BeginMainFrameQueueDurationCriticalEstimate());
+  EXPECT_EQ(begin_main_frame_queue_duration_not_critical,
+            timing_history_.BeginMainFrameQueueDurationNotCriticalEstimate());
+
+  EXPECT_EQ(begin_main_frame_start_to_commit_duration,
+            timing_history_.BeginMainFrameStartToCommitDurationEstimate());
+
+  base::TimeDelta begin_main_frame_to_commit_duration_expected_ =
+      begin_main_frame_queue_duration_not_critical +
+      begin_main_frame_start_to_commit_duration;
+  EXPECT_EQ(begin_main_frame_to_commit_duration_expected_,
+            timing_history_.BeginMainFrameToCommitDurationEstimate());
+}
+
+TEST_F(CompositorTimingHistoryTest, BeginMainFrames_NewCriticalSlower) {
+  // Critical BeginMainFrames are slower than non critical ones,
+  // which is unexpected, but could occur if one type of frame
+  // hasn't been sent for a significant amount of time.
+  base::TimeDelta begin_main_frame_queue_duration_critical =
+      base::TimeDelta::FromMilliseconds(2);
+  base::TimeDelta begin_main_frame_queue_duration_not_critical =
+      base::TimeDelta::FromMilliseconds(1);
+  base::TimeDelta begin_main_frame_start_to_commit_duration =
+      base::TimeDelta::FromMilliseconds(1);
+
+  // A single non critical frame that is fast.
+  timing_history_.WillBeginMainFrame(false);
+  AdvanceNowBy(begin_main_frame_queue_duration_not_critical);
+  timing_history_.BeginMainFrameStarted(Now());
+  AdvanceNowBy(begin_main_frame_start_to_commit_duration);
+  timing_history_.BeginMainFrameAborted();
+
+  // A bunch of slower critical frames that are newer.
+  for (int i = 0; i < 100; i++) {
+    timing_history_.WillBeginMainFrame(true);
+    AdvanceNowBy(begin_main_frame_queue_duration_critical);
+    timing_history_.BeginMainFrameStarted(Now());
+    AdvanceNowBy(begin_main_frame_start_to_commit_duration);
+    timing_history_.BeginMainFrameAborted();
+  }
+
+  // Recent slow critical BeginMainFrames should result in the
+  // not critical estimate also being slow.
+  EXPECT_EQ(begin_main_frame_queue_duration_critical,
+            timing_history_.BeginMainFrameQueueDurationCriticalEstimate());
+  EXPECT_EQ(begin_main_frame_queue_duration_critical,
+            timing_history_.BeginMainFrameQueueDurationNotCriticalEstimate());
+
+  EXPECT_EQ(begin_main_frame_start_to_commit_duration,
+            timing_history_.BeginMainFrameStartToCommitDurationEstimate());
+
+  base::TimeDelta begin_main_frame_to_commit_duration_expected_ =
+      begin_main_frame_queue_duration_critical +
+      begin_main_frame_start_to_commit_duration;
+  EXPECT_EQ(begin_main_frame_to_commit_duration_expected_,
+            timing_history_.BeginMainFrameToCommitDurationEstimate());
+}
+
 }  // namespace
 }  // namespace cc
diff --git a/cc/scheduler/scheduler.cc b/cc/scheduler/scheduler.cc
index 39dcc08..499fae7 100644
--- a/cc/scheduler/scheduler.cc
+++ b/cc/scheduler/scheduler.cc
@@ -486,32 +486,30 @@ void Scheduler::BeginImplFrameWithDeadline(const BeginFrameArgs& args) {
       compositor_timing_history_->CommitToReadyToActivateDurationEstimate() +
       compositor_timing_history_->ActivateDurationEstimate();
 
-  base::TimeDelta bmf_to_activate_estimate_if_critical =
+  base::TimeDelta bmf_to_activate_estimate_critical =
       bmf_start_to_activate +
       compositor_timing_history_->BeginMainFrameQueueDurationCriticalEstimate();
 
-  bool can_activate_before_deadline_if_critical =
-      CanBeginMainFrameAndActivateBeforeDeadline(
-          adjusted_args, bmf_to_activate_estimate_if_critical);
   state_machine_.SetCriticalBeginMainFrameToActivateIsFast(
-      can_activate_before_deadline_if_critical);
+      bmf_to_activate_estimate_critical < args.interval);
 
   // Update the BeginMainFrame args now that we know whether the main
   // thread will be on the critical path or not.
   begin_main_frame_args_ = adjusted_args;
   begin_main_frame_args_.on_critical_path = !ImplLatencyTakesPriority();
 
-  bool can_activate_before_deadline = can_activate_before_deadline_if_critical;
+  base::TimeDelta bmf_to_activate_estimate = bmf_to_activate_estimate_critical;
   if (!begin_main_frame_args_.on_critical_path) {
-    base::TimeDelta bmf_to_activate_estimate =
+    bmf_to_activate_estimate =
         bmf_start_to_activate +
         compositor_timing_history_
             ->BeginMainFrameQueueDurationNotCriticalEstimate();
-
-    can_activate_before_deadline = CanBeginMainFrameAndActivateBeforeDeadline(
-        adjusted_args, bmf_to_activate_estimate);
   }
 
+  bool can_activate_before_deadline =
+      CanBeginMainFrameAndActivateBeforeDeadline(adjusted_args,
+                                                 bmf_to_activate_estimate);
+
   if (ShouldRecoverMainLatency(adjusted_args, can_activate_before_deadline)) {
     TRACE_EVENT_INSTANT0("cc", "SkipBeginMainFrameToReduceLatency",
                          TRACE_EVENT_SCOPE_THREAD);
@@ -842,6 +840,7 @@ bool Scheduler::ShouldRecoverMainLatency(
     bool can_activate_before_deadline) const {
   DCHECK(!settings_.using_synchronous_renderer_compositor);
 
+  // The main thread is in a low latency mode and there's no need to recover.
   if (!state_machine_.main_thread_missed_last_deadline())
     return false;