Bug 1543032 - Extend metrics for dropped frames - r=padenot
authorTarek Ziadé <tarek@mozilla.com>
Tue, 16 Apr 2019 11:50:38 +0000
changeset 469700 fbd1effe6fe4
parent 469699 ae91cf128a4c
child 469701 c640010582e2
push id35879
push usernerli@mozilla.com
push dateTue, 16 Apr 2019 22:01:48 +0000
treeherdermozilla-central@12a60898fdc1 [default view] [failures only]
perfherder[talos] [build metrics] [platform microbench] (compared to previous push)
reviewerspadenot
bugs1543032
milestone68.0a1
first release with
nightly linux32
nightly linux64
nightly mac
nightly win32
nightly win64
last release without
nightly linux32
nightly linux64
nightly mac
nightly win32
nightly win64
Bug 1543032 - Extend metrics for dropped frames - r=padenot This patch adds the number of dropped frames for each step of the process (read/sink/compositor) and gives us more insight about where frames are dropped, as opposed to the getVideoPlaybackQuality() API which gives the grand total. Differential Revision: https://phabricator.services.mozilla.com/D27488
dom/html/HTMLMediaElement.cpp
dom/html/HTMLVideoElement.cpp
dom/media/FrameStatistics.h
dom/media/MediaFormatReader.cpp
dom/media/mediasink/VideoSink.cpp
dom/media/test/marionette/yttest/ytpage.py
--- a/dom/html/HTMLMediaElement.cpp
+++ b/dom/html/HTMLMediaElement.cpp
@@ -4193,21 +4193,23 @@ void HTMLMediaElement::ReportTelemetry()
   LOG(LogLevel::Debug, ("%p VIDEO_UNLOAD_STATE = %d", this, state));
 
   FrameStatisticsData data;
 
   if (HTMLVideoElement* vid = HTMLVideoElement::FromNodeOrNull(this)) {
     FrameStatistics* stats = vid->GetFrameStatistics();
     if (stats) {
       data = stats->GetFrameStatisticsData();
-      if (data.mParsedFrames) {
-        MOZ_ASSERT(data.mDroppedFrames <= data.mParsedFrames);
+      uint64_t parsedFrames = stats->GetParsedFrames();
+      if (parsedFrames) {
+        uint64_t droppedFrames = stats->GetDroppedFrames();
+        MOZ_ASSERT(droppedFrames <= parsedFrames);
         // Dropped frames <= total frames, so 'percentage' cannot be higher than
         // 100 and therefore can fit in a uint32_t (that Telemetry takes).
-        uint32_t percentage = 100 * data.mDroppedFrames / data.mParsedFrames;
+        uint32_t percentage = 100 * droppedFrames / parsedFrames;
         LOG(LogLevel::Debug,
             ("Reporting telemetry DROPPED_FRAMES_IN_VIDEO_PLAYBACK"));
         Telemetry::Accumulate(Telemetry::VIDEO_DROPPED_FRAMES_PROPORTION,
                               percentage);
       }
     }
   }
 
--- a/dom/html/HTMLVideoElement.cpp
+++ b/dom/html/HTMLVideoElement.cpp
@@ -308,32 +308,31 @@ HTMLVideoElement::GetVideoPlaybackQualit
 
     if (mDecoder) {
       if (nsContentUtils::ShouldResistFingerprinting(OwnerDoc())) {
         totalFrames = nsRFPService::GetSpoofedTotalFrames(TotalPlayTime());
         droppedFrames = nsRFPService::GetSpoofedDroppedFrames(
             TotalPlayTime(), VideoWidth(), VideoHeight());
         corruptedFrames = 0;
       } else {
-        FrameStatisticsData stats =
-            mDecoder->GetFrameStatistics().GetFrameStatisticsData();
-        if (sizeof(totalFrames) >= sizeof(stats.mParsedFrames)) {
-          totalFrames = stats.mPresentedFrames + stats.mDroppedFrames;
-          droppedFrames = stats.mDroppedFrames;
+        FrameStatistics* stats = &mDecoder->GetFrameStatistics();
+        if (sizeof(totalFrames) >= sizeof(stats->GetParsedFrames())) {
+          totalFrames = stats->GetTotalFrames();
+          droppedFrames = stats->GetDroppedFrames();
         } else {
-          uint64_t total = stats.mPresentedFrames + stats.mDroppedFrames;
+          uint64_t total = stats->GetTotalFrames();
           const auto maxNumber = std::numeric_limits<uint32_t>::max();
           if (total <= maxNumber) {
             totalFrames = uint32_t(total);
-            droppedFrames = uint32_t(stats.mDroppedFrames);
+            droppedFrames = uint32_t(stats->GetDroppedFrames());
           } else {
             // Too big number(s) -> Resize everything to fit in 32 bits.
             double ratio = double(maxNumber) / double(total);
             totalFrames = maxNumber;  // === total * ratio
-            droppedFrames = uint32_t(double(stats.mDroppedFrames) * ratio);
+            droppedFrames = uint32_t(double(stats->GetDroppedFrames()) * ratio);
           }
         }
         corruptedFrames = 0;
       }
     }
   }
 
   RefPtr<VideoPlaybackQuality> playbackQuality = new VideoPlaybackQuality(
--- a/dom/media/FrameStatistics.h
+++ b/dom/media/FrameStatistics.h
@@ -15,47 +15,61 @@ struct FrameStatisticsData {
   // Number of frames parsed and demuxed from media.
   // Access protected by mReentrantMonitor.
   uint64_t mParsedFrames = 0;
 
   // Number of parsed frames which were actually decoded.
   // Access protected by mReentrantMonitor.
   uint64_t mDecodedFrames = 0;
 
+  // Number of parsed frames which were dropped in the decoder.
+  // Access protected by mReentrantMonitor.
+  uint64_t mDroppedDecodedFrames = 0;
+
+  // Number of decoded frames which were dropped in the sink
+  // Access protected by mReentrantMonitor.
+  uint64_t mDroppedSinkFrames = 0;
+
+  // Number of sinked frames which were dropped in the compositor
+  // Access protected by mReentrantMonitor.
+  uint64_t mDroppedCompositorFrames = 0;
+
   // Number of decoded frames which were actually sent down the rendering
   // pipeline to be painted ("presented"). Access protected by
   // mReentrantMonitor.
   uint64_t mPresentedFrames = 0;
 
-  // Number of frames that have been skipped because they have missed their
-  // composition deadline.
-  uint64_t mDroppedFrames = 0;
-
   // Sum of all inter-keyframe segment durations, in microseconds.
   // Dividing by count will give the average inter-keyframe time.
   uint64_t mInterKeyframeSum_us = 0;
   // Number of inter-keyframe segments summed so far.
   size_t mInterKeyframeCount = 0;
 
   // Maximum inter-keyframe segment duration, in microseconds.
   uint64_t mInterKeyFrameMax_us = 0;
 
   FrameStatisticsData() = default;
-  FrameStatisticsData(uint64_t aParsed, uint64_t aDecoded, uint64_t aDropped,
-                      uint64_t aPresented)
+  FrameStatisticsData(uint64_t aParsed, uint64_t aDecoded, uint64_t aPresented,
+                      uint64_t aDroppedDecodedFrames,
+                      uint64_t aDroppedSinkFrames,
+                      uint64_t aDroppedCompositorFrames)
       : mParsedFrames(aParsed),
         mDecodedFrames(aDecoded),
-        mPresentedFrames(aPresented),
-        mDroppedFrames(aDropped) {}
+        mDroppedDecodedFrames(aDroppedDecodedFrames),
+        mDroppedSinkFrames(aDroppedSinkFrames),
+        mDroppedCompositorFrames(aDroppedCompositorFrames),
+        mPresentedFrames(aPresented) {}
 
   void Accumulate(const FrameStatisticsData& aStats) {
     mParsedFrames += aStats.mParsedFrames;
     mDecodedFrames += aStats.mDecodedFrames;
     mPresentedFrames += aStats.mPresentedFrames;
-    mDroppedFrames += aStats.mDroppedFrames;
+    mDroppedDecodedFrames += aStats.mDroppedDecodedFrames;
+    mDroppedSinkFrames += aStats.mDroppedSinkFrames;
+    mDroppedCompositorFrames += aStats.mDroppedCompositorFrames;
     mInterKeyframeSum_us += aStats.mInterKeyframeSum_us;
     mInterKeyframeCount += aStats.mInterKeyframeCount;
     // It doesn't make sense to add max numbers, instead keep the bigger one.
     if (mInterKeyFrameMax_us < aStats.mInterKeyFrameMax_us) {
       mInterKeyFrameMax_us = aStats.mInterKeyFrameMax_us;
     }
   }
 };
@@ -92,21 +106,30 @@ class FrameStatistics {
   // Returns the number of decoded frames which have been sent to the rendering
   // pipeline for painting ("presented").
   // Can be called on any thread.
   uint64_t GetPresentedFrames() const {
     ReentrantMonitorAutoEnter mon(mReentrantMonitor);
     return mFrameStatisticsData.mPresentedFrames;
   }
 
+  // Returns the number of presented and dropped frames
+  // Can be called on any thread.
+  uint64_t GetTotalFrames() const {
+    ReentrantMonitorAutoEnter mon(mReentrantMonitor);
+    return mFrameStatisticsData.mPresentedFrames + GetDroppedFrames();
+  }
+
   // Returns the number of frames that have been skipped because they have
   // missed their composition deadline.
   uint64_t GetDroppedFrames() const {
     ReentrantMonitorAutoEnter mon(mReentrantMonitor);
-    return mFrameStatisticsData.mDroppedFrames;
+    return mFrameStatisticsData.mDroppedDecodedFrames +
+           mFrameStatisticsData.mDroppedSinkFrames +
+           mFrameStatisticsData.mDroppedCompositorFrames;
   }
 
   // Increments the parsed and decoded frame counters by the passed in counts.
   // Can be called on any thread.
   void Accumulate(const FrameStatisticsData& aStats) {
     ReentrantMonitorAutoEnter mon(mReentrantMonitor);
     mFrameStatisticsData.Accumulate(aStats);
   }
--- a/dom/media/MediaFormatReader.cpp
+++ b/dom/media/MediaFormatReader.cpp
@@ -2502,17 +2502,17 @@ void MediaFormatReader::DropDecodedSampl
     if (time >= decoder.mTimeThreshold.ref().Time()) {
       // We would have reached our internal seek target.
       decoder.mTimeThreshold.reset();
     }
   }
   decoder.mOutput.Clear();
   decoder.mSizeOfQueue -= lengthDecodedQueue;
   if (aTrack == TrackInfo::kVideoTrack && mFrameStats) {
-    mFrameStats->Accumulate({0, 0, lengthDecodedQueue, 0});
+    mFrameStats->Accumulate({0, 0, 0, lengthDecodedQueue, 0, 0});
   }
 }
 
 void MediaFormatReader::SkipVideoDemuxToNextKeyFrame(TimeUnit aTimeThreshold) {
   MOZ_ASSERT(OnTaskQueue());
   LOG("Skipping up to %" PRId64, aTimeThreshold.ToMicroseconds());
 
   // We've reached SkipVideoDemuxToNextKeyFrame when our decoding is late.
@@ -2531,25 +2531,26 @@ void MediaFormatReader::VideoSkipReset(u
   PROFILER_ADD_MARKER("SkippedVideoDecode", GRAPHICS);
   MOZ_ASSERT(OnTaskQueue());
 
   // Some frames may have been output by the decoder since we initiated the
   // videoskip process and we know they would be late.
   DropDecodedSamples(TrackInfo::kVideoTrack);
   // Report the pending frames as dropped.
   if (mFrameStats) {
-    mFrameStats->Accumulate({0, 0, SizeOfVideoQueueInFrames(), 0});
+    uint32_t droppedDecoderCount = SizeOfVideoQueueInFrames();
+    mFrameStats->Accumulate({0, 0, 0, droppedDecoderCount, 0, 0});
   }
 
   // Cancel any pending demux request and pending demuxed samples.
   mVideo.mDemuxRequest.DisconnectIfExists();
   Reset(TrackType::kVideoTrack);
 
   if (mFrameStats) {
-    mFrameStats->Accumulate({aSkipped, 0, aSkipped, 0});
+    mFrameStats->Accumulate({aSkipped, 0, 0, aSkipped, 0, 0});
   }
 
   mVideo.mNumSamplesSkippedTotal += aSkipped;
 }
 
 void MediaFormatReader::OnVideoSkipCompleted(uint32_t aSkipped) {
   MOZ_ASSERT(OnTaskQueue());
   LOG("Skipping succeeded, skipped %u frames", aSkipped);
@@ -3030,16 +3031,25 @@ void MediaFormatReader::GetMozDebugReade
                               : -1.0,
         mVideo.mTimeThreshold ? mVideo.mTimeThreshold.ref().mHasSeeked : -1,
         mVideo.mNumSamplesInput, mVideo.mNumSamplesOutput,
         unsigned(size_t(mVideo.mSizeOfQueue)),
         unsigned(mVideo.mOutput.Length()), mVideo.mWaitingForData,
         mVideo.mDemuxEOS, int32_t(mVideo.mDrainState), mVideo.mWaitingForKey,
         mVideo.mLastStreamSourceID);
   }
+
+  // Looking at dropped frames in details.
+  FrameStatisticsData stats = mFrameStats->GetFrameStatisticsData();
+  result +=
+      nsPrintfCString("Dropped Frames: reader=%" PRIu64 " sink=%" PRIu64
+                      " compositor=%" PRIu64 "\n",
+                      stats.mDroppedDecodedFrames, stats.mDroppedSinkFrames,
+                      stats.mDroppedCompositorFrames);
+
   aString += result;
 }
 
 void MediaFormatReader::SetVideoNullDecode(bool aIsNullDecode) {
   MOZ_ASSERT(OnTaskQueue());
   return SetNullDecode(TrackType::kVideoTrack, aIsNullDecode);
 }
 
