bug 868441 Bypass Cache when lock held too long r=novotny
authorPatrick McManus <mcmanus@ducksong.com>
Sun, 12 May 2013 10:01:13 -0400
changeset 131658 e1eb29a56dab37ba0fe5e7f8f2eb778ae772c88d
parent 131657 87fc70f25ef4fbf7513f83b5db6531390d0fbfbb
child 131659 b7c8751945bbfb1cabe92d49f2ef28721d5a078e
push id27926
push usermcmanus@ducksong.com
push dateSun, 12 May 2013 14:01:26 +0000
treeherdermozilla-inbound@e1eb29a56dab [default view] [failures only]
perfherder[talos] [build metrics] [platform microbench] (compared to previous push)
reviewersnovotny
bugs868441
milestone23.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 868441 Bypass Cache when lock held too long r=novotny
modules/libpref/src/init/all.js
netwerk/cache/nsCacheService.cpp
netwerk/cache/nsCacheService.h
netwerk/cache/nsICacheService.idl
netwerk/protocol/http/nsHttpChannel.cpp
netwerk/protocol/http/nsHttpChannel.h
netwerk/protocol/http/nsHttpHandler.cpp
netwerk/protocol/http/nsHttpHandler.h
--- a/modules/libpref/src/init/all.js
+++ b/modules/libpref/src/init/all.js
@@ -994,16 +994,20 @@ pref("network.http.speculative-parallel-
 // Whether or not to block requests for non head js/css items (e.g. media)
 // while those elements load.
 pref("network.http.rendering-critical-requests-prioritization", true);
 
 // Disable IPv6 for backup connections to workaround problems about broken
 // IPv6 connectivity.
 pref("network.http.fast-fallback-to-IPv4", true);
 
+// The maximum amount of time the cache session lock can be held
+// before a new transaction bypasses the cache. In milliseconds.
+pref("network.http.bypass-cachelock-threshold", 250);
+
 // Try and use SPDY when using SSL
 pref("network.http.spdy.enabled", true);
 pref("network.http.spdy.enabled.v2", true);
 pref("network.http.spdy.enabled.v3", true);
 pref("network.http.spdy.chunk-size", 4096);
 pref("network.http.spdy.timeout", 180);
 pref("network.http.spdy.coalesce-hostnames", true);
 pref("network.http.spdy.use-alternate-protocol", true);
--- a/netwerk/cache/nsCacheService.cpp
+++ b/netwerk/cache/nsCacheService.cpp
@@ -1066,22 +1066,23 @@ private:
     nsCOMPtr<nsIThread>   mThread;
 };
 
 /******************************************************************************
  * nsCacheService
  *****************************************************************************/
 nsCacheService *   nsCacheService::gService = nullptr;
 
-NS_IMPL_THREADSAFE_ISUPPORTS1(nsCacheService, nsICacheService)
+NS_IMPL_THREADSAFE_ISUPPORTS2(nsCacheService, nsICacheService, nsICacheServiceInternal)
 
 nsCacheService::nsCacheService()
     : mObserver(nullptr),
       mLock("nsCacheService.mLock"),
       mCondVar(mLock, "nsCacheService.mCondVar"),
+      mTimeStampLock("nsCacheService.mTimeStampLock"),
       mInitialized(false),
       mClearingEntries(false),
       mEnableMemoryDevice(true),
       mEnableDiskDevice(true),
       mMemoryDevice(nullptr),
       mDiskDevice(nullptr),
       mOfflineDevice(nullptr),
       mTotalEntries(0),
@@ -1523,16 +1524,34 @@ NS_IMETHODIMP nsCacheService::GetCacheIO
 
     if (!NS_IsMainThread()) {
         Unlock();
     }
 
     return rv;
 }
 
