Bug 1336904 - Add timeouts for Safe Browsing updates draft
authorThomas Nguyen <tnguyen@mozilla.com>
Mon, 24 Apr 2017 17:51:06 +0800
changeset 571112 ccc0789e90a44c04e8669b0f4d9d3caf38faf0a8
parent 568509 0f5ba06c4c5959030a05cb852656d854065e2226
child 626672 3bf37d89c5753e89d3c6bbc797a31dcfb9f1a03f
push id56684
push userbmo:tnguyen@mozilla.com
push dateTue, 02 May 2017 03:35:52 +0000
bugs1336904
milestone55.0a1
Bug 1336904 - Add timeouts for Safe Browsing updates These timeouts will ensure that we don't block the Safe Browsing update thread for too long when we encounter slow or bad network conditions. MozReview-Commit-ID: AJfR193cTf8
modules/libpref/init/all.js
toolkit/components/telemetry/Histograms.json
toolkit/components/url-classifier/SBTelemetryUtils.h
toolkit/components/url-classifier/nsUrlClassifierStreamUpdater.cpp
toolkit/components/url-classifier/nsUrlClassifierStreamUpdater.h
--- a/modules/libpref/init/all.js
+++ b/modules/libpref/init/all.js
@@ -5194,16 +5194,20 @@ pref("urlclassifier.disallow_completions
 pref("urlclassifier.trackingTable", "test-track-simple,base-track-digest256");
 pref("urlclassifier.trackingWhitelistTable", "test-trackwhite-simple,mozstd-trackwhite-digest256");
 
 // The number of random entries to send with a gethash request.
 pref("urlclassifier.gethashnoise", 4);
 
 // Gethash timeout for Safebrowsing.
 pref("urlclassifier.gethash.timeout_ms", 5000);
+// Update server response timeout for Safebrowsing.
+pref("urlclassifier.update.response_timeout_ms", 5000);
+// Download update timeout for Safebrowsing.
+pref("urlclassifier.update.timeout_ms", 60000);
 
 // If an urlclassifier table has not been updated in this number of seconds,
 // a gethash request will be forced to check that the result is still in
 // the database.
 pref("urlclassifier.max-complete-age", 2700);
 
 // Name of the about: page contributed by safebrowsing to handle display of error
 // pages on phishing/malware hits.  (bug 399233)
--- a/toolkit/components/telemetry/Histograms.json
+++ b/toolkit/components/telemetry/Histograms.json
@@ -4206,16 +4206,25 @@
     "expires_in_version": "61",
     "kind": "exponential",
     "keyed": true,
     "high": 100000,
     "n_buckets": 30,
     "bug_numbers": [1336903],
     "description": "Server response time to update request (ms). Keyed by provider"
   },
+  "URLCLASSIFIER_UPDATE_TIMEOUT": {
+    "alert_emails": ["safebrowsing-telemetry@mozilla.org"],
+    "expires_in_version": "61",
+    "kind": "enumerated",
+    "keyed": true,
+    "n_values": 4,
+    "bug_numbers": [1336904],
+    "description": " Whether or not an update timed out (0 = no timeout, 1 = server respond timeout, 2 = overall timeout). Keyed by provider"
+  },
   "URLCLASSIFIER_COMPLETE_REMOTE_STATUS2": {
     "alert_emails": ["safebrowsing-telemetry@mozilla.org"],
     "expires_in_version": "never",
     "kind": "enumerated",
     "keyed": true,
     "n_values": 16,
     "bug_numbers": [1150921, 1311926],
     "description": "Server HTTP status code from remote SafeBrowsing gethash lookups. (0=1xx, 1=200, 2=2xx, 3=204, 4=3xx, 5=400, 6=4xx, 7=403, 8=404, 9=408, 10=413, 11=5xx, 12=502|504|511, 13=503, 14=505, 15=Other). Keyed by provider"
@@ -4241,17 +4250,16 @@
     "expires_in_version": "61",
     "kind": "exponential",
     "keyed": true,
     "high": 5000,
     "n_buckets": 15,
     "bug_numbers": [1336903],
     "description": "Server response time to getHash request (ms). Keyed by provider"
   },
