Add DCheck for total latency being equal to sum of parts

The end_time of SendBeginMainToCommit would be set by the time that
OnFinishImplFrame is received, which might be before the MainFrameAbort.
This could result into TotalLatency being smaller than the sum of stages.

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

cc/metrics/compositor_frame_reporter.cc

@@ -249,8 +249,13 @@ void CompositorFrameReporter::OnFinishImplFrame(base::TimeTicks timestamp) {
   impl_frame_finish_time_ = timestamp;
 }
 
-void CompositorFrameReporter::OnAbortBeginMainFrame() {
+void CompositorFrameReporter::OnAbortBeginMainFrame(base::TimeTicks timestamp) {
+  DCHECK(!did_abort_main_frame_);
+
   did_abort_main_frame_ = true;
+  impl_frame_finish_time_ = timestamp;
+  // impl_frame_finish_time_ can be used for the end of BeginMain to Commit
+  // stage
 }
 
 void CompositorFrameReporter::SetBlinkBreakdown(
@@ -329,6 +334,8 @@ void CompositorFrameReporter::TerminateReporter() {
   // Only report compositor latency histograms if the frame was produced.
   if (report_compositor_latency) {
     DCHECK(stage_history_.size());
+    DCHECK_EQ(SumOfStageHistory(), stage_history_.back().end_time -
+                                       stage_history_.front().start_time);
     stage_history_.emplace_back(StageType::kTotalLatency,
                                 stage_history_.front().start_time,
                                 stage_history_.back().end_time);
@@ -514,4 +521,11 @@ void CompositorFrameReporter::ReportEventLatencyHistograms() const {
   }
 }
 
+base::TimeDelta CompositorFrameReporter::SumOfStageHistory() const {
+  base::TimeDelta sum;
+  for (const StageData& stage : stage_history_)
+    sum += stage.end_time - stage.start_time;
+  return sum;
+}
+
 }  // namespace cc

cc/metrics/compositor_frame_reporter.h

@@ -144,7 +144,7 @@ class CC_EXPORT CompositorFrameReporter {
   int StageHistorySizeForTesting() { return stage_history_.size(); }
 
   void OnFinishImplFrame(base::TimeTicks timestamp);
-  void OnAbortBeginMainFrame();
+  void OnAbortBeginMainFrame(base::TimeTicks timestamp);
   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 {
@@ -182,6 +182,9 @@ class CC_EXPORT CompositorFrameReporter {
   // be divided based on the frame submission status.
   std::vector<StageData> stage_history_;
 
+  // This method is only used for DCheck
+  base::TimeDelta SumOfStageHistory() const;
+
   // List of metrics for events affecting this frame.
   std::vector<EventMetrics> events_metrics_;
 

cc/metrics/compositor_frame_reporting_controller.cc

@@ -102,7 +102,7 @@ void CompositorFrameReportingController::BeginMainFrameAborted(
   DCHECK(reporters_[PipelineStage::kBeginMainFrame]);
   DCHECK_EQ(reporters_[PipelineStage::kBeginMainFrame]->frame_id_, id);
   auto& begin_main_reporter = reporters_[PipelineStage::kBeginMainFrame];
-  begin_main_reporter->OnAbortBeginMainFrame();
+  begin_main_reporter->OnAbortBeginMainFrame(Now());
 }
 
 void CompositorFrameReportingController::WillCommit() {