cc/metrics/frame_sequence_tracker.cc

   1 // Copyright 2019 The Chromium Authors
   2 // Use of this source code is governed by a BSD-style license that can be
   3 // found in the LICENSE file.
   4
   5 #include "cc/metrics/frame_sequence_tracker.h"
   6
   7 #include <algorithm>
   8 #include <memory>
   9 #include <string>
  10 #include <utility>
  11
  12 #include "base/bind.h"
  13 #include "base/containers/contains.h"
  14 #include "base/containers/cxx20_erase.h"
  15 #include "base/logging.h"
  16 #include "base/metrics/histogram.h"
  17 #include "base/metrics/histogram_macros.h"
  18 #include "base/notreached.h"
  19 #include "base/trace_event/trace_event.h"
  20 #include "base/trace_event/traced_value.h"
  21 #include "components/viz/common/frame_sinks/begin_frame_args.h"
  22 #include "components/viz/common/quads/compositor_frame_metadata.h"
  23 #include "ui/gfx/presentation_feedback.h"
  24
  25 // This macro is used with DCHECK to provide addition debug info.
  26 #if DCHECK_IS_ON()
  27 #define TRACKER_TRACE_STREAM frame_sequence_trace_
  28 #define TRACKER_DCHECK_MSG                                      \
  29   " in " << GetFrameSequenceTrackerTypeName(this->type())       \
  30          << " tracker: " << frame_sequence_trace_.str() << " (" \
  31          << frame_sequence_trace_.str().size() << ")";
  32 #else
  33 #define TRACKER_TRACE_STREAM EAT_STREAM_PARAMETERS
  34 #define TRACKER_DCHECK_MSG ""
  35 #endif
  36
  37 namespace cc {
  38
  39 namespace {
  40
  41 constexpr char kTraceCategory[] =
  42     "cc,benchmark," TRACE_DISABLED_BY_DEFAULT("devtools.timeline.frame");
  43
  44 }  // namespace
  45
  46 using ThreadType = FrameInfo::SmoothEffectDrivingThread;
  47
  48 // In the |TRACKER_TRACE_STREAM|, we mod the numbers such as frame sequence
  49 // number, or frame token, such that the debug string is not too long.
  50 constexpr int kDebugStrMod = 1000;
  51
  52 const char* FrameSequenceTracker::GetFrameSequenceTrackerTypeName(
  53     FrameSequenceTrackerType type) {
  54   switch (type) {
  55     case FrameSequenceTrackerType::kCompositorAnimation:
  56       return "CompositorAnimation";
  57     case FrameSequenceTrackerType::kMainThreadAnimation:
  58       return "MainThreadAnimation";
  59     case FrameSequenceTrackerType::kPinchZoom:
  60       return "PinchZoom";
  61     case FrameSequenceTrackerType::kRAF:
  62       return "RAF";
  63     case FrameSequenceTrackerType::kTouchScroll:
  64       return "TouchScroll";
  65     case FrameSequenceTrackerType::kVideo:
  66       return "Video";
  67     case FrameSequenceTrackerType::kWheelScroll:
  68       return "WheelScroll";
  69     case FrameSequenceTrackerType::kScrollbarScroll:
  70       return "ScrollbarScroll";
  71     case FrameSequenceTrackerType::kCustom:
  72       return "Custom";
  73     case FrameSequenceTrackerType::kCanvasAnimation:
  74       return "CanvasAnimation";
  75     case FrameSequenceTrackerType::kJSAnimation:
  76       return "JSAnimation";
  77     case FrameSequenceTrackerType::kSETMainThreadAnimation:
  78       return "SETMainThreadAnimation";
  79     case FrameSequenceTrackerType::kSETCompositorAnimation:
  80       return "SETCompositorAnimation";
  81     case FrameSequenceTrackerType::kMaxType:
  82       return "";
  83   }
  84 }
  85
  86 FrameSequenceTracker::FrameSequenceTracker(
  87     FrameSequenceTrackerType type,
  88     ThroughputUkmReporter* throughput_ukm_reporter)
  89     : custom_sequence_id_(-1),
  90       metrics_(
  91           std::make_unique<FrameSequenceMetrics>(type,
  92                                                  throughput_ukm_reporter)) {
  93   DCHECK_LT(type, FrameSequenceTrackerType::kMaxType);
  94   DCHECK(type != FrameSequenceTrackerType::kCustom);
  95   // TODO(crbug.com/1158439): remove the trace event once the validation is
  96   // completed.
  97   TRACE_EVENT_NESTABLE_ASYNC_BEGIN_WITH_TIMESTAMP1(
  98       kTraceCategory, "TrackerValidation", TRACE_ID_LOCAL(this),
  99       base::TimeTicks::Now(), "name", GetFrameSequenceTrackerTypeName(type));
 100 }
 101
 102 FrameSequenceTracker::FrameSequenceTracker(
 103     int custom_sequence_id,
 104     FrameSequenceMetrics::CustomReporter custom_reporter)
 105     : custom_sequence_id_(custom_sequence_id),
 106       metrics_(std::make_unique<FrameSequenceMetrics>(
 107           FrameSequenceTrackerType::kCustom,
 108           /*ukm_reporter=*/nullptr)) {
 109   DCHECK_GT(custom_sequence_id_, 0);
 110   metrics_->SetCustomReporter(std::move(custom_reporter));
 111 }
 112
 113 FrameSequenceTracker::~FrameSequenceTracker() {
 114   TRACE_EVENT_NESTABLE_ASYNC_END_WITH_TIMESTAMP2(
 115       kTraceCategory, "TrackerValidation", TRACE_ID_LOCAL(this),
 116       base::TimeTicks::Now(), "aborted_main", aborted_main_frame_,
 117       "no_damage_main", no_damage_draw_main_frames_);
 118   CleanUp();
 119 }
 120
 121 void FrameSequenceTracker::ScheduleTerminate() {
 122   // If the last frame has ended and there is no frame awaiting presentation,
 123   // then it is ready to terminate.
 124   if (!is_inside_frame_ && last_submitted_frame_ == 0)
 125     termination_status_ = TerminationStatus::kReadyForTermination;
 126   else
 127     termination_status_ = TerminationStatus::kScheduledForTermination;
 128 }
 129
 130 void FrameSequenceTracker::ReportBeginImplFrame(
 131     const viz::BeginFrameArgs& args) {
 132   if (termination_status_ != TerminationStatus::kActive)
 133     return;
 134
 135   if (ShouldIgnoreBeginFrameSource(args.frame_id.source_id))
 136     return;
 137
 138   TRACKER_TRACE_STREAM << "b(" << args.frame_id.sequence_number % kDebugStrMod
 139                        << ")";
 140
 141   DCHECK(!is_inside_frame_) << TRACKER_DCHECK_MSG;
 142   is_inside_frame_ = true;
 143 #if DCHECK_IS_ON()
 144   if (args.type == viz::BeginFrameArgs::NORMAL)
 145     impl_frames_.insert(args.frame_id);
 146 #endif
 147
 148   DCHECK_EQ(last_started_impl_sequence_, 0u) << TRACKER_DCHECK_MSG;
 149   last_started_impl_sequence_ = args.frame_id.sequence_number;
 150   if (reset_all_state_) {
 151     begin_impl_frame_data_ = {};
 152     begin_main_frame_data_ = {};
 153     reset_all_state_ = false;
 154   }
 155
 156   DCHECK(!frame_had_no_compositor_damage_) << TRACKER_DCHECK_MSG;
 157   DCHECK(!compositor_frame_submitted_) << TRACKER_DCHECK_MSG;
 158
 159   UpdateTrackedFrameData(&begin_impl_frame_data_, args.frame_id.source_id,
 160                          args.frame_id.sequence_number,
 161                          args.frames_throttled_since_last);
 162   impl_throughput().frames_expected +=
 163       begin_impl_frame_data_.previous_sequence_delta;
 164 #if DCHECK_IS_ON()
 165   ++impl_throughput().frames_received;
 166 #endif
 167
 168   if (first_frame_timestamp_.is_null())
 169     first_frame_timestamp_ = args.frame_time;
 170 }
 171
 172 void FrameSequenceTracker::ReportBeginMainFrame(
 173     const viz::BeginFrameArgs& args) {
 174   if (termination_status_ != TerminationStatus::kActive)
 175     return;
 176
 177   if (ShouldIgnoreBeginFrameSource(args.frame_id.source_id))
 178     return;
 179
 180   TRACKER_TRACE_STREAM << "B("
 181                        << begin_main_frame_data_.previous_sequence %
 182                               kDebugStrMod
 183                        << "," << args.frame_id.sequence_number % kDebugStrMod
 184                        << ")";
 185
 186   if (first_received_main_sequence_ &&
 187       first_received_main_sequence_ > args.frame_id.sequence_number) {
 188     return;
 189   }
 190
 191   if (!first_received_main_sequence_ &&
 192       ShouldIgnoreSequence(args.frame_id.sequence_number)) {
 193     return;
 194   }
 195
 196 #if DCHECK_IS_ON()
 197   if (args.type == viz::BeginFrameArgs::NORMAL) {
 198     DCHECK(impl_frames_.contains(args.frame_id)) << TRACKER_DCHECK_MSG;
 199   }
 200 #endif
 201
 202   last_processed_main_sequence_latency_ = 0;
 203   pending_main_sequences_.push_back(args.frame_id.sequence_number);
 204
 205   UpdateTrackedFrameData(&begin_main_frame_data_, args.frame_id.source_id,
 206                          args.frame_id.sequence_number,
 207                          args.frames_throttled_since_last);
 208   if (!first_received_main_sequence_ ||
 209       first_received_main_sequence_ <= last_no_main_damage_sequence_) {
 210     first_received_main_sequence_ = args.frame_id.sequence_number;
 211   }
 212   main_throughput().frames_expected +=
 213       begin_main_frame_data_.previous_sequence_delta;
 214   previous_begin_main_sequence_ = current_begin_main_sequence_;
 215   current_begin_main_sequence_ = args.frame_id.sequence_number;
 216 }
 217
 218 void FrameSequenceTracker::ReportMainFrameProcessed(
 219     const viz::BeginFrameArgs& args) {
 220   if (termination_status_ != TerminationStatus::kActive)
 221     return;
 222
 223   if (ShouldIgnoreBeginFrameSource(args.frame_id.source_id))
 224     return;
 225
 226   TRACKER_TRACE_STREAM << "E(" << args.frame_id.sequence_number % kDebugStrMod
 227                        << ")";
 228
 229   const bool previous_main_frame_submitted_or_no_damage =
 230       previous_begin_main_sequence_ != 0 &&
 231       (last_submitted_main_sequence_ == previous_begin_main_sequence_ ||
 232        last_no_main_damage_sequence_ == previous_begin_main_sequence_);
 233   if (last_processed_main_sequence_ != 0 &&
 234       !had_impl_frame_submitted_between_commits_ &&
 235       !previous_main_frame_submitted_or_no_damage) {
 236     DCHECK_GE(main_throughput().frames_expected,
 237               begin_main_frame_data_.previous_sequence_delta)
 238         << TRACKER_DCHECK_MSG;
 239     main_throughput().frames_expected -=
 240         begin_main_frame_data_.previous_sequence_delta;
 241     last_no_main_damage_sequence_ = previous_begin_main_sequence_;
 242   }
 243   had_impl_frame_submitted_between_commits_ = false;
 244
 245   if (first_received_main_sequence_ &&
 246       args.frame_id.sequence_number >= first_received_main_sequence_) {
 247     DCHECK_EQ(last_processed_main_sequence_latency_, 0u) << TRACKER_DCHECK_MSG;
 248     last_processed_main_sequence_ = args.frame_id.sequence_number;
 249     last_processed_main_sequence_latency_ =
 250         std::max(last_started_impl_sequence_, last_processed_impl_sequence_) -
 251         args.frame_id.sequence_number;
 252   }
 253 }
 254
 255 void FrameSequenceTracker::ReportSubmitFrame(
 256     uint32_t frame_token,
 257     bool has_missing_content,
 258     const viz::BeginFrameAck& ack,
 259     const viz::BeginFrameArgs& origin_args) {
 260   DCHECK_NE(termination_status_, TerminationStatus::kReadyForTermination);
 261
 262   // TODO(crbug.com/1072482): find a proper way to terminate a tracker.
 263   // Right now, we define a magical number |frames_to_terminate_tracker| = 3,
 264   // which means that if this frame_token is more than 3 frames compared with
 265   // the last submitted frame, then we assume that the last submitted frame is
 266   // not going to be presented, and thus terminate this tracker.
 267   const uint32_t frames_to_terminate_tracker = 3;
 268   if (termination_status_ == TerminationStatus::kScheduledForTermination &&
 269       last_submitted_frame_ != 0 &&
 270       viz::FrameTokenGT(frame_token,
 271                         last_submitted_frame_ + frames_to_terminate_tracker)) {
 272     termination_status_ = TerminationStatus::kReadyForTermination;
 273     return;
 274   }
 275
 276   if (ShouldIgnoreBeginFrameSource(ack.frame_id.source_id) ||
 277       ShouldIgnoreSequence(ack.frame_id.sequence_number)) {
 278     ignored_frame_tokens_.insert(frame_token);
 279     return;
 280   }
 281
 282 #if DCHECK_IS_ON()
 283   DCHECK(is_inside_frame_) << TRACKER_DCHECK_MSG;
 284   DCHECK_LT(impl_throughput().frames_processed,
 285             impl_throughput().frames_received)
 286       << TRACKER_DCHECK_MSG;
 287   ++impl_throughput().frames_processed;
 288 #endif
 289
 290   last_processed_impl_sequence_ = ack.frame_id.sequence_number;
 291   if (first_submitted_frame_ == 0)
 292     first_submitted_frame_ = frame_token;
 293   last_submitted_frame_ = frame_token;
 294   compositor_frame_submitted_ = true;
 295
 296   TRACKER_TRACE_STREAM << "s(" << frame_token % kDebugStrMod << ")";
 297   had_impl_frame_submitted_between_commits_ = true;
 298   metrics()->NotifySubmitForJankReporter(
 299       FrameInfo::SmoothEffectDrivingThread::kCompositor, frame_token,
 300       ack.frame_id.sequence_number);
 301
 302   const bool main_changes_after_sequence_started =
 303       first_received_main_sequence_ &&
 304       origin_args.frame_id.sequence_number >= first_received_main_sequence_;
 305   const bool main_changes_include_new_changes =
 306       last_submitted_main_sequence_ == 0 ||
 307       origin_args.frame_id.sequence_number > last_submitted_main_sequence_;
 308   const bool main_change_had_no_damage =
 309       last_no_main_damage_sequence_ != 0 &&
 310       origin_args.frame_id.sequence_number == last_no_main_damage_sequence_;
 311   const bool origin_args_is_valid = origin_args.frame_id.sequence_number <=
 312                                     begin_main_frame_data_.previous_sequence;
 313
 314   if (!ShouldIgnoreBeginFrameSource(origin_args.frame_id.source_id) &&
 315       origin_args_is_valid) {
 316     if (main_changes_after_sequence_started &&
 317         main_changes_include_new_changes && !main_change_had_no_damage) {
 318       submitted_frame_had_new_main_content_ = true;
 319       TRACKER_TRACE_STREAM << "S("
 320                            << origin_args.frame_id.sequence_number %
 321                                   kDebugStrMod
 322                            << ")";
 323       metrics()->NotifySubmitForJankReporter(
 324           FrameInfo::SmoothEffectDrivingThread::kMain, frame_token,
 325           origin_args.frame_id.sequence_number);
 326
 327       last_submitted_main_sequence_ = origin_args.frame_id.sequence_number;
 328       main_frames_.push_back(frame_token);
 329       DCHECK_GE(main_throughput().frames_expected, main_frames_.size())
 330           << TRACKER_DCHECK_MSG;
 331     }
 332   }
 333
 334   if (has_missing_content) {
 335     checkerboarding_.frames.push_back(frame_token);
 336   }
 337 }
 338
 339 void FrameSequenceTracker::ReportFrameEnd(
 340     const viz::BeginFrameArgs& args,
 341     const viz::BeginFrameArgs& main_args) {
 342   DCHECK_NE(termination_status_, TerminationStatus::kReadyForTermination);
 343
 344   if (ShouldIgnoreBeginFrameSource(args.frame_id.source_id))
 345     return;
 346
 347   // We only update the `pending_main_sequences` when the frame has successfully
 348   // submitted, or when we determine that it has no damage. See
 349   // ReportMainFrameCausedNoDamage. We do not do this in
 350   // NotifyMainFrameProcessed, as that can occur during Commit, and we may yet
 351   // determine at Draw that there was no damage.
 352   while (!pending_main_sequences_.empty() &&
 353          pending_main_sequences_.front() <=
 354              main_args.frame_id.sequence_number) {
 355     pending_main_sequences_.pop_front();
 356   }
 357   TRACKER_TRACE_STREAM << "e(" << args.frame_id.sequence_number % kDebugStrMod
 358                        << ","
 359                        << main_args.frame_id.sequence_number % kDebugStrMod
 360                        << ")";
 361
 362   bool should_ignore_sequence =
 363       ShouldIgnoreSequence(args.frame_id.sequence_number);
 364   if (reset_all_state_) {
 365     begin_impl_frame_data_ = {};
 366     begin_main_frame_data_ = {};
 367     reset_all_state_ = false;
 368   }
 369
 370   if (should_ignore_sequence) {
 371     is_inside_frame_ = false;
 372     return;
 373   }
 374
 375   if (compositor_frame_submitted_ && submitted_frame_had_new_main_content_ &&
 376       last_processed_main_sequence_latency_) {
 377     // If a compositor frame was submitted with new content from the
 378     // main-thread, then make sure the latency gets accounted for.
 379     main_throughput().frames_expected += last_processed_main_sequence_latency_;
 380   }
 381
 382   // It is possible that the compositor claims there was no damage from the
 383   // compositor, but before the frame ends, it submits a compositor frame (e.g.
 384   // with some damage from main). In such cases, the compositor is still
 385   // responsible for processing the update, and therefore the 'no damage' claim
 386   // is ignored.
 387   if (frame_had_no_compositor_damage_ && !compositor_frame_submitted_) {
 388     DCHECK_GT(impl_throughput().frames_expected, 0u) << TRACKER_DCHECK_MSG;
 389     DCHECK_GT(impl_throughput().frames_expected,
 390               impl_throughput().frames_produced)
 391         << TRACKER_DCHECK_MSG;
 392     DCHECK_GE(impl_throughput().frames_produced,
 393               impl_throughput().frames_ontime)
 394         << TRACKER_DCHECK_MSG;
 395     --impl_throughput().frames_expected;
 396     metrics()->NotifyNoUpdateForJankReporter(
 397         FrameInfo::SmoothEffectDrivingThread::kCompositor,
 398         args.frame_id.sequence_number, args.interval);
 399 #if DCHECK_IS_ON()
 400     ++impl_throughput().frames_processed;
 401     // If these two are the same, it means that each impl frame is either
 402     // no-damage or submitted. That's expected, so we don't need those in the
 403     // output of DCHECK.
 404     if (impl_throughput().frames_processed == impl_throughput().frames_received)
 405       ignored_trace_char_count_ = frame_sequence_trace_.str().size();
 406     else
 407       NOTREACHED() << TRACKER_DCHECK_MSG;
 408 #endif
 409     begin_impl_frame_data_.previous_sequence = 0;
 410   }
 411   // last_submitted_frame_ == 0 means the last impl frame has been presented.
 412   if (termination_status_ == TerminationStatus::kScheduledForTermination &&
 413       last_submitted_frame_ == 0)
 414     termination_status_ = TerminationStatus::kReadyForTermination;
 415
 416   frame_had_no_compositor_damage_ = false;
 417   compositor_frame_submitted_ = false;
 418   submitted_frame_had_new_main_content_ = false;
 419   last_processed_main_sequence_latency_ = 0;
 420
 421   DCHECK(is_inside_frame_) << TRACKER_DCHECK_MSG;
 422   is_inside_frame_ = false;
 423
 424   DCHECK_EQ(last_started_impl_sequence_, last_processed_impl_sequence_)
 425       << TRACKER_DCHECK_MSG;
 426   last_started_impl_sequence_ = 0;
 427 }
 428
 429 void FrameSequenceTracker::ReportFramePresented(
 430     uint32_t frame_token,
 431     const gfx::PresentationFeedback& feedback) {
 432   // TODO(xidachen): We should early exit if |last_submitted_frame_| = 0, as it
 433   // means that we are presenting the same frame_token again.
 434   const bool submitted_frame_since_last_presentation = !!last_submitted_frame_;
 435   // !viz::FrameTokenGT(a, b) is equivalent to b >= a.
 436   const bool frame_token_acks_last_frame =
 437       !viz::FrameTokenGT(last_submitted_frame_, frame_token);
 438
 439   // Even if the presentation timestamp is null, we set last_submitted_frame_ to
 440   // 0 such that the tracker can be terminated.
 441   if (last_submitted_frame_ && frame_token_acks_last_frame)
 442     last_submitted_frame_ = 0;
 443   // Update termination status if this is scheduled for termination, and it is
 444   // not waiting for any frames, or it has received the presentation-feedback
 445   // for the latest frame it is tracking.
 446   //
 447   // We should always wait for an impl frame to end, that is, ReportFrameEnd.
 448   if (termination_status_ == TerminationStatus::kScheduledForTermination &&
 449       last_submitted_frame_ == 0 && !is_inside_frame_) {
 450     termination_status_ = TerminationStatus::kReadyForTermination;
 451   }
 452
 453   if (first_submitted_frame_ == 0 ||
 454       viz::FrameTokenGT(first_submitted_frame_, frame_token)) {
 455     // We are getting presentation feedback for frames that were submitted
 456     // before this sequence started. So ignore these.
 457     return;
 458   }
 459
 460   TRACKER_TRACE_STREAM << "P(" << frame_token % kDebugStrMod << ")";
 461
 462   base::EraseIf(ignored_frame_tokens_, [frame_token](const uint32_t& token) {
 463     return viz::FrameTokenGT(frame_token, token);
 464   });
 465   if (ignored_frame_tokens_.contains(frame_token))
 466     return;
 467
 468   const auto vsync_interval =
 469       (feedback.interval.is_zero() ? viz::BeginFrameArgs::DefaultInterval()
 470                                    : feedback.interval);
 471   DCHECK(!vsync_interval.is_zero()) << TRACKER_DCHECK_MSG;
 472   base::TimeTicks safe_deadline_for_frame =
 473       last_frame_presentation_timestamp_ + vsync_interval * 1.5;
 474
 475   const bool was_presented = !feedback.failed();
 476   if (was_presented && submitted_frame_since_last_presentation) {
 477     if (!last_frame_presentation_timestamp_.is_null() &&
 478         (safe_deadline_for_frame < feedback.timestamp)) {
 479       DCHECK_LE(impl_throughput().frames_ontime,
 480                 impl_throughput().frames_produced)
 481           << TRACKER_DCHECK_MSG;
 482       ++impl_throughput().frames_ontime;
 483     }
 484
 485     DCHECK_LT(impl_throughput().frames_produced,
 486               impl_throughput().frames_expected)
 487         << TRACKER_DCHECK_MSG;
 488     ++impl_throughput().frames_produced;
 489     if (metrics()->GetEffectiveThread() == ThreadType::kCompositor) {
 490       metrics()->AdvanceTrace(feedback.timestamp);
 491     }
 492
 493     metrics()->ComputeJank(FrameInfo::SmoothEffectDrivingThread::kCompositor,
 494                            frame_token, feedback.timestamp, vsync_interval);
 495   }
 496
 497   if (was_presented) {
 498     // This presentation includes the visual update from all main frame tokens
 499     // <= |frame_token|.
 500     const unsigned size_before_erase = main_frames_.size();
 501     while (!main_frames_.empty() &&
 502            !viz::FrameTokenGT(main_frames_.front(), frame_token)) {
 503       main_frames_.pop_front();
 504     }
 505     if (main_frames_.size() < size_before_erase) {
 506       DCHECK_LT(main_throughput().frames_produced,
 507                 main_throughput().frames_expected)
 508           << TRACKER_DCHECK_MSG;
 509       ++main_throughput().frames_produced;
 510       if (metrics()->GetEffectiveThread() == ThreadType::kMain) {
 511         metrics()->AdvanceTrace(feedback.timestamp);
 512       }
 513
 514       metrics()->ComputeJank(FrameInfo::SmoothEffectDrivingThread::kMain,
 515                              frame_token, feedback.timestamp, vsync_interval);
 516     }
 517     if (main_frames_.size() < size_before_erase) {
 518       if (!last_frame_presentation_timestamp_.is_null() &&
 519           (safe_deadline_for_frame < feedback.timestamp)) {
 520         DCHECK_LE(main_throughput().frames_ontime,
 521                   main_throughput().frames_produced)
 522             << TRACKER_DCHECK_MSG;
 523         ++main_throughput().frames_ontime;
 524       }
 525     }
 526     last_frame_presentation_timestamp_ = feedback.timestamp;
 527
 528     if (checkerboarding_.last_frame_had_checkerboarding) {
 529       DCHECK(!checkerboarding_.last_frame_timestamp.is_null())
 530           << TRACKER_DCHECK_MSG;
 531       DCHECK(!feedback.timestamp.is_null()) << TRACKER_DCHECK_MSG;
 532
 533       // |feedback.timestamp| is the timestamp when the latest frame was
 534       // presented. |checkerboarding_.last_frame_timestamp| is the timestamp
 535       // when the previous frame (which had checkerboarding) was presented. Use
 536       // |feedback.interval| to compute the number of vsyncs that have passed
 537       // between the two frames (since that is how many times the user saw that
 538       // checkerboarded frame).
 539       base::TimeDelta difference =
 540           feedback.timestamp - checkerboarding_.last_frame_timestamp;
 541       const auto& interval = feedback.interval.is_zero()
 542                                  ? viz::BeginFrameArgs::DefaultInterval()
 543                                  : feedback.interval;
 544       DCHECK(!interval.is_zero()) << TRACKER_DCHECK_MSG;
 545       constexpr base::TimeDelta kEpsilon = base::Milliseconds(1);
 546       int64_t frames = (difference + kEpsilon).IntDiv(interval);
 547       metrics_->add_checkerboarded_frames(frames);
 548     }
 549
 550     const bool frame_had_checkerboarding =
 551         base::Contains(checkerboarding_.frames, frame_token);
 552     checkerboarding_.last_frame_had_checkerboarding = frame_had_checkerboarding;
 553     checkerboarding_.last_frame_timestamp = feedback.timestamp;
 554   }
 555
 556   while (!checkerboarding_.frames.empty() &&
 557          !viz::FrameTokenGT(checkerboarding_.frames.front(), frame_token)) {
 558     checkerboarding_.frames.pop_front();
 559   }
 560 }
 561
 562 void FrameSequenceTracker::ReportImplFrameCausedNoDamage(
 563     const viz::BeginFrameAck& ack) {
 564   DCHECK_NE(termination_status_, TerminationStatus::kReadyForTermination);
 565
 566   if (ShouldIgnoreBeginFrameSource(ack.frame_id.source_id))
 567     return;
 568
 569   TRACKER_TRACE_STREAM << "n(" << ack.frame_id.sequence_number % kDebugStrMod
 570                        << ")";
 571
 572   // This tracker would be scheduled to terminate, and this frame doesn't belong
 573   // to that tracker.
 574   if (ShouldIgnoreSequence(ack.frame_id.sequence_number))
 575     return;
 576
 577   last_processed_impl_sequence_ = ack.frame_id.sequence_number;
 578   // If there is no damage for this frame (and no frame is submitted), then the
 579   // impl-sequence needs to be reset. However, this should be done after the
 580   // processing the frame is complete (i.e. in ReportFrameEnd()), so that other
 581   // notifications (e.g. 'no main damage' etc.) can be handled correctly.
 582   DCHECK_EQ(begin_impl_frame_data_.previous_sequence,
 583             ack.frame_id.sequence_number);
 584   frame_had_no_compositor_damage_ = true;
 585 }
 586
 587 void FrameSequenceTracker::ReportMainFrameCausedNoDamage(
 588     const viz::BeginFrameArgs& args,
 589     bool aborted) {
 590   if (termination_status_ != TerminationStatus::kActive)
 591     return;
 592
 593   if (ShouldIgnoreBeginFrameSource(args.frame_id.source_id))
 594     return;
 595
 596   TRACKER_TRACE_STREAM << "N("
 597                        << begin_main_frame_data_.previous_sequence %
 598                               kDebugStrMod
 599                        << "," << args.frame_id.sequence_number % kDebugStrMod
 600                        << ")";
 601
 602   if (!first_received_main_sequence_ ||
 603       first_received_main_sequence_ > args.frame_id.sequence_number) {
 604     return;
 605   }
 606
 607   if (last_no_main_damage_sequence_ == args.frame_id.sequence_number)
 608     return;
 609
 610   auto initial_pending_size = pending_main_sequences_.size();
 611   while (!pending_main_sequences_.empty() &&
 612          pending_main_sequences_.front() <= args.frame_id.sequence_number) {
 613     pending_main_sequences_.pop_front();
 614   }
 615   // If we didn't remove any `pending_main_sequences`, then we have previously
 616   // submitted a CompositorFrame with damage for `args.frame_id.sequence_number`
 617   // and the sequence is being re-used on a subsequent Impl frame. Which just
 618   // happens to have no damage.
 619   //
 620   // This can occur when there is a Compositor Animation that is offscreen, and
 621   // when we are awaiting the next BeginMainFrame to be Committed and Activated.
 622   //
 623   // We do not change the `main_throughput` expectations when the sequence is
 624   // re-used.
 625   if (pending_main_sequences_.size() == initial_pending_size)
 626     return;
 627
 628   if (aborted)
 629     ++aborted_main_frame_;
 630   else
 631     ++no_damage_draw_main_frames_;
 632
 633   DCHECK_GT(main_throughput().frames_expected, 0u) << TRACKER_DCHECK_MSG;
 634   DCHECK_GT(main_throughput().frames_expected,
 635             main_throughput().frames_produced)
 636       << TRACKER_DCHECK_MSG;
 637   DCHECK_GE(main_throughput().frames_produced, main_throughput().frames_ontime)
 638       << TRACKER_DCHECK_MSG;
 639   last_no_main_damage_sequence_ = args.frame_id.sequence_number;
 640   --main_throughput().frames_expected;
 641   metrics()->NotifyNoUpdateForJankReporter(
 642       FrameInfo::SmoothEffectDrivingThread::kMain,
 643       args.frame_id.sequence_number, args.interval);
 644
 645   DCHECK_GE(main_throughput().frames_expected, main_frames_.size())
 646       << TRACKER_DCHECK_MSG;
 647
 648   // Could be 0 if there were a pause frame production.
 649   if (begin_main_frame_data_.previous_sequence != 0) {
 650     DCHECK_GE(begin_main_frame_data_.previous_sequence,
 651               args.frame_id.sequence_number)
 652         << TRACKER_DCHECK_MSG;
 653   }
 654   begin_main_frame_data_.previous_sequence = 0;
 655 }
 656
 657 void FrameSequenceTracker::PauseFrameProduction() {
 658   // The states need to be reset, so that the tracker ignores the vsyncs until
 659   // the next received begin-frame. However, defer doing that until the frame
 660   // ends (or a new frame starts), so that in case a frame is in-progress,
 661   // subsequent notifications for that frame can be handled correctly.
 662   TRACKER_TRACE_STREAM << 'R';
 663   reset_all_state_ = true;
 664 }
 665
 666 void FrameSequenceTracker::UpdateTrackedFrameData(
 667     TrackedFrameData* frame_data,
 668     uint64_t source_id,
 669     uint64_t sequence_number,
 670     uint64_t throttled_frame_count) {
 671   if (frame_data->previous_sequence &&
 672       frame_data->previous_source == source_id) {
 673     uint32_t current_latency =
 674         sequence_number - frame_data->previous_sequence - throttled_frame_count;
 675     DCHECK_GT(current_latency, 0u) << TRACKER_DCHECK_MSG;
 676     frame_data->previous_sequence_delta = current_latency;
 677   } else {
 678     frame_data->previous_sequence_delta = 1;
 679   }
 680   frame_data->previous_source = source_id;
 681   frame_data->previous_sequence = sequence_number;
 682 }
 683
 684 bool FrameSequenceTracker::ShouldIgnoreBeginFrameSource(
 685     uint64_t source_id) const {
 686   if (begin_impl_frame_data_.previous_source == 0)
 687     return source_id == viz::BeginFrameArgs::kManualSourceId;
 688   return source_id != begin_impl_frame_data_.previous_source;
 689 }
 690
 691 // This check handles two cases:
 692 // 1. When there is a call to ReportBeginMainFrame, or ReportSubmitFrame, or
 693 // ReportFramePresented, there must be a ReportBeginImplFrame for that sequence.
 694 // Otherwise, the begin_impl_frame_data_.previous_sequence would be 0.
 695 // 2. A tracker is scheduled to terminate, then any new request to handle a new
 696 // impl frame whose sequence_number > begin_impl_frame_data_.previous_sequence
 697 // should be ignored.
 698 // Note that sequence_number < begin_impl_frame_data_.previous_sequence cannot
 699 // happen.
 700 bool FrameSequenceTracker::ShouldIgnoreSequence(
 701     uint64_t sequence_number) const {
 702   return sequence_number != begin_impl_frame_data_.previous_sequence;
 703 }
 704
 705 bool FrameSequenceTracker::ShouldReportMetricsNow(
 706     const viz::BeginFrameArgs& args) const {
 707   return metrics_->HasEnoughDataForReporting() &&
 708          !first_frame_timestamp_.is_null() &&
 709          args.frame_time - first_frame_timestamp_ >= time_delta_to_report_;
 710 }
 711
 712 std::unique_ptr<FrameSequenceMetrics> FrameSequenceTracker::TakeMetrics() {
 713 #if DCHECK_IS_ON()
 714   DCHECK_EQ(impl_throughput().frames_received,
 715             impl_throughput().frames_processed)
 716       << frame_sequence_trace_.str().substr(ignored_trace_char_count_);
 717 #endif
 718   return std::move(metrics_);
 719 }
 720
 721 void FrameSequenceTracker::CleanUp() {
 722   if (metrics_)
 723     metrics_->ReportLeftoverData();
 724 }
 725
 726 void FrameSequenceTracker::AddSortedFrame(const viz::BeginFrameArgs& args,
 727                                           const FrameInfo& frame_info) {
 728   if (metrics_)
 729     metrics_->AddSortedFrame(args, frame_info);
 730 }
 731
 732 FrameSequenceTracker::CheckerboardingData::CheckerboardingData() = default;
 733 FrameSequenceTracker::CheckerboardingData::~CheckerboardingData() = default;
 734
 735 }  // namespace cc