Bug 686948 - Add telemetry for cache hit/miss with/without revalidation. r=mcmanus
authorNick Hurley <hurley@todesschaf.org>
Sat, 17 Sep 2011 10:22:09 +0100
changeset 78427 0b31c67e1423b8e1fff2d3956e0cad6a38204cf0
parent 78426 13d1f83e452a7fbc986f97af65857e26517fa1c4
child 78428 f827e9173fea8cbcfd3c16347f212fa0e7a7730b
push id78
push userclegnitto@mozilla.com
push dateFri, 16 Dec 2011 17:32:24 +0000
treeherdermozilla-release@79d24e644fdd [default view] [failures only]
perfherder[talos] [build metrics] [platform microbench] (compared to previous push)
reviewersmcmanus
bugs686948
milestone9.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 686948 - Add telemetry for cache hit/miss with/without revalidation. r=mcmanus
netwerk/protocol/http/nsHttpChannel.cpp
netwerk/protocol/http/nsHttpChannel.h
toolkit/components/telemetry/TelemetryHistograms.h
--- a/netwerk/protocol/http/nsHttpChannel.cpp
+++ b/netwerk/protocol/http/nsHttpChannel.cpp
@@ -61,16 +61,17 @@
 #include "nsEscape.h"
 #include "nsStreamUtils.h"
 #include "nsIOService.h"
 #include "nsICacheService.h"
 #include "nsDNSPrefetch.h"
 #include "nsChannelClassifier.h"
 #include "nsIRedirectResultListener.h"
 #include "mozilla/TimeStamp.h"
+#include "mozilla/Telemetry.h"
 
 // True if the local cache should be bypassed when processing a request.
 #define BYPASS_LOCAL_CACHE(loadFlags) \
         (loadFlags & (nsIRequest::LOAD_BYPASS_CACHE | \
                       nsICachingChannel::LOAD_BYPASS_LOCAL_CACHE))
 
 static NS_DEFINE_CID(kStreamListenerTeeCID, NS_STREAMLISTENERTEE_CID);
 
@@ -123,16 +124,17 @@ nsHttpChannel::nsHttpChannel()
     , mInitedCacheEntry(PR_FALSE)
     , mCacheForOfflineUse(PR_FALSE)
     , mCachingOpportunistically(PR_FALSE)
     , mFallbackChannel(PR_FALSE)
     , mCustomConditionalRequest(PR_FALSE)
     , mFallingBack(PR_FALSE)
     , mWaitingForRedirectCallback(PR_FALSE)
     , mRequestTimeInitialized(PR_FALSE)
+    , mDidReval(false)
 {
     LOG(("Creating nsHttpChannel [this=%p]\n", this));
     mChannelCreationTime = PR_Now();
     mChannelCreationTimestamp = mozilla::TimeStamp::Now();
 }
 
 nsHttpChannel::~nsHttpChannel()
 {
@@ -262,16 +264,18 @@ nsHttpChannel::Connect(PRBool firstTime)
             nsRunnableMethod<nsHttpChannel> *event = nsnull;
             if (!mCachedContentIsPartial) {
                 AsyncCall(&nsHttpChannel::AsyncOnExamineCachedResponse, &event);
             }
             rv = ReadFromCache();
             if (NS_FAILED(rv) && event) {
                 event->Revoke();
             }
+            mozilla::Telemetry::Accumulate(
+                    mozilla::Telemetry::HTTP_CACHE_DISPOSITION, kCacheHit);
             return rv;
         }
         else if (mLoadFlags & LOAD_ONLY_FROM_CACHE) {
             // the cache contains the requested resource, but it must be 
             // validated before we can reuse it.  since we are not allowed
             // to hit the net, there's nothing more to do.  the document
             // is effectively not in the cache.
             return NS_ERROR_DOCUMENT_NOT_CACHED;
@@ -969,16 +973,18 @@ nsHttpChannel::ProcessResponse()
 
         // reset the authentication's current continuation state because our
         // last authentication attempt has been completed successfully
         mAuthProvider->Disconnect(NS_ERROR_ABORT);
         mAuthProvider = nsnull;
         LOG(("  continuation state has been reset"));
     }
 
+    bool successfulReval = false;
+
     // handle different server response categories.  Note that we handle
     // caching or not caching of error pages in
     // nsHttpResponseHead::MustValidate; if you change this switch, update that
     // one
     switch (httpStatus) {
     case 200:
     case 203:
         // Per RFC 2616, 14.35.2, "A server MAY ignore the Range header".
@@ -1020,16 +1026,19 @@ nsHttpChannel::ProcessResponse()
         }
         break;
     case 304:
         rv = ProcessNotModified();
         if (NS_FAILED(rv)) {
             LOG(("ProcessNotModified failed [rv=%x]\n", rv));
             rv = ProcessNormal();
         }
