Bug 1269408: P6. Add debugging information, useful when a mochitest timeout. r?gerald draft
authorJean-Yves Avenard <jyavenard@mozilla.com>
Thu, 05 May 2016 15:11:21 +1000
changeset 364203 e0590174f7587c9a1ffbbe4e7a065a5af2706271
parent 364202 4c7b1824bd51ca566a112d81b7509a011ba2bd46
child 364204 d839ee5f7e64423eaef5236a1b9a0cda5a4201d0
push id17383
push userbmo:jyavenard@mozilla.com
push dateFri, 06 May 2016 06:16:15 +0000
reviewersgerald
bugs1269408
milestone49.0a1
Bug 1269408: P6. Add debugging information, useful when a mochitest timeout. r?gerald Access to some members is not thread-safe; but the typical use of those informations is when a mochitest has timed out, and by that time the MFR will have been idled for over 5 minutes. MozReview-Commit-ID: 21BxrSZXVVJ
dom/media/MediaFormatReader.cpp
dom/media/MediaFormatReader.h
--- a/dom/media/MediaFormatReader.cpp
+++ b/dom/media/MediaFormatReader.cpp
@@ -109,17 +109,17 @@ MediaFormatReader::Shutdown()
     mAudio.mTrackDemuxer->BreakCycles();
     mAudio.mTrackDemuxer = nullptr;
   }
   if (mAudio.mTaskQueue) {
     mAudio.mTaskQueue->BeginShutdown();
     mAudio.mTaskQueue->AwaitShutdownAndIdle();
     mAudio.mTaskQueue = nullptr;
   }
-  MOZ_ASSERT(mAudio.mPromise.IsEmpty());
+  MOZ_ASSERT(!mAudio.HasPromise());
 
   if (mVideo.mDecoder) {
     Reset(TrackInfo::kVideoTrack);
     if (mVideo.HasPromise()) {
       mVideo.RejectPromise(CANCELED, __func__);
     }
     mVideo.mInitPromise.DisconnectIfExists();
     mVideo.ShutdownDecoder();
@@ -129,17 +129,17 @@ MediaFormatReader::Shutdown()
     mVideo.mTrackDemuxer->BreakCycles();
     mVideo.mTrackDemuxer = nullptr;
   }
   if (mVideo.mTaskQueue) {
     mVideo.mTaskQueue->BeginShutdown();
     mVideo.mTaskQueue->AwaitShutdownAndIdle();
     mVideo.mTaskQueue = nullptr;
   }
-  MOZ_ASSERT(mVideo.mPromise.IsEmpty());
+  MOZ_ASSERT(!mVideo.HasPromise());
 
   mDemuxer = nullptr;
 
   mPlatform = nullptr;
 
   return MediaDecoderReader::Shutdown();
 }
 
@@ -536,17 +536,17 @@ MediaFormatReader::RequestVideoData(bool
     mDecoder->NotifyDecodedFrames(0, 0, SizeOfVideoQueueInFrames());
 
     Reset(TrackInfo::kVideoTrack);
     RefPtr<MediaDataPromise> p = mVideo.EnsurePromise(__func__);
     SkipVideoDemuxToNextKeyFrame(timeThreshold);
     return p;
   }
 
-  RefPtr<MediaDataPromise> p = mVideo.mPromise.Ensure(__func__);
+  RefPtr<MediaDataPromise> p = mVideo.EnsurePromise(__func__);
   NotifyDecodingRequested(TrackInfo::kVideoTrack);
 
   return p;
 }
 
 void
 MediaFormatReader::OnDemuxFailed(TrackType aTrack, DemuxerFailureReason aFailure)
 {
@@ -622,17 +622,17 @@ MediaFormatReader::RequestAudioData()
     return MediaDataPromise::CreateAndReject(CANCELED, __func__);
   }
 
   if (mShutdown) {
     NS_WARNING("RequestAudioData on shutdown MediaFormatReader!");
     return MediaDataPromise::CreateAndReject(CANCELED, __func__);
   }
 
