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 280826 b578a9def3278b66b4ff63d167e5d9c1eff05a7b
parent 280825 a24d6c2b7525f4e1f5a32c3d54444f01c09e82fe
child 280827 b5cfe78829739a8daeb4916e5302ba8f80a75356
child 280912 977d78a8dd78afbc0153d37fd9887c3a200dce6a
push id70601
push userjwwang@mozilla.com
push dateThu, 21 Jan 2016 06:23:31 +0000
treeherdermozilla-inbound@b578a9def327 [default view] [failures only]
perfherder[talos] [build metrics] [platform microbench] (compared to previous push)
reviewerskinetik
bugs1240419
milestone46.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 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),