Bug 1249706: Added telemetry for the proportion of frames dropped keyed by several details. r=jya
authorLouis Christie <lchristie@mozilla.com>
Tue, 23 Feb 2016 13:19:40 +1300
changeset 285813 a085ea2d24bbff3026f0c54639f64787776a20b6
parent 285812 1e882a4bf894ecfec2c8ce56d8b4e2ae036d8c77
child 285814 fe8939c91205cfdbf34c7ab8d010e7d129f17edc
push id30036
push usercbook@mozilla.com
push dateMon, 29 Feb 2016 10:35:59 +0000
treeherdermozilla-central@9da51cb4974e [default view] [failures only]
perfherder[talos] [build metrics] [platform microbench] (compared to previous push)
reviewersjya
bugs1249706
milestone47.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 1249706: Added telemetry for the proportion of frames dropped keyed by several details. r=jya
dom/media/MediaFormatReader.cpp
dom/media/MediaFormatReader.h
dom/media/platforms/wmf/WMFVideoMFTManager.cpp
dom/media/platforms/wmf/WMFVideoMFTManager.h
toolkit/components/telemetry/Histograms.json
--- a/dom/media/MediaFormatReader.cpp
+++ b/dom/media/MediaFormatReader.cpp
@@ -81,16 +81,20 @@ MediaFormatReader::~MediaFormatReader()
   MOZ_COUNT_DTOR(MediaFormatReader);
 }
 
 RefPtr<ShutdownPromise>
 MediaFormatReader::Shutdown()
 {
   MOZ_ASSERT(OnTaskQueue());
 
+  if (HasVideo()) {
+    ReportDroppedFramesTelemetry();
+  }
+
   mDemuxerInitRequest.DisconnectIfExists();
   mMetadataPromise.RejectIfExists(ReadMetadataFailureReason::METADATA_ERROR, __func__);
   mSeekPromise.RejectIfExists(NS_ERROR_FAILURE, __func__);
   mSkipRequest.DisconnectIfExists();
 
   if (mAudio.mDecoder) {
     Flush(TrackInfo::kAudioTrack);
     if (mAudio.HasPromise()) {
@@ -662,16 +666,17 @@ MediaFormatReader::NotifyNewOutput(Track
   auto& decoder = GetDecoderData(aTrack);
   if (!decoder.mOutputRequested) {
     LOG("MediaFormatReader produced output while flushing, discarding.");
     return;
   }
   decoder.mOutput.AppendElement(aSample);
   decoder.mNumSamplesOutput++;
   decoder.mNumSamplesOutputTotal++;
+  decoder.mNumSamplesOutputTotalSinceTelemetry++;
   ScheduleUpdate(aTrack);
 }
 
 void
 MediaFormatReader::NotifyInputExhausted(TrackType aTrack)
 {
   MOZ_ASSERT(OnTaskQueue());
   LOGV("Decoder has requested more %s data", TrackTypeToStr(aTrack));
@@ -905,16 +910,19 @@ MediaFormatReader::HandleDemuxedSamples(
         return;
       }
 
       if (decoder.mNextStreamSourceID.isNothing() ||
           decoder.mNextStreamSourceID.ref() != info->GetID()) {
         LOG("%s stream id has changed from:%d to:%d, draining decoder.",
             TrackTypeToStr(aTrack), decoder.mLastStreamSourceID,
             info->GetID());
+        if (aTrack == TrackType::kVideoTrack) {
+          ReportDroppedFramesTelemetry();
+        }
         decoder.mNeedDraining = true;
         decoder.mNextStreamSourceID = Some(info->GetID());
         ScheduleUpdate(aTrack);
         return;
       }
 
       LOG("%s stream id has changed from:%d to:%d, recreating decoder.",
           TrackTypeToStr(aTrack), decoder.mLastStreamSourceID,
@@ -1366,16 +1374,17 @@ MediaFormatReader::OnVideoSkipCompleted(
 {
   MOZ_ASSERT(OnTaskQueue());
   LOG("Skipping succeeded, skipped %u frames", aSkipped);
   mSkipRequest.Complete();
   if (mDecoder) {
     mDecoder->NotifyDecodedFrames(aSkipped, 0, aSkipped);
   }
   mVideo.mNumSamplesSkippedTotal += aSkipped;
+  mVideo.mNumSamplesSkippedTotalSinceTelemetry += aSkipped;
   MOZ_ASSERT(!mVideo.mError); // We have flushed the decoder, no frame could
                               // have been decoded (and as such errored)
   NotifyDecodingRequested(TrackInfo::kVideoTrack);
 }
 
 void
 MediaFormatReader::OnVideoSkipFailed(MediaTrackDemuxer::SkipFailureHolder aFailure)
 {
@@ -1695,9 +1704,56 @@ MediaFormatReader::GetMozDebugReaderData
   result += nsPrintfCString("hardware video decoding: %s\n",
                             VideoIsHardwareAccelerated() ? "enabled" : "disabled");
   result += nsPrintfCString("video frames decoded: %lld (skipped:%lld)\n",
                             mVideo.mNumSamplesOutputTotal,
                             mVideo.mNumSamplesSkippedTotal);
   aString += NS_ConvertUTF8toUTF16(result);
 }
 
+void
+MediaFormatReader::ReportDroppedFramesTelemetry()
+{
+  MOZ_ASSERT(OnTaskQueue());
+
+  const VideoInfo* info =
+    mVideo.mInfo ? mVideo.mInfo->GetAsVideoInfo() : &mInfo.mVideo;
+
+  if (!info || !mVideo.mDecoder) {
+    return;
+  }
+
+  nsCString keyPhrase = nsCString("MimeType=");
+  keyPhrase.Append(info->mMimeType);
+  keyPhrase.Append("; ");
+
+  keyPhrase.Append("Resolution=");
+  keyPhrase.AppendInt(info->mDisplay.width);
+  keyPhrase.Append('x');
+  keyPhrase.AppendInt(info->mDisplay.height);
+  keyPhrase.Append("; ");
+
+  keyPhrase.Append("HardwareAcceleration=");
+  if (VideoIsHardwareAccelerated()) {
+    keyPhrase.Append(mVideo.mDecoder->GetDescriptionName());
+    keyPhrase.Append("enabled");
+  } else {
+    keyPhrase.Append("disabled");
+  }
+
+  if (mVideo.mNumSamplesOutputTotalSinceTelemetry) {
+    uint32_t percentage =
+      100 * mVideo.mNumSamplesSkippedTotalSinceTelemetry /
+            mVideo.mNumSamplesOutputTotalSinceTelemetry;
+    nsCOMPtr<nsIRunnable> task = NS_NewRunnableFunction([=]() -> void {
+      LOG("Reporting telemetry DROPPED_FRAMES_IN_VIDEO_PLAYBACK");
+      Telemetry::Accumulate(Telemetry::VIDEO_DETAILED_DROPPED_FRAMES_PROPORTION,
+                            keyPhrase,
+                            percentage);
+    });
+    AbstractThread::MainThread()->Dispatch(task.forget());
+  }
+
+  mVideo.mNumSamplesSkippedTotalSinceTelemetry = 0;
+  mVideo.mNumSamplesOutputTotalSinceTelemetry = 0;
+}
+
 } // namespace mozilla
--- a/dom/media/MediaFormatReader.h
+++ b/dom/media/MediaFormatReader.h
@@ -229,16 +229,18 @@ private:
       , mError(false)
       , mNeedDraining(false)
       , mDraining(false)
       , mDrainComplete(false)
       , mNumSamplesInput(0)
       , mNumSamplesOutput(0)
       , mNumSamplesOutputTotal(0)
       , mNumSamplesSkippedTotal(0)
+      , mNumSamplesOutputTotalSinceTelemetry(0)
+      , mNumSamplesSkippedTotalSinceTelemetry(0)
       , mSizeOfQueue(0)
       , mIsHardwareAccelerated(false)
       , mLastStreamSourceID(UINT32_MAX)
     {}
 
     MediaFormatReader* mOwner;
     // Disambiguate Audio vs Video.
     MediaData::Type mType;
@@ -307,16 +309,19 @@ private:
     // Decoded samples returned my mDecoder awaiting being returned to
     // state machine upon request.
     nsTArray<RefPtr<MediaData>> mOutput;
     uint64_t mNumSamplesInput;
     uint64_t mNumSamplesOutput;
     uint64_t mNumSamplesOutputTotal;
     uint64_t mNumSamplesSkippedTotal;
 
+    uint64_t mNumSamplesOutputTotalSinceTelemetry;
+    uint64_t mNumSamplesSkippedTotalSinceTelemetry;
+
     // These get overriden in the templated concrete class.
     // Indicate if we have a pending promise for decoded frame.
     // Rejecting the promise will stop the reader from decoding ahead.
     virtual bool HasPromise() = 0;
     virtual void RejectPromise(MediaDecoderReader::NotDecodedReason aReason,
                                const char* aMethodName) = 0;
 
     void ResetDemuxer()
@@ -460,16 +465,19 @@ private:
   }
 
   void DoAudioSeek();
   void OnAudioSeekCompleted(media::TimeUnit aTime);
   void OnAudioSeekFailed(DemuxerFailureReason aFailure)
   {
     OnSeekFailed(TrackType::kAudioTrack, aFailure);
   }
+
+  void ReportDroppedFramesTelemetry();
+
   // Temporary seek information while we wait for the data
   Maybe<SeekTarget> mOriginalSeekTarget;
   Maybe<media::TimeUnit> mPendingSeekTime;
   MozPromiseHolder<SeekPromise> mSeekPromise;
 
   RefPtr<VideoFrameContainer> mVideoFrameContainer;
   layers::ImageContainer* GetImageContainer();
 
--- a/dom/media/platforms/wmf/WMFVideoMFTManager.cpp
+++ b/dom/media/platforms/wmf/WMFVideoMFTManager.cpp
@@ -646,16 +646,27 @@ WMFVideoMFTManager::Shutdown()
 
 bool
 WMFVideoMFTManager::IsHardwareAccelerated(nsACString& aFailureReason) const
 {
   aFailureReason = mDXVAFailureReason;
   return mDecoder && mUseHwAccel;
 }
 
+const char*
+WMFVideoMFTManager::GetDescriptionName() const
+{
+  if (mDecoder && mUseHwAccel && mDXVA2Manager) {
+    return (mDXVA2Manager->IsD3D11()) ?
+      "D3D11 Hardware Decoder" : "D3D9 Hardware Decoder";
+  } else {
+    return "wmf software video decoder";
+  }
+}
+
 void
 WMFVideoMFTManager::ConfigurationChanged(const TrackInfo& aConfig)
 {
   MOZ_ASSERT(aConfig.GetAsVideoInfo());
   mVideoInfo = *aConfig.GetAsVideoInfo();
 }
 
 } // namespace mozilla
--- a/dom/media/platforms/wmf/WMFVideoMFTManager.h
+++ b/dom/media/platforms/wmf/WMFVideoMFTManager.h
@@ -36,22 +36,17 @@ public:
   bool IsHardwareAccelerated(nsACString& aFailureReason) const override;
 
   TrackInfo::TrackType GetType() override {
     return TrackInfo::kVideoTrack;
   }
 
   void ConfigurationChanged(const TrackInfo& aConfig) override;
 
-  const char* GetDescriptionName() const override
-  {
-    nsCString failureReason;
-    return IsHardwareAccelerated(failureReason)
-      ? "wmf hardware video decoder" : "wmf software video decoder";
-  }
+  const char* GetDescriptionName() const override;
 
 private:
 
   bool InitializeDXVA(bool aForceD3D9);
 
   bool InitInternal(bool aForceD3D9);
 
   HRESULT ConfigureVideoFrameGeometry();
--- a/toolkit/components/telemetry/Histograms.json
+++ b/toolkit/components/telemetry/Histograms.json
@@ -10323,16 +10323,26 @@
     "alert_emails": ["lchristie@mozilla.com", "cpearce@mozilla.com"],
     "expires_in_version": "55",
     "kind": "linear",
     "high": 100,
     "n_buckets": 50,
     "bug_numbers": [1238433],
     "description": "Percentage of frames decoded frames dropped in an HTMLVideoElement"
   },
+  "VIDEO_DETAILED_DROPPED_FRAMES_PROPORTION" : {
+    "alert_emails": ["lchristie@mozilla.com", "cpearce@mozilla.com"],
+    "expires_in_version": "55",
+    "kind": "linear",
+    "high": 100,
+    "n_buckets": 50,
+    "keyed": true,
+    "bug_numbers": [1238433],
+    "description": "Percentage of frames decoded frames dropped in an HTMLVideoElement, keyed by MimeType, Resolution and Hardware Accelerated Decoding"
+  },
   "TAB_SWITCH_CACHE_POSITION": {
     "expires_in_version": "55",
     "bug_numbers": [1242013],
     "kind": "linear",
     "high": 100,
     "n_buckets": 50,
     "description": "Position in (theoretical) tab cache of tab being switched to"
   }