Bug 1297553 - Dump more debugging messages for MDSM and MediaSink. r=kaku

MozReview-Commit-ID: ILcF1hT2hVN

--HG--
extra : rebase_source : 1f6564eb5161608ee6031b1c362a6b689762dcfe

dom/media/MediaDecoderStateMachine.cpp

@@ -2855,15 +2855,17 @@ MediaDecoderStateMachine::DumpDebugInfo()
   // It is fine to capture a raw pointer here because MediaDecoder only call
   // this function before shutdown begins.
   nsCOMPtr<nsIRunnable> r = NS_NewRunnableFunction([this] () {
+    mMediaSink->DumpDebugInfo();
     DUMP_LOG(
-      "GetMediaTime=%lld GetClock=%lld "
+      "GetMediaTime=%lld GetClock=%lld mMediaSink=%p "
       "mState=%s mPlayState=%d mDecodingFirstFrame=%d IsPlaying=%d "
       "mAudioStatus=%s mVideoStatus=%s mDecodedAudioEndTime=%lld mDecodedVideoEndTime=%lld "
-      "mIsAudioPrerolling=%d mIsVideoPrerolling=%d",
-      GetMediaTime(), mMediaSink->IsStarted() ? GetClock() : -1,
+      "mIsAudioPrerolling=%d mIsVideoPrerolling=%d "
+      "mAudioCompleted=%d mVideoCompleted=%d",
+      GetMediaTime(), mMediaSink->IsStarted() ? GetClock() : -1, mMediaSink.get(),
       ToStateStr(), mPlayState.Ref(), mDecodingFirstFrame, IsPlaying(),
       AudioRequestStatus(), VideoRequestStatus(), mDecodedAudioEndTime, mDecodedVideoEndTime,
-      mIsAudioPrerolling, mIsVideoPrerolling);
+      mIsAudioPrerolling, mIsVideoPrerolling, mAudioCompleted.Ref(), mVideoCompleted.Ref());
   });
 
   OwnerThread()->DispatchStateChange(r.forget());

dom/media/mediasink/MediaSink.h

@@ -119,6 +119,10 @@ public:
   // Must be called after playback stopped.
   virtual void Shutdown() {}
 
+  // Dump debugging information to the logs.
+  // Can be called in any phase.
+  virtual void DumpDebugInfo() {}
+
 protected:
   virtual ~MediaSink() {}
 };

dom/media/mediasink/VideoSink.cpp

@@ -11,12 +11,14 @@
 namespace mozilla {
 
 extern LazyLogModule gMediaDecoderLog;
-#define VSINK_LOG(msg, ...) \
-  MOZ_LOG(gMediaDecoderLog, LogLevel::Debug, \
-    ("VideoSink=%p " msg, this, ##__VA_ARGS__))
-#define VSINK_LOG_V(msg, ...) \
-  MOZ_LOG(gMediaDecoderLog, LogLevel::Verbose, \
-  ("VideoSink=%p " msg, this, ##__VA_ARGS__))
+
+#undef FMT
+#undef DUMP_LOG
+
+#define FMT(x, ...) "VideoSink=%p " x, this, ##__VA_ARGS__
+#define VSINK_LOG(...)   MOZ_LOG(gMediaDecoderLog, LogLevel::Debug,   (FMT(__VA_ARGS__)))
+#define VSINK_LOG_V(...) MOZ_LOG(gMediaDecoderLog, LogLevel::Verbose, (FMT(__VA_ARGS__)))
+#define DUMP_LOG(...) NS_DebugBreak(NS_DEBUG_WARNING, nsPrintfCString(FMT(__VA_ARGS__)).get(), nullptr, nullptr, -1)
 
 using namespace mozilla::layers;
 
@@ -445,5 +447,17 @@ VideoSink::UpdateRenderedVideoFrames()
   });
 }
 
+void
+VideoSink::DumpDebugInfo()
+{
+  AssertOwnerThread();
+  DUMP_LOG(
+    "IsStarted=%d IsPlaying=%d, VideoQueue: finished=%d size=%d, "
+    "mVideoFrameEndTime=%lld mHasVideo=%d mVideoSinkEndRequest.Exists()=%d "
+    "mEndPromiseHolder.IsEmpty()=%d",
+    IsStarted(), IsPlaying(), VideoQueue().IsFinished(), VideoQueue().GetSize(),
+    mVideoFrameEndTime, mHasVideo, mVideoSinkEndRequest.Exists(), mEndPromiseHolder.IsEmpty());
+}
+
 } // namespace media
 } // namespace mozilla

dom/media/mediasink/VideoSink.h

@@ -68,6 +68,8 @@ public:
 
   void Shutdown() override;
 
+  void DumpDebugInfo() override;
+
 private:
   virtual ~VideoSink();