-  RefPtr<MediaDataPromise> p = mAudio.mPromise.Ensure(__func__);
+  RefPtr<MediaDataPromise> p = mAudio.EnsurePromise(__func__);
   NotifyDecodingRequested(TrackInfo::kAudioTrack);
 
   return p;
 }
 
 void
 MediaFormatReader::DoDemuxAudio()
 {
@@ -735,17 +735,16 @@ MediaFormatReader::NotifyDecodingRequest
   auto& decoder = GetDecoderData(aTrack);
   decoder.mDecodingRequested = true;
   ScheduleUpdate(aTrack);
 }
 
 bool
 MediaFormatReader::NeedInput(DecoderData& aDecoder)
 {
-  MOZ_ASSERT(OnTaskQueue());
   // We try to keep a few more compressed samples input than decoded samples
   // have been output, provided the state machine has requested we send it a
   // decoded sample. To account for H.264 streams which may require a longer
   // run of input than we input, decoders fire an "input exhausted" callback,
   // which overrides our "few more samples" threshold.
   return
     !aDecoder.mDraining &&
     !aDecoder.mError &&
@@ -1232,29 +1231,29 @@ MediaFormatReader::ReturnOutput(MediaDat
           audioData->mRate != mInfo.mAudio.mRate) {
         LOG("change of audio format (rate:%d->%d). "
             "This is an unsupported configuration",
             mInfo.mAudio.mRate, audioData->mRate);
         mInfo.mAudio.mRate = audioData->mRate;
         mInfo.mAudio.mChannels = audioData->mChannels;
       }
     }
