Reland "[cc/metrics] Introduce FrameSorter.""

This reverts commit 4d2c797.

Changes since revert:
- Code cleanup: Multiple containers are replaced by a map from Frame_id
to FrameState, which tracks the number of AddNewFrame/AddResults/Resets
received regarding the frame.
- Order of variable definition change in scheduler_test_common.h (for
dropped_counter) which was causing destruction of FrameSorter prior to
Acks being recorded and frames being flushed in some of the scheduler
tests.
- Added a new test for when reset happens in middle of two AddNewFrame
calls with the same frame_id, which depending on the order of acks
received afterwards could results into Dcheck failures (initial
implementation would not cover such cases).

[cc/metrics] Introduce FrameSorter.

The begin-frames do not always terminate in the same order as they
start. For example, a frame that does not have any updates can terminate
earlier than a previous frame that had an update and is awaiting
presentation. This can make it tricky to measure dropped-frames in a
sliding window. To make this easier, introduce a FrameSorter, that makes
sure the sliding-window can process the frames in order, regardless of
when they are terminated.

BUG=1138552, 1144480, 1145636

Change-Id: Icb8898b0185baa2fa1c8d0c4619f9576acc07fd1
Reviewed-on: https://chromium-review.googlesource.com/c/chromium/src/+/2518696
Reviewed-by: Jonathan Ross <jonross@chromium.org>
Reviewed-by: Sadrul Chowdhury <sadrul@chromium.org>
Commit-Queue: Behdad Bakhshinategh <behdadb@chromium.org>
Auto-Submit: Behdad Bakhshinategh <behdadb@chromium.org>
Cr-Commit-Position: refs/heads/master@{#825528}

cc/BUILD.gn

@@ -177,6 +177,8 @@ cc_component("cc") {
     "metrics/frame_sequence_tracker.h",
     "metrics/frame_sequence_tracker_collection.cc",
     "metrics/frame_sequence_tracker_collection.h",
+    "metrics/frame_sorter.cc",
+    "metrics/frame_sorter.h",
     "metrics/jank_metrics.cc",
     "metrics/jank_metrics.h",
     "metrics/latency_ukm_reporter.cc",
@@ -689,6 +691,7 @@ cc_test("cc_unittests") {
     "metrics/events_metrics_manager_unittest.cc",
     "metrics/frame_sequence_metrics_unittest.cc",
     "metrics/frame_sequence_tracker_unittest.cc",
+    "metrics/frame_sorter_unittest.cc",
     "metrics/jank_metrics_unittest.cc",
     "metrics/total_frame_counter_unittest.cc",
     "metrics/video_playback_roughness_reporter_unittest.cc",

cc/metrics/compositor_frame_reporter.cc

@@ -292,13 +292,17 @@ CompositorFrameReporter::CompositorFrameReporter(
     LatencyUkmReporter* latency_ukm_reporter,
     bool should_report_metrics,
     SmoothThread smooth_thread,
-    int layer_tree_host_id)
+    int layer_tree_host_id,
+    DroppedFrameCounter* dropped_frame_counter)
     : should_report_metrics_(should_report_metrics),
       args_(args),
       active_trackers_(active_trackers),
       latency_ukm_reporter_(latency_ukm_reporter),
+      dropped_frame_counter_(dropped_frame_counter),
       smooth_thread_(smooth_thread),
-      layer_tree_host_id_(layer_tree_host_id) {}
+      layer_tree_host_id_(layer_tree_host_id) {
+  dropped_frame_counter_->OnBeginFrame(args);
+}
 
 std::unique_ptr<CompositorFrameReporter>
 CompositorFrameReporter::CopyReporterAtBeginImplStage() {
@@ -310,15 +314,14 @@ CompositorFrameReporter::CopyReporterAtBeginImplStage() {
   }
   auto new_reporter = std::make_unique<CompositorFrameReporter>(
       active_trackers_, args_, latency_ukm_reporter_, should_report_metrics_,
-      smooth_thread_, layer_tree_host_id_);
+      smooth_thread_, layer_tree_host_id_, dropped_frame_counter_);
   new_reporter->did_finish_impl_frame_ = did_finish_impl_frame_;
   new_reporter->impl_frame_finish_time_ = impl_frame_finish_time_;
   new_reporter->main_frame_abort_time_ = main_frame_abort_time_;
   new_reporter->current_stage_.stage_type =
       StageType::kBeginImplFrameToSendBeginMainFrame;
   new_reporter->current_stage_.start_time = stage_history_.front().start_time;
   new_reporter->set_tick_clock(tick_clock_);
-  new_reporter->SetDroppedFrameCounter(dropped_frame_counter_);
   new_reporter->cloned_from_ = weak_factory_.GetWeakPtr();
 
   // TODO(https://crbug.com/1127872) Check |cloned_to_| is null before replacing
@@ -494,8 +497,8 @@ void CompositorFrameReporter::TerminateReporter() {
         dropped_frame_counter_->AddGoodFrame();
     }
 
-    if (IsDroppedFrameAffectingSmoothness())
-      dropped_frame_counter_->AddDroppedFrameAffectingSmoothness();
+    dropped_frame_counter_->OnEndFrame(args_,
+                                       IsDroppedFrameAffectingSmoothness());
   }
 }
 

