Bug 1795840 - Add various markers around video frame scheduling. r=alwu

Differential Revision: https://phabricator.services.mozilla.com/D159580
This commit is contained in:
Paul Adenot 2022-10-20 07:37:54 +00:00
parent cffbe6faec
commit 6cd95831a0
6 changed files with 72 additions and 8 deletions

View File

@ -601,6 +601,9 @@ class MediaDecoderStateMachine::DecodingState
if (!mVideoFirstLateTime) {
mVideoFirstLateTime = Some(TimeStamp::Now());
}
PROFILER_MARKER("Video falling behind", MEDIA_PLAYBACK, {},
VideoFallingBehindMarker, aVideo->mTime.ToMicroseconds(),
currentTime.ToMicroseconds());
SLOG("video %" PRId64 " starts being late (current=%" PRId64 ")",
aVideo->mTime.ToMicroseconds(), currentTime.ToMicroseconds());
} else {
@ -778,6 +781,7 @@ class MediaDecoderStateMachine::DecodingState
const bool rv = elapsedTimeMs >=
StaticPrefs::media_decoder_skip_when_video_too_slow_ms();
if (rv) {
PROFILER_MARKER_UNTYPED("Skipping to next keyframe", MEDIA_PLAYBACK);
SLOG(
"video has been late behind media time for %f ms, should skip to "
"next key frame",
@ -2933,7 +2937,8 @@ void MediaDecoderStateMachine::PushAudio(AudioData* aSample) {
AudioQueue().Push(aSample);
PROFILER_MARKER("MDSM::PushAudio", MEDIA_PLAYBACK, {}, MediaSampleMarker,
aSample->mTime.ToMicroseconds(),
aSample->GetEndTime().ToMicroseconds());
aSample->GetEndTime().ToMicroseconds(),
AudioQueue().GetSize());
}
void MediaDecoderStateMachine::PushVideo(VideoData* aSample) {
@ -2943,7 +2948,8 @@ void MediaDecoderStateMachine::PushVideo(VideoData* aSample) {
VideoQueue().Push(aSample);
PROFILER_MARKER("MDSM::PushVideo", MEDIA_PLAYBACK, {}, MediaSampleMarker,
aSample->mTime.ToMicroseconds(),
aSample->GetEndTime().ToMicroseconds());
aSample->GetEndTime().ToMicroseconds(),
VideoQueue().GetSize());
}
void MediaDecoderStateMachine::OnAudioPopped(const RefPtr<AudioData>& aSample) {

View File

@ -478,7 +478,8 @@ void VideoSink::RenderVideoFrames(int32_t aMaxFrames, int64_t aClockTime,
if (!wasSent) {
PROFILER_MARKER("PlayVideo", MEDIA_PLAYBACK, {}, MediaSampleMarker,
frame->mTime.ToMicroseconds(),
frame->GetEndTime().ToMicroseconds());
frame->GetEndTime().ToMicroseconds(),
VideoQueue().GetSize());
}
}

View File

@ -33,9 +33,11 @@ struct MediaSampleMarker {
}
static void StreamJSONMarkerData(SpliceableJSONWriter& aWriter,
int64_t aSampleStartTimeUs,
int64_t aSampleEndTimeUs) {
int64_t aSampleEndTimeUs,
int64_t aQueueLength) {
aWriter.IntProperty("sampleStartTimeUs", aSampleStartTimeUs);
aWriter.IntProperty("sampleEndTimeUs", aSampleEndTimeUs);
aWriter.IntProperty("queueLength", aQueueLength);
}
static MarkerSchema MarkerTypeDisplay() {
using MS = MarkerSchema;
@ -44,6 +46,29 @@ struct MediaSampleMarker {
MS::Format::Microseconds);
schema.AddKeyLabelFormat("sampleEndTimeUs", "Sample end time",
MS::Format::Microseconds);
schema.AddKeyLabelFormat("queueLength", "Queue length",
MS::Format::Integer);
return schema;
}
};
struct VideoFallingBehindMarker {
static constexpr Span<const char> MarkerTypeName() {
return MakeStringSpan("VideoFallingBehind");
}
static void StreamJSONMarkerData(SpliceableJSONWriter& aWriter,
int64_t aVideoFrameStartTimeUs,
int64_t aMediaCurrentTimeUs) {
aWriter.IntProperty("videoFrameStartTimeUs", aVideoFrameStartTimeUs);
aWriter.IntProperty("mediaCurrentTimeUs", aMediaCurrentTimeUs);
}
static MarkerSchema MarkerTypeDisplay() {
using MS = MarkerSchema;
MS schema{MS::Location::MarkerChart, MS::Location::MarkerTable};
schema.AddKeyLabelFormat("videoFrameStartTimeUs", "Video frame start time",
MS::Format::Microseconds);
schema.AddKeyLabelFormat("mediaCurrentTimeUs", "Media current time",
MS::Format::Microseconds);
return schema;
}
};

View File

@ -4989,7 +4989,11 @@ void TestProfiler() {
MOZ_RELEASE_ASSERT(baseprofiler::AddMarker(
"media sample", mozilla::baseprofiler::category::OTHER, {},
mozilla::baseprofiler::markers::MediaSampleMarker{}, 123, 456));
mozilla::baseprofiler::markers::MediaSampleMarker{}, 123, 456, 789));
MOZ_RELEASE_ASSERT(baseprofiler::AddMarker(
"video falling behind", mozilla::baseprofiler::category::OTHER, {},
mozilla::baseprofiler::markers::VideoFallingBehindMarker{}, 123, 456));
printf("Sleep 1s...\n");
{
@ -5607,7 +5611,11 @@ void TestPredefinedMarkers() {
MOZ_RELEASE_ASSERT(mozilla::baseprofiler::AddMarkerToBuffer(
buffer, std::string_view("media"), mozilla::baseprofiler::category::OTHER,
{}, mozilla::baseprofiler::markers::MediaSampleMarker{}, 123, 456));
{}, mozilla::baseprofiler::markers::MediaSampleMarker{}, 123, 456, 789));
MOZ_RELEASE_ASSERT(mozilla::baseprofiler::AddMarkerToBuffer(
buffer, std::string_view("media"), mozilla::baseprofiler::category::OTHER,
{}, mozilla::baseprofiler::markers::VideoFallingBehindMarker{}, 123, 456));
# ifdef DEBUG
buffer.Dump();