-    mAudio.mPromise.Resolve(aData, __func__);
+    mAudio.ResolvePromise(aData, __func__);
   } else if (aTrack == TrackInfo::kVideoTrack) {
     if (aData->mType != MediaData::RAW_DATA) {
       VideoData* videoData = static_cast<VideoData*>(aData);
 
       if (videoData->mDisplay != mInfo.mVideo.mDisplay) {
         LOG("change of video display size (%dx%d->%dx%d)",
             mInfo.mVideo.mDisplay.width, mInfo.mVideo.mDisplay.height,
             videoData->mDisplay.width, videoData->mDisplay.height);
         mInfo.mVideo.mDisplay = videoData->mDisplay;
       }
     }
-    mVideo.mPromise.Resolve(aData, __func__);
+    mVideo.ResolvePromise(aData, __func__);
   }
   LOG("Resolved data promise for %s", TrackTypeToStr(aTrack));
 }
 
 size_t
 MediaFormatReader::SizeOfVideoQueueInFrames()
 {
   return SizeOfQueue(TrackInfo::kVideoTrack);
@@ -1765,22 +1764,58 @@ MediaFormatReader::GetMozDebugReaderData
   if (HasVideo()) {
     MonitorAutoLock mon(mVideo.mMonitor);
     videoName = mVideo.mDescription;
   }
 
   result += nsPrintfCString("audio decoder: %s\n", audioName);
   result += nsPrintfCString("audio frames decoded: %lld\n",
                             mAudio.mNumSamplesOutputTotal);
+  if (HasAudio()) {
+    result += nsPrintfCString("audio state: ni=%d no=%d ie=%d demuxr:%d demuxq:%d decoder:%d tt:%f tths:%d in:%llu out:%llu qs=%u pending:%u waiting:%d sid:%u\n",
+                              NeedInput(mAudio), mAudio.HasPromise(),
+                              mAudio.mInputExhausted,
+                              mAudio.mDemuxRequest.Exists(),
+                              int(mAudio.mQueuedSamples.Length()),
+                              mAudio.mDecodingRequested,
+                              mAudio.mTimeThreshold
+                              ? mAudio.mTimeThreshold.ref().mTime.ToSeconds()
+                              : -1.0,
+                              mAudio.mTimeThreshold
+                              ? mAudio.mTimeThreshold.ref().mHasSeeked
+                              : -1,
+                              mAudio.mNumSamplesInput, mAudio.mNumSamplesOutput,
+                              unsigned(size_t(mAudio.mSizeOfQueue)),
+                              unsigned(mAudio.mOutput.Length()),
+                              mAudio.mWaitingForData, mAudio.mLastStreamSourceID);
+  }
   result += nsPrintfCString("video decoder: %s\n", videoName);
   result += nsPrintfCString("hardware video decoding: %s\n",
                             VideoIsHardwareAccelerated() ? "enabled" : "disabled");
   result += nsPrintfCString("video frames decoded: %lld (skipped:%lld)\n",
                             mVideo.mNumSamplesOutputTotal,
                             mVideo.mNumSamplesSkippedTotal);
+  if (HasVideo()) {
+    result += nsPrintfCString("video state: ni=%d no=%d ie=%d demuxr:%d demuxq:%d decoder:%d tt:%f tths:%d in:%llu out:%llu qs=%u pending:%u waiting:%d sid:%u\n",
+                              NeedInput(mVideo), mVideo.HasPromise(),
+                              mVideo.mInputExhausted,
+                              mVideo.mDemuxRequest.Exists(),
+                              int(mVideo.mQueuedSamples.Length()),
+                              mVideo.mDecodingRequested,
+                              mVideo.mTimeThreshold
+                              ? mVideo.mTimeThreshold.ref().mTime.ToSeconds()
+                              : -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.mLastStreamSourceID);
+  }
   aString += NS_ConvertUTF8toUTF16(result);
 }
 
 void
 MediaFormatReader::ReportDroppedFramesTelemetry()
 {
   MOZ_ASSERT(OnTaskQueue());
 
--- a/dom/media/MediaFormatReader.h
+++ b/dom/media/MediaFormatReader.h
@@ -320,17 +320,19 @@ private:
     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 bool HasPromise() const = 0;
+    virtual RefPtr<MediaDataPromise> EnsurePromise(const char* aMethodName) = 0;
+    virtual void ResolvePromise(MediaData* aData, const char* aMethodName) = 0;
     virtual void RejectPromise(MediaDecoderReader::NotDecodedReason aReason,
                                const char* aMethodName) = 0;
 
     // Clear track demuxer related data.
     void ResetDemuxer()
     {
       mDemuxRequest.DisconnectIfExists();
       mSeekRequest.DisconnectIfExists();
@@ -397,38 +399,57 @@ private:
     // Sample format monitoring.
     uint32_t mLastStreamSourceID;
     Maybe<uint32_t> mNextStreamSourceID;
     media::TimeIntervals mTimeRanges;
     Maybe<media::TimeUnit> mLastTimeRangesEnd;
     RefPtr<SharedTrackInfo> mInfo;
   };
 
-  struct DecoderDataWithPromise : public DecoderData {
+  class DecoderDataWithPromise : public DecoderData {
+  public:
     DecoderDataWithPromise(MediaFormatReader* aOwner,
                            MediaData::Type aType,
-                           uint32_t aDecodeAhead) :
-      DecoderData(aOwner, aType, aDecodeAhead)
+                           uint32_t aDecodeAhead)
+      : DecoderData(aOwner, aType, aDecodeAhead)
+      , mHasPromise(false)
+
     {}
 
-    MozPromiseHolder<MediaDataPromise> mPromise;
+    bool HasPromise() const override
+    {
+      return mHasPromise;
+    }
 
-    bool HasPromise() override
+    RefPtr<MediaDataPromise> EnsurePromise(const char* aMethodName) override
     {
       MOZ_ASSERT(mOwner->OnTaskQueue());
-      return !mPromise.IsEmpty();
+      mHasPromise = true;
+      return mPromise.Ensure(aMethodName);
+    }
+
+    void ResolvePromise(MediaData* aData, const char* aMethodName) override
+    {
+      MOZ_ASSERT(mOwner->OnTaskQueue());
+      mPromise.Resolve(aData, aMethodName);
+      mHasPromise = false;
     }
 
     void RejectPromise(MediaDecoderReader::NotDecodedReason aReason,
                        const char* aMethodName) override
     {
       MOZ_ASSERT(mOwner->OnTaskQueue());
       mPromise.Reject(aReason, aMethodName);
       mDecodingRequested = false;
+      mHasPromise = false;
     }
+
+  private:
+    MozPromiseHolder<MediaDataPromise> mPromise;
+    Atomic<bool> mHasPromise;
   };
 
   DecoderDataWithPromise mAudio;
   DecoderDataWithPromise mVideo;
 
   // Returns true when the decoder for this track needs input.
   bool NeedInput(DecoderData& aDecoder);