Bug 998168 - add decoder pointer to the log message of MediaDecoderStateMachine/MediaDecoder for debugging. r=cpearce
authorJW Wang <jwwang@mozilla.com>
Wed, 23 Apr 2014 05:29:04 -0400
changeset 180100 d97882e9c503b30a66c3e842156d3a152a8adfb1
parent 180099 368a6f1f7eea8b7a99a2f89b32649aec499291ac
child 180101 243bf2777fa46e67016265f46ee2e23e889805a6
push id272
push userpvanderbeken@mozilla.com
push dateMon, 05 May 2014 16:31:18 +0000
reviewerscpearce
bugs998168
milestone31.0a1
Bug 998168 - add decoder pointer to the log message of MediaDecoderStateMachine/MediaDecoder for debugging. r=cpearce
content/media/MediaDecoder.cpp
content/media/MediaDecoderStateMachine.cpp
--- a/content/media/MediaDecoder.cpp
+++ b/content/media/MediaDecoder.cpp
@@ -43,21 +43,25 @@ static const uint32_t STALL_MS = 3000;
 // Number of estimated seconds worth of data we need to have buffered
 // ahead of the current playback position before we allow the media decoder
 // to report that it can play through the entire media without the decode
 // catching up with the download. Having this margin make the
 // MediaDecoder::CanPlayThrough() calculation more stable in the case of
 // fluctuating bitrates.
 static const int64_t CAN_PLAY_THROUGH_MARGIN = 1;
 
+// avoid redefined macro in unified build
+#undef DECODER_LOG
+
 #ifdef PR_LOGGING
 PRLogModuleInfo* gMediaDecoderLog;
