Reland "Record latency for Impl thread in case of no begin main frame."

This is a reland of 2fcffb28

The cause of crashes on webview_instrumentation_test_apk was that reporter was
terminated without a termination status (instance being destroyed) in
TerminateReporter method of compositor_frame_reporter.

Original change's description:
> Record latency for Impl thread in case of no begin main frame.
>
> This CL reports the latency in case of no begin main frame.
> This can happen in any of the scenarios below:
>
> 1) WillBeginImplFrame -> DidFinishImplFrame -> DidSubmitCompositorFrame
>
> 2) WillBeginImplFrame -> WillBeginMainFrame -> BeginMainFrameAborted ->
> DidFinishImplFrame -> DidSubmitCompositorFrame
>
> 3) WillBeginImplFrame -> WillBeginMainFrame -> DidFinishImplFrame ->
> BeginMainFrameAborted -> DidSubmitCompositorFrame
>
> In these cases there will be no latency to report for stages of:
> - SendBeginMainFrameToCommit
> - Commit
> - EndCommitToActivation
> But the latency will be reported for the remaining stages.
>
> Bug: chromium:1003038
> Change-Id: Id0d6a65603b2b15a0ee04a6974a4bd0b2a5a803b
> Reviewed-on: https://chromium-review.googlesource.com/c/chromium/src/+/1799026
> Commit-Queue: Behdad Bakhshinategh <behdadb@chromium.org>
> Reviewed-by: Sadrul Chowdhury <sadrul@chromium.org>
> Cr-Commit-Position: refs/heads/master@{#705964}

Bug: chromium:1003038
Change-Id: I95651557c6e50b9f2e8ee3ae1043616fff8c88ee
Reviewed-on: https://chromium-review.googlesource.com/c/chromium/src/+/1865535
Commit-Queue: Behdad Bakhshinategh <behdadb@chromium.org>
Reviewed-by: Sadrul Chowdhury <sadrul@chromium.org>
Cr-Commit-Position: refs/heads/master@{#707357}

cc/metrics/compositor_frame_reporter.cc

@@ -153,6 +153,17 @@ void CompositorFrameReporter::TerminateFrame(
   EndCurrentStage(frame_termination_time_);
 }
 
+void CompositorFrameReporter::OnFinishImplFrame(base::TimeTicks timestamp) {
+  DCHECK(!did_finish_impl_frame_);
+
+  did_finish_impl_frame_ = true;
+  impl_frame_finish_time_ = timestamp;
+}
+
+void CompositorFrameReporter::OnAbortBeginMainFrame() {
+  did_abort_main_frame_ = false;
+}
+
 void CompositorFrameReporter::SetVizBreakdown(
     const viz::FrameTimingDetails& viz_breakdown) {
   DCHECK(current_stage_.viz_breakdown.received_compositor_frame_timestamp
@@ -161,7 +172,8 @@ void CompositorFrameReporter::SetVizBreakdown(
 }
 
 void CompositorFrameReporter::TerminateReporter() {
-  DCHECK_EQ(current_stage_.start_time, base::TimeTicks());
+  if (frame_termination_status_ != FrameTerminationStatus::kUnknown)
+    DCHECK_EQ(current_stage_.start_time, base::TimeTicks());
   bool report_latency = false;
   const char* termination_status_str = nullptr;
   switch (frame_termination_status_) {
@@ -186,7 +198,7 @@ void CompositorFrameReporter::TerminateReporter() {
       termination_status_str = "did_not_produce_frame";
       break;
     case FrameTerminationStatus::kUnknown:
-      NOTREACHED();
+      termination_status_str = "terminated_before_ending";
       break;
   }
   const char* submission_status_str =

cc/metrics/compositor_frame_reporter.h

@@ -111,6 +111,14 @@ class CC_EXPORT CompositorFrameReporter {
 
   int StageHistorySizeForTesting() { return stage_history_.size(); }
 
+  void OnFinishImplFrame(base::TimeTicks timestamp);
+  void OnAbortBeginMainFrame();
+  bool did_finish_impl_frame() const { return did_finish_impl_frame_; }
+  bool did_abort_main_frame() const { return did_abort_main_frame_; }
+  base::TimeTicks impl_frame_finish_time() const {
+    return impl_frame_finish_time_;
+  }
+
  protected:
   struct StageData {
     StageType stage_type;
@@ -161,6 +169,14 @@ class CC_EXPORT CompositorFrameReporter {
       FrameTerminationStatus::kUnknown;
 
   const base::flat_set<FrameSequenceTrackerType>* active_trackers_;
+
+  // Indicates if work on Impl frame is finished.
+  bool did_finish_impl_frame_ = false;
+  // Indicates if main frame is aborted after begin.
+  bool did_abort_main_frame_ = false;
+  // The time that work on Impl frame is finished. It's only valid if the
+  // reporter is in a stage other than begin impl frame.
+  base::TimeTicks impl_frame_finish_time_;
 };
 }  // namespace cc
 

cc/metrics/compositor_frame_reporting_controller.cc

@@ -59,43 +59,60 @@ void CompositorFrameReportingController::WillBeginImplFrame() {
   std::unique_ptr<CompositorFrameReporter> reporter =
       std::make_unique<CompositorFrameReporter>(&active_trackers_,
                                                 is_single_threaded_);
-  reporter->StartStage(
-      CompositorFrameReporter::StageType::kBeginImplFrameToSendBeginMainFrame,
-      begin_time);
+  reporter->StartStage(StageType::kBeginImplFrameToSendBeginMainFrame,
+                       begin_time);
   reporters_[PipelineStage::kBeginImplFrame] = std::move(reporter);
 }
 
 void CompositorFrameReportingController::WillBeginMainFrame() {
-  DCHECK(reporters_[PipelineStage::kBeginImplFrame]);
-  // We need to use .get() below because operator<< in std::unique_ptr is a
-  // C++20 feature.
-  DCHECK_NE(reporters_[PipelineStage::kBeginMainFrame].get(),
-            reporters_[PipelineStage::kBeginImplFrame].get());
-  reporters_[PipelineStage::kBeginImplFrame]->StartStage(
-      CompositorFrameReporter::StageType::kSendBeginMainFrameToCommit, Now());
-  AdvanceReporterStage(PipelineStage::kBeginImplFrame,
-                       PipelineStage::kBeginMainFrame);
+  if (reporters_[PipelineStage::kBeginImplFrame]) {
+    // We need to use .get() below because operator<< in std::unique_ptr is a
+    // C++20 feature.
+    DCHECK_NE(reporters_[PipelineStage::kBeginMainFrame].get(),
+              reporters_[PipelineStage::kBeginImplFrame].get());
+    reporters_[PipelineStage::kBeginImplFrame]->StartStage(
+        StageType::kSendBeginMainFrameToCommit, Now());
+    AdvanceReporterStage(PipelineStage::kBeginImplFrame,
+                         PipelineStage::kBeginMainFrame);
+  } else {
+    // In this case we have already submitted the ImplFrame, but we received
+    // beginMain frame before next BeginImplFrame (Not reached the ImplFrame
+    // deadline yet). So will start a new reporter at BeginMainFrame.
+    std::unique_ptr<CompositorFrameReporter> reporter =
+        std::make_unique<CompositorFrameReporter>(&active_trackers_,
+                                                  is_single_threaded_);
+    reporter->StartStage(StageType::kSendBeginMainFrameToCommit, Now());
+    reporters_[PipelineStage::kBeginMainFrame] = std::move(reporter);
+  }
 }
 
 void CompositorFrameReportingController::BeginMainFrameAborted() {
   DCHECK(reporters_[PipelineStage::kBeginMainFrame]);
-  std::unique_ptr<CompositorFrameReporter> aborted_frame_reporter =
-      std::move(reporters_[PipelineStage::kBeginMainFrame]);
-  aborted_frame_reporter->TerminateFrame(
-      CompositorFrameReporter::FrameTerminationStatus::kMainFrameAborted,
-      Now());
+
+  auto& begin_main_reporter = reporters_[PipelineStage::kBeginMainFrame];
+  begin_main_reporter->OnAbortBeginMainFrame();
+
+  // If the main-frame was aborted (e.g. there was no visible update), then
+  // advance to activate stage if the compositor has already made changes to
+  // the active tree (i.e. if impl-frame has finished).
+  if (begin_main_reporter->did_finish_impl_frame()) {
+    begin_main_reporter->StartStage(
+        StageType::kEndActivateToSubmitCompositorFrame, Now());
+    AdvanceReporterStage(PipelineStage::kBeginMainFrame,
+                         PipelineStage::kActivate);
+  }
 }
 
 void CompositorFrameReportingController::WillCommit() {
   DCHECK(reporters_[PipelineStage::kBeginMainFrame]);
-  reporters_[PipelineStage::kBeginMainFrame]->StartStage(
-      CompositorFrameReporter::StageType::kCommit, Now());
+  reporters_[PipelineStage::kBeginMainFrame]->StartStage(StageType::kCommit,
+                                                         Now());
 }
 
 void CompositorFrameReportingController::DidCommit() {
   DCHECK(reporters_[PipelineStage::kBeginMainFrame]);
   reporters_[PipelineStage::kBeginMainFrame]->StartStage(
-      CompositorFrameReporter::StageType::kEndCommitToActivation, Now());
+      StageType::kEndCommitToActivation, Now());
   AdvanceReporterStage(PipelineStage::kBeginMainFrame, PipelineStage::kCommit);
 }
 
@@ -109,8 +126,7 @@ void CompositorFrameReportingController::WillActivate() {
   DCHECK(reporters_[PipelineStage::kCommit] || next_activate_has_invalidation_);
   if (!reporters_[PipelineStage::kCommit])
     return;
-  reporters_[PipelineStage::kCommit]->StartStage(
-      CompositorFrameReporter::StageType::kActivation, Now());
+  reporters_[PipelineStage::kCommit]->StartStage(StageType::kActivation, Now());
 }
 
 void CompositorFrameReportingController::DidActivate() {
@@ -119,25 +135,57 @@ void CompositorFrameReportingController::DidActivate() {
   if (!reporters_[PipelineStage::kCommit])
     return;
   reporters_[PipelineStage::kCommit]->StartStage(
-      CompositorFrameReporter::StageType::kEndActivateToSubmitCompositorFrame,
-      Now());
+      StageType::kEndActivateToSubmitCompositorFrame, Now());
   AdvanceReporterStage(PipelineStage::kCommit, PipelineStage::kActivate);
 }
 
 void CompositorFrameReportingController::DidSubmitCompositorFrame(
     uint32_t frame_token) {
+  // If there is no reporter in active stage and there exists a finished
+  // BeginImplFrame reporter (i.e. if impl-frame has finished), then advance it
+  // to the activate stage.
+  if (!reporters_[PipelineStage::kActivate] &&
+      reporters_[PipelineStage::kBeginImplFrame]) {
+    auto& begin_impl_frame = reporters_[PipelineStage::kBeginImplFrame];
+    if (begin_impl_frame->did_finish_impl_frame()) {
+      begin_impl_frame->StartStage(
+          StageType::kEndActivateToSubmitCompositorFrame,
+          begin_impl_frame->impl_frame_finish_time());
+      AdvanceReporterStage(PipelineStage::kBeginImplFrame,
+                           PipelineStage::kActivate);
+    }
+  }
+
   if (!reporters_[PipelineStage::kActivate])
     return;
+
   std::unique_ptr<CompositorFrameReporter> submitted_reporter =
       std::move(reporters_[PipelineStage::kActivate]);
   submitted_reporter->StartStage(
-      CompositorFrameReporter::StageType::
-          kSubmitCompositorFrameToPresentationCompositorFrame,
-      Now());
+      StageType::kSubmitCompositorFrameToPresentationCompositorFrame, Now());
   submitted_compositor_frames_.emplace_back(frame_token,
                                             std::move(submitted_reporter));
 }
 
+void CompositorFrameReportingController::OnFinishImplFrame() {
+  if (reporters_[PipelineStage::kBeginImplFrame]) {
+    reporters_[PipelineStage::kBeginImplFrame]->OnFinishImplFrame(Now());
+  } else if (reporters_[PipelineStage::kBeginMainFrame]) {
+    auto& begin_main_reporter = reporters_[PipelineStage::kBeginMainFrame];
+    begin_main_reporter->OnFinishImplFrame(Now());
+
+    // If the main-frame was aborted (e.g. there was no visible update), then
+    // advance to activate stage if the compositor has already made changes to
+    // the active tree (i.e. if impl-frame has finished).
+    if (begin_main_reporter->did_abort_main_frame()) {
+      begin_main_reporter->StartStage(
+          StageType::kEndActivateToSubmitCompositorFrame, Now());
+      AdvanceReporterStage(PipelineStage::kBeginMainFrame,
+                           PipelineStage::kActivate);
+    }
+  }
+}
+
 void CompositorFrameReportingController::DidPresentCompositorFrame(
     uint32_t frame_token,
     const viz::FrameTimingDetails& details) {

cc/metrics/compositor_frame_reporting_controller.h

@@ -57,6 +57,7 @@ class CC_EXPORT CompositorFrameReportingController {
   virtual void WillActivate();
   virtual void DidActivate();
   virtual void DidSubmitCompositorFrame(uint32_t frame_token);
+  virtual void OnFinishImplFrame();
   virtual void DidPresentCompositorFrame(
       uint32_t frame_token,
       const viz::FrameTimingDetails& details);

cc/metrics/compositor_timing_history.cc

@@ -735,6 +735,8 @@ void CompositorTimingHistory::WillBeginImplFrame(
 void CompositorTimingHistory::WillFinishImplFrame(bool needs_redraw) {
   if (!needs_redraw)
     SetCompositorDrawingContinuously(false);
+
+  compositor_frame_reporting_controller_->OnFinishImplFrame();
 }
 
 void CompositorTimingHistory::BeginImplFrameNotExpectedSoon() {