View File

@ -29,6 +29,8 @@ namespace geckoprofiler::markers {
// Import some common markers from mozilla::baseprofiler::markers.
using MediaSampleMarker = mozilla::baseprofiler::markers::MediaSampleMarker;
using VideoFallingBehindMarker =
mozilla::baseprofiler::markers::VideoFallingBehindMarker;
using ContentBuildMarker = mozilla::baseprofiler::markers::ContentBuildMarker;
} // namespace geckoprofiler::markers

View File

@ -2744,7 +2744,7 @@ TEST(GeckoProfiler, Markers)
EXPECT_TRUE(profiler_add_marker(
"MediaSample", geckoprofiler::category::OTHER, {},
geckoprofiler::markers::MediaSampleMarker{}, 123, 456));
geckoprofiler::markers::MediaSampleMarker{}, 123, 456, 789));
SpliceableChunkedJSONWriter w{FailureLatchInfallibleSource::Singleton()};
w.Start();
@ -3343,7 +3343,7 @@ TEST(GeckoProfiler, Markers)
EXPECT_EQ(display[0u].asString(), "marker-chart");
EXPECT_EQ(display[1u].asString(), "marker-table");
ASSERT_EQ(data.size(), 2u);
ASSERT_EQ(data.size(), 3u);
ASSERT_TRUE(data[0u].isObject());
EXPECT_EQ_JSON(data[0u]["key"], String, "sampleStartTimeUs");
@ -3355,6 +3355,28 @@ TEST(GeckoProfiler, Markers)
EXPECT_EQ_JSON(data[1u]["label"], String, "Sample end time");
EXPECT_EQ_JSON(data[1u]["format"], String, "microseconds");
ASSERT_TRUE(data[2u].isObject());
EXPECT_EQ_JSON(data[2u]["key"], String, "queueLength");
EXPECT_EQ_JSON(data[2u]["label"], String, "Queue length");
EXPECT_EQ_JSON(data[2u]["format"], String, "integer");
} else if (nameString == "VideoFallingBehind") {
EXPECT_EQ(display.size(), 2u);
EXPECT_EQ(display[0u].asString(), "marker-chart");
EXPECT_EQ(display[1u].asString(), "marker-table");
ASSERT_EQ(data.size(), 2u);
ASSERT_TRUE(data[0u].isObject());
EXPECT_EQ_JSON(data[0u]["key"], String, "videoFrameStartTimeUs");
EXPECT_EQ_JSON(data[0u]["label"], String, "Video frame start time");
EXPECT_EQ_JSON(data[0u]["format"], String, "microseconds");
ASSERT_TRUE(data[1u].isObject());
EXPECT_EQ_JSON(data[1u]["key"], String, "mediaCurrentTimeUs");
EXPECT_EQ_JSON(data[1u]["label"], String, "Media current time");
EXPECT_EQ_JSON(data[1u]["format"], String, "microseconds");
} else if (nameString == "Budget") {
EXPECT_EQ(display.size(), 2u);
EXPECT_EQ(display[0u].asString(), "marker-chart");