-
   "URLCLASSIFIER_UPDATE_ERROR": {
     "alert_emails": ["safebrowsing-telemetry@mozilla.org"],
     "expires_in_version": "59",
     "kind": "enumerated",
     "keyed": true,
     "n_values": 16,
     "bug_numbers": [1311910],
     "description": "Whether or not an error was encountered while processing a Safe Browsing update (0 = success, 1 = unspecified error, 2 = addition of an already existing prefix, 3 = parser got into an infinite loop, 4 = removal index out of bounds, 5 = checksum mismatch, 6 = missing checksum, 7 = update while shutdown, 8 = cannot find table, 9 = build prefix failure, 10 = write disk failure, 11 = protocol parser error). Keyed by provider"
--- a/toolkit/components/url-classifier/SBTelemetryUtils.h
+++ b/toolkit/components/url-classifier/SBTelemetryUtils.h
@@ -46,12 +46,18 @@ enum class MatchThreatType : uint8_t
 MOZ_MAKE_ENUM_CLASS_BITWISE_OPERATORS(MatchThreatType)
 
 uint8_t
 MatchResultToUint(const MatchResult& aResult);
 
 MatchThreatType
 TableNameToThreatType(bool aIsV2, const nsACString& aTable);
 
+enum UpdateTimeout {
+  eNoTimeout = 0,
+  eResponseTimeout = 1,
+  eDownloadTimeout = 2,
+};
+
 } // namespace safebrowsing
 } // namespace mozilla
 
 #endif //SBTelemetryUtils_h__
--- a/toolkit/components/url-classifier/nsUrlClassifierStreamUpdater.cpp
+++ b/toolkit/components/url-classifier/nsUrlClassifierStreamUpdater.cpp
@@ -20,19 +20,30 @@
 #include "mozilla/ErrorNames.h"
 #include "mozilla/Logging.h"
 #include "nsIInterfaceRequestor.h"
 #include "mozilla/LoadContext.h"
 #include "mozilla/Telemetry.h"
 #include "nsContentUtils.h"
 #include "nsIURLFormatter.h"
 #include "Classifier.h"
+#include "SBTelemetryUtils.h"
+
+using namespace mozilla::safebrowsing;
+
+#define DEFAULT_RESPONSE_TIMEOUT 5 * 1000
+#define DEFAULT_TIMEOUT_MS 60 * 1000
+static_assert(DEFAULT_TIMEOUT_MS > DEFAULT_RESPONSE_TIMEOUT,
+  "General timeout must be greater than reponse timeout");
 
 static const char* gQuitApplicationMessage = "quit-application";
 
+static uint32_t sResponseTimeoutMs = DEFAULT_RESPONSE_TIMEOUT;
+static uint32_t sTimeoutMs = DEFAULT_TIMEOUT_MS;
+
 // Limit the list file size to 32mb
 const uint32_t MAX_FILE_SIZE = (32 * 1024 * 1024);
 
 // Retry delay when we failed to DownloadUpdate() if due to
 // DBService busy.
 const uint32_t FETCH_NEXT_REQUEST_RETRY_DELAY_MS = 1000;
 
 #undef LOG
@@ -183,18 +194,53 @@ nsUrlClassifierStreamUpdater::FetchUpdat
     NS_ENSURE_SUCCESS(rv, rv);
   }
 
   // Make the request.
   rv = mChannel->AsyncOpen2(this);
   NS_ENSURE_SUCCESS(rv, rv);
 
   mTelemetryClockStart = PR_IntervalNow();
+  mStreamTable = aStreamTable;
 
