Bug 1162336 - Part 2: Wrap expensive calls in PR_LOG_TEST. r=froydnj
☠☠ backed out by a74ede09893f ☠ ☠
authorEric Rahm <erahm@mozilla.com>
Thu, 07 May 2015 10:35:29 -0700
changeset 242800 8952a7fa40507660721df603fdf05434a318140d
parent 242799 0170a6c2a5bebc37e2ca4c92110dbad6784fbc57
child 242801 4dc03fc3888594f7713747e8af689d12897e6c7f
push id59512
push usererahm@mozilla.com
push dateThu, 07 May 2015 17:36:03 +0000
treeherdermozilla-inbound@8952a7fa4050 [default view] [failures only]
perfherder[talos] [build metrics] [platform microbench] (compared to previous push)
reviewersfroydnj
bugs1162336
milestone40.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 1162336 - Part 2: Wrap expensive calls in PR_LOG_TEST. r=froydnj Check that logging is enabled before performing potentially expensive operations.
netwerk/base/nsLoadGroup.cpp
netwerk/cache/nsCacheService.cpp
netwerk/cache/nsDiskCacheDeviceSQL.cpp
netwerk/cache2/CacheFileIOManager.cpp
netwerk/cache2/CacheLog.h
netwerk/cache2/CacheStorageService.cpp
netwerk/cookie/nsCookieService.cpp
netwerk/protocol/http/HttpBaseChannel.cpp
netwerk/protocol/http/nsHttpChannel.cpp
netwerk/socket/nsSOCKSIOLayer.cpp
--- a/netwerk/base/nsLoadGroup.cpp
+++ b/netwerk/base/nsLoadGroup.cpp
@@ -252,20 +252,22 @@ nsLoadGroup::Cancel(nsresult status)
         NS_ASSERTION(request, "NULL request found in list.");
 
         if (!PL_DHashTableSearch(&mRequests, request)) {
             // |request| was removed already
             NS_RELEASE(request);
             continue;
         }
 
-        nsAutoCString nameStr;
-        request->GetName(nameStr);
-        LOG(("LOADGROUP [%x]: Canceling request %x %s.\n",
-             this, request, nameStr.get()));
+        if (PR_LOG_TEST(gLoadGroupLog, PR_LOG_DEBUG)) {
+            nsAutoCString nameStr;
+            request->GetName(nameStr);
+            LOG(("LOADGROUP [%x]: Canceling request %x %s.\n",
+                 this, request, nameStr.get()));
+        }
 
         //
         // Remove the request from the load group...  This may cause
         // the OnStopRequest notification to fire...
         //
         // XXX: What should the context be?
         //
         (void)RemoveRequest(request, nullptr, status);
