Bug 1368837 - Convert printfs into MOZ_LOG(MediaResourceIndex) - r=cpearce
authorGerald Squelart <gsquelart@mozilla.com>
Tue, 30 May 2017 14:12:38 +1200
changeset 361724 30a1c114fe232099815361fbef331468abf44041
parent 361723 cc5eaeefd44520822edf91a49355d354d6f38ad5
child 361725 9d84b3d85bbcad165660eb149744b260b2108862
push id31939
push usercbook@mozilla.com
push dateThu, 01 Jun 2017 11:49:28 +0000
treeherdermozilla-central@d96110d76619 [default view] [failures only]
perfherder[talos] [build metrics] [platform microbench] (compared to previous push)
reviewerscpearce
bugs1368837
milestone55.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 1368837 - Convert printfs into MOZ_LOG(MediaResourceIndex) - r=cpearce MozReview-Commit-ID: Bhi1vxDPwDV
dom/media/MediaResource.cpp
dom/media/MediaResource.h
--- a/dom/media/MediaResource.cpp
+++ b/dom/media/MediaResource.cpp
@@ -30,22 +30,30 @@
 #include "nsHostObjectProtocolHandler.h"
 #include <algorithm>
 #include "nsProxyRelease.h"
 #include "nsIContentPolicy.h"
 
 using mozilla::media::TimeUnit;
 
 #undef LOG