-  mStreamTable = aStreamTable;
+  static bool preferencesInitialized = false;
+
+  if (!preferencesInitialized) {
+    mozilla::Preferences::AddUintVarCache(&sTimeoutMs,
+                                          "urlclassifier.update.timeout_ms",
+                                          DEFAULT_TIMEOUT_MS);
+    mozilla::Preferences::AddUintVarCache(&sResponseTimeoutMs,
+                                          "urlclassifier.update.response_timeout_ms",
+                                          DEFAULT_RESPONSE_TIMEOUT);
+    preferencesInitialized = true;
+  }
+
+  if (sResponseTimeoutMs > sTimeoutMs) {
+    NS_WARNING("Safe Browsing response timeout is greater than the general "
+      "timeout. Disabling these update timeouts.");
+    return NS_OK;
+  }
+  mResponseTimeoutTimer = do_CreateInstance("@mozilla.org/timer;1", &rv);
+  if (NS_SUCCEEDED(rv)) {
+    rv = mResponseTimeoutTimer->InitWithCallback(this,
+                                                 sResponseTimeoutMs,
+                                                 nsITimer::TYPE_ONE_SHOT);
+  }
+
+  mTimeoutTimer = do_CreateInstance("@mozilla.org/timer;1", &rv);
+
+  if (NS_SUCCEEDED(rv)) {
+    if (sTimeoutMs < DEFAULT_TIMEOUT_MS) {
+      LOG(("Download update timeout %d ms (< %d ms) would be too small",
+           sTimeoutMs, DEFAULT_TIMEOUT_MS));
+    }
+    rv = mTimeoutTimer->InitWithCallback(this,
+                                         sTimeoutMs,
+                                         nsITimer::TYPE_ONE_SHOT);
+  }
 
   return NS_OK;
 }
 
 nsresult
 nsUrlClassifierStreamUpdater::FetchUpdate(const nsACString & aUpdateUrl,
                                           const nsACString & aRequestPayload,
                                           bool aIsPostRequest,
@@ -693,16 +739,21 @@ nsUrlClassifierStreamUpdater::OnStartReq
     }
     if (mTelemetryClockStart > 0) {
       uint32_t msecs = PR_IntervalToMilliseconds(PR_IntervalNow() - mTelemetryClockStart);
       mozilla::Telemetry::Accumulate(mozilla::Telemetry::URLCLASSIFIER_UPDATE_SERVER_RESPONSE_TIME,
                                      mTelemetryProvider, msecs);
 
     }
 
+    if (mResponseTimeoutTimer) {
+      mResponseTimeoutTimer->Cancel();
+      mResponseTimeoutTimer = nullptr;
+    }
+
     uint8_t netErrCode = NS_FAILED(status) ? NetworkErrorToBucket(status) : 0;
     mozilla::Telemetry::Accumulate(
       mozilla::Telemetry::URLCLASSIFIER_UPDATE_REMOTE_NETWORK_ERROR,
       mTelemetryProvider, netErrCode);
 
     if (NS_FAILED(status)) {
       // Assume we're overloading the server and trigger backoff.
       downloadError = true;
@@ -798,16 +849,31 @@ nsUrlClassifierStreamUpdater::OnStopRequ
   } else {
     LOG(("OnStopRequest::Finishing update [this=%p]", this));
     // The fetch failed, but we didn't start the stream (probably a
     // server or connection error).  We can commit what we've applied
     // so far, and request again later.
     rv = mDBService->FinishUpdate();
   }
 
+  if (mResponseTimeoutTimer) {
+    mResponseTimeoutTimer->Cancel();
+    mResponseTimeoutTimer = nullptr;
+  }
+
+  // mResponseTimeoutTimer may be cleared in OnStartRequest, so we check mTimeoutTimer
+  // to see whether the update was has timed out
+  if (mTimeoutTimer) {
+    mozilla::Telemetry::Accumulate(mozilla::Telemetry::URLCLASSIFIER_UPDATE_TIMEOUT,
+                                   mTelemetryProvider,
+                                   static_cast<uint8_t>(eNoTimeout));
+    mTimeoutTimer->Cancel();
+    mTimeoutTimer = nullptr;
+  }
+
   mTelemetryProvider.Truncate();
   mTelemetryClockStart = 0;
   mChannel = nullptr;
 
   // If the fetch failed, return the network status rather than NS_OK, the
   // result of finishing a possibly-empty update
   if (NS_SUCCEEDED(aStatus)) {
     return rv;
@@ -835,16 +901,25 @@ nsUrlClassifierStreamUpdater::Observe(ns
     if (mFetchIndirectUpdatesTimer) {
       mFetchIndirectUpdatesTimer->Cancel();
       mFetchIndirectUpdatesTimer = nullptr;
     }
     if (mFetchNextRequestTimer) {
       mFetchNextRequestTimer->Cancel();
       mFetchNextRequestTimer = nullptr;
     }
+    if (mResponseTimeoutTimer) {
+      mResponseTimeoutTimer->Cancel();
+      mResponseTimeoutTimer = nullptr;
+    }
+    if (mTimeoutTimer) {
+      mTimeoutTimer->Cancel();
+      mTimeoutTimer = nullptr;
+    }
+
   }
   return NS_OK;
 }
 
 ///////////////////////////////////////////////////////////////////////////////
 // nsIInterfaceRequestor implementation
 
 NS_IMETHODIMP
