Bug 1240419 - improve logging macros and include |this| in the log message. r=kinetik.
authorJW Wang <jwwang@mozilla.com>
Wed, 20 Jan 2016 10:28:36 +0800
changeset 303107 b578a9def3278b66b4ff63d167e5d9c1eff05a7b
parent 303106 a24d6c2b7525f4e1f5a32c3d54444f01c09e82fe
child 303108 977d78a8dd78afbc0153d37fd9887c3a200dce6a
child 303163 b5cfe78829739a8daeb4916e5302ba8f80a75356
push id8978
push userraliiev@mozilla.com
push dateMon, 25 Jan 2016 14:05:32 +0000
treeherdermozilla-aurora@b9a803752a2c [default view] [failures only]
perfherder[talos] [build metrics] [platform microbench] (compared to previous push)
reviewerskinetik
bugs1240419
milestone46.0a1
Bug 1240419 - improve logging macros and include |this| in the log message. r=kinetik.
dom/media/AudioStream.cpp
--- a/dom/media/AudioStream.cpp
+++ b/dom/media/AudioStream.cpp
@@ -16,23 +16,23 @@
 #include <algorithm>
 #include "mozilla/Telemetry.h"
 #include "CubebUtils.h"
 #include "nsPrintfCString.h"
 #include "gfxPrefs.h"
 
 namespace mozilla {
 
-#ifdef LOG
 #undef LOG
-#endif
+#undef LOGW
 
 LazyLogModule gAudioStreamLog("AudioStream");
 // For simple logs
-#define LOG(x) MOZ_LOG(gAudioStreamLog, mozilla::LogLevel::Debug, x)
+#define LOG(x, ...) MOZ_LOG(gAudioStreamLog, mozilla::LogLevel::Debug, ("%p " x, this, ##__VA_ARGS__))
+#define LOGW(x, ...) MOZ_LOG(gAudioStreamLog, mozilla::LogLevel::Warning, ("%p " x, this, ##__VA_ARGS__))
 
 /**
  * When MOZ_DUMP_AUDIO is set in the environment (to anything),
  * we'll drop a series of files in the current working directory named
  * dumped-audio-<nnn>.wav, one per AudioStream created, containing
  * the audio for the stream including any skips due to underruns.
  */
 static int gDumpedAudioCount = 0;
@@ -130,17 +130,17 @@ AudioStream::AudioStream(DataSource& aSo
   , mState(INITIALIZED)
   , mIsMonoAudioEnabled(gfxPrefs::MonoAudio())
   , mDataSource(aSource)
 {
 }
 
 AudioStream::~AudioStream()
 {
-  LOG(("AudioStream: delete %p, state %d", this, mState));
+  LOG("deleted, state %d", mState);
   MOZ_ASSERT(mState == SHUTDOWN && !mCubebStream,
              "Should've called Shutdown() before deleting an AudioStream");
   if (mDumpFile) {
     fclose(mDumpFile);
   }
   if (mTimeStretcher) {
     soundtouch::destroySoundTouchObj(mTimeStretcher);
   }
@@ -376,18 +376,18 @@ AudioStream::OpenCubeb(cubeb_stream_para
       return NS_ERROR_FAILURE;
     }
   }
 
   mState = INITIALIZED;
 
   if (!mStartTime.IsNull()) {
     TimeDuration timeDelta = TimeStamp::Now() - mStartTime;
-    LOG(("AudioStream creation time %sfirst: %u ms", mIsFirst ? "" : "not ",
-          (uint32_t) timeDelta.ToMilliseconds()));
+    LOG("creation time %sfirst: %u ms", mIsFirst ? "" : "not ",
+        (uint32_t) timeDelta.ToMilliseconds());
     Telemetry::Accumulate(mIsFirst ? Telemetry::AUDIOSTREAM_FIRST_OPEN_MS :
         Telemetry::AUDIOSTREAM_LATER_OPEN_MS, timeDelta.ToMilliseconds());
   }
 
   return NS_OK;
 }
 
 void
@@ -423,17 +423,17 @@ AudioStream::StartUnlocked()
       r = cubeb_stream_start(mCubebStream.get());
       // DataCallback might be called before we exit this scope
       // if cubeb_stream_start() succeeds. mState must be set to STARTED
       // beforehand.
     }
     if (r != CUBEB_OK) {
       mState = ERRORED;
     }
-    LOG(("AudioStream: started %p, state %s", this, mState == STARTED ? "STARTED" : "ERRORED"));
+    LOG("started, state %s", mState == STARTED ? "STARTED" : "ERRORED");
   }
 }
 
 void
 AudioStream::Pause()
 {
   MonitorAutoLock mon(mMonitor);
 
@@ -473,17 +473,17 @@ AudioStream::Resume()
     mState = STARTED;
   }
 }
 
 void
 AudioStream::Shutdown()
 {
   MonitorAutoLock mon(mMonitor);
-  LOG(("AudioStream: Shutdown %p, state %d", this, mState));
+  LOG("Shutdown, state %d", mState);
 
   if (mCubebStream) {
     MonitorAutoUnlock mon(mMonitor);
     // Force stop to put the cubeb stream in a stable state before deletion.
     cubeb_stream_stop(mCubebStream.get());
     // Must not try to shut down cubeb from within the lock!  wasapi may still
     // call our callback after Pause()/stop()!?! Bug 996162
     mCubebStream.reset();
@@ -652,18 +652,17 @@ AudioStream::DataCallback(void* aBuffer,
     GetTimeStretched(writer);
   }
 
   // Always send audible frames first, and silent frames later.
   // Otherwise it will break the assumption of FrameHistory.
   if (!mDataSource.Ended()) {
     mAudioClock.UpdateFrameHistory(aFrames - writer.Available(), writer.Available());
     if (writer.Available() > 0) {
-      MOZ_LOG(gAudioStreamLog, LogLevel::Warning,
-             ("AudioStream %p lost %d frames", this, writer.Available()));
+      LOGW("lost %d frames", writer.Available());
       writer.WriteZeros(writer.Available());
     }
   } else {
     // No more new data in the data source. Don't send silent frames so the
     // cubeb stream can start draining.
     mAudioClock.UpdateFrameHistory(aFrames - writer.Available(), 0);
   }
 
@@ -672,22 +671,22 @@ AudioStream::DataCallback(void* aBuffer,
   return aFrames - writer.Available();
 }
 
 void
 AudioStream::StateCallback(cubeb_state aState)
 {
   MonitorAutoLock mon(mMonitor);
   MOZ_ASSERT(mState != SHUTDOWN, "No state callback after shutdown");
-  LOG(("AudioStream: StateCallback %p, mState=%d cubeb_state=%d", this, mState, aState));
+  LOG("StateCallback, mState=%d cubeb_state=%d", mState, aState);
   if (aState == CUBEB_STATE_DRAINED) {
     mState = DRAINED;
     mDataSource.Drained();
   } else if (aState == CUBEB_STATE_ERROR) {
-    LOG(("AudioStream::StateCallback() state %d cubeb error", mState));
+    LOG("StateCallback() state %d cubeb error", mState);
     mState = ERRORED;
   }
 }
 
 AudioClock::AudioClock(AudioStream* aStream)
  :mAudioStream(aStream),
   mOutRate(0),
   mInRate(0),