bug 729736 - runtime experiment with different spdy ping thresholds r=honzab
authorPatrick McManus <mcmanus@ducksong.com>
Mon, 27 Feb 2012 10:32:09 -0500
changeset 87845 483efb99bf3fbad5980870bee93d234817de59bb
parent 87844 75deec1f1a7bcd502b5679c15bd3b9cde6872b07
child 87846 54ff182dd2f3438cc6ab3bdb08e05c10f543f0a1
push id22160
push usermbrubeck@mozilla.com
push dateTue, 28 Feb 2012 17:21:33 +0000
treeherdermozilla-central@dde4e0089a18 [default view] [failures only]
perfherder[talos] [build metrics] [platform microbench] (compared to previous push)
reviewershonzab
bugs729736
milestone13.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 729736 - runtime experiment with different spdy ping thresholds r=honzab
modules/libpref/src/init/all.js
netwerk/base/src/nsSocketTransportService2.cpp
netwerk/protocol/http/SpdySession.cpp
netwerk/protocol/http/SpdySession.h
netwerk/protocol/http/nsHttpHandler.cpp
netwerk/protocol/http/nsHttpHandler.h
toolkit/components/telemetry/TelemetryHistograms.h
--- a/modules/libpref/src/init/all.js
+++ b/modules/libpref/src/init/all.js
@@ -673,16 +673,21 @@ pref("security.fileuri.strict_origin_pol
 // If there is ever a security firedrill that requires
 // us to block certian ports global, this is the pref 
 // to use.  Is is a comma delimited list of port numbers
 // for example:
 //   pref("network.security.ports.banned", "1,2,3,4,5");
 // prevents necko connecting to ports 1-5 unless the protocol
 // overrides.
 
+// Allow necko to do A/B testing. Will generally only happen if
+// telemetry is also enabled as otherwise there is no way to report
+// the results
+pref("network.allow-experiments", true);
+
 // Default action for unlisted external protocol handlers
 pref("network.protocol-handler.external-default", true);      // OK to load
 pref("network.protocol-handler.warn-external-default", true); // warn before load
 
 // Prevent using external protocol handlers for these schemes
 pref("network.protocol-handler.external.hcp", false);
 pref("network.protocol-handler.external.vbscript", false);
 pref("network.protocol-handler.external.javascript", false);
--- a/netwerk/base/src/nsSocketTransportService2.cpp
+++ b/netwerk/base/src/nsSocketTransportService2.cpp
@@ -627,16 +627,19 @@ nsSocketTransportService::Run()
     mPollList[0].out_flags = 0;
 
     nsIThread *thread = NS_GetCurrentThread();
 
     // hook ourselves up to observe event processing for this thread
     nsCOMPtr<nsIThreadInternal> threadInt = do_QueryInterface(thread);
     threadInt->SetObserver(this);
 
+    // make sure the pseudo random number generator is seeded on this thread
+    srand(PR_Now());
+
     for (;;) {
         bool pendingEvents = false;
         thread->HasPendingEvents(&pendingEvents);
 
         do {
             // If there are pending events for this thread then
             // DoPollIteration() should service the network without blocking.
             DoPollIteration(!pendingEvents);
--- a/netwerk/protocol/http/SpdySession.cpp
+++ b/netwerk/protocol/http/SpdySession.cpp
@@ -88,17 +88,18 @@ SpdySession::SpdySession(nsAHttpTransact
     mMaxConcurrent(kDefaultMaxConcurrent),
     mConcurrent(0),
     mServerPushedResources(0),
     mOutputQueueSize(kDefaultQueueSize),
     mOutputQueueUsed(0),
     mOutputQueueSent(0),
     mLastReadEpoch(PR_IntervalNow()),
     mPingSentEpoch(0),
-    mNextPingID(1)
+    mNextPingID(1),
+    mPingThresholdExperiment(false)
 {
   NS_ABORT_IF_FALSE(PR_GetCurrentThread() == gSocketThread, "wrong thread");
 
   LOG3(("SpdySession::SpdySession %p transaction 1 = %p",
         this, aHttpTransaction));
   
   mStreamIDHash.Init();
   mStreamTransactionHash.Init();
@@ -106,16 +107,51 @@ SpdySession::SpdySession(nsAHttpTransact
   mInputFrameBuffer = new char[mInputFrameBufferSize];
   mDecompressBuffer = new char[mDecompressBufferSize];
   mOutputQueueBuffer = new char[mOutputQueueSize];
   zlibInit();
   
   mSendingChunkSize = gHttpHandler->SpdySendingChunkSize();
   AddStream(aHttpTransaction, firstPriority);
   mLastDataReadEpoch = mLastReadEpoch;
+  
+  DeterminePingThreshold();
+}
+
+void
+SpdySession::DeterminePingThreshold()
+{
+  mPingThreshold = gHttpHandler->SpdyPingThreshold();
+
+  if (!mPingThreshold || !gHttpHandler->AllowExperiments())
+    return;
+
+  PRUint32 randomVal = gHttpHandler->Get32BitsOfPseudoRandom();
+  
+  // Use the lower 10 bits to select 1 in 1024 sessions for the
+  // ping threshold experiment. Somewhat less than that will actually be
+  // used because random values greater than the total http idle timeout
+  // for the session are discarded.
+  if ((randomVal & 0x3ff) != 1)  // lottery
+    return;
+  
+  randomVal = randomVal >> 10; // those bits are used up
+
+  // This session has been selected - use a random ping threshold of 10 +
+  // a random number from 0 to 255, based on the next 8 bits of the
+  // random buffer
+  PRIntervalTime randomThreshold =
+    PR_SecondsToInterval((randomVal & 0xff) + 10);
+  if (randomThreshold > gHttpHandler->IdleTimeout())
+    return;
+  
+  mPingThreshold = randomThreshold;
+  mPingThresholdExperiment = true;
+  LOG3(("SpdySession %p Ping Threshold Experimental Selection : %dsec\n",
+        this, PR_IntervalToSeconds(mPingThreshold)));
 }
 
 PLDHashOperator
 SpdySession::ShutdownEnumerator(nsAHttpTransaction *key,
                                 nsAutoPtr<SpdyStream> &stream,
                                 void *closure)
 {
   SpdySession *self = static_cast<SpdySession *>(closure);
@@ -223,34 +259,35 @@ SpdySession::IdleTime()
 }
 
 void
 SpdySession::ReadTimeoutTick(PRIntervalTime now)
 {
     NS_ABORT_IF_FALSE(PR_GetCurrentThread() == gSocketThread, "wrong thread");
     NS_ABORT_IF_FALSE(mNextPingID & 1, "Ping Counter Not Odd");
 
-    PRIntervalTime threshold = gHttpHandler->SpdyPingThreshold();
-    if (!threshold)
+    if (!mPingThreshold)
       return;
 
     LOG(("SpdySession::ReadTimeoutTick %p delta since last read %ds\n",
          this, PR_IntervalToSeconds(now - mLastReadEpoch)));
 
-    if ((now - mLastReadEpoch) < threshold) {
+    if ((now - mLastReadEpoch) < mPingThreshold) {
       // recent activity means ping is not an issue
-      mPingSentEpoch = 0;
+      if (mPingSentEpoch)
+        ClearPing(true);
       return;
     }
 
     if (mPingSentEpoch) {
       LOG(("SpdySession::ReadTimeoutTick %p handle outstanding ping\n"));
       if ((now - mPingSentEpoch) >= gHttpHandler->SpdyPingTimeout()) {
         LOG(("SpdySession::ReadTimeoutTick %p Ping Timer Exhaustion\n",
              this));
+        ClearPing(false);
         Close(NS_ERROR_NET_TIMEOUT);
       }
       return;
     }
     
     LOG(("SpdySession::ReadTimeoutTick %p generating ping 0x%x\n",
          this, mNextPingID));
 
@@ -268,16 +305,37 @@ SpdySession::ReadTimeoutTick(PRIntervalT
 
     if (mNextPingID == 0xffffffff) {
       LOG(("SpdySession::ReadTimeoutTick %p "
            "ping ids exhausted marking goaway\n", this));
       mShouldGoAway = true;
     }
 }
 
+void
+SpdySession::ClearPing(bool pingOK)
+{
+  mPingSentEpoch = 0;
+
+  if (mPingThresholdExperiment) {
+    LOG3(("SpdySession::ClearPing %p mPingThresholdExperiment %dsec %s\n",
+          this, PR_IntervalToSeconds(mPingThreshold),
+          pingOK ? "pass" :"fail"));
+
+    if (pingOK)
+      Telemetry::Accumulate(Telemetry::SPDY_PING_EXPERIMENT_PASS,
+                            PR_IntervalToSeconds(mPingThreshold));
+    else
+      Telemetry::Accumulate(Telemetry::SPDY_PING_EXPERIMENT_FAIL,
+                            PR_IntervalToSeconds(mPingThreshold));
+    mPingThreshold = gHttpHandler->SpdyPingThreshold();
+    mPingThresholdExperiment = false;
+  }
+}
+
 PRUint32
 SpdySession::RegisterStreamID(SpdyStream *stream)
 {
   NS_ABORT_IF_FALSE(PR_GetCurrentThread() == gSocketThread, "wrong thread");
 
   LOG3(("SpdySession::RegisterStreamID session=%p stream=%p id=0x%X "
         "concurrent=%d",this, stream, mNextStreamID, mConcurrent));
 
@@ -1182,17 +1240,17 @@ SpdySession::HandlePing(SpdySession *sel
 
   PRUint32 pingID =
     PR_ntohl(reinterpret_cast<PRUint32 *>(self->mInputFrameBuffer.get())[2]);
 
   LOG3(("SpdySession::HandlePing %p PING ID 0x%X.", self, pingID));
 
   if (pingID & 0x01) {
     // presumably a reply to our timeout ping
-    self->mPingSentEpoch = 0;
+    self->ClearPing(true);
   }
   else {
     // Servers initiate even numbered pings, go ahead and echo it back
     self->GeneratePing(pingID);
   }
     
   self->ResetDownstreamState();
   return NS_OK;
--- a/netwerk/protocol/http/SpdySession.h
+++ b/netwerk/protocol/http/SpdySession.h
@@ -183,26 +183,28 @@ private:
     BUFFERING_FRAME_HEADER,
     BUFFERING_CONTROL_FRAME,
     PROCESSING_DATA_FRAME,
     DISCARDING_DATA_FRAME,
     PROCESSING_CONTROL_SYN_REPLY,
     PROCESSING_CONTROL_RST_STREAM
   };
 
+  void        DeterminePingThreshold();
   nsresult    HandleSynReplyForValidStream();
   PRUint32    GetWriteQueueSize();
   void        ChangeDownstreamState(enum stateType);
   void        ResetDownstreamState();
   nsresult    DownstreamUncompress(char *, PRUint32);
   void        zlibInit();
   nsresult    FindHeader(nsCString, nsDependentCSubstring &);
   nsresult    ConvertHeaders(nsDependentCSubstring &,
                              nsDependentCSubstring &);
   void        GeneratePing(PRUint32);
+  void        ClearPing(bool);
   void        GenerateRstStream(PRUint32, PRUint32);
   void        GenerateGoAway();
   void        CleanupStream(SpdyStream *, nsresult, rstReason);
 
   void        SetWriteCallbacks();
   void        FlushOutputQueue();
 
   bool        RoomForMoreConcurrent();
@@ -340,17 +342,19 @@ private:
   // coalesced together here. This results in larger writes to the SSL layer.
   // The buffer is not dynamically grown to accomodate stream writes, but
   // does expand to accept infallible session wide frames like GoAway and RST.
   PRUint32             mOutputQueueSize;
   PRUint32             mOutputQueueUsed;
   PRUint32             mOutputQueueSent;
   nsAutoArrayPtr<char> mOutputQueueBuffer;
 
+  PRIntervalTime       mPingThreshold;
   PRIntervalTime       mLastReadEpoch;     // used for ping timeouts
   PRIntervalTime       mLastDataReadEpoch; // used for IdleTime()
   PRIntervalTime       mPingSentEpoch;
   PRUint32             mNextPingID;
+  bool                 mPingThresholdExperiment;
 };
 
 }} // namespace mozilla::net
 
 #endif // mozilla_net_SpdySession_h
--- a/netwerk/protocol/http/nsHttpHandler.cpp
+++ b/netwerk/protocol/http/nsHttpHandler.cpp
@@ -123,16 +123,18 @@ static NS_DEFINE_CID(kSocketProviderServ
 #define UA_SPARE_PLATFORM
 #endif
 
 #define HTTP_PREF_PREFIX        "network.http."
 #define INTL_ACCEPT_LANGUAGES   "intl.accept_languages"
 #define NETWORK_ENABLEIDN       "network.enableIDN"
 #define BROWSER_PREF_PREFIX     "browser.cache."
 #define DONOTTRACK_HEADER_ENABLED "privacy.donottrackheader.enabled"
+#define TELEMETRY_ENABLED        "toolkit.telemetry.enabled"
+#define ALLOW_EXPERIMENTS        "network.allow-experiments"
 
 #define UA_PREF(_pref) UA_PREF_PREFIX _pref
 #define HTTP_PREF(_pref) HTTP_PREF_PREFIX _pref
 #define BROWSER_PREF(_pref) BROWSER_PREF_PREFIX _pref
 
 #define NS_HTTP_PROTOCOL_FLAGS (URI_STD | ALLOWS_PROXY | ALLOWS_PROXY_HTTP | URI_LOADABLE_BY_ANYONE)
 
 //-----------------------------------------------------------------------------
@@ -195,16 +197,18 @@ nsHttpHandler::nsHttpHandler()
     , mLegacyAppVersion("5.0")
     , mProduct("Gecko")
     , mUserAgentIsDirty(true)
     , mUseCache(true)
     , mPromptTempRedirect(true)
     , mSendSecureXSiteReferrer(true)
     , mEnablePersistentHttpsCaching(false)
     , mDoNotTrackEnabled(false)
+    , mTelemetryEnabled(false)
+    , mAllowExperiments(true)
     , mEnableSpdy(false)
     , mCoalesceSpdy(true)
     , mUseAlternateProtocol(false)
     , mSpdySendingChunkSize(SpdySession::kSendingChunkSize)
     , mSpdyPingThreshold(PR_SecondsToInterval(44))
     , mSpdyPingTimeout(PR_SecondsToInterval(8))
 {
 #if defined(PR_LOGGING)
@@ -263,16 +267,17 @@ nsHttpHandler::Init()
     nsCOMPtr<nsIPrefBranch> prefBranch = do_GetService(NS_PREFSERVICE_CONTRACTID);
     if (prefBranch) {
         prefBranch->AddObserver(HTTP_PREF_PREFIX, this, true);
         prefBranch->AddObserver(UA_PREF_PREFIX, this, true);
         prefBranch->AddObserver(INTL_ACCEPT_LANGUAGES, this, true); 
         prefBranch->AddObserver(NETWORK_ENABLEIDN, this, true);
         prefBranch->AddObserver(BROWSER_PREF("disk_cache_ssl"), this, true);
         prefBranch->AddObserver(DONOTTRACK_HEADER_ENABLED, this, true);
+        prefBranch->AddObserver(TELEMETRY_ENABLED, this, true);
 
         PrefsChanged(prefBranch, nsnull);
     }
 
     mMisc.AssignLiteral("rv:" MOZILLA_UAVERSION);
 
     nsCOMPtr<nsIXULAppInfo> appInfo =
         do_GetService("@mozilla.org/xre/app-info;1");
@@ -531,16 +536,37 @@ nsHttpHandler::GetCookieService()
 
 nsresult 
 nsHttpHandler::GetIOService(nsIIOService** result)
 {
     NS_ADDREF(*result = mIOService);
     return NS_OK;
 }
 
+PRUint32
+nsHttpHandler::Get32BitsOfPseudoRandom()
+{
+    // only confirm rand seeding on socket thread
+    NS_ABORT_IF_FALSE(PR_GetCurrentThread() == gSocketThread, "wrong thread");
+
+    // rand() provides different amounts of PRNG on different platforms.
+    // 15 or 31 bits are common amounts.
+
+    PR_STATIC_ASSERT(RAND_MAX >= 0xfff);
+    
+#if RAND_MAX < 0xffffU
+    return ((PRUint16) rand() << 20) |
+            (((PRUint16) rand() & 0xfff) << 8) |
+            ((PRUint16) rand() & 0xff);
+#elif RAND_MAX < 0xffffffffU
+    return ((PRUint16) rand() << 16) | ((PRUint16) rand() & 0xffff);
+#else
+    return (PRUint32) rand();
+#endif
+}
 
 void
 nsHttpHandler::NotifyObservers(nsIHttpChannel *chan, const char *event)
 {
     LOG(("nsHttpHandler::NotifyObservers [chan=%x event=\"%s\"]\n", chan, event));
     if (mObserverService)
         mObserverService->NotifyObservers(chan, event, nsnull);
 }
@@ -1182,16 +1208,40 @@ nsHttpHandler::PrefsChanged(nsIPrefBranc
     if (PREF_CHANGED(DONOTTRACK_HEADER_ENABLED)) {
         cVar = false;
         rv = prefs->GetBoolPref(DONOTTRACK_HEADER_ENABLED, &cVar);
         if (NS_SUCCEEDED(rv)) {
             mDoNotTrackEnabled = cVar;
         }
     }
 
+    //
+    // Telemetry
+    //
+
+    if (PREF_CHANGED(TELEMETRY_ENABLED)) {
+        cVar = false;
+        rv = prefs->GetBoolPref(TELEMETRY_ENABLED, &cVar);
+        if (NS_SUCCEEDED(rv)) {
+            mTelemetryEnabled = cVar;
+        }
+    }
+
+    //
+    // network.allow-experiments
+    //
+
+    if (PREF_CHANGED(ALLOW_EXPERIMENTS)) {
+        cVar = true;
+        rv = prefs->GetBoolPref(ALLOW_EXPERIMENTS, &cVar);
+        if (NS_SUCCEEDED(rv)) {
+            mAllowExperiments = cVar;
+        }
+    }
+
 #undef PREF_CHANGED
 #undef MULTI_PREF_CHANGED
 }
 
 /**
  *  Allocates a C string into that contains a ISO 639 language list
  *  notated with HTTP "q" values for output with a HTTP Accept-Language
  *  header. Previous q values will be stripped because the order of
--- a/netwerk/protocol/http/nsHttpHandler.h
+++ b/netwerk/protocol/http/nsHttpHandler.h
@@ -107,16 +107,18 @@ public:
     nsIIDNService *IDNConverter()            { return mIDNConverter; }
     PRUint32       PhishyUserPassLength()    { return mPhishyUserPassLength; }
     PRUint8        GetQoSBits()              { return mQoSBits; }
     PRUint16       GetIdleSynTimeout()       { return mIdleSynTimeout; }
     bool           FastFallbackToIPv4()      { return mFastFallbackToIPv4; }
     PRUint32       MaxSocketCount();
 
     bool           IsPersistentHttpsCachingEnabled() { return mEnablePersistentHttpsCaching; }
+    bool           IsTelemetryEnabled() { return mTelemetryEnabled; }
+    bool           AllowExperiments() { return mTelemetryEnabled && mAllowExperiments; }
 
     bool           IsSpdyEnabled() { return mEnableSpdy; }
     bool           CoalesceSpdy() { return mCoalesceSpdy; }
     bool           UseAlternateProtocol() { return mUseAlternateProtocol; }
     PRUint32       SpdySendingChunkSize() { return mSpdySendingChunkSize; }
     PRIntervalTime SpdyPingThreshold() { return mSpdyPingThreshold; }
     PRIntervalTime SpdyPingTimeout() { return mSpdyPingTimeout; }
 
@@ -186,16 +188,19 @@ public:
     // The HTTP handler caches pointers to specific XPCOM services, and
     // provides the following helper routines for accessing those services:
     //
     nsresult GetStreamConverterService(nsIStreamConverterService **);
     nsresult GetIOService(nsIIOService** service);
     nsICookieService * GetCookieService(); // not addrefed
     nsIStrictTransportSecurityService * GetSTSService();
 
+    // callable from socket thread only
+    PRUint32 Get32BitsOfPseudoRandom();
+
     // Called by the channel before writing a request
     void OnModifyRequest(nsIHttpChannel *chan)
     {
         NotifyObservers(chan, NS_HTTP_ON_MODIFY_REQUEST_TOPIC);
     }
 
     // Called by the channel once headers are available
     void OnExamineResponse(nsIHttpChannel *chan)
@@ -338,16 +343,22 @@ private:
     bool           mSendSecureXSiteReferrer;
 
     // Persistent HTTPS caching flag
     bool           mEnablePersistentHttpsCaching;
 
     // For broadcasting the preference to not be tracked
     bool           mDoNotTrackEnabled;
     
+    // Whether telemetry is reported or not
+    bool           mTelemetryEnabled;
+
+    // The value of network.allow-experiments
+    bool           mAllowExperiments;
+
     // Try to use SPDY features instead of HTTP/1.1 over SSL
     bool           mEnableSpdy;
     bool           mCoalesceSpdy;
     bool           mUseAlternateProtocol;
     PRUint32       mSpdySendingChunkSize;
     PRIntervalTime mSpdyPingThreshold;
     PRIntervalTime mSpdyPingTimeout;
 };
--- a/toolkit/components/telemetry/TelemetryHistograms.h
+++ b/toolkit/components/telemetry/TelemetryHistograms.h
@@ -195,16 +195,18 @@ HISTOGRAM(SPDY_SERVER_INITIATED_STREAMS,
 HISTOGRAM(SPDY_CHUNK_RECVD, 1, 1000, 100, EXPONENTIAL,  "SPDY: Recvd Chunk Size (rounded to KB)")
 HISTOGRAM(SPDY_SYN_SIZE, 20, 20000, 50, EXPONENTIAL,  "SPDY: SYN Frame Header Size")
 HISTOGRAM(SPDY_SYN_RATIO, 1, 99, 20, LINEAR,  "SPDY: SYN Frame Header Ratio (lower better)")
 HISTOGRAM(SPDY_SYN_REPLY_SIZE, 16, 20000, 50, EXPONENTIAL,  "SPDY: SYN Reply Header Size")
 HISTOGRAM(SPDY_SYN_REPLY_RATIO, 1, 99, 20, LINEAR,  "SPDY: SYN Reply Header Ratio (lower better)")
 HISTOGRAM(SPDY_NPN_CONNECT, 0, 1, 2, BOOLEAN,  "SPDY: NPN Negotiated")
 HISTOGRAM(SPDY_NPN_JOIN, 0, 1, 2, BOOLEAN,  "SPDY: Coalesce Succeeded")
 HISTOGRAM(SPDY_KBREAD_PER_CONN, 1, 3000, 50, EXPONENTIAL, "SPDY: KB read per connection")
+HISTOGRAM(SPDY_PING_EXPERIMENT_PASS, 10, 355, 64, LINEAR, "SPDY: Ping Interval Passed")
+HISTOGRAM(SPDY_PING_EXPERIMENT_FAIL, 10, 355, 64, LINEAR, "SPDY: Ping Interval Failed")
 
 HISTOGRAM(SPDY_SETTINGS_UL_BW, 1, 10000, 100, EXPONENTIAL,  "SPDY: Settings Upload Bandwidth")
 HISTOGRAM(SPDY_SETTINGS_DL_BW, 1, 10000, 100, EXPONENTIAL,  "SPDY: Settings Download Bandwidth")
 HISTOGRAM(SPDY_SETTINGS_RTT, 1, 1000, 100, EXPONENTIAL,  "SPDY: Settings RTT")
 HISTOGRAM(SPDY_SETTINGS_MAX_STREAMS, 1, 5000, 100, EXPONENTIAL,  "SPDY: Settings Max Streams parameter")
 HISTOGRAM(SPDY_SETTINGS_CWND, 1, 500, 50, EXPONENTIAL,  "SPDY: Settings CWND (packets)")
 HISTOGRAM(SPDY_SETTINGS_RETRANS, 1, 100, 50, EXPONENTIAL,  "SPDY: Retransmission Rate")
 HISTOGRAM(SPDY_SETTINGS_IW, 1, 1000, 50, EXPONENTIAL,  "SPDY: Settings IW (rounded to KB)")