cc/metrics/compositor_frame_reporter.h

@@ -148,7 +148,8 @@ class CC_EXPORT CompositorFrameReporter {
                           LatencyUkmReporter* latency_ukm_reporter,
                           bool should_report_metrics,
                           SmoothThread smooth_thread,
-                          int layer_tree_host_id);
+                          int layer_tree_host_id,
+                          DroppedFrameCounter* dropped_frame_counter);
   ~CompositorFrameReporter();
 
   CompositorFrameReporter(const CompositorFrameReporter& reporter) = delete;
@@ -199,10 +200,6 @@ class CC_EXPORT CompositorFrameReporter {
     tick_clock_ = tick_clock;
   }
 
-  void SetDroppedFrameCounter(DroppedFrameCounter* counter) {
-    dropped_frame_counter_ = counter;
-  }
-
   bool has_partial_update() const { return has_partial_update_; }
   void set_has_partial_update(bool has_partial_update) {
     has_partial_update_ = has_partial_update;

cc/metrics/compositor_frame_reporter_unittest.cc

@@ -12,7 +12,9 @@
 #include "base/test/metrics/histogram_tester.h"
 #include "base/test/simple_test_tick_clock.h"
 #include "cc/metrics/compositor_frame_reporting_controller.h"
+#include "cc/metrics/dropped_frame_counter.h"
 #include "cc/metrics/event_metrics.h"
+#include "cc/metrics/total_frame_counter.h"
 #include "components/viz/common/frame_timing_details.h"
 #include "testing/gmock/include/gmock/gmock.h"
 #include "testing/gtest/include/gtest/gtest.h"
@@ -34,9 +36,11 @@ class CompositorFrameReporterTest : public testing::Test {
             nullptr,
             /*should_report_metrics=*/true,
             CompositorFrameReporter::SmoothThread::kSmoothBoth,
-            /*layer_tree_host_id=*/1)) {
+            /*layer_tree_host_id=*/1,
+            &dropped_frame_counter_)) {
     pipeline_reporter_->set_tick_clock(&test_tick_clock_);
     AdvanceNowByMs(1);
+    dropped_frame_counter_.set_total_counter(&total_frame_counter_);
   }
 
  protected:
@@ -80,6 +84,8 @@ class CompositorFrameReporterTest : public testing::Test {
   // and destroyed after that.
   base::SimpleTestTickClock test_tick_clock_;
 
+  DroppedFrameCounter dropped_frame_counter_;
+  TotalFrameCounter total_frame_counter_;
   std::unique_ptr<CompositorFrameReporter> pipeline_reporter_;
 };
 

cc/metrics/compositor_frame_reporting_controller.cc

@@ -84,11 +84,11 @@ void CompositorFrameReportingController::WillBeginImplFrame(
   }
   auto reporter = std::make_unique<CompositorFrameReporter>(
       active_trackers_, args, latency_ukm_reporter_.get(),
-      should_report_metrics_, GetSmoothThread(), layer_tree_host_id_);
+      should_report_metrics_, GetSmoothThread(), layer_tree_host_id_,
+      dropped_frame_counter_);
   reporter->set_tick_clock(tick_clock_);
   reporter->StartStage(StageType::kBeginImplFrameToSendBeginMainFrame,
                        begin_time);
-  reporter->SetDroppedFrameCounter(dropped_frame_counter_);
   reporters_[PipelineStage::kBeginImplFrame] = std::move(reporter);
 }
 
@@ -111,10 +111,10 @@ void CompositorFrameReportingController::WillBeginMainFrame(
     // deadline yet). So will start a new reporter at BeginMainFrame.
     auto reporter = std::make_unique<CompositorFrameReporter>(
         active_trackers_, args, latency_ukm_reporter_.get(),
-        should_report_metrics_, GetSmoothThread(), layer_tree_host_id_);
+        should_report_metrics_, GetSmoothThread(), layer_tree_host_id_,
+        dropped_frame_counter_);
     reporter->set_tick_clock(tick_clock_);
     reporter->StartStage(StageType::kSendBeginMainFrameToCommit, Now());
