Bug 839650: Add debugs to MediaStreamGraph to ease investigation of issues in the future r=roc
authorRandell Jesup <rjesup@jesup.org>
Thu, 07 Mar 2013 03:53:45 -0500
changeset 124122 e2f80c264f1055545d3b68df3f5948349856cd02
parent 124121 ad01bb8a6742f8b1d9549bdab2be1c9aa045565b
child 124123 577f5474a1b7c9cb49ba335809332185e9ccbb4f
push id24408
push userryanvm@gmail.com
push dateFri, 08 Mar 2013 04:58:11 +0000
treeherdermozilla-central@cb432984d5ce [default view] [failures only]
perfherder[talos] [build metrics] [platform microbench] (compared to previous push)
reviewersroc
bugs839650
milestone22.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 839650: Add debugs to MediaStreamGraph to ease investigation of issues in the future r=roc
content/media/MediaStreamGraph.cpp
content/media/MediaStreamGraph.h
content/media/StreamBuffer.cpp
content/media/StreamBuffer.h
dom/media/MediaManager.cpp
--- a/content/media/MediaStreamGraph.cpp
+++ b/content/media/MediaStreamGraph.cpp
@@ -118,16 +118,24 @@ MediaStreamGraphImpl::ExtractPendingInpu
       StreamTime t =
         GraphTimeToStreamTime(aStream, mStateComputedTime) +
         (aDesiredUpToTime - mStateComputedTime);
       LOG(PR_LOG_DEBUG, ("Calling NotifyPull aStream=%p t=%f current end=%f", aStream,
                          MediaTimeToSeconds(t),
                          MediaTimeToSeconds(aStream->mBuffer.GetEnd())));
       if (t > aStream->mBuffer.GetEnd()) {
         *aEnsureNextIteration = true;
+#ifdef DEBUG
+        if (aStream->mListeners.Length() == 0) {
+          LOG(PR_LOG_ERROR, ("No listeners in NotifyPull aStream=%p desired=%f current end=%f",
+                             aStream, MediaTimeToSeconds(t),
+                             MediaTimeToSeconds(aStream->mBuffer.GetEnd())));
+          aStream->DumpTrackInfo();
+        }
+#endif
         for (uint32_t j = 0; j < aStream->mListeners.Length(); ++j) {
           MediaStreamListener* l = aStream->mListeners[j];
           {
             MutexAutoUnlock unlock(aStream->mMutex);
             l->NotifyPull(this, t);
           }
         }
       }
