From a712047ec5747261703e65ef7f225dda1ea29cf9 Mon Sep 17 00:00:00 2001 From: Drew Thomas Date: Mon, 1 Apr 2024 16:40:32 -0700 Subject: [PATCH] Add Seek Latency Telemetry (#2735) Added the ability to track the latency of `WebMediaPlayer` actions to the existing `MediaMetricsProvider` class, and instrumented `Seek` as the first action. Added basic unit tests for the new code. b/329439521 Change-Id: Icbbfd0da148e48d2137da7662b91e6e2d52de590 --- cobalt/media/BUILD.gn | 1 + cobalt/media/base/metrics_provider.cc | 41 +++++++++++ cobalt/media/base/metrics_provider.h | 28 +++++++- cobalt/media/base/metrics_provider_test.cc | 70 +++++++++++++++++++ cobalt/media/player/web_media_player_impl.cc | 10 +++ .../histograms/metadata/cobalt/histograms.xml | 11 +++ 6 files changed, 160 insertions(+), 1 deletion(-) create mode 100644 cobalt/media/base/metrics_provider_test.cc diff --git a/cobalt/media/BUILD.gn b/cobalt/media/BUILD.gn index c4f9774a512a..aaf87647018f 100644 --- a/cobalt/media/BUILD.gn +++ b/cobalt/media/BUILD.gn @@ -122,6 +122,7 @@ target(gtest_target_type, "media_test") { sources = [ "base/cval_stats_test.cc", "base/decoder_buffer_cache_test.cc", + "base/metrics_provider_test.cc", "bidirectional_fit_reuse_allocator_test.cc", "file_data_source_test.cc", "progressive/demuxer_extension_wrapper_test.cc", diff --git a/cobalt/media/base/metrics_provider.cc b/cobalt/media/base/metrics_provider.cc index 510d5a867feb..beccc2454401 100644 --- a/cobalt/media/base/metrics_provider.cc +++ b/cobalt/media/base/metrics_provider.cc @@ -16,6 +16,8 @@ #include "base/logging.h" #include "base/metrics/histogram_functions.h" +#include "base/metrics/histogram_macros.h" +#include "base/time/time.h" namespace cobalt { namespace media { @@ -122,5 +124,44 @@ bool MediaMetricsProvider::IsInitialized() const { return media_info_.has_value(); } +void MediaMetricsProvider::StartTrackingAction(WebMediaPlayerAction action) { + DCHECK(IsInitialized()); + DCHECK(!IsActionCurrentlyTracked(action)); + ScopedLock scoped_lock(mutex_); + + tracked_actions_start_times_[action] = clock_->NowTicks(); +} + +void MediaMetricsProvider::EndTrackingAction(WebMediaPlayerAction action) { + DCHECK(IsInitialized()); + DCHECK(IsActionCurrentlyTracked(action)); + ScopedLock scoped_lock(mutex_); + + auto duration = clock_->NowTicks() - tracked_actions_start_times_[action]; + ReportActionLatencyUMA(action, duration); + tracked_actions_start_times_.erase(action); +} + +bool MediaMetricsProvider::IsActionCurrentlyTracked( + WebMediaPlayerAction action) { + DCHECK(IsInitialized()); + ScopedLock scoped_lock(mutex_); + return tracked_actions_start_times_.find(action) != + tracked_actions_start_times_.end(); +} + +void MediaMetricsProvider::ReportActionLatencyUMA( + WebMediaPlayerAction action, const base::TimeDelta& action_duration) { + switch (action) { + case WebMediaPlayerAction::SEEK: + UMA_HISTOGRAM_TIMES("Cobalt.Media.WebMediaPlayer.Seek.Timing", + action_duration); + break; + case WebMediaPlayerAction::UNKNOWN_ACTION: + default: + break; + } +} + } // namespace media } // namespace cobalt diff --git a/cobalt/media/base/metrics_provider.h b/cobalt/media/base/metrics_provider.h index 18bd530eefb3..b6efd0d76165 100644 --- a/cobalt/media/base/metrics_provider.h +++ b/cobalt/media/base/metrics_provider.h @@ -15,14 +15,20 @@ #ifndef COBALT_MEDIA_BASE_METRICS_PROVIDER_H_ #define COBALT_MEDIA_BASE_METRICS_PROVIDER_H_ +#include #include +#include "base/containers/small_map.h" +#include "base/time/default_tick_clock.h" +#include "base/time/tick_clock.h" +#include "base/time/time.h" #include "media/base/audio_codecs.h" #include "media/base/container_names.h" #include "media/base/pipeline_status.h" #include "media/base/timestamp_constants.h" #include "media/base/video_codecs.h" #include "starboard/common/mutex.h" +#include "starboard/types.h" namespace cobalt { namespace media { @@ -32,9 +38,16 @@ using VideoCodec = ::media::VideoCodec; using PipelineStatus = ::media::PipelineStatus; using VideoDecoderType = ::media::VideoDecoderType; +enum class WebMediaPlayerAction : uint8_t { + UNKNOWN_ACTION, + SEEK, +}; + class MediaMetricsProvider { public: - MediaMetricsProvider() = default; + MediaMetricsProvider( + const base::TickClock* clock = base::DefaultTickClock::GetInstance()) + : clock_(clock) {} ~MediaMetricsProvider(); private: @@ -71,11 +84,24 @@ class MediaMetricsProvider { void ReportPipelineUMA(); + // Used to record the latency of an action in the WebMediaPlayer. + void StartTrackingAction(WebMediaPlayerAction action); + void EndTrackingAction(WebMediaPlayerAction action); + bool IsActionCurrentlyTracked(WebMediaPlayerAction action); + private: std::string GetUMANameForAVStream(const PipelineInfo& player_info) const; bool IsInitialized() const; + void ReportActionLatencyUMA(WebMediaPlayerAction action, + const base::TimeDelta& action_duration); + private: + // Media player action latency data. + const base::TickClock* clock_; + base::small_map, 2> + tracked_actions_start_times_; + // UMA pipeline packaged data PipelineInfo uma_info_; diff --git a/cobalt/media/base/metrics_provider_test.cc b/cobalt/media/base/metrics_provider_test.cc new file mode 100644 index 000000000000..78a1fe4bfa1c --- /dev/null +++ b/cobalt/media/base/metrics_provider_test.cc @@ -0,0 +1,70 @@ +// Copyright 2024 The Cobalt Authors. All Rights Reserved. +// +// Licensed under the Apache License, Version 2.0 (the "License"); +// you may not use this file except in compliance with the License. +// You may obtain a copy of the License at +// +// http://www.apache.org/licenses/LICENSE-2.0 +// +// Unless required by applicable law or agreed to in writing, software +// distributed under the License is distributed on an "AS IS" BASIS, +// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +// See the License for the specific language governing permissions and +// limitations under the License. + +#include "cobalt/media/base/metrics_provider.h" + +#include +#include + +#include "base/test/metrics/histogram_tester.h" +#include "base/test/simple_test_tick_clock.h" +#include "base/time/time.h" +#include "testing/gtest/include/gtest/gtest.h" + +namespace cobalt { +namespace media { +namespace { +constexpr char kUmaPrefix[] = "Cobalt.Media."; + +class MediaMetricsProviderTest : public ::testing::Test { + protected: + MediaMetricsProviderTest() : metrics_(&clock_) {} + + void SetUp() override { clock_.SetNowTicks(base::TimeTicks()); } + + base::HistogramTester histogram_tester_; + base::SimpleTestTickClock clock_; + + MediaMetricsProvider metrics_; +}; + +TEST_F(MediaMetricsProviderTest, ReportsSeekLatency) { + metrics_.Initialize(true); + metrics_.StartTrackingAction(WebMediaPlayerAction::SEEK); + + clock_.Advance(base::TimeDelta::FromMilliseconds(100)); + metrics_.EndTrackingAction(WebMediaPlayerAction::SEEK); + + histogram_tester_.ExpectUniqueSample( + std::string(kUmaPrefix) + "WebMediaPlayer.Seek.Timing", 100, 1); +} + +TEST_F(MediaMetricsProviderTest, SupportsTrackingMultipleActions) { + metrics_.Initialize(true); + metrics_.StartTrackingAction(WebMediaPlayerAction::SEEK); + metrics_.StartTrackingAction(WebMediaPlayerAction::UNKNOWN_ACTION); + + clock_.Advance(base::TimeDelta::FromMilliseconds(100)); + metrics_.EndTrackingAction(WebMediaPlayerAction::UNKNOWN_ACTION); + + clock_.Advance(base::TimeDelta::FromMilliseconds(1000)); + metrics_.EndTrackingAction(WebMediaPlayerAction::SEEK); + + histogram_tester_.ExpectUniqueSample( + std::string(kUmaPrefix) + "WebMediaPlayer.Seek.Timing", 1100, 1); +} + +} // namespace +} // namespace media +} // namespace cobalt diff --git a/cobalt/media/player/web_media_player_impl.cc b/cobalt/media/player/web_media_player_impl.cc index 8451b187653c..3a1ac3521c84 100644 --- a/cobalt/media/player/web_media_player_impl.cc +++ b/cobalt/media/player/web_media_player_impl.cc @@ -22,6 +22,7 @@ #include "base/trace_event/trace_event.h" #include "cobalt/base/instance_counter.h" #include "cobalt/media/base/drm_system.h" +#include "cobalt/media/base/metrics_provider.h" #include "cobalt/media/base/sbplayer_pipeline.h" #include "cobalt/media/player/web_media_player_proxy.h" #include "cobalt/media/progressive/data_source_reader.h" @@ -353,6 +354,7 @@ void WebMediaPlayerImpl::Seek(double seconds) { return; } + media_metrics_provider_.StartTrackingAction(WebMediaPlayerAction::SEEK); media_log_->AddEvent<::media::MediaLogEvent::kSeek>(seconds); base::TimeDelta seek_time = ConvertSecondsToTimestamp(seconds); @@ -630,6 +632,14 @@ void WebMediaPlayerImpl::OnPipelineSeek(::media::PipelineStatus status, const bool kEosPlayed = false; GetClient()->TimeChanged(kEosPlayed); } + + // WebMediaPlayerImpl::OnPipelineSeek() is called frequently, more than just + // when WebMediaPlayerImpl::Seek() is called. This helps to filter out when + // the pipeline seeks without being initiated by WebMediaPlayerImpl. + if (media_metrics_provider_.IsActionCurrentlyTracked( + WebMediaPlayerAction::SEEK)) { + media_metrics_provider_.EndTrackingAction(WebMediaPlayerAction::SEEK); + } } void WebMediaPlayerImpl::OnPipelineEnded(::media::PipelineStatus status) { diff --git a/tools/metrics/histograms/metadata/cobalt/histograms.xml b/tools/metrics/histograms/metadata/cobalt/histograms.xml index 13f4d9d71a57..74dd40006175 100644 --- a/tools/metrics/histograms/metadata/cobalt/histograms.xml +++ b/tools/metrics/histograms/metadata/cobalt/histograms.xml @@ -185,6 +185,17 @@ Always run the pretty print utility on this file after editing: + + + + async@google.com + cobalt-team@google.com + + Timing data for the seek latency of WebMediaPlayer. + + +