-    reporter->SetDroppedFrameCounter(dropped_frame_counter_);
     reporters_[PipelineStage::kBeginMainFrame] = std::move(reporter);
   }
 }
@@ -495,11 +495,11 @@ void CompositorFrameReportingController::CreateReportersForDroppedFrames(
         viz::BeginFrameArgs::NORMAL);
     auto reporter = std::make_unique<CompositorFrameReporter>(
         active_trackers_, args, latency_ukm_reporter_.get(),
-        should_report_metrics_, GetSmoothThread(), layer_tree_host_id_);
+        should_report_metrics_, GetSmoothThread(), layer_tree_host_id_,
+        dropped_frame_counter_);
     reporter->set_tick_clock(tick_clock_);
     reporter->StartStage(StageType::kBeginImplFrameToSendBeginMainFrame,
                          timestamp);
-    reporter->SetDroppedFrameCounter(dropped_frame_counter_);
     reporter->TerminateFrame(FrameTerminationStatus::kDidNotPresentFrame,
                              args.deadline);
   }

cc/metrics/compositor_frame_reporting_controller_unittest.cc

@@ -13,6 +13,7 @@
 #include "base/test/simple_test_tick_clock.h"
 #include "cc/metrics/dropped_frame_counter.h"
 #include "cc/metrics/event_metrics.h"
+#include "cc/metrics/total_frame_counter.h"
 #include "components/viz/common/frame_timing_details.h"
 #include "components/viz/common/quads/compositor_frame_metadata.h"
 #include "testing/gmock/include/gmock/gmock.h"
@@ -61,6 +62,8 @@ class CompositorFrameReportingControllerTest : public testing::Test {
     test_tick_clock_.SetNowTicks(base::TimeTicks::Now());
     reporting_controller_.set_tick_clock(&test_tick_clock_);
     args_ = SimulateBeginFrameArgs(current_id_);
+    reporting_controller_.SetDroppedFrameCounter(&dropped_counter);
+    dropped_counter.set_total_counter(&total_frame_counter_);
   }
 
   // The following functions simulate the actions that would