-#define DECODER_LOG(type, msg) PR_LOG(gMediaDecoderLog, type, msg)
+#define DECODER_LOG(type, msg, ...) \
+  PR_LOG(gMediaDecoderLog, type, ("Decoder=%p " msg, this, ##__VA_ARGS__))
 #else
-#define DECODER_LOG(type, msg)
+#define DECODER_LOG(type, msg, ...)
 #endif
 
 class MediaMemoryTracker : public nsIMemoryReporter
 {
   NS_DECL_THREADSAFE_ISUPPORTS
   NS_DECL_NSIMEMORYREPORTER
 
   MOZ_DEFINE_MALLOC_SIZE_OF(MallocSizeOf);
@@ -309,18 +313,17 @@ void MediaDecoder::UpdateStreamBlockingF
     }
   }
 }
 
 void MediaDecoder::RecreateDecodedStream(int64_t aStartTimeUSecs)
 {
   MOZ_ASSERT(NS_IsMainThread());
   GetReentrantMonitor().AssertCurrentThreadIn();
-  DECODER_LOG(PR_LOG_DEBUG, ("MediaDecoder::RecreateDecodedStream this=%p aStartTimeUSecs=%lld!",
-                             this, (long long)aStartTimeUSecs));
+  DECODER_LOG(PR_LOG_DEBUG, "RecreateDecodedStream aStartTimeUSecs=%lld!", aStartTimeUSecs);
 
   DestroyDecodedStream();
 
   mDecodedStream = new DecodedStreamData(this, aStartTimeUSecs,
     MediaStreamGraph::GetInstance()->CreateSourceStream(nullptr));
 
   // Note that the delay between removing ports in DestroyDecodedStream
   // and adding new ones won't cause a glitch since all graph operations
@@ -342,18 +345,17 @@ void MediaDecoder::RecreateDecodedStream
     mDecodedStream->mStream->ChangeExplicitBlockerCount(1);
   }
 }
 
 void MediaDecoder::AddOutputStream(ProcessedMediaStream* aStream,
                                    bool aFinishWhenEnded)
 {
   MOZ_ASSERT(NS_IsMainThread());
-  DECODER_LOG(PR_LOG_DEBUG, ("MediaDecoder::AddOutputStream this=%p aStream=%p!",
-                             this, aStream));
+  DECODER_LOG(PR_LOG_DEBUG, "AddOutputStream aStream=%p!", aStream);
 
   {
     ReentrantMonitorAutoEnter mon(GetReentrantMonitor());
     if (!mDecodedStream) {
       RecreateDecodedStream(mDecoderStateMachine ?
           int64_t(mDecoderStateMachine->GetCurrentTime()*USECS_PER_S) : 0);
     }
     OutputStreamData* os = mOutputStreams.AppendElement();
@@ -504,49 +506,49 @@ nsresult MediaDecoder::OpenResource(nsIS
   {
     // Hold the lock while we do this to set proper lock ordering
     // expectations for dynamic deadlock detectors: decoder lock(s)
     // should be grabbed before the cache lock
     ReentrantMonitorAutoEnter mon(GetReentrantMonitor());
 
     nsresult rv = mResource->Open(aStreamListener);
     if (NS_FAILED(rv)) {
-      DECODER_LOG(PR_LOG_DEBUG, ("%p Failed to open stream!", this));
+      DECODER_LOG(PR_LOG_WARNING, "Failed to open stream!");
       return rv;
     }
   }
   return NS_OK;
 }
 
 nsresult MediaDecoder::Load(nsIStreamListener** aStreamListener,
                             MediaDecoder* aCloneDonor)
 {
   MOZ_ASSERT(NS_IsMainThread());
 
   nsresult rv = OpenResource(aStreamListener);
   NS_ENSURE_SUCCESS(rv, rv);
 
   mDecoderStateMachine = CreateStateMachine();
   if (!mDecoderStateMachine) {
-    DECODER_LOG(PR_LOG_DEBUG, ("%p Failed to create state machine!", this));
+    DECODER_LOG(PR_LOG_WARNING, "Failed to create state machine!");
     return NS_ERROR_FAILURE;
   }
 
   return InitializeStateMachine(aCloneDonor);
 }
 
 nsresult MediaDecoder::InitializeStateMachine(MediaDecoder* aCloneDonor)
 {
   MOZ_ASSERT(NS_IsMainThread());
   NS_ASSERTION(mDecoderStateMachine, "Cannot initialize null state machine!");
 
   MediaDecoder* cloneDonor = static_cast<MediaDecoder*>(aCloneDonor);
   if (NS_FAILED(mDecoderStateMachine->Init(cloneDonor ?
                                            cloneDonor->mDecoderStateMachine : nullptr))) {
-    DECODER_LOG(PR_LOG_DEBUG, ("%p Failed to init state machine!", this));
+    DECODER_LOG(PR_LOG_WARNING, "Failed to init state machine!");
     return NS_ERROR_FAILURE;
   }
   {
     ReentrantMonitorAutoEnter mon(GetReentrantMonitor());
     mDecoderStateMachine->SetTransportSeekable(mTransportSeekable);
     mDecoderStateMachine->SetMediaSeekable(mMediaSeekable);
     mDecoderStateMachine->SetDuration(mDuration);
     mDecoderStateMachine->SetVolume(mInitialVolume);
@@ -1228,17 +1230,17 @@ void MediaDecoder::DurationChanged()
   int64_t oldDuration = mDuration;
   mDuration = mDecoderStateMachine ? mDecoderStateMachine->GetDuration() : -1;
   // Duration has changed so we should recompute playback rate
   UpdatePlaybackRate();
 
   SetInfinite(mDuration == -1);
 
   if (mOwner && oldDuration != mDuration && !IsInfinite()) {
-    DECODER_LOG(PR_LOG_DEBUG, ("%p duration changed to %lld", this, mDuration));
+    DECODER_LOG(PR_LOG_DEBUG, "Duration changed to %lld", mDuration);
     mOwner->DispatchEvent(NS_LITERAL_STRING("durationchange"));
   }
 }
 
 void MediaDecoder::SetDuration(double aDuration)
 {
   MOZ_ASSERT(NS_IsMainThread());
   if (mozilla::IsInfinite(aDuration)) {
@@ -1794,8 +1796,10 @@ MediaMemoryTracker::InitMemoryReporter()
 
 MediaMemoryTracker::~MediaMemoryTracker()
 {
   UnregisterWeakMemoryReporter(this);
 }
 
 } // namespace mozilla
 
+// avoid redefined macro in unified build
+#undef DECODER_LOG
--- a/content/media/MediaDecoderStateMachine.cpp
+++ b/content/media/MediaDecoderStateMachine.cpp
@@ -38,21 +38,33 @@
 #include <algorithm>
 
 namespace mozilla {
 
 using namespace mozilla::layers;
 using namespace mozilla::dom;
 using namespace mozilla::gfx;
 
+// avoid redefined macro in unified build
+#undef DECODER_LOG
+#undef VERBOSE_LOG
+
 #ifdef PR_LOGGING
 extern PRLogModuleInfo* gMediaDecoderLog;
-#define DECODER_LOG(type, msg) PR_LOG(gMediaDecoderLog, type, msg)
+#define DECODER_LOG(type, msg, ...) \
+  PR_LOG(gMediaDecoderLog, type, ("Decoder=%p " msg, mDecoder.get(), ##__VA_ARGS__))
+#define VERBOSE_LOG(msg, ...)                          \
+    PR_BEGIN_MACRO                                     \
+      if (!PR_GetEnv("MOZ_QUIET")) {                   \
+        DECODER_LOG(PR_LOG_DEBUG, msg, ##__VA_ARGS__); \
+      }                                                \
+    PR_END_MACRO
 #else
-#define DECODER_LOG(type, msg)
+#define DECODER_LOG(type, msg, ...)
+#define VERBOSE_LOG(msg, ...)
 #endif
 
 // GetCurrentTime is defined in winbase.h as zero argument macro forwarding to
 // GetTickCount() and conflicts with MediaDecoderStateMachine::GetCurrentTime
 // implementation.  With unified builds, putting this in headers is not enough.
 #ifdef GetCurrentTime
 #undef GetCurrentTime
 #endif
@@ -294,18 +306,18 @@ void MediaDecoderStateMachine::SendStrea
   // the exact same silences
   CheckedInt64 audioWrittenOffset = UsecsToFrames(mInfo.mAudio.mRate,
       aStream->mInitialTime + mStartTime) + aStream->mAudioFramesWritten;
   CheckedInt64 frameOffset = UsecsToFrames(mInfo.mAudio.mRate, aAudio->mTime);
   if (!audioWrittenOffset.isValid() || !frameOffset.isValid())
     return;
   if (audioWrittenOffset.value() < frameOffset.value()) {
     // Write silence to catch up
-    DECODER_LOG(PR_LOG_DEBUG, ("%p Decoder writing %d frames of silence to MediaStream",
-                               mDecoder.get(), int32_t(frameOffset.value() - audioWrittenOffset.value())));
+    VERBOSE_LOG("writing %d frames of silence to MediaStream",
+                int32_t(frameOffset.value() - audioWrittenOffset.value()));
     AudioSegment silence;
     silence.InsertNullDataAtStart(frameOffset.value() - audioWrittenOffset.value());
     aStream->mAudioFramesWritten += silence.GetDuration();
     aOutput->AppendFrom(&silence);
   }
 
   int64_t offset;
   if (aStream->mAudioFramesWritten == 0) {
@@ -324,18 +336,18 @@ void MediaDecoderStateMachine::SendStrea
   aAudio->EnsureAudioBuffer();
   nsRefPtr<SharedBuffer> buffer = aAudio->mAudioBuffer;
   AudioDataValue* bufferData = static_cast<AudioDataValue*>(buffer->Data());
   nsAutoTArray<const AudioDataValue*,2> channels;
   for (uint32_t i = 0; i < aAudio->mChannels; ++i) {
     channels.AppendElement(bufferData + i*aAudio->mFrames + offset);
   }
   aOutput->AppendFrames(buffer.forget(), channels, aAudio->mFrames);
-  DECODER_LOG(PR_LOG_DEBUG, ("%p Decoder writing %d frames of data to MediaStream for AudioData at %lld",
-                             mDecoder.get(), aAudio->mFrames - int32_t(offset), aAudio->mTime));
+  VERBOSE_LOG("writing %d frames of data to MediaStream for AudioData at %lld",
+              aAudio->mFrames - int32_t(offset), aAudio->mTime);
   aStream->mAudioFramesWritten += aAudio->mFrames - int32_t(offset);
 }
 
 static void WriteVideoToMediaStream(layers::Image* aImage,
                                     int64_t aDuration,
                                     const IntSize& aIntrinsicSize,
                                     VideoSegment* aOutput)
 {
@@ -416,39 +428,37 @@ void MediaDecoderStateMachine::SendStrea
       nsAutoTArray<VideoData*,10> video;
       // It's OK to hold references to the VideoData only the decoder thread
       // pops from the queue.
       mReader->VideoQueue().GetElementsAfter(stream->mNextVideoTime, &video);
       VideoSegment output;
       for (uint32_t i = 0; i < video.Length(); ++i) {
         VideoData* v = video[i];
         if (stream->mNextVideoTime < v->mTime) {
-          DECODER_LOG(PR_LOG_DEBUG, ("%p Decoder writing last video to MediaStream %p for %lldus",
-                                     mDecoder.get(), mediaStream,
-                                     v->mTime - stream->mNextVideoTime));
+          VERBOSE_LOG("writing last video to MediaStream %p for %lldus",
+                      mediaStream, v->mTime - stream->mNextVideoTime);
           // Write last video frame to catch up. mLastVideoImage can be null here
           // which is fine, it just means there's no video.
           WriteVideoToMediaStream(stream->mLastVideoImage,
             v->mTime - stream->mNextVideoTime, stream->mLastVideoImageDisplaySize,
               &output);
           stream->mNextVideoTime = v->mTime;
         }
         if (stream->mNextVideoTime < v->GetEndTime()) {
-          DECODER_LOG(PR_LOG_DEBUG, ("%p Decoder writing video frame %lldus to MediaStream %p for %lldus",
-                                     mDecoder.get(), v->mTime, mediaStream,
-                                     v->GetEndTime() - stream->mNextVideoTime));
+          VERBOSE_LOG("writing video frame %lldus to MediaStream %p for %lldus",
+                      v->mTime, mediaStream, v->GetEndTime() - stream->mNextVideoTime);
           WriteVideoToMediaStream(v->mImage,
               v->GetEndTime() - stream->mNextVideoTime, v->mDisplay,
               &output);
           stream->mNextVideoTime = v->GetEndTime();
           stream->mLastVideoImage = v->mImage;
           stream->mLastVideoImageDisplaySize = v->mDisplay;
         } else {
-          DECODER_LOG(PR_LOG_DEBUG, ("%p Decoder skipping writing video frame %lldus (end %lldus) to MediaStream",
-                                     mDecoder.get(), v->mTime, v->GetEndTime()));
+          VERBOSE_LOG("skipping writing video frame %lldus (end %lldus) to MediaStream",
+                      v->mTime, v->GetEndTime());
         }
       }
       if (output.GetDuration() > 0) {
         mediaStream->AppendToTrack(TRACK_VIDEO, &output);
       }
       if (mReader->VideoQueue().IsFinished() && !stream->mHaveSentFinishVideo) {
         mediaStream->EndTrack(TRACK_VIDEO);
         stream->mHaveSentFinishVideo = true;
@@ -593,17 +603,17 @@ MediaDecoderStateMachine::DecodeVideo()
          // don't skip frame when |clock time| <= |mVideoFrameEndTime| for
          // we are still in the safe range without underrunning video frames
          GetClock() > mVideoFrameEndTime &&
         (static_cast<uint32_t>(mReader->VideoQueue().GetSize())
           < LOW_VIDEO_FRAMES * mPlaybackRate))) &&
       !HasLowUndecodedData())
   {
     mSkipToNextKeyFrame = true;
-    DECODER_LOG(PR_LOG_DEBUG, ("%p Skipping video decode to the next keyframe", mDecoder.get()));
+    DECODER_LOG(PR_LOG_DEBUG, "Skipping video decode to the next keyframe");
   }
 
   // Time the video decode, so that if it's slow, we can increase our low
   // audio threshold to reduce the chance of an audio underrun while we're
   // waiting for a video decode to complete.
   TimeDuration decodeTime;
   {
     int64_t currentTime = GetMediaTime();
@@ -620,19 +630,18 @@ MediaDecoderStateMachine::DecodeVideo()
 
   if (THRESHOLD_FACTOR * DurationToUsecs(decodeTime) > mLowAudioThresholdUsecs &&
       !HasLowUndecodedData())
   {
     mLowAudioThresholdUsecs =
       std::min(THRESHOLD_FACTOR * DurationToUsecs(decodeTime), AMPLE_AUDIO_USECS);
     mAmpleAudioThresholdUsecs = std::max(THRESHOLD_FACTOR * mLowAudioThresholdUsecs,
                                           mAmpleAudioThresholdUsecs);
-    DECODER_LOG(PR_LOG_DEBUG,
-                ("Slow video decode, set mLowAudioThresholdUsecs=%lld mAmpleAudioThresholdUsecs=%lld",
-                mLowAudioThresholdUsecs, mAmpleAudioThresholdUsecs));
+    DECODER_LOG(PR_LOG_DEBUG, "Slow video decode, set mLowAudioThresholdUsecs=%lld mAmpleAudioThresholdUsecs=%lld",
+                mLowAudioThresholdUsecs, mAmpleAudioThresholdUsecs);
   }
 
   SendStreamData();
 
   // The ready state can change when we've decoded data, so update the
   // ready state, so that DOM events can fire.
   UpdateReadyState();
 
@@ -710,19 +719,18 @@ MediaDecoderStateMachine::CheckIfDecodeC
   MOZ_ASSERT(!mReader->VideoQueue().IsFinished() || !mIsVideoDecoding);
   if (!mIsVideoDecoding && !mIsAudioDecoding) {
     // We've finished decoding all active streams,
     // so move to COMPLETED state.
     mState = DECODER_STATE_COMPLETED;
     DispatchDecodeTasksIfNeeded();
     ScheduleStateMachine();
   }
-  DECODER_LOG(PR_LOG_DEBUG,
-    ("%p CheckIfDecodeComplete %scompleted", mDecoder.get(),
-    ((mState == DECODER_STATE_COMPLETED) ? "" : "NOT ")));
+  DECODER_LOG(PR_LOG_DEBUG, "CheckIfDecodeComplete %scompleted",
+              ((mState == DECODER_STATE_COMPLETED) ? "" : "NOT "));
 }
 
 bool MediaDecoderStateMachine::IsPlaying()
 {
   AssertCurrentThreadInMonitor();
 
   return !mPlayStartTime.IsNull();
 }
@@ -748,17 +756,17 @@ static void WriteSilence(AudioStream* aS
   aStream->Write(buf.Elements(), aFrames);
 
   StartAudioStreamPlaybackIfNeeded(aStream);
 }
 
 void MediaDecoderStateMachine::AudioLoop()
 {
   NS_ASSERTION(OnAudioThread(), "Should be on audio thread.");
-  DECODER_LOG(PR_LOG_DEBUG, ("%p Begun audio thread/loop", mDecoder.get()));
+  DECODER_LOG(PR_LOG_DEBUG, "Begun audio thread/loop");
   int64_t audioDuration = 0;
   int64_t audioStartTime = -1;
   uint32_t channels, rate;
   double volume = -1;
   bool setVolume;
   double playbackRate = -1;
   bool setPlaybackRate;
   bool preservesPitch;
@@ -886,18 +894,17 @@ void MediaDecoderStateMachine::AudioLoop
 
     int64_t framesWritten = 0;
     if (missingFrames.value() > 0) {
       // The next audio chunk begins some time after the end of the last chunk
       // we pushed to the audio hardware. We must push silence into the audio
       // hardware so that the next audio chunk begins playback at the correct
       // time.
       missingFrames = std::min<int64_t>(UINT32_MAX, missingFrames.value());
-      DECODER_LOG(PR_LOG_DEBUG, ("%p Decoder playing %d frames of silence",
-                                 mDecoder.get(), int32_t(missingFrames.value())));
+      VERBOSE_LOG("playing %d frames of silence", int32_t(missingFrames.value()));
       framesWritten = PlaySilence(static_cast<uint32_t>(missingFrames.value()),
                                   channels, playedFrames.value());
     } else {
       framesWritten = PlayFromAudioQueue(sampleTime.value(), channels);
     }
     audioDuration += framesWritten;
     {
       ReentrantMonitorAutoEnter mon(mDecoder->GetReentrantMonitor());
@@ -940,32 +947,32 @@ void MediaDecoderStateMachine::AudioLoop
       if (!seeking && !mAudioStream->IsPaused()) {
         {
           ReentrantMonitorAutoExit exit(mDecoder->GetReentrantMonitor());
           mAudioStream->Drain();
         }
       }
     }
   }
-  DECODER_LOG(PR_LOG_DEBUG, ("%p Reached audio stream end.", mDecoder.get()));
+  DECODER_LOG(PR_LOG_DEBUG, "Reached audio stream end.");
   {
     // Must hold lock while shutting down and anulling the audio stream to prevent
     // state machine thread trying to use it while we're destroying it.
     ReentrantMonitorAutoEnter mon(mDecoder->GetReentrantMonitor());
     mAudioStream->Shutdown();
     mAudioStream = nullptr;
     if (!mAudioCaptured) {
       mAudioCompleted = true;
       UpdateReadyState();
       // Kick the decode thread; it may be sleeping waiting for this to finish.
       mDecoder->GetReentrantMonitor().NotifyAll();
     }
   }
 
-  DECODER_LOG(PR_LOG_DEBUG, ("%p Audio stream finished playing, audio thread exit", mDecoder.get()));
+  DECODER_LOG(PR_LOG_DEBUG, "Audio stream finished playing, audio thread exit");
 }
 
 uint32_t MediaDecoderStateMachine::PlaySilence(uint32_t aFrames,
                                                    uint32_t aChannels,
                                                    uint64_t aFrameOffset)
 
 {
   NS_ASSERTION(OnAudioThread(), "Only call on audio thread.");
@@ -986,20 +993,18 @@ uint32_t MediaDecoderStateMachine::PlayF
     ReentrantMonitorAutoEnter mon(mDecoder->GetReentrantMonitor());
     NS_WARN_IF_FALSE(IsPlaying(), "Should be playing");
     // Awaken the decode loop if it's waiting for space to free up in the
     // audio queue.
     mDecoder->GetReentrantMonitor().NotifyAll();
   }
   int64_t offset = -1;
   uint32_t frames = 0;
-  if (!PR_GetEnv("MOZ_QUIET")) {
-    DECODER_LOG(PR_LOG_DEBUG, ("%p Decoder playing %d frames of data to stream for AudioData at %lld",
-                               mDecoder.get(), audio->mFrames, audio->mTime));
-  }
+  VERBOSE_LOG("playing %d frames of data to stream for AudioData at %lld",
+              audio->mFrames, audio->mTime);
   mAudioStream->Write(audio->mAudioData,
                       audio->mFrames);
 
   aChannels = mAudioStream->GetOutChannels();
 
   StartAudioStreamPlaybackIfNeeded(mAudioStream);
 
   offset = audio->mOffset;
@@ -1040,17 +1045,17 @@ nsresult MediaDecoderStateMachine::Init(
   rv = mTimer->SetTarget(GetStateMachineThread());
   NS_ENSURE_SUCCESS(rv, rv);
 
   return mReader->Init(cloneReader);
 }
 
 void MediaDecoderStateMachine::StopPlayback()
 {
-  DECODER_LOG(PR_LOG_DEBUG, ("%p StopPlayback()", mDecoder.get()));
+  DECODER_LOG(PR_LOG_DEBUG, "StopPlayback()");
 
   AssertCurrentThreadInMonitor();
 
   mDecoder->NotifyPlaybackStopped();
 
   if (IsPlaying()) {
     mPlayDuration = GetClock();
     mPlayStartTime = TimeStamp();
@@ -1083,17 +1088,17 @@ int64_t MediaDecoderStateMachine::GetCur
   NS_ASSERTION(mSyncPointInDecodedStream >= 0, "Should have set up sync point");
   DecodedStreamData* stream = mDecoder->GetDecodedStream();
   StreamTime streamDelta = stream->GetLastOutputTime() - mSyncPointInMediaStream;
   return mSyncPointInDecodedStream + MediaTimeToMicroseconds(streamDelta);
 }
 
 void MediaDecoderStateMachine::StartPlayback()
 {
-  DECODER_LOG(PR_LOG_DEBUG, ("%p StartPlayback()", mDecoder.get()));
+  DECODER_LOG(PR_LOG_DEBUG, "StartPlayback()");
 
   NS_ASSERTION(!IsPlaying(), "Shouldn't be playing when StartPlayback() is called");
   AssertCurrentThreadInMonitor();
 
   mDecoder->NotifyPlaybackStarted();
   mPlayStartTime = TimeStamp::Now();
 
   NS_ASSERTION(IsPlaying(), "Should report playing by end of StartPlayback()");
@@ -1295,17 +1300,17 @@ void MediaDecoderStateMachine::Shutdown(
 {
   NS_ASSERTION(NS_IsMainThread(), "Should be on main thread.");
 
   // Once we've entered the shutdown state here there's no going back.
   ReentrantMonitorAutoEnter mon(mDecoder->GetReentrantMonitor());
 
   // Change state before issuing shutdown request to threads so those
   // threads can start exiting cleanly during the Shutdown call.
-  DECODER_LOG(PR_LOG_DEBUG, ("%p Changed state to SHUTDOWN", mDecoder.get()));
+  DECODER_LOG(PR_LOG_DEBUG, "Changed state to SHUTDOWN");
   ScheduleStateMachine();
   mState = DECODER_STATE_SHUTDOWN;
   mDecoder->GetReentrantMonitor().NotifyAll();
 }
 
 void MediaDecoderStateMachine::StartDecoding()
 {
   NS_ASSERTION(OnStateMachineThread() || OnDecodeThread(),
@@ -1363,17 +1368,17 @@ void MediaDecoderStateMachine::NotifyWai
 void MediaDecoderStateMachine::Play()
 {
   NS_ASSERTION(NS_IsMainThread(), "Should be on main thread.");
   // When asked to play, switch to decoding state only if
   // we are currently buffering. In other cases, we'll start playing anyway
   // when the state machine notices the decoder's state change to PLAYING.
   ReentrantMonitorAutoEnter mon(mDecoder->GetReentrantMonitor());
   if (mState == DECODER_STATE_BUFFERING) {
-    DECODER_LOG(PR_LOG_DEBUG, ("%p Changed state from BUFFERING to DECODING", mDecoder.get()));
+    DECODER_LOG(PR_LOG_DEBUG, "Changed state from BUFFERING to DECODING");
     mState = DECODER_STATE_DECODING;
     mDecodeStartTime = TimeStamp::Now();
   }
   // Once we start playing, we don't want to minimize our prerolling, as we
   // assume the user is likely to want to keep playing in future.
   mMinimizePreroll = false;
   ScheduleStateMachine();
 }
@@ -1437,17 +1442,17 @@ void MediaDecoderStateMachine::Seek(cons
   int64_t seekTime = aTarget.mTime + mStartTime;
   seekTime = std::min(seekTime, mEndTime);
   seekTime = std::max(mStartTime, seekTime);
   NS_ASSERTION(seekTime >= mStartTime && seekTime <= mEndTime,
                "Can only seek in range [0,duration]");
   mSeekTarget = SeekTarget(seekTime, aTarget.mType);
 
   mBasePosition = seekTime - mStartTime;
-  DECODER_LOG(PR_LOG_DEBUG, ("%p Changed state to SEEKING (to %ld)", mDecoder.get(), mSeekTarget.mTime));
+  DECODER_LOG(PR_LOG_DEBUG, "Changed state to SEEKING (to %ld)", mSeekTarget.mTime);
   mState = DECODER_STATE_SEEKING;
   if (mDecoder->GetDecodedStream()) {
     mDecoder->RecreateDecodedStream(seekTime - mStartTime);
   }
   ScheduleStateMachine();
 }
 
 void MediaDecoderStateMachine::StopAudioThread()
@@ -1459,17 +1464,17 @@ void MediaDecoderStateMachine::StopAudio
   if (mStopAudioThread) {
     // Nothing to do, since the thread is already stopping
     return;
   }
 
   mStopAudioThread = true;
   mDecoder->GetReentrantMonitor().NotifyAll();
   if (mAudioThread) {
-    DECODER_LOG(PR_LOG_DEBUG, ("%p Shutdown audio thread", mDecoder.get()));
+    DECODER_LOG(PR_LOG_DEBUG, "Shutdown audio thread");
     {
       ReentrantMonitorAutoExit exitMon(mDecoder->GetReentrantMonitor());
       mAudioThread->Shutdown();
     }
     mAudioThread = nullptr;
     // Now that the audio thread is dead, try sending data to our MediaStream(s).
     // That may have been waiting for the audio thread to stop.
     SendStreamData();
@@ -1507,30 +1512,29 @@ MediaDecoderStateMachine::EnsureActive()
 }
 
 void
 MediaDecoderStateMachine::SetReaderIdle()
 {
 #ifdef PR_LOGGING
   {
     ReentrantMonitorAutoEnter mon(mDecoder->GetReentrantMonitor());
-    DECODER_LOG(PR_LOG_DEBUG, ("%p SetReaderIdle() audioQueue=%lld videoQueue=%lld",
-                               mDecoder.get(),
-                               GetDecodedAudioDuration(),
-                               mReader->VideoQueue().Duration()));
+    DECODER_LOG(PR_LOG_DEBUG, "SetReaderIdle() audioQueue=%lld videoQueue=%lld",
+                GetDecodedAudioDuration(),
+                mReader->VideoQueue().Duration());
   }
 #endif
   MOZ_ASSERT(OnDecodeThread());
   mReader->SetIdle();
 }
 
 void
 MediaDecoderStateMachine::SetReaderActive()
 {
-  DECODER_LOG(PR_LOG_DEBUG, ("%p SetReaderActive()", mDecoder.get()));
+  DECODER_LOG(PR_LOG_DEBUG, "SetReaderActive()");
   MOZ_ASSERT(OnDecodeThread());
   mReader->SetActive();
 }
 
 void
 MediaDecoderStateMachine::DispatchDecodeTasksIfNeeded()
 {
   AssertCurrentThreadInMonitor();
@@ -1694,17 +1698,17 @@ MediaDecoderStateMachine::StartAudioThre
 
   mStopAudioThread = false;
   if (HasAudio() && !mAudioThread) {
     nsresult rv = NS_NewNamedThread("Media Audio",
                                     getter_AddRefs(mAudioThread),
                                     nullptr,
                                     MEDIA_THREAD_STACK_SIZE);
     if (NS_FAILED(rv)) {
-      DECODER_LOG(PR_LOG_DEBUG, ("%p Changed state to SHUTDOWN because failed to create audio thread", mDecoder.get()));
+      DECODER_LOG(PR_LOG_WARNING, "Changed state to SHUTDOWN because failed to create audio thread");
       mState = DECODER_STATE_SHUTDOWN;
       return rv;
     }
 
     nsCOMPtr<nsIRunnable> event =
       NS_NewRunnableMethod(this, &MediaDecoderStateMachine::AudioLoop);
     mAudioThread->Dispatch(event, NS_DISPATCH_NORMAL);
   }
@@ -1771,17 +1775,17 @@ void
 MediaDecoderStateMachine::DecodeError()
 {
   AssertCurrentThreadInMonitor();
   NS_ASSERTION(OnDecodeThread(), "Should be on decode thread.");
 
   // Change state to shutdown before sending error report to MediaDecoder
   // and the HTMLMediaElement, so that our pipeline can start exiting
   // cleanly during the sync dispatch below.
-  DECODER_LOG(PR_LOG_DEBUG, ("%p Changed state to SHUTDOWN", mDecoder.get()));
+  DECODER_LOG(PR_LOG_WARNING, "Decode error, changed state to SHUTDOWN");
   ScheduleStateMachine();
   mState = DECODER_STATE_SHUTDOWN;
   mDecoder->GetReentrantMonitor().NotifyAll();
 
   // Dispatch the event to call DecodeError synchronously. This ensures
   // we're in shutdown state by the time we exit the decode thread.
   // If we just moved to shutdown state here on the decode thread, we may
   // cause the state machine to shutdown/free memory without closing its
@@ -1798,26 +1802,26 @@ MediaDecoderStateMachine::DecodeError()
 void
 MediaDecoderStateMachine::CallDecodeMetadata()
 {
   ReentrantMonitorAutoEnter mon(mDecoder->GetReentrantMonitor());
   if (mState != DECODER_STATE_DECODING_METADATA) {
     return;
   }
   if (NS_FAILED(DecodeMetadata())) {
-    DECODER_LOG(PR_LOG_DEBUG, ("Decode metadata failed, shutting down decoder"));
+    DECODER_LOG(PR_LOG_WARNING, "Decode metadata failed, shutting down decoder");
     DecodeError();
   }
 }
 
 nsresult MediaDecoderStateMachine::DecodeMetadata()
 {
   AssertCurrentThreadInMonitor();
   NS_ASSERTION(OnDecodeThread(), "Should be on decode thread.");
-  DECODER_LOG(PR_LOG_DEBUG, ("%p Decoding Media Headers", mDecoder.get()));
+  DECODER_LOG(PR_LOG_DEBUG, "Decoding Media Headers");
   if (mState != DECODER_STATE_DECODING_METADATA) {
     return NS_ERROR_FAILURE;
   }
   EnsureActive();
 
   nsresult res;
   MediaInfo info;
   MetadataTags* tags;
@@ -1852,20 +1856,19 @@ nsresult MediaDecoderStateMachine::Decod
   }
 
   NS_ASSERTION(mStartTime != -1, "Must have start time");
   MOZ_ASSERT((!HasVideo() && !HasAudio()) ||
               !(mMediaSeekable && mTransportSeekable) || mEndTime != -1,
               "Active seekable media should have end time");
   MOZ_ASSERT(!(mMediaSeekable && mTransportSeekable) ||
              GetDuration() != -1, "Seekable media should have duration");
-  DECODER_LOG(PR_LOG_DEBUG, ("%p Media goes from %lld to %lld (duration %lld)"
-                             " transportSeekable=%d, mediaSeekable=%d",
-                             mDecoder.get(), mStartTime, mEndTime, GetDuration(),
-                             mTransportSeekable, mMediaSeekable));
+  DECODER_LOG(PR_LOG_DEBUG, "Media goes from %lld to %lld (duration %lld) "
+              "transportSeekable=%d, mediaSeekable=%d",
+              mStartTime, mEndTime, GetDuration(), mTransportSeekable, mMediaSeekable);
 
   if (HasAudio() && !HasVideo()) {
     // We're playing audio only. We don't need to worry about slow video
     // decodes causing audio underruns, so don't buffer so much audio in
     // order to reduce memory usage.
     mAmpleAudioThresholdUsecs /= NO_VIDEO_AMPLE_AUDIO_DIVISOR;
     mLowAudioThresholdUsecs /= NO_VIDEO_AMPLE_AUDIO_DIVISOR;
   }
@@ -1887,17 +1890,17 @@ nsresult MediaDecoderStateMachine::Decod
   }
   if (HasVideo()) {
     RefPtr<nsIRunnable> decodeTask(
       NS_NewRunnableMethod(this, &MediaDecoderStateMachine::DispatchVideoDecodeTaskIfNeeded));
     mReader->VideoQueue().AddPopListener(decodeTask, mDecodeTaskQueue);
   }
 
   if (mState == DECODER_STATE_DECODING_METADATA) {
-    DECODER_LOG(PR_LOG_DEBUG, ("%p Changed state from DECODING_METADATA to DECODING", mDecoder.get()));
+    DECODER_LOG(PR_LOG_DEBUG, "Changed state from DECODING_METADATA to DECODING");
     StartDecoding();
   }
 
   // For very short media FindStartTime() can decode the entire media.
   // So we need to check if this has occurred, else our decode pipeline won't
   // run (since it doesn't need to) and we won't detect end of stream.
   CheckIfDecodeComplete();
 
@@ -2020,42 +2023,39 @@ void MediaDecoderStateMachine::DecodeSee
   // if we need to seek again.
 
   nsCOMPtr<nsIRunnable> stopEvent;
   bool isLiveStream = mDecoder->GetResource()->GetLength() == -1;
   if (GetMediaTime() == mEndTime && !isLiveStream) {
     // Seeked to end of media, move to COMPLETED state. Note we don't do
     // this if we're playing a live stream, since the end of media will advance
     // once we download more data!
-    DECODER_LOG(PR_LOG_DEBUG, ("%p Changed state from SEEKING (to %lld) to COMPLETED",
-                               mDecoder.get(), seekTime));
+    DECODER_LOG(PR_LOG_DEBUG, "Changed state from SEEKING (to %lld) to COMPLETED", seekTime);
     stopEvent = NS_NewRunnableMethod(mDecoder, &MediaDecoder::SeekingStoppedAtEnd);
     // Explicitly set our state so we don't decode further, and so
     // we report playback ended to the media element.
     mState = DECODER_STATE_COMPLETED;
     mIsAudioDecoding = false;
     mIsVideoDecoding = false;
     DispatchDecodeTasksIfNeeded();
   } else {
-    DECODER_LOG(PR_LOG_DEBUG, ("%p Changed state from SEEKING (to %lld) to DECODING",
-                               mDecoder.get(), seekTime));
+    DECODER_LOG(PR_LOG_DEBUG, "Changed state from SEEKING (to %lld) to DECODING", seekTime);
     stopEvent = NS_NewRunnableMethod(mDecoder, &MediaDecoder::SeekingStopped);
     StartDecoding();
   }
 
   if (newCurrentTime != mediaTime) {
     UpdatePlaybackPositionInternal(newCurrentTime);
     if (mDecoder->GetDecodedStream()) {
       SetSyncPointForMediaStream();
     }
   }
 
   // Try to decode another frame to detect if we're at the end...
-  DECODER_LOG(PR_LOG_DEBUG, ("%p Seek completed, mCurrentFrameTime=%lld\n",
-              mDecoder.get(), mCurrentFrameTime));
+  DECODER_LOG(PR_LOG_DEBUG, "Seek completed, mCurrentFrameTime=%lld", mCurrentFrameTime);
 
   {
     ReentrantMonitorAutoExit exitMon(mDecoder->GetReentrantMonitor());
     NS_DispatchToMainThread(stopEvent, NS_DISPATCH_SYNC);
   }
 
   // Reset quick buffering status. This ensures that if we began the
   // seek while quick-buffering, we won't bypass quick buffering mode
@@ -2221,29 +2221,24 @@ nsresult MediaDecoderStateMachine::RunSt
       bool isLiveStream = resource->GetLength() == -1;
       if ((isLiveStream || !mDecoder->CanPlayThrough()) &&
             elapsed < TimeDuration::FromSeconds(mBufferingWait * mPlaybackRate) &&
             (mQuickBuffering ? HasLowDecodedData(QUICK_BUFFERING_LOW_DATA_USECS)
                             : HasLowUndecodedData(mBufferingWait * USECS_PER_S)) &&
             !mDecoder->IsDataCachedToEndOfResource() &&
             !resource->IsSuspended())
       {
-        DECODER_LOG(PR_LOG_DEBUG,
-                    ("%p Buffering: wait %ds, timeout in %.3lfs %s",
-                      mDecoder.get(),
-                      mBufferingWait,
-                      mBufferingWait - elapsed.ToSeconds(),
-                      (mQuickBuffering ? "(quick exit)" : "")));
+        DECODER_LOG(PR_LOG_DEBUG, "Buffering: wait %ds, timeout in %.3lfs %s",
+                    mBufferingWait, mBufferingWait - elapsed.ToSeconds(),
+                    (mQuickBuffering ? "(quick exit)" : ""));
         ScheduleStateMachine(USECS_PER_S);
         return NS_OK;
       } else {
-        DECODER_LOG(PR_LOG_DEBUG, ("%p Changed state from BUFFERING to DECODING", mDecoder.get()));
-        DECODER_LOG(PR_LOG_DEBUG, ("%p Buffered for %.3lfs",
-                                   mDecoder.get(),
-                                   (now - mBufferingStart).ToSeconds()));
+        DECODER_LOG(PR_LOG_DEBUG, "Changed state from BUFFERING to DECODING");
+        DECODER_LOG(PR_LOG_DEBUG, "Buffered for %.3lfs", (now - mBufferingStart).ToSeconds());
         StartDecoding();
       }
 
       // Notify to allow blocked decoder thread to continue
       mDecoder->GetReentrantMonitor().NotifyAll();
       UpdateReadyState();
       if (mDecoder->GetState() == MediaDecoder::PLAY_STATE_PLAYING &&
           !IsPlaying())
@@ -2319,20 +2314,17 @@ void MediaDecoderStateMachine::RenderVid
   NS_ASSERTION(OnStateMachineThread() || OnDecodeThread(),
                "Should be on state machine or decode thread.");
   mDecoder->GetReentrantMonitor().AssertNotCurrentThreadIn();
 
   if (aData->mDuplicate) {
     return;
   }
 
-  if (!PR_GetEnv("MOZ_QUIET")) {
-    DECODER_LOG(PR_LOG_DEBUG, ("%p Decoder playing video frame %lld",
-                               mDecoder.get(), aData->mTime));
-  }
+  VERBOSE_LOG("playing video frame %lld", aData->mTime);
 
   VideoFrameContainer* container = mDecoder->GetVideoFrameContainer();
   if (container) {
     container->SetCurrentFrame(ThebesIntSize(aData->mDisplay), aData->mImage,
                                aTarget);
   }
 }
 
@@ -2433,22 +2425,19 @@ void MediaDecoderStateMachine::AdvanceFr
   int32_t droppedFrames = 0;
 #endif
   if (mReader->VideoQueue().GetSize() > 0) {
     VideoData* frame = mReader->VideoQueue().PeekFront();
     while (mRealTime || clock_time >= frame->mTime) {
       mVideoFrameEndTime = frame->GetEndTime();
       currentFrame = frame;
 #ifdef PR_LOGGING
-      if (!PR_GetEnv("MOZ_QUIET")) {
-        DECODER_LOG(PR_LOG_DEBUG, ("%p Decoder discarding video frame %lld", mDecoder.get(), frame->mTime));
-        if (droppedFrames++) {
-          DECODER_LOG(PR_LOG_DEBUG, ("%p Decoder discarding video frame %lld (%d so far)",
-                      mDecoder.get(), frame->mTime, droppedFrames - 1));
-        }
+      VERBOSE_LOG("discarding video frame %lld", frame->mTime);
+      if (droppedFrames++) {
+        VERBOSE_LOG("discarding video frame %lld (%d so far)", frame->mTime, droppedFrames-1);
       }
 #endif
       mReader->VideoQueue().PopFront();
       // Notify the decode thread that the video queue's buffers may have
       // free'd up space for more frames.
       mDecoder->GetReentrantMonitor().NotifyAll();
       mDecoder->UpdatePlaybackOffset(frame->mOffset);
       if (mReader->VideoQueue().GetSize() == 0)
@@ -2576,17 +2565,17 @@ VideoData* MediaDecoderStateMachine::Fin
       // duration.
       mEndTime = mStartTime + mEndTime;
     }
   }
   // Set the audio start time to be start of media. If this lies before the
   // first actual audio frame we have, we'll inject silence during playback
   // to ensure the audio starts at the correct time.
   mAudioStartTime = mStartTime;
-  DECODER_LOG(PR_LOG_DEBUG, ("%p Media start time is %lld", mDecoder.get(), mStartTime));
+  DECODER_LOG(PR_LOG_DEBUG, "Media start time is %lld", mStartTime);
   return v;
 }
 
 void MediaDecoderStateMachine::UpdateReadyState() {
   AssertCurrentThreadInMonitor();
 
   MediaDecoderOwner::NextFrameStatus nextFrameStatus = GetNextFrameStatus();
   if (nextFrameStatus == mLastFrameStatus) {
@@ -2646,24 +2635,23 @@ void MediaDecoderStateMachine::StartBuff
   // there might be pending main-thread events, such as "data
   // received" notifications, that mean we're not actually still
   // buffering by the time this runnable executes. So instead
   // we just trigger UpdateReadyStateForData; when it runs, it
   // will check the current state and decide whether to tell
   // the element we're buffering or not.
   UpdateReadyState();
   mState = DECODER_STATE_BUFFERING;
-  DECODER_LOG(PR_LOG_DEBUG, ("%p Changed state from DECODING to BUFFERING, decoded for %.3lfs",
-                             mDecoder.get(), decodeDuration.ToSeconds()));
+  DECODER_LOG(PR_LOG_DEBUG, "Changed state from DECODING to BUFFERING, decoded for %.3lfs",
+              decodeDuration.ToSeconds());
 #ifdef PR_LOGGING
   MediaDecoder::Statistics stats = mDecoder->GetStatistics();
-  DECODER_LOG(PR_LOG_DEBUG, ("%p Playback rate: %.1lfKB/s%s download rate: %.1lfKB/s%s",
-              mDecoder.get(),
+  DECODER_LOG(PR_LOG_DEBUG, "Playback rate: %.1lfKB/s%s download rate: %.1lfKB/s%s",
               stats.mPlaybackRate/1024, stats.mPlaybackRateReliable ? "" : " (unreliable)",
-              stats.mDownloadRate/1024, stats.mDownloadRateReliable ? "" : " (unreliable)"));
+              stats.mDownloadRate/1024, stats.mDownloadRateReliable ? "" : " (unreliable)");
 #endif
 }
 
 nsresult MediaDecoderStateMachine::GetBuffered(dom::TimeRanges* aBuffered) {
   MediaResource* resource = mDecoder->GetResource();
   NS_ENSURE_TRUE(resource, NS_ERROR_FAILURE);
   resource->Pin();
   nsresult res = mReader->GetBuffered(aBuffered, mStartTime);
@@ -2822,8 +2810,11 @@ void MediaDecoderStateMachine::QueueMeta
   metadata->mHasAudio = aHasAudio;
   metadata->mHasVideo = aHasVideo;
   metadata->mTags = aTags;
   mMetadataManager.QueueMetadata(metadata);
 }
 
 } // namespace mozilla
 
+// avoid redefined macro in unified build
+#undef DECODER_LOG
+#undef VERBOSE_LOG