Bug 1440040 - Improve MediaEngineWebRTCMicrophoneSource logging. r?padenot draft
authorAndreas Pehrson <pehrsons@mozilla.com>
Wed, 28 Feb 2018 22:46:33 +0100
changeset 762087 d7897ecd82ac606ca1fd54b6362af7b8b07788a6
parent 762086 9a296c7096682197c05c7144e834226915168d58
child 762369 d7d9e806c02d096bf218b106e3e5798fa19598cf
child 762378 e3e1633f2622971a71e0c4d9744d4fcc16c01e06
child 762481 ac2c735fe70329aaf98f1ab32a4f4535bf025532
push id101079
push userbmo:apehrson@mozilla.com
push dateThu, 01 Mar 2018 20:12:43 +0000
reviewerspadenot
bugs1440040
milestone60.0a1
Bug 1440040 - Improve MediaEngineWebRTCMicrophoneSource logging. r?padenot MozReview-Commit-ID: 3mB1gZOGfCY
dom/media/webrtc/MediaEngineWebRTCAudio.cpp
--- a/dom/media/webrtc/MediaEngineWebRTCAudio.cpp
+++ b/dom/media/webrtc/MediaEngineWebRTCAudio.cpp
@@ -223,16 +223,19 @@ nsresult
 MediaEngineWebRTCMicrophoneSource::Reconfigure(const RefPtr<AllocationHandle>& aHandle,
                                                const dom::MediaTrackConstraints& aConstraints,
                                                const MediaEnginePrefs& aPrefs,
                                                const nsString& aDeviceId,
                                                const char** aOutBadConstraint)
 {
   AssertIsOnOwningThread();
   MOZ_ASSERT(aHandle);
+
+  LOG(("Mic source %p allocation %p Reconfigure()", this, aHandle.get()));
+
   NormalizedConstraints constraints(aConstraints);
   return ReevaluateAllocation(aHandle, &constraints, aPrefs, aDeviceId,
                               aOutBadConstraint);
 }
 
 bool operator == (const MediaEnginePrefs& a, const MediaEnginePrefs& b)
 {
   return !memcmp(&a, &b, sizeof(MediaEnginePrefs));
@@ -564,16 +567,19 @@ MediaEngineWebRTCMicrophoneSource::Alloc
                                             const ipc::PrincipalInfo& aPrincipalInfo,
                                             AllocationHandle** aOutHandle,
                                             const char** aOutBadConstraint)
 {
   AssertIsOnOwningThread();
   MOZ_ASSERT(aOutHandle);
   auto handle = MakeRefPtr<AllocationHandle>(aConstraints, aPrincipalInfo,
                                              aPrefs, aDeviceId);
+
+  LOG(("Mic source %p allocation %p Allocate()", this, handle.get()));
+
   nsresult rv = ReevaluateAllocation(handle, nullptr, aPrefs, aDeviceId,
                                      aOutBadConstraint);
   if (NS_FAILED(rv)) {
     return rv;
   }
 
   {
     MutexAutoLock lock(mMutex);
@@ -589,16 +595,18 @@ MediaEngineWebRTCMicrophoneSource::Deall
 {
   AssertIsOnOwningThread();
 
   size_t i = mAllocations.IndexOf(aHandle, 0, AllocationHandleComparator());
   MOZ_DIAGNOSTIC_ASSERT(i != mAllocations.NoIndex);
   MOZ_DIAGNOSTIC_ASSERT(!mAllocations[i].mEnabled,
                         "Source should be stopped for the track before removing");
 
+  LOG(("Mic source %p allocation %p Deallocate()", this, aHandle.get()));
+
   if (mAllocations[i].mStream && IsTrackIDExplicit(mAllocations[i].mTrackID)) {
     mAllocations[i].mStream->EndTrack(mAllocations[i].mTrackID);
   }
 
   {
     MutexAutoLock lock(mMutex);
     mAllocations.RemoveElementAt(i);
   }
@@ -624,16 +632,19 @@ MediaEngineWebRTCMicrophoneSource::SetTr
                                             const RefPtr<SourceMediaStream>& aStream,
                                             TrackID aTrackID,
                                             const PrincipalHandle& aPrincipal)
 {
   AssertIsOnOwningThread();
   MOZ_ASSERT(aStream);
   MOZ_ASSERT(IsTrackIDExplicit(aTrackID));
 
+  LOG(("Mic source %p allocation %p SetTrack() stream=%p, track=%" PRId32,
+       this, aHandle.get(), aStream.get(), aTrackID));
+
   // Until we fix bug 1400488 we need to block a second tab (OuterWindow)
   // from opening an already-open device.  If it's the same tab, they
   // will share a Graph(), and we can allow it.
   if (!mAllocations.IsEmpty() &&
       mAllocations[0].mStream &&
       mAllocations[0].mStream->Graph() != aStream->Graph()) {
     return NS_ERROR_NOT_AVAILABLE;
   }
@@ -669,16 +680,18 @@ nsresult
 MediaEngineWebRTCMicrophoneSource::Start(const RefPtr<const AllocationHandle>& aHandle)
 {
   AssertIsOnOwningThread();
 
   if (sChannelsOpen == 0) {
     return NS_ERROR_FAILURE;
   }
 
+  LOG(("Mic source %p allocation %p Start()", this, aHandle.get()));
+
   size_t i = mAllocations.IndexOf(aHandle, 0, AllocationHandleComparator());
   MOZ_DIAGNOSTIC_ASSERT(i != mAllocations.NoIndex,
                         "Can't start track that hasn't been added");
   Allocation& allocation = mAllocations[i];
 
   MOZ_ASSERT(!allocation.mEnabled, "Source already started");
   {
     // This spans setting both the enabled state and mState.
@@ -711,16 +724,18 @@ MediaEngineWebRTCMicrophoneSource::Start
   return NS_OK;
 }
 
 nsresult
 MediaEngineWebRTCMicrophoneSource::Stop(const RefPtr<const AllocationHandle>& aHandle)
 {
   AssertIsOnOwningThread();
 
+  LOG(("Mic source %p allocation %p Stop()", this, aHandle.get()));
+
   size_t i = mAllocations.IndexOf(aHandle, 0, AllocationHandleComparator());
   MOZ_DIAGNOSTIC_ASSERT(i != mAllocations.NoIndex,
                         "Cannot stop track that we don't know about");
   Allocation& allocation = mAllocations[i];
 
   if (!allocation.mEnabled) {
     // Already stopped - this is allowed
     return NS_OK;
@@ -753,18 +768,16 @@ MediaEngineWebRTCMicrophoneSource::Stop(
 
 void
 MediaEngineWebRTCMicrophoneSource::Pull(const RefPtr<const AllocationHandle>& aHandle,
                                         const RefPtr<SourceMediaStream>& aStream,
                                         TrackID aTrackID,
                                         StreamTime aDesiredTime,
                                         const PrincipalHandle& aPrincipalHandle)
 {
-  LOG_FRAMES(("NotifyPull, desired = %" PRId64, (int64_t) aDesiredTime));
-
   StreamTime delta;
 
   {
     MutexAutoLock lock(mMutex);
     size_t i = mAllocations.IndexOf(aHandle, 0, AllocationHandleComparator());
     if (i == mAllocations.NoIndex) {
       // This handle must have been deallocated. That's fine, and its track
       // will already be ended. No need to do anything.
@@ -786,16 +799,19 @@ MediaEngineWebRTCMicrophoneSource::Pull(
     }
 
     if (delta < 0) {
       LOG_FRAMES(("Not appending silence for allocation %p; %" PRId64 " frames already buffered",
                   mAllocations[i].mHandle.get(), -delta));
       return;
     }
 
+    LOG_FRAMES(("Pulling %" PRId64 " frames of silence for allocation %p",
+                delta, mAllocations[i].mHandle.get()));
+
     // This assertion fails when we append silence here in the same iteration
     // as there were real audio samples already appended by the audio callback.
     // Note that this is exempted until live samples and a subsequent chunk of silence have been appended to the track. This will cover cases like:
     // - After Start(), there is silence (maybe multiple times) appended before
     //   the first audio callback.
     // - After Start(), there is real data (maybe multiple times) appended
     //   before the first graph iteration.
     // And other combinations of order of audio sample sources.
@@ -1003,16 +1019,19 @@ MediaEngineWebRTCMicrophoneSource::Packe
       if (!allocation.mStream) {
         continue;
       }
 
       if (!allocation.mEnabled) {
         continue;
       }
 
+      LOG_FRAMES(("Appending %" PRIu32 " frames of packetized audio for allocation %p",
+                  mPacketizerInput->PacketSize(), allocation.mHandle.get()));
+
 #ifdef DEBUG
       allocation.mLastCallbackAppendTime =
         allocation.mStream->GraphImpl()->IterationEnd();
 #endif
       allocation.mLiveFramesAppended = true;
 
       // We already have planar audio data of the right format. Insert into the
       // MSG.
@@ -1108,16 +1127,19 @@ MediaEngineWebRTCMicrophoneSource::Inser
       }
 
       DeinterleaveAndConvertBuffer(aBuffer,
                                    aFrames,
                                    aChannels,
                                    write_channels.Elements());
     }
 
+    LOG_FRAMES(("Appending %zu frames of raw audio for allocation %p",
+                aFrames, allocation.mHandle.get()));
+
     MOZ_ASSERT(aChannels == channels.Length());
     segment.AppendFrames(buffer.forget(), channels, aFrames,
                           allocation.mPrincipal);
     segment.GetStartTime(insertTime);
 
     allocation.mStream->AppendToTrack(allocation.mTrackID, &segment);
   }
 }