[throughput] Fix ScheduleTerminate

While debugging, we found that a ReportBeginImpl(Main)Frame could
happen before ScheduleTerminate, and then that main/impl frame is
never processed (meaning that it didn't report no damage and didn't
submit the frame).

This CL handles the impl case, main frame handling will be in a
separate CL.

Bug: 1021963
Change-Id: Ib9a1bd7b894bba3018f120590511c6dba22d1d00
Reviewed-on: https://chromium-review.googlesource.com/c/chromium/src/+/1994086
Reviewed-by: Sadrul Chowdhury <sadrul@chromium.org>
Commit-Queue: Xida Chen <xidachen@chromium.org>
Cr-Commit-Position: refs/heads/master@{#730205}

cc/metrics/frame_sequence_tracker.cc

@@ -417,6 +417,16 @@ FrameSequenceTracker::FrameSequenceTracker(
 FrameSequenceTracker::~FrameSequenceTracker() {
 }
 
+void FrameSequenceTracker::ScheduleTerminate() {
+  termination_status_ = TerminationStatus::kScheduledForTermination;
+  // It could happen that a main/impl frame is generated, but never processed
+  // (didn't report no damage and didn't submit) when this happens.
+  if (last_processed_impl_sequence_ < last_started_impl_sequence_) {
+    impl_throughput().frames_expected -=
+        begin_impl_frame_data_.previous_sequence_delta;
+  }
+}
+
 void FrameSequenceTracker::ReportMetricsForTesting() {
   metrics_->ReportMetrics();
 }
@@ -437,12 +447,12 @@ void FrameSequenceTracker::ReportBeginImplFrame(
 
   DCHECK_EQ(last_started_impl_sequence_, 0u) << TRACKER_DCHECK_MSG;
   DCHECK_EQ(last_processed_impl_sequence_, 0u) << TRACKER_DCHECK_MSG;
-  last_started_impl_sequence_ = args.frame_id.sequence_number;
 
   if (args.type == viz::BeginFrameArgs::NORMAL)
     impl_frames_.insert(args.frame_id);
 #endif
 
+  last_started_impl_sequence_ = args.frame_id.sequence_number;
   if (reset_all_state_) {
     begin_impl_frame_data_ = {};
     begin_main_frame_data_ = {};
@@ -507,9 +517,9 @@ void FrameSequenceTracker::ReportSubmitFrame(
 
 #if DCHECK_IS_ON()
   DCHECK(is_inside_frame_) << TRACKER_DCHECK_MSG;
-  last_processed_impl_sequence_ = ack.frame_id.sequence_number;
 #endif
 
+  last_processed_impl_sequence_ = ack.frame_id.sequence_number;
   if (first_submitted_frame_ == 0)
     first_submitted_frame_ = frame_token;
   last_submitted_frame_ = frame_token;
@@ -587,8 +597,9 @@ void FrameSequenceTracker::ReportFrameEnd(const viz::BeginFrameArgs& args) {
   DCHECK_EQ(last_started_impl_sequence_, last_processed_impl_sequence_)
       << TRACKER_DCHECK_MSG;
   is_inside_frame_ = false;
-  last_started_impl_sequence_ = last_processed_impl_sequence_ = 0;
 #endif
+
+  last_started_impl_sequence_ = last_processed_impl_sequence_ = 0;
 }
 
 void FrameSequenceTracker::ReportFramePresented(
@@ -693,10 +704,7 @@ void FrameSequenceTracker::ReportImplFrameCausedNoDamage(
   if (ShouldIgnoreSequence(ack.frame_id.sequence_number))
     return;
 
-#if DCHECK_IS_ON()
   last_processed_impl_sequence_ = ack.frame_id.sequence_number;
-#endif
-
   // If there is no damage for this frame (and no frame is submitted), then the
   // impl-sequence needs to be reset. However, this should be done after the
   // processing the frame is complete (i.e. in ReportFrameEnd()), so that other

cc/metrics/frame_sequence_tracker.h

@@ -291,9 +291,7 @@ class CC_EXPORT FrameSequenceTracker {
     return metrics_->main_throughput();
   }
 
-  void ScheduleTerminate() {
-    termination_status_ = TerminationStatus::kScheduledForTermination;
-  }
+  void ScheduleTerminate();
 
   struct TrackedFrameData {
     // Represents the |BeginFrameArgs::source_id| and
@@ -393,6 +391,9 @@ class CC_EXPORT FrameSequenceTracker {
   // Report the throughput metrics every 5 seconds.
   const base::TimeDelta time_delta_to_report_ = base::TimeDelta::FromSeconds(5);
 
+  uint64_t last_started_impl_sequence_ = 0;
+  uint64_t last_processed_impl_sequence_ = 0;
+
 #if DCHECK_IS_ON()
   bool is_inside_frame_ = false;
 
@@ -406,9 +407,6 @@ class CC_EXPORT FrameSequenceTracker {
   // when DCHECK is on.
   std::stringstream frame_sequence_trace_;
 
-  uint64_t last_started_impl_sequence_ = 0;
-  uint64_t last_processed_impl_sequence_ = 0;
-
   uint64_t last_started_main_sequence_ = 0;
 
   // If ReportBeginImplFrame is never called on a arg, then ReportBeginMainFrame

cc/metrics/frame_sequence_tracker_unittest.cc

@@ -696,4 +696,14 @@ TEST_F(FrameSequenceTrackerTest, SequenceStateResetsDuringFrame) {
   EXPECT_EQ(MainThroughput().frames_produced, 0u);
 }
 
+TEST_F(FrameSequenceTrackerTest, BeginImplFrameBeforeTerminate) {
+  const char sequence[] = "b(1)s(1)e(1)b(4)P(1)";
+  GenerateSequence(sequence);
+  EXPECT_EQ(ImplThroughput().frames_expected, 4u);
+  EXPECT_EQ(ImplThroughput().frames_produced, 1u);
+  collection_.StopSequence(FrameSequenceTrackerType::kTouchScroll);
+  EXPECT_EQ(ImplThroughput().frames_expected, 1u);
+  EXPECT_EQ(ImplThroughput().frames_produced, 1u);
+}
+
 }  // namespace cc