--- a/dom/media/mediasink/VideoSink.cpp
+++ b/dom/media/mediasink/VideoSink.cpp
@@ -512,54 +512,54 @@ void VideoSink::UpdateRenderedVideoFrame
   MOZ_ASSERT(mAudioSink->IsPlaying(), "should be called while playing.");
 
   // Get the current playback position.
   TimeStamp nowTime;
   const auto clockTime = mAudioSink->GetPosition(&nowTime);
   MOZ_ASSERT(!clockTime.IsNegative(), "Should have positive clock time.");
 
   uint32_t sentToCompositorCount = 0;
-  uint32_t droppedCount = 0;
+  uint32_t droppedInSink = 0;
 
   // Skip frames up to the playback position.
   TimeUnit lastFrameEndTime;
   while (VideoQueue().GetSize() > mMinVideoQueueSize &&
          clockTime >= VideoQueue().PeekFront()->GetEndTime()) {
     RefPtr<VideoData> frame = VideoQueue().PopFront();
     lastFrameEndTime = frame->GetEndTime();
     if (frame->IsSentToCompositor()) {
       sentToCompositorCount++;
     } else {
-      droppedCount++;
+      droppedInSink++;
       VSINK_LOG_V("discarding video frame mTime=%" PRId64
                   " clock_time=%" PRId64,
                   frame->mTime.ToMicroseconds(), clockTime.ToMicroseconds());
       VSINK_ADD_PROFILER_MARKER("VideoSink: discard", nowTime,
                                 clockTime.ToMicroseconds(),
                                 frame->mTime.ToMicroseconds());
     }
   }
 