@@ -384,17 +392,26 @@ MediaStreamGraphImpl::WillUnderrun(Media
   // underrun currently, since we'll always be able to produce data for them
   // unless they block on some other stream.
   if (aStream->mFinished || aStream->AsProcessedStream()) {
     return false;
   }
   GraphTime bufferEnd =
     StreamTimeToGraphTime(aStream, aStream->GetBufferEnd(),
                           INCLUDE_TRAILING_BLOCKED_INTERVAL);
-  NS_ASSERTION(bufferEnd >= mCurrentTime, "Buffer underran");
+#ifdef DEBUG
+  if (bufferEnd < mCurrentTime) {
+    LOG(PR_LOG_ERROR, ("MediaStream %p underrun, "
+                       "bufferEnd %f < mCurrentTime %f (%lld < %lld), Streamtime %lld",
+                       aStream, MediaTimeToSeconds(bufferEnd), MediaTimeToSeconds(mCurrentTime),
+                       bufferEnd, mCurrentTime, aStream->GetBufferEnd()));
+    aStream->DumpTrackInfo();
+    NS_ASSERTION(bufferEnd >= mCurrentTime, "Buffer underran");
+  }
+#endif
   // We should block after bufferEnd.
   if (bufferEnd <= aTime) {
     LOG(PR_LOG_DEBUG, ("MediaStream %p will block due to data underrun, "
                        "bufferEnd %f",
                        aStream, MediaTimeToSeconds(bufferEnd)));
     return true;
   }
   // We should keep blocking if we're currently blocked and we don't have
@@ -1211,17 +1228,17 @@ MediaStreamGraphImpl::RunInStableState()
     }
 
     if (mLifecycleState == LIFECYCLE_THREAD_NOT_STARTED) {
       mLifecycleState = LIFECYCLE_RUNNING;
       // Start the thread now. We couldn't start it earlier because
       // the graph might exit immediately on finding it has no streams. The
       // first message for a new graph must create a stream.
       nsCOMPtr<nsIRunnable> event = new MediaStreamGraphThreadRunnable(this);
-      NS_NewThread(getter_AddRefs(mThread), event);
+      NS_NewNamedThread("MediaStreamGrph", getter_AddRefs(mThread), event);
     }
 
     if (mCurrentTaskMessageQueue.IsEmpty()) {
       if (mLifecycleState == LIFECYCLE_WAITING_FOR_MAIN_THREAD_CLEANUP && IsEmpty()) {
         // Complete shutdown. First, ensure that this graph is no longer used.
         // A new graph graph will be created if one is needed.
         LOG(PR_LOG_DEBUG, ("Disconnecting MediaStreamGraph %p", this));
         if (this == gGraph) {
--- a/content/media/MediaStreamGraph.h
+++ b/content/media/MediaStreamGraph.h
@@ -360,16 +360,19 @@ public:
   // These Impl methods perform the core functionality of the control methods
   // above, on the media graph thread.
   /**
    * Stop all stream activity and disconnect it from all inputs and outputs.
    * This must be idempotent.
    */
   virtual void DestroyImpl();
   StreamTime GetBufferEnd() { return mBuffer.GetEnd(); }
+#ifdef DEBUG
+  void DumpTrackInfo() { return mBuffer.DumpTrackInfo(); }
+#endif
   void SetAudioOutputVolumeImpl(void* aKey, float aVolume);
   void AddAudioOutputImpl(void* aKey)
   {
     mAudioOutputs.AppendElement(AudioOutput(aKey));
   }
   void RemoveAudioOutputImpl(void* aKey);
   void AddVideoOutputImpl(already_AddRefed<VideoFrameContainer> aContainer)
   {
--- a/content/media/StreamBuffer.cpp
+++ b/content/media/StreamBuffer.cpp
@@ -3,16 +3,40 @@
  * License, v. 2.0. If a copy of the MPL was not distributed with this file,
  * You can obtain one at http://mozilla.org/MPL/2.0/. */
 
 #include "StreamBuffer.h"
 #include <algorithm>
 
 namespace mozilla {
 
+#ifdef PR_LOGGING
+extern PRLogModuleInfo* gMediaStreamGraphLog;
+#define LOG(type, msg) PR_LOG(gMediaStreamGraphLog, type, msg)
+#else
+#define LOG(type, msg)
+#endif
+
+#ifdef DEBUG
+void
+StreamBuffer::DumpTrackInfo() const
+{
+  LOG(PR_LOG_ALWAYS, ("DumpTracks: mTracksKnownTime %lld", mTracksKnownTime));
+  for (uint32_t i = 0; i < mTracks.Length(); ++i) {
+    Track* track = mTracks[i];
+    if (track->IsEnded()) {
+      LOG(PR_LOG_ALWAYS, ("Track[%d] %d: ended", i, track->GetID()));
+    } else {
+      LOG(PR_LOG_ALWAYS, ("Track[%d] %d: %lld", i, track->GetID(),
+                          track->GetEndTimeRoundDown()));
+    }
+  }
+}
+#endif
+
 StreamTime
 StreamBuffer::GetEnd() const
 {
   StreamTime t = mTracksKnownTime;
   for (uint32_t i = 0; i < mTracks.Length(); ++i) {
     Track* track = mTracks[i];
     if (!track->IsEnded()) {
       t = std::min(t, track->GetEndTimeRoundDown());
--- a/content/media/StreamBuffer.h
+++ b/content/media/StreamBuffer.h
@@ -229,16 +229,20 @@ public:
   }
 
   /**
    * The end time for the StreamBuffer is the latest time for which we have
    * data for all tracks that haven't ended by that time.
    */
   StreamTime GetEnd() const;
 
+#ifdef DEBUG
+  void DumpTrackInfo() const;
+#endif
+
   Track* FindTrack(TrackID aID);
 
   class TrackIter {
   public:
     /**
      * Iterate through the tracks of aBuffer in order of ID.
      */
     TrackIter(const StreamBuffer& aBuffer) :
--- a/dom/media/MediaManager.cpp
+++ b/dom/media/MediaManager.cpp
@@ -854,17 +854,17 @@ NS_IMPL_THREADSAFE_ISUPPORTS2(MediaManag
 // NOTE: never Dispatch(....,NS_DISPATCH_SYNC) to the MediaManager
 // thread from the MainThread, as we NS_DISPATCH_SYNC to MainThread
 // from MediaManager thread.
 /* static */  MediaManager*
 MediaManager::Get() {
   if (!sSingleton) {
     sSingleton = new MediaManager();
 
-    NS_NewThread(getter_AddRefs(sSingleton->mMediaThread));
+    NS_NewNamedThread("MediaManager", getter_AddRefs(sSingleton->mMediaThread));
     LOG(("New Media thread for gum"));
 
     NS_ASSERTION(NS_IsMainThread(), "Only create MediaManager on main thread");
     nsCOMPtr<nsIObserverService> obs = services::GetObserverService();
     if (obs) {
       obs->AddObserver(sSingleton, "xpcom-shutdown", false);
       obs->AddObserver(sSingleton, "getUserMedia:response:allow", false);
       obs->AddObserver(sSingleton, "getUserMedia:response:deny", false);