+/* nsICacheServiceInternal
+ * readonly attribute double lockHeldTime;
+*/
+NS_IMETHODIMP nsCacheService::GetLockHeldTime(double *aLockHeldTime)
+{
+    MutexAutoLock lock(mTimeStampLock);
+
+    if (mLockAcquiredTimeStamp.IsNull()) {
+        *aLockHeldTime = 0.0;
+    }
+    else {
+        *aLockHeldTime = 
+            (TimeStamp::Now() - mLockAcquiredTimeStamp).ToMilliseconds();
+    }
+
+    return NS_OK;
+}
+
 /**
  * Internal Methods
  */
 nsresult
 nsCacheService::CreateDiskDevice()
 {
     if (!mInitialized)      return NS_ERROR_NOT_AVAILABLE;
     if (!mEnableDiskDevice) return NS_ERROR_NOT_AVAILABLE;
@@ -2593,16 +2612,30 @@ nsCacheService::OnDataSizeChange(nsCache
 {
     nsCacheDevice * device = gService->EnsureEntryHasDevice(entry);
     if (!device)  return  NS_ERROR_UNEXPECTED;
 
     return device->OnDataSizeChange(entry, deltaSize);
 }
 
 void
+nsCacheService::LockAcquired()
+{
+    MutexAutoLock lock(mTimeStampLock);
+    mLockAcquiredTimeStamp = TimeStamp::Now();
+}
+
+void
+nsCacheService::LockReleased()
+{
+    MutexAutoLock lock(mTimeStampLock);
+    mLockAcquiredTimeStamp = TimeStamp();
+}
+
+void
 nsCacheService::Lock(mozilla::Telemetry::ID mainThreadLockerID)
 {
     mozilla::Telemetry::ID lockerID;
     mozilla::Telemetry::ID generalID;
 
     if (NS_IsMainThread()) {
         lockerID = mainThreadLockerID;
         generalID = mozilla::Telemetry::CACHE_SERVICE_LOCK_WAIT_MAINTHREAD_2;
@@ -2610,16 +2643,17 @@ nsCacheService::Lock(mozilla::Telemetry:
         lockerID = mozilla::Telemetry::HistogramCount;
         generalID = mozilla::Telemetry::CACHE_SERVICE_LOCK_WAIT_2;
     }
 
     TimeStamp start(TimeStamp::Now());
     MOZ_EVENT_TRACER_WAIT(nsCacheService::gService, "net::cache::lock");
 
     gService->mLock.Lock();
+    gService->LockAcquired();
 
     TimeStamp stop(TimeStamp::Now());
     MOZ_EVENT_TRACER_EXEC(nsCacheService::gService, "net::cache::lock");
 
     // Telemetry isn't thread safe on its own, but this is OK because we're
     // protecting it with the cache lock. 
     if (lockerID != mozilla::Telemetry::HistogramCount) {
         mozilla::Telemetry::AccumulateTimeDelta(lockerID, start, stop);
@@ -2630,16 +2664,17 @@ nsCacheService::Lock(mozilla::Telemetry:
 void
 nsCacheService::Unlock()
 {
     gService->mLock.AssertCurrentThreadOwns();
 
     nsTArray<nsISupports*> doomed;
     doomed.SwapElements(gService->mDoomedObjects);
 
+    gService->LockReleased();
     gService->mLock.Unlock();
 
     MOZ_EVENT_TRACER_DONE(nsCacheService::gService, "net::cache::lock");
 
     for (uint32_t i = 0; i < doomed.Length(); ++i)
         doomed[i]->Release();
 }
 
--- a/netwerk/cache/nsCacheService.h
+++ b/netwerk/cache/nsCacheService.h
@@ -56,21 +56,22 @@ private:
     nsICacheListener *mListener;
     nsresult          mStatus;
 };
 
 /******************************************************************************
  *  nsCacheService
  ******************************************************************************/
 
-class nsCacheService : public nsICacheService
+class nsCacheService : public nsICacheServiceInternal
 {
 public:
     NS_DECL_ISUPPORTS
     NS_DECL_NSICACHESERVICE
+    NS_DECL_NSICACHESERVICEINTERNAL
 
     nsCacheService();
     virtual ~nsCacheService();
 
     // Define a Create method to be used with a factory:
     static nsresult
     Create(nsISupports* outer, const nsIID& iid, void* *result);
 
@@ -234,16 +235,18 @@ private:
     friend class nsCacheEntryDescriptor;
 
     /**
      * Internal Methods
      */
 
     static void      Lock(::mozilla::Telemetry::ID mainThreadLockerID);
     static void      Unlock();
+    void             LockAcquired();
+    void             LockReleased();
 
     nsresult         CreateDiskDevice();
     nsresult         CreateOfflineDevice();
     nsresult         CreateCustomOfflineDevice(nsIFile *aProfileDir,
                                                int32_t aQuota,
                                                nsOfflineCacheDevice **aDevice);
     nsresult         CreateMemoryDevice();
 
@@ -319,16 +322,19 @@ private:
 
     nsCOMPtr<mozIStorageService>    mStorageService;
 
     nsCacheProfilePrefObserver *    mObserver;
 
     mozilla::Mutex                  mLock;
     mozilla::CondVar                mCondVar;
 
+    mozilla::Mutex                  mTimeStampLock;
+    mozilla::TimeStamp              mLockAcquiredTimeStamp;
+
     nsCOMPtr<nsIThread>             mCacheIOThread;
 
     nsTArray<nsISupports*>          mDoomedObjects;
     nsCOMPtr<nsITimer>              mSmartSizeTimer;
 
     bool                            mInitialized;
     bool                            mClearingEntries;
 
--- a/netwerk/cache/nsICacheService.idl
+++ b/netwerk/cache/nsICacheService.idl
@@ -62,8 +62,24 @@ interface nsICacheService : nsISupports
 %{C++
 /**
  * Observer service notification that is sent when
  * nsICacheService::evictEntries() or nsICacheSession::evictEntries()
  * is called.
  */
 #define NS_CACHESERVICE_EMPTYCACHE_TOPIC_ID "cacheservice:empty-cache"
 %}
+
+[scriptable, builtinclass, uuid(d0fc8d38-db80-4928-bf1c-b0085ddfa9dc)]
+interface nsICacheServiceInternal : nsICacheService
+{
+    /**
+     * This is an internal interface. It changes so frequently that it probably
+     * went away while you were reading this.
+     */
+
+    /**
+     * Milliseconds for which the service lock has been held. 0 if unlocked.
+     */
+    readonly attribute double lockHeldTime;
+};
+
+
--- a/netwerk/protocol/http/nsHttpChannel.cpp
+++ b/netwerk/protocol/http/nsHttpChannel.cpp
@@ -402,17 +402,17 @@ nsHttpChannel::Connect()
     SpeculativeConnect();
 
     // Don't allow resuming when cache must be used
     if (mResuming && (mLoadFlags & LOAD_ONLY_FROM_CACHE)) {
         LOG(("Resuming from cache is not supported yet"));
         return NS_ERROR_DOCUMENT_NOT_CACHED;
     }
 
-    if (!gHttpHandler->UseCache())
+    if (ShouldSkipCache())
         return ContinueConnect();
 
     // open a cache entry for this channel...
     rv = OpenCacheEntry(usingSSL);
 
     // do not continue if asyncOpenCacheEntry is in progress
     if (mOnCacheEntryAvailableCallback) {
         NS_ASSERTION(NS_SUCCEEDED(rv), "Unexpected state");
@@ -5993,16 +5993,62 @@ nsHttpChannel::UpdateAggregateCallbacks(
     }
     nsCOMPtr<nsIInterfaceRequestor> callbacks;
     NS_NewNotificationCallbacksAggregation(mCallbacks, mLoadGroup,
                                            NS_GetCurrentThread(),
                                            getter_AddRefs(callbacks));
     mTransaction->SetSecurityCallbacks(callbacks);
 }
 
+bool
+nsHttpChannel::ShouldSkipCache()
+{
+    if (!gHttpHandler->UseCache())
+        return true;
+
+    if (mLoadFlags & LOAD_ONLY_FROM_CACHE)
+        return false;
+    
+    if (mChooseApplicationCache || (mLoadFlags & LOAD_CHECK_OFFLINE_CACHE))
+        return false;
+
+    TimeStamp cacheSkippedUntil = gHttpHandler->GetCacheSkippedUntil();
+    if (!cacheSkippedUntil.IsNull()) {
+        TimeStamp now = TimeStamp::Now();
+        if (now < cacheSkippedUntil) {
+            LOG(("channel=%p Cache bypassed because of dampener\n", this));
+            return true;
+        }
+        LOG(("channel=%p Cache dampener released\n", this));
+        gHttpHandler->ClearCacheSkippedUntil();
+    }
+
+    // If the cache lock has been held for a long time then just
+    // bypass the cache instead of getting in that queue.
+    nsCOMPtr<nsICacheService> cacheService =
+        do_GetService(NS_CACHESERVICE_CONTRACTID);
+    nsCOMPtr<nsICacheServiceInternal> internalCacheService =
+        do_QueryInterface(cacheService);
+    if (!internalCacheService)
+        return false;
+    
+    double timeLocked;
+    if (NS_FAILED(internalCacheService->GetLockHeldTime(&timeLocked)))
+        return false;
+    
+    if (timeLocked <= gHttpHandler->BypassCacheLockThreshold())
+        return false;
+
+    LOG(("Cache dampener installed because service lock held too long [%fms]\n",
+         timeLocked));
+    cacheSkippedUntil = TimeStamp::Now() + TimeDuration::FromSeconds(60);
+    gHttpHandler->SetCacheSkippedUntil(cacheSkippedUntil);
+    return true;
+}
+
 NS_IMETHODIMP
 nsHttpChannel::SetLoadGroup(nsILoadGroup *aLoadGroup)
 {
     MOZ_ASSERT(NS_IsMainThread(), "Wrong thread.");
 
     nsresult rv = HttpBaseChannel::SetLoadGroup(aLoadGroup);
     if (NS_SUCCEEDED(rv)) {
         UpdateAggregateCallbacks();
--- a/netwerk/protocol/http/nsHttpChannel.h
+++ b/netwerk/protocol/http/nsHttpChannel.h
@@ -275,16 +275,19 @@ private:
                rv == NS_ERROR_UNKNOWN_PROTOCOL      ||
                rv == NS_ERROR_MALFORMED_URI;
     }
 
     // Create a aggregate set of the current notification callbacks
     // and ensure the transaction is updated to use it.
     void UpdateAggregateCallbacks();
 
+    // Disk cache is skipped for some requests when it is behaving slowly
+    bool ShouldSkipCache();
+
 private:
     nsCOMPtr<nsISupports>             mSecurityInfo;
     nsCOMPtr<nsICancelable>           mProxyRequest;
 
     nsRefPtr<nsInputStreamPump>       mTransactionPump;
     nsRefPtr<nsHttpTransaction>       mTransaction;
 
     uint64_t                          mLogicalOffset;
--- a/netwerk/protocol/http/nsHttpHandler.cpp
+++ b/netwerk/protocol/http/nsHttpHandler.cpp
@@ -183,16 +183,17 @@ nsHttpHandler::nsHttpHandler()
     , mCoalesceSpdy(true)
     , mUseAlternateProtocol(false)
     , mSpdyPersistentSettings(false)
     , mSpdySendingChunkSize(ASpdySession::kSendingChunkSize)
     , mSpdySendBufferSize(ASpdySession::kTCPSendBufferSize)
     , mSpdyPingThreshold(PR_SecondsToInterval(58))
     , mSpdyPingTimeout(PR_SecondsToInterval(8))
     , mConnectTimeout(90000)
+    , mBypassCacheLockThreshold(250.0)
     , mParallelSpeculativeConnectLimit(6)
     , mRequestTokenBucketEnabled(true)
     , mRequestTokenBucketMinParallelism(6)
     , mRequestTokenBucketHz(100)
     , mRequestTokenBucketBurst(32)
     , mCritialRequestPrioritization(true)
 {
 #if defined(PR_LOGGING)
@@ -1170,16 +1171,26 @@ nsHttpHandler::PrefsChanged(nsIPrefBranc
     // established
     if (PREF_CHANGED(HTTP_PREF("connection-timeout"))) {
         rv = prefs->GetIntPref(HTTP_PREF("connection-timeout"), &val);
         if (NS_SUCCEEDED(rv))
             // the pref is in seconds, but the variable is in milliseconds
             mConnectTimeout = clamped(val, 1, 0xffff) * PR_MSEC_PER_SEC;
     }
 
+    // The maximum amount of time the cache session lock can be held
+    // before a new transaction bypasses the cache. In milliseconds.
+    if (PREF_CHANGED(HTTP_PREF("bypass-cachelock-threshold"))) {
+        rv = prefs->GetIntPref(HTTP_PREF("bypass-cachelock-threshold"), &val);
+        if (NS_SUCCEEDED(rv))
+            // the pref and variable are both in milliseconds
+            mBypassCacheLockThreshold =
+                static_cast<double>(clamped(val, 0, 0x7ffffff));
+    }
+
     // The maximum number of current global half open sockets allowable
     // for starting a new speculative connection.
     if (PREF_CHANGED(HTTP_PREF("speculative-parallel-limit"))) {
         rv = prefs->GetIntPref(HTTP_PREF("speculative-parallel-limit"), &val);
         if (NS_SUCCEEDED(rv))
             mParallelSpeculativeConnectLimit = (uint32_t) clamped(val, 0, 1024);
     }
 
--- a/netwerk/protocol/http/nsHttpHandler.h
+++ b/netwerk/protocol/http/nsHttpHandler.h
@@ -101,16 +101,17 @@ public:
     bool           UseSpdyPersistentSettings() { return mSpdyPersistentSettings; }
     uint32_t       SpdySendingChunkSize() { return mSpdySendingChunkSize; }
     uint32_t       SpdySendBufferSize()      { return mSpdySendBufferSize; }
     PRIntervalTime SpdyPingThreshold() { return mSpdyPingThreshold; }
     PRIntervalTime SpdyPingTimeout() { return mSpdyPingTimeout; }
     uint32_t       ConnectTimeout()  { return mConnectTimeout; }
     uint32_t       ParallelSpeculativeConnectLimit() { return mParallelSpeculativeConnectLimit; }
     bool           CritialRequestPrioritization() { return mCritialRequestPrioritization; }
+    double         BypassCacheLockThreshold() { return mBypassCacheLockThreshold; }
 
     bool           UseRequestTokenBucket() { return mRequestTokenBucketEnabled; }
     uint16_t       RequestTokenBucketMinParallelism() { return mRequestTokenBucketMinParallelism; }
     uint32_t       RequestTokenBucketHz() { return mRequestTokenBucketHz; }
     uint32_t       RequestTokenBucketBurst() {return mRequestTokenBucketBurst; }
 
     bool           PromptTempRedirect()      { return mPromptTempRedirect; }
 
@@ -266,16 +267,23 @@ public:
     bool Active() { return mHandlerActive; }
 
     static void GetCacheSessionNameForStoragePolicy(
             nsCacheStoragePolicy storagePolicy,
             bool isPrivate,
             uint32_t appId,
             bool inBrowser,
             nsACString& sessionName);
+
+    // When the disk cache is responding slowly its use is suppressed
+    // for 1 minute for most requests. Callable from main thread only.
+    mozilla::TimeStamp GetCacheSkippedUntil() { return mCacheSkippedUntil; }
+    void SetCacheSkippedUntil(mozilla::TimeStamp arg) { mCacheSkippedUntil = arg; }
+    void ClearCacheSkippedUntil() { mCacheSkippedUntil = mozilla::TimeStamp(); }
+
 private:
 
     //
     // Useragent/prefs helper methods
     //
     void     BuildUserAgent();
     void     InitUserAgentComponents();
     void     PrefsChanged(nsIPrefBranch *prefs, const char *pref);
@@ -412,31 +420,39 @@ private:
     uint32_t       mSpdySendBufferSize;
     PRIntervalTime mSpdyPingThreshold;
     PRIntervalTime mSpdyPingTimeout;
 
     // The maximum amount of time to wait for socket transport to be
     // established. In milliseconds.
     uint32_t       mConnectTimeout;
 
+    // The maximum amount of time the nsICacheSession lock can be held
+    // before a new transaction bypasses the cache. In milliseconds.
+    double         mBypassCacheLockThreshold;
+
     // The maximum number of current global half open sockets allowable
     // when starting a new speculative connection.
     uint32_t       mParallelSpeculativeConnectLimit;
 
     // For Rate Pacing of HTTP/1 requests through a netwerk/base/src/EventTokenBucket
     // Active requests <= *MinParallelism are not subject to the rate pacing
     bool           mRequestTokenBucketEnabled;
     uint16_t       mRequestTokenBucketMinParallelism;
     uint32_t       mRequestTokenBucketHz;  // EventTokenBucket HZ
     uint32_t       mRequestTokenBucketBurst; // EventTokenBucket Burst
 
     // Whether or not to block requests for non head js/css items (e.g. media)
     // while those elements load.
     bool           mCritialRequestPrioritization;
 
+    // When the disk cache is responding slowly its use is suppressed
+    // for 1 minute for most requests.
+    mozilla::TimeStamp                mCacheSkippedUntil;
+
 private:
     // For Rate Pacing Certain Network Events. Only assign this pointer on
     // socket thread.
     void MakeNewRequestTokenBucket();
     nsRefPtr<mozilla::net::EventTokenBucket> mRequestTokenBucket;
 
 public:
     // Socket thread only