-  if (droppedCount || sentToCompositorCount) {
+  if (droppedInSink || sentToCompositorCount) {
     uint32_t totalCompositorDroppedCount = mContainer->GetDroppedImageCount();
-    uint32_t compositorDroppedCount =
+    uint32_t droppedInCompositor =
         totalCompositorDroppedCount - mOldCompositorDroppedCount;
-    if (compositorDroppedCount > 0) {
+    if (droppedInCompositor > 0) {
       mOldCompositorDroppedCount = totalCompositorDroppedCount;
       VSINK_LOG_V("%u video frame previously discarded by compositor",
-                  compositorDroppedCount);
+                  droppedInCompositor);
     }
-    mPendingDroppedCount += compositorDroppedCount;
+    mPendingDroppedCount += droppedInCompositor;
     uint32_t droppedReported = mPendingDroppedCount > sentToCompositorCount
                                    ? sentToCompositorCount
                                    : mPendingDroppedCount;
     mPendingDroppedCount -= droppedReported;
 
-    mFrameStats.Accumulate({0, 0, droppedCount + droppedReported,
-                            sentToCompositorCount - droppedReported});
+    mFrameStats.Accumulate({0, 0, sentToCompositorCount - droppedReported, 0,
+                            droppedInSink, droppedInCompositor});
   }
 
   // The presentation end time of the last video frame displayed is either
   // the end time of the current frame, or if we dropped all frames in the
   // queue, the end time of the last frame we removed from the queue.
   RefPtr<VideoData> currentFrame = VideoQueue().PeekFront();
   mVideoFrameEndTime =
       std::max(mVideoFrameEndTime,
@@ -596,17 +596,17 @@ void VideoSink::MaybeResolveEndPromise()
   AssertOwnerThread();
   // All frames are rendered, Let's resolve the promise.
   if (VideoQueue().IsFinished() && VideoQueue().GetSize() <= 1 &&
       !mVideoSinkEndRequest.Exists()) {
     if (VideoQueue().GetSize() == 1) {
       // Remove the last frame since we have sent it to compositor.
       RefPtr<VideoData> frame = VideoQueue().PopFront();
       if (mPendingDroppedCount > 0) {
-        mFrameStats.Accumulate({0, 0, 1, 0});
+        mFrameStats.Accumulate({0, 0, 0, 0, 0, 1});
         mPendingDroppedCount--;
       } else {
         mFrameStats.NotifyPresentedFrame();
       }
     }
     mEndPromiseHolder.ResolveIfExists(true, __func__);
   }
 }
--- a/dom/media/test/marionette/yttest/ytpage.py
+++ b/dom/media/test/marionette/yttest/ytpage.py
@@ -34,16 +34,17 @@ SPLIT_FIELD = (
     "AudioSink",
     "MDSM",
     "Video State",
     "Video Track Buffer Details",
     "Dumping Audio Track",
     "Dumping Video Track",
     "MediaDecoder",
     "VideoSink",
+    "Dropped Frames"
 )
 
 
 class YoutubePage:
     def __init__(self, video_id, marionette, **options):
         self.video_id = video_id
         self.marionette = marionette
         self.url = "https://www.youtube.com/watch?v=%s" % self.video_id