+        else {
+            successfulReval = true;
+        }
         break;
     case 401:
     case 407:
         rv = mAuthProvider->ProcessAuthentication(
             httpStatus, mConnectionInfo->UsingSSL() &&
                         mTransaction->SSLConnectFailed());
         if (rv == NS_ERROR_IN_PROGRESS)  {
             // authentication prompt has been invoked and result
@@ -1055,16 +1064,27 @@ nsHttpChannel::ProcessResponse()
             mAuthRetryPending = PR_TRUE; // see DoAuthRetry
         break;
     default:
         rv = ProcessNormal();
         MaybeInvalidateCacheEntryForSubsequentGet();
         break;
     }
 
+    if (!mDidReval)
+        mozilla::Telemetry::Accumulate(
+                mozilla::Telemetry::HTTP_CACHE_DISPOSITION, kCacheMissed);
+    else if (successfulReval)
+        mozilla::Telemetry::Accumulate(
+                mozilla::Telemetry::HTTP_CACHE_DISPOSITION, kCacheHitViaReval);
+    else
+        mozilla::Telemetry::Accumulate(
+                mozilla::Telemetry::HTTP_CACHE_DISPOSITION,
+                kCacheMissedViaReval);
+
     return rv;
 }
 
 nsresult
 nsHttpChannel::ContinueProcessResponse(nsresult rv)
 {
     if (NS_SUCCEEDED(rv)) {
         InitCacheEntry();
@@ -2661,16 +2681,17 @@ nsHttpChannel::CheckCache()
                     mRequestHead.SetHeader(nsHttp::If_Modified_Since,
                                            nsDependentCString(val));
             }
             // Add If-None-Match header if an ETag was given in the response
             val = mCachedResponseHead->PeekHeader(nsHttp::ETag);
             if (val)
                 mRequestHead.SetHeader(nsHttp::If_None_Match,
                                        nsDependentCString(val));
+            mDidReval = true;
         }
     }
 
     LOG(("nsHTTPChannel::CheckCache exit [this=%p doValidation=%d]\n", this, doValidation));
     return NS_OK;
 }
 
 PRBool
--- a/netwerk/protocol/http/nsHttpChannel.h
+++ b/netwerk/protocol/http/nsHttpChannel.h
@@ -361,11 +361,20 @@ private:
     nsRefPtr<nsDNSPrefetch>           mDNSPrefetch;
 
     nsresult WaitForRedirectCallback();
     void PushRedirectAsyncFunc(nsContinueRedirectionFunc func);
     void PopRedirectAsyncFunc(nsContinueRedirectionFunc func);
 
 protected:
     virtual void DoNotifyListenerCleanup();
+
+private: // cache telemetry
+    enum {
+        kCacheHit = 1,
+        kCacheHitViaReval = 2,
+        kCacheMissedViaReval = 3,
+        kCacheMissed = 4
+    };
+    bool mDidReval;
 };
 
 #endif // nsHttpChannel_h__
--- a/toolkit/components/telemetry/TelemetryHistograms.h
+++ b/toolkit/components/telemetry/TelemetryHistograms.h
@@ -127,16 +127,19 @@ HISTOGRAM(HTTP_REQUEST_PER_PAGE_FROM_CAC
   _HTTP_HIST(HTTP_##prefix##_COMPLETE_LOAD_CACHED, labelprefix "Overall load time - cache hits (ms)") \
   _HTTP_HIST(HTTP_##prefix##_COMPLETE_LOAD_NET, labelprefix "Overall load time - network (ms)") \
 
 HTTP_HISTOGRAMS(PAGE, "page: ")
 HTTP_HISTOGRAMS(SUB, "subitem: ")
 
 #undef _HTTP_HIST
 #undef HTTP_HISTOGRAMS
+
+HISTOGRAM(HTTP_CACHE_DISPOSITION, 1, 5, 5, LINEAR, "HTTP Cache Hit, Reval, Failed-Reval, Miss")
+
 HISTOGRAM(FIND_PLUGINS, 1, 3000, 10, EXPONENTIAL, "Time spent scanning filesystem for plugins (ms)")
 HISTOGRAM(CHECK_JAVA_ENABLED, 1, 3000, 10, EXPONENTIAL, "Time spent checking if Java is enabled (ms)")
 
 /* Define 2 histograms: MOZ_SQLITE_(NAME)_MS and
  * MOZ_SQLITE_(NAME)_MAIN_THREAD_MS. These are meant to be used by
  * IOThreadAutoTimer which relies on _MAIN_THREAD_MS histogram being
  * "+ 1" away from MOZ_SQLITE_(NAME)_MS.
  */