@@ -869,12 +944,53 @@ nsUrlClassifierStreamUpdater::Notify(nsI
 
   if (timer == mFetchIndirectUpdatesTimer) {
     mFetchIndirectUpdatesTimer = nullptr;
     // Start the update process up again.
     FetchNext();
     return NS_OK;
   }
 
+  bool updateFailed = false;
+  if (timer == mResponseTimeoutTimer) {
+    mResponseTimeoutTimer = nullptr;
+    if (mTimeoutTimer) {
+      mTimeoutTimer->Cancel();
+      mTimeoutTimer = nullptr;
+    }
+    mDownloadError = true; // Trigger backoff
+    updateFailed = true;
+    mozilla::Telemetry::Accumulate(mozilla::Telemetry::URLCLASSIFIER_UPDATE_TIMEOUT,
+                                   mTelemetryProvider,
+                                   static_cast<uint8_t>(eResponseTimeout));
+  }
+
+  if (timer == mTimeoutTimer) {
+    mTimeoutTimer = nullptr;
+    // No backoff since the connection may just be temporarily slow.
+    updateFailed = true;
+    mozilla::Telemetry::Accumulate(mozilla::Telemetry::URLCLASSIFIER_UPDATE_TIMEOUT,
+                                   mTelemetryProvider,
+                                   static_cast<uint8_t>(eDownloadTimeout));
+  }
+
+  if (updateFailed) {
+    // Cancelling the channel will trigger OnStopRequest.
+    mozilla::Unused << mChannel->Cancel(NS_ERROR_ABORT);
+    mChannel = nullptr;
+    mTelemetryClockStart = 0;
+
+    if (mFetchIndirectUpdatesTimer) {
+      mFetchIndirectUpdatesTimer->Cancel();
+      mFetchIndirectUpdatesTimer = nullptr;
+    }
+    if (mFetchNextRequestTimer) {
+      mFetchNextRequestTimer->Cancel();
+      mFetchNextRequestTimer = nullptr;
+    }
+
+    return NS_OK;
+  }
+
   MOZ_ASSERT_UNREACHABLE("A timer is fired from nowhere.");
   return NS_OK;
 }
 
--- a/toolkit/components/url-classifier/nsUrlClassifierStreamUpdater.h
+++ b/toolkit/components/url-classifier/nsUrlClassifierStreamUpdater.h
@@ -86,16 +86,22 @@ private:
   // timer is for fetching the redirected update.
   nsCOMPtr<nsITimer> mFetchIndirectUpdatesTimer;
 
   // When we DownloadUpdate(), the DBService might be busy on processing
   // request issused outside of StreamUpdater. We have to fire a timer to
   // retry on our own.
   nsCOMPtr<nsITimer> mFetchNextRequestTimer;
 
+  // Timer to abort the download if the server takes too long to respond.
+  nsCOMPtr<nsITimer> mResponseTimeoutTimer;
+
+  // Timer to abort the download if it takes too long.
+  nsCOMPtr<nsITimer> mTimeoutTimer;
+
   struct PendingRequest {
     nsCString mTables;
     nsCString mRequestPayload;
     bool mIsPostRequest;
     nsCString mUrl;
     nsCOMPtr<nsIUrlClassifierCallback> mSuccessCallback;
     nsCOMPtr<nsIUrlClassifierCallback> mUpdateErrorCallback;
     nsCOMPtr<nsIUrlClassifierCallback> mDownloadErrorCallback;