+#undef ILOG
 
 mozilla::LazyLogModule gMediaResourceLog("MediaResource");
 // Debug logging macro with object pointer and class name.
 #define LOG(msg, ...) MOZ_LOG(gMediaResourceLog, mozilla::LogLevel::Debug, \
   ("%p " msg, this, ##__VA_ARGS__))
 
+mozilla::LazyLogModule gMediaResourceIndexLog("MediaResourceIndex");
+// Debug logging macro with object pointer and class name.
+#define ILOG(msg, ...)                                                         \
+  MOZ_LOG(gMediaResourceIndexLog,                                              \
+          mozilla::LogLevel::Debug,                                            \
+          ("%p " msg, this, ##__VA_ARGS__))
+
 static const uint32_t HTTP_OK_CODE = 200;
 static const uint32_t HTTP_PARTIAL_RESPONSE_CODE = 206;
 
 namespace mozilla {
 
 void
 MediaResource::Destroy()
 {
@@ -1638,17 +1646,17 @@ MediaResourceIndex::Read(char* aBuffer, 
   nsresult rv = ReadAt(mOffset, aBuffer, aCount, aBytes);
   if (NS_FAILED(rv)) {
     return rv;
   }
   mOffset += *aBytes;
   return NS_OK;
 }
 
-nsCString
+static nsCString
 ResultName(nsresult aResult)
 {
   nsCString name;
   GetErrorName(aResult, name);
   return name;
 }
 
 nsresult
@@ -1656,25 +1664,19 @@ MediaResourceIndex::ReadAt(int64_t aOffs
                            char* aBuffer,
                            uint32_t aCount,
                            uint32_t* aBytes)
 {
   if (mCacheBlockSize == 0) {
     return UncachedReadAt(aOffset, aBuffer, aCount, aBytes);
   }
 
-  const int oOffset = int(aOffset);
-  const unsigned oCount = unsigned(aCount);
   *aBytes = 0;
 
   if (aCount == 0) {
-    printf("**** [%p]ReadAt(%u@%d) - aCount==0 -> NS_OK, 0\n",
-           this,
-           oCount,
-           oOffset);
     return NS_OK;
   }
 
   const int64_t endOffset = aOffset + aCount;
   const int64_t lastBlockOffset = CacheOffsetContaining(endOffset - 1);
 
   if (mCachedBytes != 0 && mCachedOffset + mCachedBytes >= aOffset &&
       mCachedOffset < endOffset) {
@@ -1683,173 +1685,164 @@ MediaResourceIndex::ReadAt(int64_t aOffs
     if (aOffset < mCachedOffset) {
       // We need to read before the cached data.
       const uint32_t toRead = uint32_t(mCachedOffset - aOffset);
       MOZ_ASSERT(toRead > 0);
       MOZ_ASSERT(toRead < aCount);
       uint32_t read = 0;
       nsresult rv = UncachedReadAt(aOffset, aBuffer, toRead, &read);
       if (NS_FAILED(rv)) {
-        printf("**** [%p]ReadAt(%u@%d) uncached read before cache -> %s\n",
-               this,
-               oCount,
-               oOffset,
-               ResultName(rv).get());
+        ILOG("ReadAt(%" PRIu32 "@%" PRId64
+             ") uncached read before cache -> %s, %" PRIu32,
+             aCount,
+             aOffset,
+             ResultName(rv).get(),
+             *aBytes);
         return rv;
       }
       *aBytes = read;
       if (read < toRead) {
         // Could not read everything we wanted, we're done.
-        printf("**** [%p]ReadAt(%u@%d) uncached read before cache, incomplete "
-               "-> OK, %u\n",
-               this,
-               oCount,
-               oOffset,
-               unsigned(*aBytes));
+        ILOG("ReadAt(%" PRIu32 "@%" PRId64
+             ") uncached read before cache, incomplete -> OK, %" PRIu32,
+             aCount,
+             aOffset,
+             *aBytes);
         return NS_OK;
       }
+      ILOG("ReadAt(%" PRIu32 "@%" PRId64
+           ") uncached read before cache: %" PRIu32 ", remaining: %" PRIu32
+           "@%" PRId64 "...",
+           aCount,
+           aOffset,
+           read,
+           aCount - read,
+           aOffset + read);
       aOffset += read;
       aBuffer += read;
       aCount -= read;
-      printf("**** [%p]ReadAt(%u@%d) uncached read before cache: %u, "
-             "remaining: %u@%d\n",
-             this,
-             oCount,
-             oOffset,
-             unsigned(read),
-             unsigned(aCount),
-             int(aOffset));
       // We should have reached the cache.
       MOZ_ASSERT(aOffset == mCachedOffset);
     }
     MOZ_ASSERT(aOffset >= mCachedOffset);
 
     // We've reached our cache.
     const uint32_t toCopy =
       std::min(aCount, uint32_t(mCachedOffset + mCachedBytes - aOffset));
     // Note that we could in fact be just after the last byte of the cache, in
     // which case we can't actually read from it! (But we will top-up next.)
     if (toCopy != 0) {
       memcpy(aBuffer, &mCachedBlock[IndexInCache(aOffset)], toCopy);
       *aBytes += toCopy;
       aCount -= toCopy;
       if (aCount == 0) {
         // All done!
-        printf("**** [%p]ReadAt(%u@%d) copied from cache(%u@%d) and done :-) "
-               "-> OK, %u\n",
-               this,
-               oCount,
-               oOffset,
-               unsigned(mCachedBytes),
-               int(mCachedOffset),
-               unsigned(*aBytes));
+        ILOG("ReadAt(%" PRIu32 "@%" PRId64 ") copied everything (%" PRIu32
+             ") from cache(%" PRIu32 "@%" PRId64 ") :-D -> OK, %" PRIu32,
+             aCount,
+             aOffset,
+             toCopy,
+             mCachedBytes,
+             mCachedOffset,
+             *aBytes);
         return NS_OK;
       }
       aOffset += toCopy;
       aBuffer += toCopy;
-      printf("**** [%p]ReadAt(%u@%d) copied %u from cache(%u@%d) :-), "
-             "remaining: %u@%d\n",
-             this,
-             oCount,
-             oOffset,
-             unsigned(toCopy),
-             unsigned(mCachedBytes),
-             int(mCachedOffset),
-             unsigned(aCount),
-             int(aOffset));
+      ILOG("ReadAt(%" PRIu32 "@%" PRId64 ") copied %" PRIu32
+           " from cache(%" PRIu32 "@%" PRId64 ") :-), remaining: %" PRIu32
+           "@%" PRId64 "...",
+           aCount + toCopy,
+           aOffset - toCopy,
+           toCopy,
+           mCachedBytes,
+           mCachedOffset,
+           aCount,
+           aOffset);
     }
 
     if (aOffset - 1 >= lastBlockOffset) {
       // We were already reading cached data from the last block, we need more
       // from it -> try to top-up, read what we can, and we'll be done.
       MOZ_ASSERT(aOffset == mCachedOffset + mCachedBytes);
       MOZ_ASSERT(endOffset <= lastBlockOffset + mCacheBlockSize);
-      return CacheOrReadAt(
-        oOffset, oCount, "top-up cache", aOffset, aBuffer, aCount, aBytes);
+      return CacheOrReadAt(aOffset, aBuffer, aCount, aBytes);
     }
 
     // We were not in the last block (but we may just have crossed the line now)
     MOZ_ASSERT(aOffset <= lastBlockOffset);
     // Continue below...
   } else if (aOffset >= lastBlockOffset) {
     // There was nothing we could get from the cache.
     // But we're already in the last block -> Cache or read what we can.
     // Make sure to invalidate the cache first.
     mCachedBytes = 0;
-    return CacheOrReadAt(
-      oOffset, oCount, "nothing in cache", aOffset, aBuffer, aCount, aBytes);
+    return CacheOrReadAt(aOffset, aBuffer, aCount, aBytes);
   }
 
   // If we're here, either there was nothing usable in the cache, or we've just
   // read what was in the cache but there's still more to read.
 
   if (aOffset < lastBlockOffset) {
     // We need to read before the last block.
     // Start with an uncached read up to the last block.
     const uint32_t toRead = uint32_t(lastBlockOffset - aOffset);
     MOZ_ASSERT(toRead > 0);
     MOZ_ASSERT(toRead < aCount);
     uint32_t read = 0;
     nsresult rv = UncachedReadAt(aOffset, aBuffer, toRead, &read);
     if (NS_FAILED(rv)) {
-      printf(
-        "**** [%p]ReadAt(%u@%d) uncached read before last block failed -> %s\n",
-        this,
-        oCount,
-        oOffset,
-        ResultName(rv).get());
+      ILOG("ReadAt(%" PRIu32 "@%" PRId64
+           ") uncached read before last block failed -> %s, %" PRIu32,
+           aCount,
+           aOffset,
+           ResultName(rv).get(),
+           *aBytes);
       return rv;
     }
     if (read == 0) {
-      printf(
-        "**** [%p]ReadAt(%u@%d) uncached read 0 before last block -> OK, %u\n",
-        this,
-        oCount,
-        oOffset,
-        unsigned(*aBytes));
+      ILOG("ReadAt(%" PRIu32 "@%" PRId64
+           ") uncached read 0 before last block -> OK, %" PRIu32,
+           aCount,
+           aOffset,
+           *aBytes);
       return NS_OK;
     }
     *aBytes += read;
     if (read < toRead) {
       // Could not read everything we wanted, we're done.
-      printf("**** [%p]ReadAt(%u@%d) uncached read before last block, "
-             "incomplete -> OK, %u\n",
-             this,
-             oCount,
-             oOffset,
-             unsigned(*aBytes));
+      ILOG("ReadAt(%" PRIu32 "@%" PRId64
+           ") uncached read before last block, incomplete -> OK, %" PRIu32,
+           aCount,
+           aOffset,
+           *aBytes);
       return NS_OK;
     }
+    ILOG("ReadAt(%" PRIu32 "@%" PRId64 ") read %" PRIu32
+         " before last block, remaining: %" PRIu32 "@%" PRId64 "...",
+         aCount,
+         aOffset,
+         read,
+         aCount - read,
+         aOffset + read);
     aOffset += read;
     aBuffer += read;
     aCount -= read;
-    printf(
-      "**** [%p]ReadAt(%u@%d) read %u before last block, remaining: %u@%d\n",
-      this,
-      oCount,
-      oOffset,
-      unsigned(read),
-      unsigned(aCount),
-      int(aOffset));
   }
 
   // We should just have reached the start of the last block.
   MOZ_ASSERT(aOffset == lastBlockOffset);
   MOZ_ASSERT(aCount <= mCacheBlockSize);
   // Make sure to invalidate the cache first.
   mCachedBytes = 0;
-  return CacheOrReadAt(
-    oOffset, oCount, "last block", aOffset, aBuffer, aCount, aBytes);
+  return CacheOrReadAt(aOffset, aBuffer, aCount, aBytes);
 }
 
 nsresult
-MediaResourceIndex::CacheOrReadAt(int oOffset,
-                                  unsigned oCount,
-                                  const char* oContext,
-                                  int64_t aOffset,
+MediaResourceIndex::CacheOrReadAt(int64_t aOffset,
                                   char* aBuffer,
                                   uint32_t aCount,
                                   uint32_t* aBytes)
 {
   // We should be here because there is more data to read.
   MOZ_ASSERT(aCount > 0);
   // We should be in the last block, so we shouldn't try to read past it.
   MOZ_ASSERT(IndexInCache(aOffset) + aCount <= mCacheBlockSize);
@@ -1870,104 +1863,101 @@ MediaResourceIndex::CacheOrReadAt(int oO
       const uint32_t toRead =
         uint32_t(std::min(cachedDataEnd - aOffset,
                           int64_t(mCacheBlockSize - cacheIndex)));
       MOZ_ASSERT(toRead >= aCount);
       nsresult rv =
         mResource->ReadFromCache(&mCachedBlock[cacheIndex], aOffset, toRead);
       if (NS_SUCCEEDED(rv)) {
         // Success means we have read the full `toRead` amount.
-        printf("**** [%p]ReadAt(%u@%d) - %s - ReadFromCache(%u@%d) succeeded\n",
-               this,
-               oCount,
-               oOffset,
-               oContext,
-               unsigned(toRead),
-               int(aOffset));
         if (mCachedOffset + mCachedBytes == aOffset) {
           // We were topping-up the cache, just update its size.
+          ILOG("ReadAt(%" PRIu32 "@%" PRId64 ") - ReadFromCache(%" PRIu32
+               "@%" PRId64 ") to top-up succeeded...",
+               aCount,
+               aOffset,
+               toRead,
+               aOffset);
           mCachedBytes += toRead;
         } else {
           // We were filling the cache from scratch, save new cache information.
+          ILOG("ReadAt(%" PRIu32 "@%" PRId64 ") - ReadFromCache(%" PRIu32
+               "@%" PRId64 ") to fill cache succeeded...",
+               aCount,
+               aOffset,
+               toRead,
+               aOffset);
           mCachedOffset = aOffset;
           mCachedBytes = toRead;
         }
         // Copy relevant part into output.
         memcpy(aBuffer, &mCachedBlock[cacheIndex], aCount);
         *aBytes += aCount;
-        printf("**** [%p]ReadAt(%u@%d) - %s - copied %u@%d, remaining: %u@%d "
-               "-> OK, %u\n",
-               this,
-               oCount,
-               oOffset,
-               oContext,
-               unsigned(aCount),
-               int(aOffset),
-               unsigned(aCount),
-               int(aOffset),
-               unsigned(*aBytes));
+        ILOG("ReadAt(%" PRIu32 "@%" PRId64 ") - copied %" PRIu32 "@%" PRId64
+             " -> OK, %" PRIu32,
+             aCount,
+             aOffset,
+             aCount,
+             aOffset,
+             *aBytes);
         // We may not have read all that was requested, but we got everything
         // we could get, so we're done.
         return NS_OK;
       }
-      printf("**** [%p]ReadAt(%u@%d) - %s - ReadFromCache(%u@%d) failed: %s, "
-             "will fallback to blocking read\n",
-             this,
-             oCount,
-             oOffset,
-             oContext,
-             unsigned(toRead),
-             int(aOffset),
-             ResultName(rv).get());
+      ILOG("ReadAt(%" PRIu32 "@%" PRId64 ") - ReadFromCache(%" PRIu32
+           "@%" PRId64 ") failed: %s, will fallback to blocking read...",
+           aCount,
+           aOffset,
+           toRead,
+           aOffset,
+           ResultName(rv).get());
       // Failure during reading. Note that this may be due to the cache
       // changing between `GetCachedDataEnd` and `ReadFromCache`, so it's not
       // totally unexpected, just hopefully rare; but we do need to handle it.
 
       // Invalidate part of cache that may have been partially overridden.
       if (mCachedOffset + mCachedBytes == aOffset) {
         // We were topping-up the cache, just keep the old untouched data.
         // (i.e., nothing to do here.)
       } else {
         // We were filling the cache from scratch, invalidate cache.
         mCachedBytes = 0;
       }
     } else {
-      printf("**** [%p]ReadAt(%u@%d) - %s - no cached data, will fallback to "
-             "blocking read\n",
-             this,
-             oCount,
-             oOffset,
-             oContext);
+      ILOG("ReadAt(%" PRIu32 "@%" PRId64
+           ") - no cached data, will fallback to blocking read...",
+           aCount,
+           aOffset);
     }
   } else {
-    printf("**** [%p]ReadAt(%u@%d) - %s - length is known and too short(!), "
-           "will fallback to blocking read as the caller requested\n",
-           this,
-           oCount,
-           oOffset,
-           oContext);
+    ILOG("ReadAt(%" PRIu32 "@%" PRId64 ") - length is %" PRId64
+         " (%s), will fallback to blocking read as the caller requested...",
+         aCount,
+         aOffset,
+         length,
+         length < 0 ? "unknown" : "too short!");
   }
   uint32_t read = 0;
   nsresult rv = UncachedReadAt(aOffset, aBuffer, aCount, &read);
   if (NS_SUCCEEDED(rv)) {
-    printf("**** [%p]ReadAt(%u@%d) - %s - fallback uncached read -> %s, %u\n",
-           this,
-           oCount,
-           oOffset,
-           oContext,
-           ResultName(rv).get(),
-           unsigned(read));
     *aBytes += read;
+    ILOG("ReadAt(%" PRIu32 "@%" PRId64 ") - fallback uncached read got %" PRIu32
+         " bytes -> %s, %" PRIu32,
+         aCount,
+         aOffset,
+         read,
+         ResultName(rv).get(),
+         *aBytes);
   } else {
-    printf("**** [%p]ReadAt(%u@%d) - %s - fallback uncached read -> %s\n",
-           this,
-           oCount,
-           oOffset,
-           oContext,
-           ResultName(rv).get());
+    ILOG("ReadAt(%" PRIu32 "@%" PRId64
+         ") - fallback uncached read failed -> %s, %" PRIu32,
+         aCount,
+         aOffset,
+         ResultName(rv).get(),
+         *aBytes);
   }
   return rv;
 }
 
 nsresult
 MediaResourceIndex::UncachedReadAt(int64_t aOffset,
                                    char* aBuffer,
                                    uint32_t aCount,
@@ -2022,8 +2012,9 @@ MediaResourceIndex::Seek(int32_t aWhence
 
   return NS_OK;
 }
 
 } // namespace mozilla
 
 // avoid redefined macro in unified build
 #undef LOG
+#undef ILOG
--- a/dom/media/MediaResource.h
+++ b/dom/media/MediaResource.h
@@ -853,20 +853,17 @@ public:
   int64_t GetLength() const { return mResource->GetLength(); }
 
 private:
   // If the resource has cached data past the requested range, try to grab it
   // into our local cache.
   // If there is no cached data, or attempting to read it fails, fallback on
   // a (potentially-blocking) read of just what was requested, so that we don't
   // get unexpected side-effects by trying to read more than intended.
-  nsresult CacheOrReadAt(int oOffset,
-                         unsigned oCount,
-                         const char* oContext,
-                         int64_t aOffset,
+  nsresult CacheOrReadAt(int64_t aOffset,
                          char* aBuffer,
                          uint32_t aCount,
                          uint32_t* aBytes);
 
   // Select the next power of 2 (in range 32B-128KB, or 0 -> no cache)
   static uint32_t SelectCacheSize(uint32_t aHint)
   {
     if (aHint == 0) {