@@ -318,20 +320,22 @@ nsLoadGroup::Suspend()
     //
     while (count > 0) {
         nsIRequest* request = requests.ElementAt(--count);
 
         NS_ASSERTION(request, "NULL request found in list.");
         if (!request)
             continue;
 
-        nsAutoCString nameStr;
-        request->GetName(nameStr);
-        LOG(("LOADGROUP [%x]: Suspending request %x %s.\n",
-            this, request, nameStr.get()));
+        if (PR_LOG_TEST(gLoadGroupLog, PR_LOG_DEBUG)) {
+            nsAutoCString nameStr;
+            request->GetName(nameStr);
+            LOG(("LOADGROUP [%x]: Suspending request %x %s.\n",
+                this, request, nameStr.get()));
+        }
 
         // Suspend the request...
         rv = request->Suspend();
 
         // Remember the first failure and return it...
         if (NS_FAILED(rv) && NS_SUCCEEDED(firstError))
             firstError = rv;
 
@@ -368,20 +372,22 @@ nsLoadGroup::Resume()
     //
     while (count > 0) {
         nsIRequest* request = requests.ElementAt(--count);
 
         NS_ASSERTION(request, "NULL request found in list.");
         if (!request)
             continue;
 
-        nsAutoCString nameStr;
-        request->GetName(nameStr);
-        LOG(("LOADGROUP [%x]: Resuming request %x %s.\n",
-            this, request, nameStr.get()));
+        if (PR_LOG_TEST(gLoadGroupLog, PR_LOG_DEBUG)) {
+            nsAutoCString nameStr;
+            request->GetName(nameStr);
+            LOG(("LOADGROUP [%x]: Resuming request %x %s.\n",
+                this, request, nameStr.get()));
+        }
 
         // Resume the request...
         rv = request->Resume();
 
         // Remember the first failure and return it...
         if (NS_FAILED(rv) && NS_SUCCEEDED(firstError))
             firstError = rv;
 
@@ -455,17 +461,17 @@ nsLoadGroup::SetDefaultLoadRequest(nsIRe
     return NS_OK;
 }
 
 NS_IMETHODIMP
 nsLoadGroup::AddRequest(nsIRequest *request, nsISupports* ctxt)
 {
     nsresult rv;
 
-    {
+    if (PR_LOG_TEST(gLoadGroupLog, PR_LOG_DEBUG)) {
         nsAutoCString nameStr;
         request->GetName(nameStr);
         LOG(("LOADGROUP [%x]: Adding request %x %s (count=%d).\n",
              this, request, nameStr.get(), mRequests.EntryCount()));
     }
 
     NS_ASSERTION(!PL_DHashTableSearch(&mRequests, request),
                  "Entry added to loadgroup twice, don't do that");
@@ -552,17 +558,17 @@ nsLoadGroup::AddRequest(nsIRequest *requ
 
 NS_IMETHODIMP
 nsLoadGroup::RemoveRequest(nsIRequest *request, nsISupports* ctxt,
                            nsresult aStatus)
 {
     NS_ENSURE_ARG_POINTER(request);
     nsresult rv;
 
-    {
+    if (PR_LOG_TEST(gLoadGroupLog, PR_LOG_DEBUG)) {
         nsAutoCString nameStr;
         request->GetName(nameStr);
         LOG(("LOADGROUP [%x]: Removing request %x %s status %x (count=%d).\n",
             this, request, nameStr.get(), aStatus, mRequests.EntryCount() - 1));
     }
 
     // Make sure we have a owning reference to the request we're about
     // to remove.
--- a/netwerk/cache/nsCacheService.cpp
+++ b/netwerk/cache/nsCacheService.cpp
@@ -1762,20 +1762,22 @@ nsCacheService::CreateOfflineDevice()
 
 nsresult
 nsCacheService::CreateCustomOfflineDevice(nsIFile *aProfileDir,
                                           int32_t aQuota,
                                           nsOfflineCacheDevice **aDevice)
 {
     NS_ENSURE_ARG(aProfileDir);
 
-    nsAutoCString profilePath;
-    aProfileDir->GetNativePath(profilePath);
-    CACHE_LOG_ALWAYS(("Creating custom offline device, %s, %d",
-                      profilePath.BeginReading(), aQuota));
+    if (PR_LOG_TEST(gCacheLog, PR_LOG_ALWAYS)) {
+      nsAutoCString profilePath;
+      aProfileDir->GetNativePath(profilePath);
+      CACHE_LOG_ALWAYS(("Creating custom offline device, %s, %d",
+                        profilePath.BeginReading(), aQuota));
+    }
 
     if (!mInitialized)         return NS_ERROR_NOT_AVAILABLE;
     if (!mEnableOfflineDevice) return NS_ERROR_NOT_AVAILABLE;
 
     *aDevice = new nsOfflineCacheDevice;
 
     NS_ADDREF(*aDevice);
 
--- a/netwerk/cache/nsDiskCacheDeviceSQL.cpp
+++ b/netwerk/cache/nsDiskCacheDeviceSQL.cpp
@@ -220,19 +220,21 @@ nsOfflineCacheEvictionFunction::OnFuncti
 }
 
 void
 nsOfflineCacheEvictionFunction::Apply()
 {
   LOG(("nsOfflineCacheEvictionFunction::Apply\n"));
 
   for (int32_t i = 0; i < mItems.Count(); i++) {
-    nsAutoCString path;
-    mItems[i]->GetNativePath(path);
-    LOG(("  removing %s\n", path.get()));
+    if (PR_LOG_TEST(gCacheLog, PR_LOG_DEBUG)) {
+      nsAutoCString path;
+      mItems[i]->GetNativePath(path);
+      LOG(("  removing %s\n", path.get()));
+    }
 
     mItems[i]->Remove(false);
   }
 
   Reset();
 }
 
 class nsOfflineCacheDiscardCache : public nsRunnable
--- a/netwerk/cache2/CacheFileIOManager.cpp
+++ b/netwerk/cache2/CacheFileIOManager.cpp
@@ -3194,21 +3194,23 @@ CacheFileIOManager::RemoveTrashInternal(
       mTrashDirEnumerator = nullptr;
       continue; // check elapsed time
     } else {
       bool isDir = false;
       file->IsDirectory(&isDir);
       if (isDir) {
         NS_WARNING("Found a directory in a trash directory! It will be removed "
                    "recursively, but this can block IO thread for a while!");
-        nsAutoCString path;
-        file->GetNativePath(path);
-        LOG(("CacheFileIOManager::RemoveTrashInternal() - Found a directory in a trash "
-            "directory! It will be removed recursively, but this can block IO "
-            "thread for a while! [file=%s]", path.get()));
+        if (LOG_ENABLED()) {
+          nsAutoCString path;
+          file->GetNativePath(path);
+          LOG(("CacheFileIOManager::RemoveTrashInternal() - Found a directory in a trash "
+              "directory! It will be removed recursively, but this can block IO "
+              "thread for a while! [file=%s]", path.get()));
+        }
       }
       file->Remove(isDir);
     }
   }
 
   NS_NOTREACHED("We should never get here");
   return NS_OK;
 }
@@ -3752,20 +3754,22 @@ CacheFileIOManager::SyncRemoveDir(nsIFil
     }
 
     rv = file->AppendNative(nsDependentCString(aDir));
     if (NS_WARN_IF(NS_FAILED(rv))) {
       return rv;
     }
   }
 
-  nsAutoCString path;
-  file->GetNativePath(path);
-  LOG(("CacheFileIOManager::SyncRemoveDir() - Removing directory %s",
-       path.get()));
+  if (LOG_ENABLED()) {
+    nsAutoCString path;
+    file->GetNativePath(path);
+    LOG(("CacheFileIOManager::SyncRemoveDir() - Removing directory %s",
+         path.get()));
+  }
 
   rv = file->Remove(true);
   if (NS_WARN_IF(NS_FAILED(rv))) {
     LOG(("CacheFileIOManager::SyncRemoveDir() - Removing failed! [rv=0x%08x]",
          rv));
   }
 
   return rv;
--- a/netwerk/cache2/CacheLog.h
+++ b/netwerk/cache2/CacheLog.h
@@ -7,13 +7,14 @@
 
 #include "prlog.h"
 
 namespace mozilla {
 namespace net {
 
 extern PRLogModuleInfo* GetCache2Log();
 #define LOG(x)  PR_LOG(GetCache2Log(), PR_LOG_DEBUG, x)
+#define LOG_ENABLED() PR_LOG_TEST(GetCache2Log(), PR_LOG_DEBUG)
 
 } // net
 } // mozilla
 
 #endif
--- a/netwerk/cache2/CacheStorageService.cpp
+++ b/netwerk/cache2/CacheStorageService.cpp
@@ -1437,20 +1437,22 @@ CacheStorageService::CheckStorageEntry(C
 
   nsAutoCString contextKey;
   CacheFileUtils::AppendKeyPrefix(aStorage->LoadInfo(), contextKey);
 
   if (!aStorage->WriteToDisk()) {
     AppendMemoryStorageID(contextKey);
   }
 
-  nsAutoCString uriSpec;
-  aURI->GetAsciiSpec(uriSpec);
-  LOG(("CacheStorageService::CheckStorageEntry [uri=%s, eid=%s, contextKey=%s]",
-    uriSpec.get(), aIdExtension.BeginReading(), contextKey.get()));
+  if (LOG_ENABLED()) {
+    nsAutoCString uriSpec;
+    aURI->GetAsciiSpec(uriSpec);
+    LOG(("CacheStorageService::CheckStorageEntry [uri=%s, eid=%s, contextKey=%s]",
+      uriSpec.get(), aIdExtension.BeginReading(), contextKey.get()));
+  }
 
   {
     mozilla::MutexAutoLock lock(mLock);
 
     NS_ENSURE_FALSE(mShutdown, NS_ERROR_NOT_INITIALIZED);
 
     nsAutoCString entryKey;
     rv = CacheEntry::HashingKey(EmptyCString(), aIdExtension, aURI, entryKey);
--- a/netwerk/cookie/nsCookieService.cpp
+++ b/netwerk/cookie/nsCookieService.cpp
@@ -346,25 +346,27 @@ class DBListenerErrorHandler : public mo
 protected:
   explicit DBListenerErrorHandler(DBState* dbState) : mDBState(dbState) { }
   nsRefPtr<DBState> mDBState;
   virtual const char *GetOpType() = 0;
 
 public:
   NS_IMETHOD HandleError(mozIStorageError* aError) override
   {
-    int32_t result = -1;
-    aError->GetResult(&result);
-
-    nsAutoCString message;
-    aError->GetMessage(message);
-    COOKIE_LOGSTRING(PR_LOG_WARNING,
-      ("DBListenerErrorHandler::HandleError(): Error %d occurred while "
-       "performing operation '%s' with message '%s'; rebuilding database.",
-       result, GetOpType(), message.get()));
+    if (PR_LOG_TEST(GetCookieLog(), PR_LOG_WARNING)) {
+      int32_t result = -1;
+      aError->GetResult(&result);
+
+      nsAutoCString message;
+      aError->GetMessage(message);
+      COOKIE_LOGSTRING(PR_LOG_WARNING,
+        ("DBListenerErrorHandler::HandleError(): Error %d occurred while "
+         "performing operation '%s' with message '%s'; rebuilding database.",
+         result, GetOpType(), message.get()));
+    }
 
     // Rebuild the database.
     gCookieService->HandleCorruptDB(mDBState);
 
     return NS_OK;
   }
 };
 
--- a/netwerk/protocol/http/HttpBaseChannel.cpp
+++ b/netwerk/protocol/http/HttpBaseChannel.cpp
@@ -2351,24 +2351,26 @@ HttpBaseChannel::SetupReplacementChannel
     if (mRedirectedCachekeys) {
         LOG(("HttpBaseChannel::SetupReplacementChannel "
              "[this=%p] transferring chain of redirect cache-keys", this));
         httpInternal->SetCacheKeysRedirectChain(mRedirectedCachekeys.forget());
     }
     // Transfer existing redirect information. Add all of our existing
     // redirects to the new channel.
     for (int32_t i = 0; i < mRedirects.Count(); ++i) {
-      nsCOMPtr<nsIURI> uri;
-      mRedirects[i]->GetURI(getter_AddRefs(uri));
-      nsCString spec;
-      if (uri) {
-        uri->GetSpec(spec);
+      if (LOG_ENABLED()) {
+        nsCOMPtr<nsIURI> uri;
+        mRedirects[i]->GetURI(getter_AddRefs(uri));
+        nsCString spec;
+        if (uri) {
+          uri->GetSpec(spec);
+        }
+        LOG(("HttpBaseChannel::SetupReplacementChannel adding redirect \'%s\' "
+             "[this=%p]", spec.get(), this));
       }
-      LOG(("HttpBaseChannel::SetupReplacementChannel adding redirect \'%s\' "
-           "[this=%p]", spec.get(), this));
 
       httpInternal->AddRedirect(mRedirects[i]);
     }
 
     // Add our own principal to the redirect information on the new channel. If
     // the redirect is vetoed, then newChannel->AsyncOpen won't be called.
     // However, the new channel's redirect chain will still be complete.
     nsCOMPtr<nsIPrincipal> principal = GetURIPrincipal();
--- a/netwerk/protocol/http/nsHttpChannel.cpp
+++ b/netwerk/protocol/http/nsHttpChannel.cpp
@@ -6553,20 +6553,22 @@ nsHttpChannel::MaybeInvalidateCacheEntry
     // any cached copy of the resource
     if (mRequestHead.IsGet() || mRequestHead.IsOptions() ||
         mRequestHead.IsHead() || mRequestHead.IsTrace() ||
         mRequestHead.IsConnect()) {
         return;
     }
 
     // Invalidate the request-uri.
-    nsAutoCString key;
-    mURI->GetAsciiSpec(key);
-    LOG(("MaybeInvalidateCacheEntryForSubsequentGet [this=%p uri=%s]\n",
-        this, key.get()));
+    if (LOG_ENABLED()) {
+      nsAutoCString key;
+      mURI->GetAsciiSpec(key);
+      LOG(("MaybeInvalidateCacheEntryForSubsequentGet [this=%p uri=%s]\n",
+          this, key.get()));
+    }
 
     DoInvalidateCacheEntry(mURI);
 
     // Invalidate Location-header if set
     const char *location = mResponseHead->PeekHeader(nsHttp::Location);
     if (location) {
         LOG(("  Location-header=%s\n", location));
         InvalidateCacheEntryForLocation(location);
@@ -6600,17 +6602,20 @@ nsHttpChannel::DoInvalidateCacheEntry(ns
     // Following comments 24,32 and 33 in bug #327765, we only care about
     // the cache in the protocol-handler, not the application cache.
     // The logic below deviates from the original logic in OpenCacheEntry on
     // one point by using only READ_ONLY access-policy. I think this is safe.
 
     nsresult rv;
 
     nsAutoCString key;
-    aURI->GetAsciiSpec(key);
+    if (LOG_ENABLED()) {
+      aURI->GetAsciiSpec(key);
+    }
+
     LOG(("DoInvalidateCacheEntry [channel=%p key=%s]", this, key.get()));
 
     nsCOMPtr<nsICacheStorageService> cacheStorageService =
         do_GetService("@mozilla.org/netwerk/cache-storage-service;1", &rv);
 
     nsCOMPtr<nsICacheStorage> cacheStorage;
     if (NS_SUCCEEDED(rv)) {
         nsRefPtr<LoadContextInfo> info = GetLoadContextInfo(this);
--- a/netwerk/socket/nsSOCKSIOLayer.cpp
+++ b/netwerk/socket/nsSOCKSIOLayer.cpp
@@ -418,20 +418,22 @@ nsSOCKSSocketInfo::ConnectToProxy(PRFile
         rv = mDnsRec->GetNextAddr(mProxyPort, &mInternalProxyAddr);
         // No more addresses to try? If so, we'll need to bail
         if (NS_FAILED(rv)) {
             LOGERROR(("socks: unable to connect to SOCKS proxy, %s",
                      mProxyHost.get()));
             return PR_FAILURE;
         }
 
-        char buf[kIPv6CStrBufSize];
-        NetAddrToString(&mInternalProxyAddr, buf, sizeof(buf));
-        LOGDEBUG(("socks: trying proxy server, %s:%hu",
-                 buf, ntohs(mInternalProxyAddr.inet.port)));
+        if (PR_LOG_TEST(gSOCKSLog, PR_LOG_DEBUG)) {
+          char buf[kIPv6CStrBufSize];
+          NetAddrToString(&mInternalProxyAddr, buf, sizeof(buf));
+          LOGDEBUG(("socks: trying proxy server, %s:%hu",
+                   buf, ntohs(mInternalProxyAddr.inet.port)));
+        }
 
         NetAddr proxy = mInternalProxyAddr;
         FixupAddressFamily(fd, &proxy);
         PRNetAddr prProxy;
         NetAddrToPRNetAddr(&proxy, &prProxy);
         status = fd->lower->methods->connect(fd->lower, &prProxy, mTimeout);
         if (status != PR_SUCCESS) {
             PRErrorCode c = PR_GetError();