Add jank metrics implementation

This CL implements the jank metrics that track abrupt drop in smoothness
(i.e. increase in frame latency). Jank metrics histograms are reported
under the "Graphics.Smoothness.Jank" namespace and the histogram names
indicate the frame sequence tracker (and its effective thread type) each
jank metric is associated with (e.g.
Graphics.Smoothness.Jank.Main.WheelScroll). Each jank occurrence is also
visualized as a trace event spanning the duration of the janky frame.

Bug: 1073216
Change-Id: I50bf8983d9c94cda68234d0423308beed1f8d5d7
Reviewed-on: https://chromium-review.googlesource.com/c/chromium/src/+/2248173Reviewed-by: Sadrul Chowdhury <sadrul@chromium.org>
Reviewed-by: Behdad Bakhshinategh <behdadb@chromium.org>
Commit-Queue: Mingjing Zhang <mjzhang@chromium.org>
Cr-Commit-Position: refs/heads/master@{#798350}

cc/BUILD.gn

-# Copyright 2014 The Chromium Authors. All rights reserved.
-# Use of this source code is governed by a BSD-style license that can be
+# Copyright 2014 The Chromium Authors.All rights reserved.
+# Use of this source code is governed by a BSD - style license that can be
 # found in the LICENSE file.
 import("//build/config/sanitizers/sanitizers.gni")
 import("//gpu/vulkan/features.gni")
@@ -175,6 +175,8 @@ cc_component("cc") {
     "metrics/frame_sequence_tracker.h",
     "metrics/frame_sequence_tracker_collection.cc",
     "metrics/frame_sequence_tracker_collection.h",
+    "metrics/jank_metrics.cc",
+    "metrics/jank_metrics.h",
     "metrics/latency_ukm_reporter.cc",
     "metrics/latency_ukm_reporter.h",
     "metrics/lcd_text_metrics_reporter.cc",
@@ -675,6 +677,7 @@ cc_test("cc_unittests") {
     "metrics/events_metrics_manager_unittest.cc",
     "metrics/frame_sequence_metrics_unittest.cc",
     "metrics/frame_sequence_tracker_unittest.cc",
+    "metrics/jank_metrics_unittest.cc",
     "metrics/video_playback_roughness_reporter_unittest.cc",
     "mojo_embedder/async_layer_tree_frame_sink_unittest.cc",
     "paint/clear_for_opaque_raster_unittest.cc",

cc/metrics/frame_sequence_metrics.cc

@@ -14,6 +14,7 @@
 #include "base/trace_event/trace_event.h"
 #include "base/trace_event/traced_value.h"
 #include "cc/metrics/frame_sequence_tracker.h"
+#include "cc/metrics/jank_metrics.h"
 #include "cc/metrics/throughput_ukm_reporter.h"
 
 namespace cc {
@@ -97,6 +98,16 @@ bool IsInteractionType(FrameSequenceTrackerType sequence_type) {
 FrameSequenceMetrics::FrameSequenceMetrics(FrameSequenceTrackerType type,
                                            ThroughputUkmReporter* ukm_reporter)
     : type_(type), throughput_ukm_reporter_(ukm_reporter) {
+  ThreadType thread_type = GetEffectiveThread();
+
+  // Only construct |jank_reporter_| if it has a valid tracker and thread type.
+  // For scrolling tracker types, |jank_reporter_| may be constructed later in
+  // SetScrollingThread().
+  if ((thread_type == ThreadType::kCompositor ||
+       thread_type == ThreadType::kMain) &&
+      type != FrameSequenceTrackerType::kUniversal &&
+      type != FrameSequenceTrackerType::kCustom)
+    jank_reporter_ = std::make_unique<JankMetrics>(type, thread_type);
 }
 
 FrameSequenceMetrics::~FrameSequenceMetrics() = default;
@@ -121,6 +132,11 @@ void FrameSequenceMetrics::SetScrollingThread(ThreadType scrolling_thread) {
          type_ == FrameSequenceTrackerType::kScrollbarScroll);
   DCHECK_EQ(scrolling_thread_, ThreadType::kUnknown);
   scrolling_thread_ = scrolling_thread;
+
+  DCHECK(!jank_reporter_);
+  DCHECK_NE(scrolling_thread, ThreadType::kSlower);
+  DCHECK_NE(scrolling_thread, ThreadType::kUnknown);
+  jank_reporter_ = std::make_unique<JankMetrics>(type_, scrolling_thread);
 }
 
 void FrameSequenceMetrics::SetCustomReporter(CustomReporter custom_reporter) {
@@ -168,6 +184,9 @@ void FrameSequenceMetrics::Merge(
   aggregated_throughput_.Merge(metrics->aggregated_throughput_);
   frames_checkerboarded_ += metrics->frames_checkerboarded_;
 
+  if (jank_reporter_)
+    jank_reporter_->Merge(std::move(metrics->jank_reporter_));
+
   // Reset the state of |metrics| before destroying it, so that it doesn't end
   // up reporting the metrics.
   metrics->impl_throughput_ = {};
@@ -296,6 +315,18 @@ void FrameSequenceMetrics::ReportMetrics() {
     frames_checkerboarded_ = 0;
   }
 
+  // Report the jank metrics
+  if (jank_reporter_) {
+    if (jank_reporter_->thread_type() ==
+            FrameSequenceMetrics::ThreadType::kCompositor &&
+        impl_throughput_.frames_expected >= kMinFramesForThroughputMetric)
+      jank_reporter_->ReportJankMetrics(impl_throughput_.frames_expected);
+    else if (jank_reporter_->thread_type() ==
+                 FrameSequenceMetrics::ThreadType::kMain &&
+             main_throughput_.frames_expected >= kMinFramesForThroughputMetric)
+      jank_reporter_->ReportJankMetrics(main_throughput_.frames_expected);
+  }
+
   // Reset the metrics that reach reporting threshold.
   if (impl_throughput_.frames_expected >= kMinFramesForThroughputMetric) {
     impl_throughput_ = {};
@@ -305,6 +336,17 @@ void FrameSequenceMetrics::ReportMetrics() {
     main_throughput_ = {};
 }
 
+void FrameSequenceMetrics::ComputeJank(
+    FrameSequenceMetrics::ThreadType thread_type,
+    base::TimeTicks presentation_time,
+    base::TimeDelta frame_interval) {
+  if (!jank_reporter_)
+    return;
+
+  if (thread_type == jank_reporter_->thread_type())
+    jank_reporter_->AddPresentedFrame(presentation_time, frame_interval);
+}
+
 base::Optional<int> FrameSequenceMetrics::ThroughputData::ReportHistogram(
     FrameSequenceMetrics* metrics,
     ThreadType thread_type,

cc/metrics/frame_sequence_metrics.h

@@ -14,6 +14,7 @@
 
 namespace cc {
 class ThroughputUkmReporter;
+class JankMetrics;
 
 enum class FrameSequenceTrackerType {
   // Used as an enum for metrics. DO NOT reorder or delete values. Rather,
@@ -126,6 +127,10 @@ class CC_EXPORT FrameSequenceMetrics {
   void AdoptTrace(FrameSequenceMetrics* adopt_from);
   void AdvanceTrace(base::TimeTicks timestamp);
 
+  void ComputeJank(FrameSequenceMetrics::ThreadType thread_type,
+                   base::TimeTicks presentation_time,
+                   base::TimeDelta frame_interval);
+
  private:
   const FrameSequenceTrackerType type_;
 
@@ -159,6 +164,8 @@ class CC_EXPORT FrameSequenceMetrics {
 
   // Callback invoked to report metrics for kCustom typed sequence.
   CustomReporter custom_reporter_;
+
+  std::unique_ptr<JankMetrics> jank_reporter_;
 };
 
 }  // namespace cc

cc/metrics/frame_sequence_tracker.cc

@@ -450,6 +450,9 @@ void FrameSequenceTracker::ReportFramePresented(
     if (metrics()->GetEffectiveThread() == ThreadType::kCompositor) {
       metrics()->AdvanceTrace(feedback.timestamp);
     }
+
+    metrics()->ComputeJank(FrameSequenceMetrics::ThreadType::kCompositor,
+                           feedback.timestamp, feedback.interval);
   }
 
   if (was_presented) {
@@ -469,6 +472,9 @@ void FrameSequenceTracker::ReportFramePresented(
       if (metrics()->GetEffectiveThread() == ThreadType::kMain) {
         metrics()->AdvanceTrace(feedback.timestamp);
       }
+
+      metrics()->ComputeJank(FrameSequenceMetrics::ThreadType::kMain,
+                             feedback.timestamp, feedback.interval);
     }
 
     if (impl_frames_produced > 0) {

cc/metrics/jank_metrics.cc

+// Copyright 2020 The Chromium Authors. All rights reserved.
+// Use of this source code is governed by a BSD-style license that can be
+// found in the LICENSE file.
+
+#include "cc/metrics/jank_metrics.h"
+
+#include <memory>
+#include <string>
+#include <utility>
+
+#include "base/metrics/histogram.h"
+#include "base/metrics/histogram_macros.h"
+#include "base/strings/strcat.h"
+#include "base/trace_event/trace_event.h"
+#include "cc/metrics/frame_sequence_tracker.h"
+
+namespace cc {
+
+namespace {
+
+constexpr int kBuiltinSequenceNum =
+    static_cast<int>(FrameSequenceTrackerType::kMaxType) + 1;
+constexpr int kMaximumJankHistogramIndex = 2 * kBuiltinSequenceNum;
+
+constexpr bool IsValidJankThreadType(FrameSequenceMetrics::ThreadType type) {
+  return type == FrameSequenceMetrics::ThreadType::kCompositor ||
+         type == FrameSequenceMetrics::ThreadType::kMain;
+}
+
+const char* GetJankThreadTypeName(FrameSequenceMetrics::ThreadType type) {
+  DCHECK(IsValidJankThreadType(type));
+
+  switch (type) {
+    case FrameSequenceMetrics::ThreadType::kCompositor:
+      return "Compositor";
+    case FrameSequenceMetrics::ThreadType::kMain:
+      return "Main";
+    default:
+      NOTREACHED();
+      return "";
+  }
+}
+
+int GetIndexForJankMetric(FrameSequenceMetrics::ThreadType thread_type,
+                          FrameSequenceTrackerType type) {
+  DCHECK(IsValidJankThreadType(thread_type));
+  if (thread_type == FrameSequenceMetrics::ThreadType::kMain)
+    return static_cast<int>(type);
+
+  DCHECK_EQ(thread_type, FrameSequenceMetrics::ThreadType::kCompositor);
+  return static_cast<int>(type) + kBuiltinSequenceNum;
+}
+
+std::string GetJankHistogramName(FrameSequenceTrackerType type,
+                                 const char* thread_name) {
+  return base::StrCat(
+      {"Graphics.Smoothness.Jank.", thread_name, ".",
+       FrameSequenceTracker::GetFrameSequenceTrackerTypeName(type)});
+}
+
+}  // namespace
+
+JankMetrics::JankMetrics(FrameSequenceTrackerType tracker_type,
+                         FrameSequenceMetrics::ThreadType effective_thread)
+    : tracker_type_(tracker_type), effective_thread_(effective_thread) {
+  DCHECK(IsValidJankThreadType(effective_thread));
+}
+JankMetrics::~JankMetrics() = default;
+
+void JankMetrics::AddPresentedFrame(
+    base::TimeTicks current_presentation_timestamp,
+    base::TimeDelta frame_interval) {
+  base::TimeDelta current_frame_delta =
+      current_presentation_timestamp - last_presentation_timestamp_;
+
+  // Only start tracking jank if this function has been called (so that
+  // |last_presentation_timestamp_| and |prev_frame_delta_| have been set).
+  //
+  // The presentation interval is typically a multiple of VSync intervals (i.e.
+  // 16.67ms, 33.33ms, 50ms ... on a 60Hz display) with small fluctuations. The
+  // 0.5 * |frame_interval| criterion is chosen so that the jank detection is
+  // robust to those fluctuations.
+  if (!last_presentation_timestamp_.is_null() && !prev_frame_delta_.is_zero() &&
+      current_frame_delta > prev_frame_delta_ + 0.5 * frame_interval) {
+    jank_count_++;
+
+    TRACE_EVENT_NESTABLE_ASYNC_BEGIN_WITH_TIMESTAMP1(
+        "cc,benchmark", "Jank", TRACE_ID_LOCAL(this),
+        last_presentation_timestamp_, "thread-type",
+        GetJankThreadTypeName(effective_thread_));
+    TRACE_EVENT_NESTABLE_ASYNC_END_WITH_TIMESTAMP1(
+        "cc,benchmark", "Jank", TRACE_ID_LOCAL(this),
+        current_presentation_timestamp, "tracker-type",
+        FrameSequenceTracker::GetFrameSequenceTrackerTypeName(tracker_type_));
+  }
+  last_presentation_timestamp_ = current_presentation_timestamp;
+
+  prev_frame_delta_ = current_frame_delta;
+}
+
+void JankMetrics::ReportJankMetrics(int frames_expected) {
+  if (tracker_type_ == FrameSequenceTrackerType::kUniversal ||
+      tracker_type_ == FrameSequenceTrackerType::kCustom)
+    return;
+
+  int jank_percent = static_cast<int>(100 * jank_count_ / frames_expected);
+
+  const char* jank_thread_name = GetJankThreadTypeName(effective_thread_);
+
+  STATIC_HISTOGRAM_POINTER_GROUP(
+      GetJankHistogramName(tracker_type_, jank_thread_name),
+      GetIndexForJankMetric(effective_thread_, tracker_type_),
+      kMaximumJankHistogramIndex, Add(jank_percent),
+      base::LinearHistogram::FactoryGet(
+          GetJankHistogramName(tracker_type_, jank_thread_name), 1, 100, 101,
+          base::HistogramBase::kUmaTargetedHistogramFlag));
+}
+
+void JankMetrics::Merge(std::unique_ptr<JankMetrics> jank_metrics) {
+  if (jank_metrics)
+    jank_count_ += jank_metrics->jank_count_;
+}
+
+}  // namespace cc

cc/metrics/jank_metrics.h

+// Copyright 2020 The Chromium Authors. All rights reserved.
+// Use of this source code is governed by a BSD-style license that can be
+// found in the LICENSE file.
+
+#ifndef CC_METRICS_JANK_METRICS_H_
+#define CC_METRICS_JANK_METRICS_H_
+
+#include <memory>
+
+#include "cc/metrics/frame_sequence_metrics.h"
+
+namespace cc {
+class CC_EXPORT JankMetrics {
+ public:
+  JankMetrics(FrameSequenceTrackerType tracker_type,
+              FrameSequenceMetrics::ThreadType effective_thread);
+  ~JankMetrics();
+
+  JankMetrics(const JankMetrics&) = delete;
+  JankMetrics& operator=(const JankMetrics&) = delete;
+
+  // Check if a jank occurs based on the timestamps of recent presentations.
+  // If there is a jank, increment |jank_count_| and log a trace event.
+  void AddPresentedFrame(base::TimeTicks current_presentation_timestamp,
+                         base::TimeDelta frame_interval);
+
+  // Report the occurrence rate of janks as a UMA metric.
+  void ReportJankMetrics(int frames_expected);
+
+  // Merge the current jank count with a previously unreported jank metrics.
+  void Merge(std::unique_ptr<JankMetrics> jank_metrics);
+
+  FrameSequenceMetrics::ThreadType thread_type() const {
+    return effective_thread_;
+  }
+
+ private:
+  // The type of the tracker this JankMetrics object is attached to.
+  const FrameSequenceTrackerType tracker_type_;
+
+  // The thread that contributes to the janks detected by the current
+  // JankMetrics object.
+  const FrameSequenceMetrics::ThreadType effective_thread_;
+
+  // Number of janks detected.
+  int jank_count_ = 0;
+
+  // The time when the last presentation occurs
+  base::TimeTicks last_presentation_timestamp_;
+
+  // The interval before the previous frame presentation.
+  base::TimeDelta prev_frame_delta_;
+};
+
+}  // namespace cc
+
+#endif  // CC_METRICS_JANK_METRICS_H_