Bug 1162336 - Part 2: Wrap expensive calls in PR_LOG_TEST. r=froydnj
authorEric Rahm <erahm@mozilla.com>
Thu, 07 May 2015 12:52:45 -0700
changeset 274246 f326f7d6ff52d94a7e49008b50a810df86f82109
parent 274245 0313bc7f60521d9807cf9d5fbdcd843d9d5b8dd4
child 274247 e76f9c955db8c5eee5409d8bb62242ad335ac130
push id863
push userraliiev@mozilla.com
push dateMon, 03 Aug 2015 13:22:43 +0000
treeherdermozilla-release@f6321b14228d [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();