Add MediaLog properties and events for use in HLS
Bug: 40057824
Change-Id: I7c75a59d24f5fab465a19d382810ae008c6f50b4
Reviewed-on: https://chromium-review.googlesource.com/c/chromium/src/+/5983472
Reviewed-by: Eugene Zemtsov <eugene@chromium.org>
Commit-Queue: Ted (Chromium) Meyer <tmathmeyer@chromium.org>
Cr-Commit-Position: refs/heads/main@{#1379191}
NOKEYCHECK=True
GitOrigin-RevId: a0d4ebc4ab1b701fc42a14ac19a3269d0ed462f8
diff --git a/base/media_log_events.h b/base/media_log_events.h
index a72b64a..79ec3e0 100644
--- a/base/media_log_events.h
+++ b/base/media_log_events.h
@@ -87,6 +87,9 @@
// Triggered whenever WMPI handles a track change.
kAudioTrackChange,
kVideoTrackChange,
+
+ // Triggered when the media element starts and finishes fetching media data.
+ kHlsSegmentFetch,
};
// Sometimes URLs can have encoded data that can be exteremly large.
@@ -116,6 +119,11 @@
std::string,
"video_occlusion_state");
+MEDIA_LOG_EVENT_NAMED_DATA_OP(kHlsSegmentFetch,
+ std::string,
+ "hls_segment_url",
+ TruncateUrlString);
+
// Each type of buffering state gets a different name.
MEDIA_LOG_EVENT_NAMED_DATA(
kBufferingStateChanged,
diff --git a/base/media_log_properties.cc b/base/media_log_properties.cc
index 12569be..1040278 100644
--- a/base/media_log_properties.cc
+++ b/base/media_log_properties.cc
@@ -39,6 +39,7 @@
STRINGIFY(kFramerate);
STRINGIFY(kVideoPlaybackRoughness);
STRINGIFY(kVideoPlaybackFreezing);
+ STRINGIFY(kHlsBufferedRanges);
}
#undef STRINGIFY
}
diff --git a/base/media_log_properties.h b/base/media_log_properties.h
index ef075d5..51c01e9 100644
--- a/base/media_log_properties.h
+++ b/base/media_log_properties.h
@@ -102,6 +102,9 @@
// A playback quality metric that tries to account for large pauses and/or
// discontinuities during playback.
kVideoPlaybackFreezing,
+
+ // Triggered when buffered ranges are changed.
+ kHlsBufferedRanges,
};
MEDIA_LOG_PROPERTY_SUPPORTS_TYPE(kResolution, gfx::Size);
@@ -130,6 +133,7 @@
MEDIA_LOG_PROPERTY_SUPPORTS_TYPE(kFramerate, double);
MEDIA_LOG_PROPERTY_SUPPORTS_TYPE(kVideoPlaybackRoughness, double);
MEDIA_LOG_PROPERTY_SUPPORTS_TYPE(kVideoPlaybackFreezing, base::TimeDelta);
+MEDIA_LOG_PROPERTY_SUPPORTS_TYPE(kHlsBufferedRanges, Ranges<base::TimeDelta>);
// Convert the enum to a string (used for the front-end enum matching).
MEDIA_EXPORT std::string MediaLogPropertyKeyToString(MediaLogProperty property);
diff --git a/base/media_serializers.h b/base/media_serializers.h
index 1fba5ad..936ce9c 100644
--- a/base/media_serializers.h
+++ b/base/media_serializers.h
@@ -17,6 +17,7 @@
#include "media/base/decoder.h"
#include "media/base/media_serializers_base.h"
#include "media/base/media_track.h"
+#include "media/base/ranges.h"
#include "media/base/renderer.h"
#include "media/base/status.h"
#include "media/base/video_decoder_config.h"
@@ -567,6 +568,20 @@
}
};
+template <typename T>
+struct MediaSerializer<Ranges<T>> {
+ static inline base::Value Serialize(Ranges<T> ranges) {
+ base::Value::List result;
+ for (size_t i = 0; i < ranges.size(); i++) {
+ base::Value::List tuple;
+ tuple.Append(MediaSerializer<T>::Serialize(ranges.start(i)));
+ tuple.Append(MediaSerializer<T>::Serialize(ranges.end(i)));
+ result.Append(std::move(tuple));
+ }
+ return base::Value(std::move(result));
+ }
+};
+
#undef FIELD_SERIALIZE
} // namespace media::internal
diff --git a/filters/hls_manifest_demuxer_engine.cc b/filters/hls_manifest_demuxer_engine.cc
index 1776333..c96d739 100644
--- a/filters/hls_manifest_demuxer_engine.cc
+++ b/filters/hls_manifest_demuxer_engine.cc
@@ -808,7 +808,8 @@
host_->SetSequenceMode(parse_info.role, true);
auto rendition = HlsRendition::CreateRendition(
- host_, this, parse_info.role, std::move(playlist), parse_info.uri);
+ host_, this, parse_info.role, std::move(playlist), parse_info.uri,
+ media_log_.get());
if (parse_info.role == kPrimary) {
auto duration_or_live = rendition->GetDuration();
diff --git a/filters/hls_manifest_demuxer_engine_unittest.cc b/filters/hls_manifest_demuxer_engine_unittest.cc
index a6b819e..590da84 100644
--- a/filters/hls_manifest_demuxer_engine_unittest.cc
+++ b/filters/hls_manifest_demuxer_engine_unittest.cc
@@ -226,27 +226,32 @@
template <typename T>
class CallbackEnforcer {
public:
- explicit CallbackEnforcer(T expected)
- : expected_(std::move(expected)), was_called_(false) {}
+ explicit CallbackEnforcer(
+ T expected,
+ const base::Location& from = base::Location::Current())
+ : expected_(std::move(expected)), created_(from) {}
base::OnceCallback<void(T)> GetCallback() {
return base::BindOnce(
- [](bool* writeback, T expected, T actual) {
+ [](size_t line, bool* writeback, T expected, T actual) {
*writeback = true;
- ASSERT_EQ(actual, expected);
+ ASSERT_EQ(actual, expected)
+ << "Callback at line:" << line << " called with wrong parameter";
},
- &was_called_, expected_);
+ created_.line_number(), &was_called_, expected_);
}
// This method is move only, so it must be std::moved.
void AssertAndReset(base::test::TaskEnvironment& env) && {
env.RunUntilIdle();
- ASSERT_TRUE(was_called_);
+ ASSERT_TRUE(was_called_)
+ << "Callback at line:" << created_.line_number() << " never called";
}
private:
T expected_;
bool was_called_ = false;
+ base::Location created_;
};
class HlsManifestDemuxerEngineTest : public testing::Test {
@@ -505,9 +510,11 @@
.WillOnce(Return(after_seg_a)) // After appending segment A
.WillOnce(Return(after_seg_a)) // Second CheckState
.WillOnce(Return(after_seg_b)) // After appending segment B
+ .WillOnce(Return(after_seg_b)) // MediaLog
.WillOnce(Return(after_seg_b)) // Third CheckState
.WillOnce(Return(after_seg_b)) // Fourth CheckState
.WillOnce(Return(after_seg_c)) // After appending segment C
+ .WillOnce(Return(after_seg_c)) // MediaLog
.WillOnce(Return(after_seg_c)) // Fifth CheckState
;
diff --git a/filters/hls_rendition.cc b/filters/hls_rendition.cc
index e1082ae..e673f88 100644
--- a/filters/hls_rendition.cc
+++ b/filters/hls_rendition.cc
@@ -41,11 +41,12 @@
HlsRenditionHost* rendition_host,
std::string role,
scoped_refptr<hls::MediaPlaylist> playlist,
- GURL uri) {
+ GURL uri,
+ MediaLog* media_log) {
auto duration = GetPlaylistDuration(playlist.get());
return std::make_unique<HlsRenditionImpl>(
engine_host, rendition_host, std::move(role), std::move(playlist),
- duration, std::move(uri));
+ duration, std::move(uri), media_log);
}
} // namespace media
diff --git a/filters/hls_rendition.h b/filters/hls_rendition.h
index 531b787..8f97f1f 100644
--- a/filters/hls_rendition.h
+++ b/filters/hls_rendition.h
@@ -74,7 +74,8 @@
HlsRenditionHost* rendition_host,
std::string role,
scoped_refptr<hls::MediaPlaylist> playlist,
- GURL uri);
+ GURL uri,
+ MediaLog* media_log);
};
} // namespace media
diff --git a/filters/hls_rendition_impl.cc b/filters/hls_rendition_impl.cc
index 45dea50..deca92d 100644
--- a/filters/hls_rendition_impl.cc
+++ b/filters/hls_rendition_impl.cc
@@ -26,7 +26,8 @@
std::string role,
scoped_refptr<hls::MediaPlaylist> playlist,
std::optional<base::TimeDelta> duration,
- GURL media_playlist_uri)
+ GURL media_playlist_uri,
+ MediaLog* media_log)
: engine_host_(engine_host),
rendition_host_(rendition_host),
segments_(std::make_unique<hls::SegmentStream>(
@@ -35,7 +36,8 @@
role_(std::move(role)),
duration_(duration),
media_playlist_uri_(std::move(media_playlist_uri)),
- last_download_time_(base::TimeTicks::Now()) {}
+ last_download_time_(base::TimeTicks::Now()),
+ media_log_(media_log->Clone()) {}
std::optional<base::TimeDelta> HlsRenditionImpl::GetDuration() {
return duration_;
@@ -338,6 +340,9 @@
engine_host_->Remove(role_, base::TimeDelta(), remove_until);
}
+ auto ranges = engine_host_->GetBufferedRanges(role_);
+ media_log_->SetProperty<MediaLogProperty::kHlsBufferedRanges>(ranges);
+
return base::TimeTicks::Now() - removal_start;
}
@@ -365,6 +370,8 @@
if (auto enc = segment->GetEncryptionData()) {
is_fetching_new_key = enc->NeedsKeyFetch();
}
+ media_log_->AddEvent<MediaLogEvent::kHlsSegmentFetch>(
+ segment->GetUri().PathForRequest());
rendition_host_->ReadMediaSegment(
*segment, /*read_chunked=*/false, include_init,
base::BindOnce(&HlsRenditionImpl::OnSegmentData,
@@ -476,6 +483,8 @@
// for the seek to complete. In this case, we just keep fetching until
// the seek time is loaded.
auto ranges = engine_host_->GetBufferedRanges(role_);
+ media_log_->SetProperty<MediaLogProperty::kHlsBufferedRanges>(ranges);
+
if (ranges.size() && ranges.contains(ranges.size() - 1, required_time)) {
std::move(cb).Run();
return;
diff --git a/filters/hls_rendition_impl.h b/filters/hls_rendition_impl.h
index fb18e7d..a34a79c 100644
--- a/filters/hls_rendition_impl.h
+++ b/filters/hls_rendition_impl.h
@@ -24,7 +24,8 @@
std::string role,
scoped_refptr<hls::MediaPlaylist> playlist,
std::optional<base::TimeDelta> duration,
- GURL media_playlist_uri);
+ GURL media_playlist_uri,
+ MediaLog* media_log);
// `HlsRendition` implementation
std::optional<base::TimeDelta> GetDuration() override;
@@ -117,6 +118,8 @@
std::unique_ptr<crypto::Encryptor> decryptor_;
scoped_refptr<hls::MediaSegment> segment_with_key_;
+ std::unique_ptr<MediaLog> media_log_;
+
// toggleable bool flags.
bool set_stream_end_ = false;
bool is_stopped_for_shutdown_ = false;
diff --git a/filters/hls_rendition_impl_unittest.cc b/filters/hls_rendition_impl_unittest.cc
index e525346..63d9091 100644
--- a/filters/hls_rendition_impl_unittest.cc
+++ b/filters/hls_rendition_impl_unittest.cc
@@ -8,6 +8,7 @@
#include "base/test/gmock_callback_support.h"
#include "base/test/task_environment.h"
+#include "media/base/mock_media_log.h"
#include "media/base/test_helpers.h"
#include "media/filters/hls_network_access_impl.h"
#include "media/filters/hls_test_helpers.h"
@@ -144,6 +145,7 @@
using testing::_;
using testing::ElementsAreArray;
+using testing::NiceMock;
using testing::Return;
MATCHER_P(MediaSegmentHasUrl, urlstr, "MediaSegment has provided URL") {
@@ -152,6 +154,7 @@
class HlsRenditionImplUnittest : public testing::Test {
protected:
+ std::unique_ptr<MediaLog> media_log_;
std::unique_ptr<MockManifestDemuxerEngineHost> mock_mdeh_;
std::unique_ptr<MockHlsRenditionHost> mock_hrh_;
base::test::TaskEnvironment task_environment_{
@@ -167,9 +170,11 @@
}
auto playlist = std::move(parsed).value();
auto duration = playlist->GetComputedDuration();
+ media_log_ = std::make_unique<NiceMock<media::MockMediaLog>>();
+
return std::make_unique<HlsRenditionImpl>(mock_mdeh_.get(), mock_hrh_.get(),
"test", std::move(playlist),
- duration, uri);
+ duration, uri, media_log_.get());
}
std::unique_ptr<HlsRenditionImpl> MakeLiveRendition(
@@ -181,9 +186,10 @@
LOG(ERROR) << MediaSerialize(std::move(parsed).error());
return nullptr;
}
- return std::make_unique<HlsRenditionImpl>(mock_mdeh_.get(), mock_hrh_.get(),
- "test", std::move(parsed).value(),
- std::nullopt, uri);
+ media_log_ = std::make_unique<NiceMock<media::MockMediaLog>>();
+ return std::make_unique<HlsRenditionImpl>(
+ mock_mdeh_.get(), mock_hrh_.get(), "test", std::move(parsed).value(),
+ std::nullopt, uri, media_log_.get());
}
MOCK_METHOD(void, CheckStateComplete, (base::TimeDelta delay), ());
@@ -217,7 +223,7 @@
ranges.Add(start, end);
}
EXPECT_CALL(*mock_mdeh_, GetBufferedRanges("test"))
- .WillOnce(Return(ranges));
+ .WillRepeatedly(Return(ranges));
}
void RespondWithRangeTwice(base::TimeDelta A,
@@ -444,7 +450,8 @@
Ranges<base::TimeDelta> loaded_ranges;
loaded_ranges.Add(base::Seconds(0), base::Seconds(12));
EXPECT_CALL(*mock_mdeh_, GetBufferedRanges(_))
- .WillOnce(Return(loaded_ranges));
+ .Times(2)
+ .WillRepeatedly(Return(loaded_ranges));
// Old data will try to be removed. Since media time is 0, there is nothing
// to do. Then there will be an attempt to fetch a new manifest, which won't
// have any work to do either, instead just posting the delay_cb back.
@@ -466,7 +473,8 @@
Ranges<base::TimeDelta> loaded_ranges;
loaded_ranges.Add(base::Seconds(0), base::Seconds(12));
EXPECT_CALL(*mock_mdeh_, GetBufferedRanges(_))
- .WillOnce(Return(loaded_ranges));
+ .Times(2)
+ .WillRepeatedly(Return(loaded_ranges));
// Old data will try to be removed. Since media time is 0, there is nothing
// to do. Then there will be an attempt to fetch a new manifest, which will
// get an update.
@@ -496,7 +504,8 @@
Ranges<base::TimeDelta> loaded_ranges;
loaded_ranges.Add(base::Seconds(0), base::Seconds(32));
EXPECT_CALL(*mock_mdeh_, GetBufferedRanges(_))
- .WillOnce(Return(loaded_ranges));
+ .Times(2)
+ .WillRepeatedly(Return(loaded_ranges));
// Old data will try to be removed. Since media time is 15, there are 5
// seconds of old data to delete. There will be no new fetch and parse for
// manifest updates.