Report frame throughput at fixed interval

Right now a FrameSequenceTracker would report its throughput data at the
end of a frame sequence only. That is, if we have a very long sequence,
it would report once. That could easily bias the data.

This CL makes changes such that a tracker would report data every 5s.

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

cc/metrics/frame_sequence_tracker.cc

@@ -125,16 +125,15 @@ void FrameSequenceTrackerCollection::ClearAll() {
 
 void FrameSequenceTrackerCollection::NotifyBeginImplFrame(
     const viz::BeginFrameArgs& args) {
-  for (auto& tracker : frame_trackers_) {
+  RecreateTrackers(args);
+  for (auto& tracker : frame_trackers_)
     tracker.second->ReportBeginImplFrame(args);
-  }
 }
 
 void FrameSequenceTrackerCollection::NotifyBeginMainFrame(
     const viz::BeginFrameArgs& args) {
-  for (auto& tracker : frame_trackers_) {
+  for (auto& tracker : frame_trackers_)
     tracker.second->ReportBeginMainFrame(args);
-  }
 }
 
 void FrameSequenceTrackerCollection::NotifyImplFrameCausedNoDamage(
@@ -185,6 +184,24 @@ void FrameSequenceTrackerCollection::NotifyFramePresented(
       });
 }
 
+void FrameSequenceTrackerCollection::RecreateTrackers(
+    const viz::BeginFrameArgs& args) {
+  std::vector<FrameSequenceTrackerType> recreate_trackers;
+  for (const auto& tracker : frame_trackers_) {
+    if (tracker.second->ShouldReportMetricsNow(args))
+      recreate_trackers.push_back(tracker.first);
+  }
+
+  for (const auto& tracker_type : recreate_trackers) {
+    // StopSequence put the tracker in the |removal_trackers_|, which will
+    // report its throughput data when its frame is presented.
+    StopSequence(tracker_type);
+    // The frame sequence is still active, so create a new tracker to keep
+    // tracking this sequence.
+    StartSequence(tracker_type);
+  }
+}
+
 FrameSequenceTracker* FrameSequenceTrackerCollection::GetTrackerForTesting(
     FrameSequenceTrackerType type) {
   if (!frame_trackers_.contains(type))
@@ -268,6 +285,9 @@ void FrameSequenceTracker::ReportBeginImplFrame(
                          args.sequence_number);
   impl_throughput_.frames_expected +=
       begin_impl_frame_data_.previous_sequence_delta;
+
+  if (first_frame_timestamp_.is_null())
+    first_frame_timestamp_ = args.frame_time;
 }
 
 void FrameSequenceTracker::ReportBeginMainFrame(
@@ -487,6 +507,14 @@ FrameSequenceTracker::ThroughputData::ToTracedValue(
   return dict;
 }
 
+bool FrameSequenceTracker::ShouldReportMetricsNow(
+    const viz::BeginFrameArgs& args) const {
+  if (!first_frame_timestamp_.is_null() &&
+      args.frame_time - first_frame_timestamp_ >= time_delta_to_report_)
+    return true;
+  return false;
+}
+
 base::Optional<int> FrameSequenceTracker::ThroughputData::ReportHistogram(
     FrameSequenceTrackerType sequence_type,
     const char* thread_name,

cc/metrics/frame_sequence_tracker.h

@@ -96,6 +96,8 @@ class CC_EXPORT FrameSequenceTrackerCollection {
  private:
   friend class FrameSequenceTrackerTest;
 
+  void RecreateTrackers(const viz::BeginFrameArgs& args);
+
   const bool is_single_threaded_;
   // The callsite can use the type to manipulate the tracker.
   base::flat_map<FrameSequenceTrackerType,
@@ -167,6 +169,9 @@ class CC_EXPORT FrameSequenceTracker {
 
   TerminationStatus termination_status() const { return termination_status_; }
 
+  // Returns true if we should ask this tracker to report its throughput data.
+  bool ShouldReportMetricsNow(const viz::BeginFrameArgs& args) const;
+
  private:
   friend class FrameSequenceTrackerCollection;
   friend class FrameSequenceTrackerTest;
@@ -272,6 +277,13 @@ class CC_EXPORT FrameSequenceTracker {
   // Keeps track of the last sequence-number that produced a frame from the
   // main-thread.
   uint64_t last_submitted_main_sequence_ = 0;
+
+  // The time when this tracker is created, or the time when it was previously
+  // scheduled to report histogram.
+  base::TimeTicks first_frame_timestamp_;
+
+  // Report the throughput metrics every 5 seconds.
+  const base::TimeDelta time_delta_to_report_ = base::TimeDelta::FromSeconds(5);
 };
 
 }  // namespace cc

cc/metrics/frame_sequence_tracker_unittest.cc

@@ -37,9 +37,10 @@ class FrameSequenceTrackerTest : public testing::Test {
         FrameSequenceTrackerType::kTouchScroll);
   }
 
-  viz::BeginFrameArgs CreateBeginFrameArgs(uint64_t source_id,
-                                           uint64_t sequence_number) {
-    auto now = base::TimeTicks::Now();
+  viz::BeginFrameArgs CreateBeginFrameArgs(
+      uint64_t source_id,
+      uint64_t sequence_number,
+      base::TimeTicks now = base::TimeTicks::Now()) {
     auto interval = base::TimeDelta::FromMilliseconds(16);
     auto deadline = now + interval;
     return viz::BeginFrameArgs::Create(BEGINFRAME_FROM_HERE, source_id,
@@ -164,6 +165,17 @@ class FrameSequenceTrackerTest : public testing::Test {
         "Graphics.Smoothness.Throughput.SlowerThread.TouchScroll", 3u);
   }
 
+  base::TimeDelta TimeDeltaToReort() const {
+    return tracker_->time_delta_to_report_;
+  }
+
+  unsigned NumberOfTrackers() const {
+    return collection_.frame_trackers_.size();
+  }
+  unsigned NumberOfRemovalTrackers() const {
+    return collection_.removal_trackers_.size();
+  }
+
  protected:
   uint32_t number_of_frames_checkerboarded() const {
     return tracker_->checkerboarding_.frames_checkerboarded;
@@ -331,4 +343,26 @@ TEST_F(FrameSequenceTrackerTest, ReportMetrics) {
   ReportMetrics();
 }
 
+TEST_F(FrameSequenceTrackerTest, ReportMetricsAtFixedInterval) {
+  const uint64_t source = 1;
+  uint64_t sequence = 0;
+  base::TimeDelta first_time_delta = base::TimeDelta::FromSeconds(1);
+  auto args = CreateBeginFrameArgs(source, ++sequence,
+                                   base::TimeTicks::Now() + first_time_delta);
+
+  // args.frame_time is less than 5s of the tracker creation time, so won't
+  // schedule this tracker to report its throughput.
+  collection_.NotifyBeginImplFrame(args);
+  EXPECT_EQ(NumberOfTrackers(), 1u);
+  EXPECT_EQ(NumberOfRemovalTrackers(), 0u);
+
+  // Now args.frame_time is 5s since the tracker creation time, so this tracker
+  // should be scheduled to report its throughput.
+  args = CreateBeginFrameArgs(source, ++sequence,
+                              args.frame_time + TimeDeltaToReort());
+  collection_.NotifyBeginImplFrame(args);
+  EXPECT_EQ(NumberOfTrackers(), 1u);
+  EXPECT_EQ(NumberOfRemovalTrackers(), 1u);
+}
+
 }  // namespace cc