@@ -200,6 +203,8 @@ class CompositorFrameReportingControllerTest : public testing::Test {
   base::TimeTicks end_activation_time_;
   base::TimeTicks submit_time_;
   viz::FrameTokenGenerator next_token_;
+  DroppedFrameCounter dropped_counter;
+  TotalFrameCounter total_frame_counter_;
 };
 
 TEST_F(CompositorFrameReportingControllerTest, ActiveReporterCounts) {
@@ -1313,9 +1318,6 @@ TEST_F(CompositorFrameReportingControllerTest,
 
 TEST_F(CompositorFrameReportingControllerTest,
        NewMainUpdateIsNotPartialUpdate) {
-  DroppedFrameCounter dropped_counter;
-  reporting_controller_.SetDroppedFrameCounter(&dropped_counter);
-
   SimulateBeginMainFrame();
   reporting_controller_.OnFinishImplFrame(current_id_);
   reporting_controller_.DidSubmitCompositorFrame(1u, current_id_, {}, {});
@@ -1346,9 +1348,6 @@ TEST_F(CompositorFrameReportingControllerTest,
 
 TEST_F(CompositorFrameReportingControllerTest,
        SkippedFramesFromDisplayCompositorAreDropped) {
-  DroppedFrameCounter dropped_counter;
-  reporting_controller_.SetDroppedFrameCounter(&dropped_counter);
-
   // Submit and present two compositor frames.
   SimulatePresentCompositorFrame();
   EXPECT_EQ(1u, dropped_counter.total_frames());

cc/metrics/compositor_timing_history_unittest.cc

@@ -48,6 +48,7 @@ class CompositorTimingHistoryTest : public testing::Test {
                         reporting_controller_.get()) {
     AdvanceNowBy(base::TimeDelta::FromMilliseconds(1));
     timing_history_.SetRecordingEnabled(true);
+    reporting_controller_->SetDroppedFrameCounter(&dropped_counter);
   }
 
   void AdvanceNowBy(base::TimeDelta delta) { now_ += delta; }
@@ -60,6 +61,7 @@ class CompositorTimingHistoryTest : public testing::Test {
   TestCompositorTimingHistory timing_history_;
   base::TimeTicks now_;
   uint64_t sequence_number = 0;
+  DroppedFrameCounter dropped_counter;
 
   viz::BeginFrameArgs GetFakeBeginFrameArg(bool on_critical_path = true) {
     viz::BeginFrameArgs args = viz::BeginFrameArgs();

cc/metrics/dropped_frame_counter.cc

@@ -4,18 +4,18 @@
 
 #include "cc/metrics/dropped_frame_counter.h"
 
-#include <stddef.h>
-
-#include <limits>
-
-#include "base/memory/ptr_util.h"
+#include "base/bind.h"
 #include "base/trace_event/trace_event.h"
+#include "cc/metrics/frame_sorter.h"
 #include "cc/metrics/total_frame_counter.h"
 #include "cc/metrics/ukm_smoothness_data.h"
 
 namespace cc {
 
-DroppedFrameCounter::DroppedFrameCounter() = default;
+DroppedFrameCounter::DroppedFrameCounter()
+    : frame_sorter_(base::BindRepeating(&DroppedFrameCounter::NotifyFrameResult,
+                                        base::Unretained(this))) {}
+DroppedFrameCounter::~DroppedFrameCounter() = default;
 
 uint32_t DroppedFrameCounter::GetAverageThroughput() const {
   size_t good_frames = 0;
@@ -44,10 +44,22 @@ void DroppedFrameCounter::AddDroppedFrame() {
   ++total_dropped_;
 }
 
-void DroppedFrameCounter::AddDroppedFrameAffectingSmoothness() {
-  if (fcp_received_)
-    ++total_smoothness_dropped_;
-  ReportFrames();
+void DroppedFrameCounter::ResetFrameSorter() {
+  frame_sorter_.Reset();
+}
+
+void DroppedFrameCounter::OnBeginFrame(const viz::BeginFrameArgs& args) {
+  frame_sorter_.AddNewFrame(args);
+}
+
+void DroppedFrameCounter::OnEndFrame(const viz::BeginFrameArgs& args,
+                                     bool is_dropped) {
+  if (is_dropped) {
+    if (fcp_received_)
+      ++total_smoothness_dropped_;
+    ReportFrames();
+  }
+  frame_sorter_.AddFrameResult(args, is_dropped);
 }
 
 void DroppedFrameCounter::ReportFrames() {
@@ -81,6 +93,12 @@ void DroppedFrameCounter::Reset() {
   total_smoothness_dropped_ = 0;
   fcp_received_ = false;
   ring_buffer_.Clear();
+  frame_sorter_.Reset();
+}
+
+void DroppedFrameCounter::NotifyFrameResult(const viz::BeginFrameArgs& args,
+                                            bool is_dropped) {
+  // TODO(crbug.com/1115141) The implementation of smoothness metrics.
 }
 
 void DroppedFrameCounter::OnFcpReceived() {

cc/metrics/dropped_frame_counter.h

@@ -7,13 +7,11 @@
 
 #include <stddef.h>
 
-#include <memory>
-
 #include "base/containers/ring_buffer.h"
 #include "cc/cc_export.h"
+#include "cc/metrics/frame_sorter.h"
 
 namespace cc {
-
 class TotalFrameCounter;
 struct UkmSmoothnessDataShared;
 
@@ -28,6 +26,7 @@ class CC_EXPORT DroppedFrameCounter {
   };
 
   DroppedFrameCounter();
+  ~DroppedFrameCounter();
 
   DroppedFrameCounter(const DroppedFrameCounter&) = delete;
   DroppedFrameCounter& operator=(const DroppedFrameCounter&) = delete;
@@ -47,20 +46,27 @@ class CC_EXPORT DroppedFrameCounter {
   void AddGoodFrame();
   void AddPartialFrame();
   void AddDroppedFrame();
-
-  void AddDroppedFrameAffectingSmoothness();
   void ReportFrames();
 
+  void OnBeginFrame(const viz::BeginFrameArgs& args);
+  void OnEndFrame(const viz::BeginFrameArgs& args, bool is_dropped);
   void SetUkmSmoothnessDestination(UkmSmoothnessDataShared* smoothness_data);
+  void OnFcpReceived();
 
+  // Reset is used on navigation, which resets frame statistics as well as
+  // frame sorter.
   void Reset();
-  void OnFcpReceived();
+  // ResetFrameSorter is used when we need to keep track of frame statistics
+  // but not to track the frames prior to reset in frame sorter.
+  void ResetFrameSorter();
 
   void set_total_counter(TotalFrameCounter* total_counter) {
     total_counter_ = total_counter;
   }
 
  private:
+  void NotifyFrameResult(const viz::BeginFrameArgs& args, bool is_dropped);
+
   RingBufferType ring_buffer_;
   size_t total_frames_ = 0;
   size_t total_partial_ = 0;
@@ -69,7 +75,7 @@ class CC_EXPORT DroppedFrameCounter {
   bool fcp_received_ = false;
 
   UkmSmoothnessDataShared* ukm_smoothness_data_ = nullptr;
-
+  FrameSorter frame_sorter_;
   TotalFrameCounter* total_counter_ = nullptr;
 };