From 16e90903bd47f121f034875487394c6556b072af Mon Sep 17 00:00:00 2001 From: behdad Date: Wed, 1 Dec 2021 17:06:04 +0000 Subject: [PATCH] Reland "Added Gpu.MultipleSwapsDelta metric" This is a reland of 75ed80532e6e038c7e85417113f6572ec3c7e8c5 Trace categories are set as constexpr to fix the compile issue. Original change's description: > Added Gpu.MultipleSwapsDelta metric > > If there are multiple swaps in the interval of two begin frames, the > delta between them would be reported in the Gpu.MultipleSwapsDelta. > Because of inaccurate swap timestamps on some platforms the current > reporting only includes the deltas that are smaller than 2/3 of interval > so that swaps than nearly pass the deadline would not be counted in. > > > Bug: chromium:1265437 > Change-Id: I521c434a7d6ce6ffb91889a6cf5d990b7881feef > Reviewed-on: https://chromium-review.googlesource.com/c/chromium/src/+/3278443 > Reviewed-by: Jonathan Ross > Commit-Queue: Behdad Bakhshinategh > Cr-Commit-Position: refs/heads/main@{#946227} Bug: chromium:1265437 Change-Id: Ia0219eae83a593a71ed20b5d03fa16e62e29eece Reviewed-on: https://chromium-review.googlesource.com/c/chromium/src/+/3307314 Auto-Submit: Behdad Bakhshinategh Commit-Queue: Jonathan Ross Reviewed-by: Jonathan Ross Cr-Commit-Position: refs/heads/main@{#947061} --- .../compositor_frame_reporting_controller.cc | 50 +++++++++++++++++++ .../compositor_frame_reporting_controller.h | 11 ++++ .../histograms/metadata/gpu/histograms.xml | 10 ++++ 3 files changed, 71 insertions(+) diff --git a/cc/metrics/compositor_frame_reporting_controller.cc b/cc/metrics/compositor_frame_reporting_controller.cc index 8a75ebcc73aca..8e9c68b1ab2f5 100644 --- a/cc/metrics/compositor_frame_reporting_controller.cc +++ b/cc/metrics/compositor_frame_reporting_controller.cc @@ -7,17 +7,21 @@ #include #include "base/trace_event/trace_event.h" +#include "base/trace_event/trace_id_helper.h" #include "cc/metrics/compositor_frame_reporter.h" #include "cc/metrics/dropped_frame_counter.h" #include "cc/metrics/latency_ukm_reporter.h" #include "components/viz/common/frame_timing_details.h" #include "components/viz/common/quads/compositor_frame_metadata.h" +#include "services/tracing/public/cpp/perfetto/macros.h" namespace cc { namespace { using SmoothThread = CompositorFrameReporter::SmoothThread; using StageType = CompositorFrameReporter::StageType; using FrameTerminationStatus = CompositorFrameReporter::FrameTerminationStatus; + +constexpr char kTraceCategory[] = "cc,benchmark"; } // namespace CompositorFrameReportingController::CompositorFrameReportingController( @@ -76,6 +80,8 @@ void CompositorFrameReportingController::ProcessSkippedFramesIfNecessary( void CompositorFrameReportingController::WillBeginImplFrame( const viz::BeginFrameArgs& args) { ProcessSkippedFramesIfNecessary(args); + ReportMultipleSwaps(args.frame_time, last_interval_); + last_interval_ = args.interval; base::TimeTicks begin_time = Now(); if (reporters_[PipelineStage::kBeginImplFrame]) { @@ -354,6 +360,46 @@ void CompositorFrameReportingController:: } } +void CompositorFrameReportingController::TrackSwapTiming( + const viz::FrameTimingDetails& details) { + if (details.swap_timings.swap_start != base::TimeTicks()) { + if (latest_swap_times_.empty() || + latest_swap_times_.back() < details.swap_timings.swap_start) + latest_swap_times_.push(details.swap_timings.swap_start); + } + + // Making sure the queue would not keep growing in size. + DCHECK_LE(latest_swap_times_.size(), 10u); +} + +void CompositorFrameReportingController::ReportMultipleSwaps( + base::TimeTicks begin_frame_time, + base::TimeDelta interval) { + while (!latest_swap_times_.empty() && + latest_swap_times_.front() <= begin_frame_time - interval) { + latest_swap_times_.pop(); + } + + if (latest_swap_times_.empty()) + return; + + if (latest_swap_times_.size() > 1) { + base::TimeDelta swap_delta = + latest_swap_times_.back() - latest_swap_times_.front(); + + if (swap_delta < interval) { + UMA_HISTOGRAM_PERCENTAGE("GPU.MultipleSwapsDelta", + swap_delta * 100.0 / interval); + + const auto trace_track = + perfetto::Track(base::trace_event::GetNextGlobalTraceId()); + TRACE_EVENT_BEGIN(kTraceCategory, "MultipleSwaps", trace_track, + latest_swap_times_.front()); + TRACE_EVENT_END(kTraceCategory, trace_track, latest_swap_times_.back()); + } + } +} + void CompositorFrameReportingController::OnFinishImplFrame( const viz::BeginFrameId& id) { for (auto& reporter : reporters_) { @@ -368,6 +414,10 @@ void CompositorFrameReportingController::DidPresentCompositorFrame( uint32_t frame_token, const viz::FrameTimingDetails& details) { bool feedback_failed = details.presentation_feedback.failed(); + + if (!feedback_failed) + TrackSwapTiming(details); + for (auto submitted_frame = submitted_compositor_frames_.begin(); submitted_frame != submitted_compositor_frames_.end() && !viz::FrameTokenGT(submitted_frame->frame_token, frame_token);) { diff --git a/cc/metrics/compositor_frame_reporting_controller.h b/cc/metrics/compositor_frame_reporting_controller.h index c766c4ebdafdc..05369f603d922 100644 --- a/cc/metrics/compositor_frame_reporting_controller.h +++ b/cc/metrics/compositor_frame_reporting_controller.h @@ -7,6 +7,7 @@ #include #include +#include #include #include "base/memory/raw_ptr.h" @@ -152,6 +153,9 @@ class CC_EXPORT CompositorFrameReportingController { // that reporter is in, its ownership might be pass or not. void SetPartialUpdateDeciderWhenWaitingOnMain( std::unique_ptr& reporter); + void TrackSwapTiming(const viz::FrameTimingDetails& details); + void ReportMultipleSwaps(base::TimeTicks begin_frame_time, + base::TimeDelta interval); const bool should_report_metrics_; const int layer_tree_host_id_; @@ -200,6 +204,13 @@ class CC_EXPORT CompositorFrameReportingController { // these metrics and report them. std::map events_metrics_from_dropped_frames_; + + // Tracking the swap times in a queue to measure delta of multiple swaps in + // each vsync. + std::queue latest_swap_times_; + + // interval of last begin frame args. + base::TimeDelta last_interval_; }; } // namespace cc diff --git a/tools/metrics/histograms/metadata/gpu/histograms.xml b/tools/metrics/histograms/metadata/gpu/histograms.xml index 53954a34b2bba..e08a9c7cd7f0f 100644 --- a/tools/metrics/histograms/metadata/gpu/histograms.xml +++ b/tools/metrics/histograms/metadata/gpu/histograms.xml @@ -1345,6 +1345,16 @@ chromium-metrics-reviews@google.com. + + behdadb@chromium.org + chrome-gpu-metrics@google.com + + Time delta between swaps, when there are multiple successful swaps in the + same vsync. The delta is reported as a percentage of vsync interval. This + can be recorded every time we present a frame. + + + khushalsagar@chromium.org