Bug 1116404 - Better timeout semantics for search service geoip lookups. r=felipe, a=sledru
authorMark Hammond <mhammond@skippinet.com.au>
Fri, 09 Jan 2015 13:43:29 +1100
changeset 242845 06bb4d89e2bf
parent 242844 6796cf5b59b1
child 242846 1d406b3f20db
push id4320
push userryanvm@gmail.com
push date2015-01-14 14:48 +0000
treeherdermozilla-beta@06bb4d89e2bf [default view] [failures only]
perfherder[talos] [build metrics] [platform microbench] (compared to previous push)
reviewersfelipe, sledru
bugs1116404
milestone36.0
Bug 1116404 - Better timeout semantics for search service geoip lookups. r=felipe, a=sledru
toolkit/components/search/nsSearchService.js
toolkit/components/search/tests/xpcshell/head_search.js
toolkit/components/search/tests/xpcshell/test_location.js
toolkit/components/search/tests/xpcshell/test_location_error.js
toolkit/components/search/tests/xpcshell/test_location_malformed_json.js
toolkit/components/search/tests/xpcshell/test_location_sync.js
toolkit/components/search/tests/xpcshell/test_location_timeout.js
toolkit/components/search/tests/xpcshell/test_location_timeout_xhr.js
toolkit/components/search/tests/xpcshell/test_selectedEngine.js
toolkit/components/search/tests/xpcshell/xpcshell.ini
toolkit/components/telemetry/Histograms.json
--- a/toolkit/components/search/nsSearchService.js
+++ b/toolkit/components/search/nsSearchService.js
@@ -20,16 +20,20 @@ XPCOMUtils.defineLazyModuleGetter(this, 
 XPCOMUtils.defineLazyModuleGetter(this, "Task",
   "resource://gre/modules/Task.jsm");
 XPCOMUtils.defineLazyModuleGetter(this, "TelemetryStopwatch",
   "resource://gre/modules/TelemetryStopwatch.jsm");
 XPCOMUtils.defineLazyModuleGetter(this, "Deprecated",
   "resource://gre/modules/Deprecated.jsm");
 XPCOMUtils.defineLazyModuleGetter(this, "SearchStaticData",
   "resource://gre/modules/SearchStaticData.jsm");
+XPCOMUtils.defineLazyModuleGetter(this, "setTimeout",
+  "resource://gre/modules/Timer.jsm");
+XPCOMUtils.defineLazyModuleGetter(this, "clearTimeout",
+  "resource://gre/modules/Timer.jsm");
 
 XPCOMUtils.defineLazyServiceGetter(this, "gTextToSubURI",
                                    "@mozilla.org/intl/texttosuburi;1",
                                    "nsITextToSubURI");
 
 Cu.importGlobalProperties(["XMLHttpRequest"]);
 
 // A text encoder to UTF8, used whenever we commit the
@@ -458,71 +462,123 @@ function isUSTimezone() {
 // the hacky method above, so isUS() can avoid the hacky timezone method.
 // If it fails we don't touch that pref so isUS() does its normal thing.
 let ensureKnownCountryCode = Task.async(function* () {
   // If we have a country-code already stored in our prefs we trust it.
   try {
     Services.prefs.getCharPref("browser.search.countryCode");
     return; // pref exists, so we've done this before.
   } catch(e) {}
-  // we don't have it cached, so fetch it.
-  let cc = yield fetchCountryCode();
-  if (cc) {
-    // we got one - stash it away
-    Services.prefs.setCharPref("browser.search.countryCode", cc);
-    // and update our "isUS" cache pref if it is US - that will prevent a
-    // fallback to the timezone check.
-    // However, only do this if the locale also matches.
-    if (getLocale() == "en-US") {
-      Services.prefs.setBoolPref("browser.search.isUS", (cc == "US"));
-    }
-    // and telemetry...
-    let isTimezoneUS = isUSTimezone();
-    if (cc == "US" && !isTimezoneUS) {
-      Services.telemetry.getHistogramById("SEARCH_SERVICE_US_COUNTRY_MISMATCHED_TIMEZONE").add(1);
-    }
-    if (cc != "US" && isTimezoneUS) {
-      Services.telemetry.getHistogramById("SEARCH_SERVICE_US_TIMEZONE_MISMATCHED_COUNTRY").add(1);
-    }
+  // We don't have it cached, so fetch it. fetchCountryCode() will call
+  // storeCountryCode if it gets a result (even if that happens after the
+  // promise resolves)
+  yield fetchCountryCode();
+  // If gInitialized is true then the search service was forced to perform
+  // a sync initialization during our XHR - capture this via telemetry.
+  Services.telemetry.getHistogramById("SEARCH_SERVICE_COUNTRY_FETCH_CAUSED_SYNC_INIT").add(gInitialized);
+});
+
+// Store the result of the geoip request as well as any other values and
+// telemetry which depend on it.
+function storeCountryCode(cc) {
+  // Set the country-code itself.
+  Services.prefs.setCharPref("browser.search.countryCode", cc);
+  // and update our "isUS" cache pref if it is US - that will prevent a
+  // fallback to the timezone check.
+  // However, only do this if the locale also matches.
+  if (getLocale() == "en-US") {
+    Services.prefs.setBoolPref("browser.search.isUS", (cc == "US"));
   }
-});
+  // and telemetry...
+  let isTimezoneUS = isUSTimezone();
+  if (cc == "US" && !isTimezoneUS) {
+    Services.telemetry.getHistogramById("SEARCH_SERVICE_US_COUNTRY_MISMATCHED_TIMEZONE").add(1);
+  }
+  if (cc != "US" && isTimezoneUS) {
+    Services.telemetry.getHistogramById("SEARCH_SERVICE_US_TIMEZONE_MISMATCHED_COUNTRY").add(1);
+  }
+}
 
 // Get the country we are in via a XHR geoip request.
 function fetchCountryCode() {
+  // values for the SEARCH_SERVICE_COUNTRY_FETCH_RESULT 'enum' telemetry probe.
+  const TELEMETRY_RESULT_ENUM = {
+    SUCCESS: 0,
+    SUCCESS_WITHOUT_DATA: 1,
+    XHRTIMEOUT: 2,
+    ERROR: 3,
+    // Note that we expect to add finer-grained error types here later (eg,
+    // dns error, network error, ssl error, etc) with .ERROR remaining as the
+    // generic catch-all that doesn't fit into other categories.
+  };
   let endpoint = Services.urlFormatter.formatURLPref("browser.search.geoip.url");
   // As an escape hatch, no endpoint means no geoip.
   if (!endpoint) {
-    return Promise.resolve(null);
+    return Promise.resolve();
   }
   let startTime = Date.now();
   return new Promise(resolve => {
+    // Instead of using a timeout on the xhr object itself, we simulate one
+    // using a timer and let the XHR request complete.  This allows us to
+    // capture reliable telemetry on what timeout value should actually be
+    // used to ensure most users don't see one while not making it so large
+    // that many users end up doing a sync init of the search service and thus
+    // would see the jank that implies.
+    // (Note we do actually use a timeout on the XHR, but that's set to be a
+    // large value just incase the request never completes - we don't want the
+    // XHR object to live forever)
+    let timeoutMS = Services.prefs.getIntPref("browser.search.geoip.timeout");
+    let timerId = setTimeout(() => {
+      LOG("_fetchCountryCode: timeout fetching country information");
+      Services.telemetry.getHistogramById("SEARCH_SERVICE_COUNTRY_TIMEOUT").add(1);
+      timerId = null;
+      resolve();
+    }, timeoutMS);
+
+    let resolveAndReportSuccess = (result, reason) => {
+      // Even if we timed out, we want to save the country code and everything
+      // related so next startup sees the value and doesn't retry this dance.
+      if (result) {
+        storeCountryCode(result);
+      }
+      Services.telemetry.getHistogramById("SEARCH_SERVICE_COUNTRY_FETCH_RESULT").add(reason);
+
+      // This notification is just for tests...
+      Services.obs.notifyObservers(null, SEARCH_SERVICE_TOPIC, "geoip-lookup-xhr-complete");
+
+      // If we've already timed out then we've already resolved the promise,
+      // so there's nothing else to do.
+      if (timerId == null) {
+        return;
+      }
+      Services.telemetry.getHistogramById("SEARCH_SERVICE_COUNTRY_TIMEOUT").add(0);
+      clearTimeout(timerId);
+      resolve();
+    };
+
     let request = new XMLHttpRequest();
-    request.timeout = Services.prefs.getIntPref("browser.search.geoip.timeout");
+    // This notification is just for tests...
+    Services.obs.notifyObservers(request, SEARCH_SERVICE_TOPIC, "geoip-lookup-xhr-starting");
+    request.timeout = 100000; // 100 seconds as the last-chance fallback
     request.onload = function(event) {
       let took = Date.now() - startTime;
       let cc = event.target.response && event.target.response.country_code;
       LOG("_fetchCountryCode got success response in " + took + "ms: " + cc);
-      Services.telemetry.getHistogramById("SEARCH_SERVICE_COUNTRY_FETCH_MS").add(took);
-      Services.telemetry.getHistogramById("SEARCH_SERVICE_COUNTRY_SUCCESS").add(cc ? 1 : 0);
-      if (!cc) {
-        Services.telemetry.getHistogramById("SEARCH_SERVICE_COUNTRY_SUCCESS_WITHOUT_DATA").add(1);
-      }
-      resolve(cc);
+      Services.telemetry.getHistogramById("SEARCH_SERVICE_COUNTRY_FETCH_TIME_MS").add(took);
+      let reason = cc ? TELEMETRY_RESULT_ENUM.SUCCESS : TELEMETRY_RESULT_ENUM.SUCCESS_WITHOUT_DATA;
+      resolveAndReportSuccess(cc, reason);
+    };
+    request.ontimeout = function(event) {
+      LOG("_fetchCountryCode: XHR finally timed-out fetching country information");
+      resolveAndReportSuccess(null, TELEMETRY_RESULT_ENUM.XHRTIMEOUT);
     };
     request.onerror = function(event) {
       LOG("_fetchCountryCode: failed to retrieve country information");
-      Services.telemetry.getHistogramById("SEARCH_SERVICE_COUNTRY_SUCCESS").add(0);
-      resolve(null);
+      resolveAndReportSuccess(null, TELEMETRY_RESULT_ENUM.ERROR);
     };
-    request.ontimeout = function(event) {
-      LOG("_fetchCountryCode: timeout fetching country information");
-      Services.telemetry.getHistogramById("SEARCH_SERVICE_COUNTRY_FETCH_TIMEOUT").add(1);
-      Services.telemetry.getHistogramById("SEARCH_SERVICE_COUNTRY_SUCCESS").add(0);
-      resolve(null);
-    }
     request.open("POST", endpoint, true);
     request.setRequestHeader("Content-Type", "application/json");
     request.responseType = "json";
     request.send("{}");
   });
 }
 
 /**
--- a/toolkit/components/search/tests/xpcshell/head_search.js
+++ b/toolkit/components/search/tests/xpcshell/head_search.js
@@ -284,8 +284,56 @@ let addTestEngines = Task.async(function
       } else {
         Services.search.addEngineWithDetails(item.name, ...item.details);
       }
     });
   }
 
   return engines;
 });
+
+/**
+ * Returns a promise that is resolved when an observer notification from the
+ * search service fires with the specified data.
+ *
+ * @param aExpectedData
+ *        The value the observer notification sends that causes us to resolve
+ *        the promise.
+ */
+function waitForSearchNotification(aExpectedData) {
+  return new Promise(resolve => {
+    const SEARCH_SERVICE_TOPIC = "browser-search-service";
+    Services.obs.addObserver(function observer(aSubject, aTopic, aData) {
+      if (aData != aExpectedData)
+        return;
+
+      Services.obs.removeObserver(observer, SEARCH_SERVICE_TOPIC);
+      resolve(aSubject);
+    }, SEARCH_SERVICE_TOPIC, false);
+  });
+}
+
+// This "enum" from nsSearchService.js
+const TELEMETRY_RESULT_ENUM = {
+  SUCCESS: 0,
+  SUCCESS_WITHOUT_DATA: 1,
+  XHRTIMEOUT: 2,
+  ERROR: 3,
+};
+
+/**
+ * Checks the value of the SEARCH_SERVICE_COUNTRY_FETCH_RESULT probe.
+ *
+ * @param aExpectedValue
+ *        If a value from TELEMETRY_RESULT_ENUM, we expect to see this value
+ *        recorded exactly once in the probe.  If |null|, we expect to see
+ *        nothing recorded in the probe at all.
+ */
+function checkCountryResultTelemetry(aExpectedValue) {
+  let histogram = Services.telemetry.getHistogramById("SEARCH_SERVICE_COUNTRY_FETCH_RESULT");
+  let snapshot = histogram.snapshot();
+  // The probe is declared with 8 values, but we get 9 back from .counts
+  let expectedCounts = [0,0,0,0,0,0,0,0,0];
+  if (aExpectedValue != null) {
+    expectedCounts[aExpectedValue] = 1;
+  }
+  deepEqual(snapshot.counts, expectedCounts);
+}
--- a/toolkit/components/search/tests/xpcshell/test_location.js
+++ b/toolkit/components/search/tests/xpcshell/test_location.js
@@ -20,16 +20,21 @@ function run_test() {
     removeCacheFile();
   });
 
   Services.prefs.setCharPref("browser.search.geoip.url", 'data:application/json,{"country_code": "AU"}');
   Services.search.init(() => {
     equal(Services.prefs.getCharPref("browser.search.countryCode"), "AU", "got the correct country code.");
     equal(Services.prefs.getBoolPref("browser.search.isUS"), false, "AU is not in the US.")
     // check we have "success" recorded in telemetry
-    let histogram = Services.telemetry.getHistogramById("SEARCH_SERVICE_COUNTRY_SUCCESS");
-    let snapshot = histogram.snapshot();
-    equal(snapshot.sum, 1)
+    checkCountryResultTelemetry(TELEMETRY_RESULT_ENUM.SUCCESS);
+    // a false value for each of SEARCH_SERVICE_COUNTRY_TIMEOUT and SEARCH_SERVICE_COUNTRY_FETCH_CAUSED_SYNC_INIT
+    for (let hid of ["SEARCH_SERVICE_COUNTRY_TIMEOUT",
+                     "SEARCH_SERVICE_COUNTRY_FETCH_CAUSED_SYNC_INIT"]) {
+      let histogram = Services.telemetry.getHistogramById(hid);
+      let snapshot = histogram.snapshot();
+      deepEqual(snapshot.counts, [1,0,0]); // boolean probe so 3 buckets, expect 1 result for |0|.
+    }
     do_test_finished();
     run_next_test();
   });
   do_test_pending();
 }
--- a/toolkit/components/search/tests/xpcshell/test_location_error.js
+++ b/toolkit/components/search/tests/xpcshell/test_location_error.js
@@ -15,31 +15,33 @@ function run_test() {
 
   do_get_file("data/engine.xml").copyTo(engineDir, "engine.xml");
 
   do_register_cleanup(function() {
     removeMetadata();
     removeCacheFile();
   });
 
-  // from server-locations.txt, we choose a URL without a cert.
+  // this will cause an "unknown host" error, but not report an external
+  // network connection in the tests (note that the hosts listed in
+  // server-locations.txt are *not* loaded for xpcshell tests...)
   let url = "https://nocert.example.com:443";
   Services.prefs.setCharPref("browser.search.geoip.url", url);
   Services.search.init(() => {
     try {
       Services.prefs.getCharPref("browser.search.countryCode");
       ok(false, "not expecting countryCode to be set");
     } catch (ex) {}
-    // should be no success recorded.
-    let histogram = Services.telemetry.getHistogramById("SEARCH_SERVICE_COUNTRY_SUCCESS");
-    let snapshot = histogram.snapshot();
-    equal(snapshot.sum, 0);
-
-    // should be no timeout either.
-    histogram = Services.telemetry.getHistogramById("SEARCH_SERVICE_COUNTRY_FETCH_TIMEOUT");
-    snapshot = histogram.snapshot();
-    equal(snapshot.sum, 0);
+    // should have an error recorded.
+    checkCountryResultTelemetry(TELEMETRY_RESULT_ENUM.ERROR);
+    // but false values for timeout and forced-sync-init.
+    for (let hid of ["SEARCH_SERVICE_COUNTRY_TIMEOUT",
+                     "SEARCH_SERVICE_COUNTRY_FETCH_CAUSED_SYNC_INIT"]) {
+      let histogram = Services.telemetry.getHistogramById(hid);
+      let snapshot = histogram.snapshot();
+      deepEqual(snapshot.counts, [1,0,0]); // boolean probe so 3 buckets, expect 1 result for |0|.
+    }
 
     do_test_finished();
     run_next_test();
   });
   do_test_pending();
 }
--- a/toolkit/components/search/tests/xpcshell/test_location_malformed_json.js
+++ b/toolkit/components/search/tests/xpcshell/test_location_malformed_json.js
@@ -31,23 +31,23 @@ function run_test() {
       Services.prefs.getCharPref("browser.search.isUS");
       ok(false, "should be no isUS pref yet either");
     } catch (_) {}
     // fetch the engines - this should force the timezone check
     Services.search.getEngines();
     equal(Services.prefs.getBoolPref("browser.search.isUS"),
           isUSTimezone(),
           "should have set isUS based on current timezone.");
-    // should have a false value for success.
-    let histogram = Services.telemetry.getHistogramById("SEARCH_SERVICE_COUNTRY_SUCCESS");
-    let snapshot = histogram.snapshot();
-    equal(snapshot.sum, 0);
-
-    // and a flag for SEARCH_SERVICE_COUNTRY_SUCCESS_WITHOUT_DATA
-    histogram = Services.telemetry.getHistogramById("SEARCH_SERVICE_COUNTRY_SUCCESS_WITHOUT_DATA");
-    snapshot = histogram.snapshot();
-    equal(snapshot.sum, 1);
+    // should have recorded SUCCESS_WITHOUT_DATA
+    checkCountryResultTelemetry(TELEMETRY_RESULT_ENUM.SUCCESS_WITHOUT_DATA);
+    // and false values for timeout and forced-sync-init.
+    for (let hid of ["SEARCH_SERVICE_COUNTRY_TIMEOUT",
+                     "SEARCH_SERVICE_COUNTRY_FETCH_CAUSED_SYNC_INIT"]) {
+      let histogram = Services.telemetry.getHistogramById(hid);
+      let snapshot = histogram.snapshot();
+      deepEqual(snapshot.counts, [1,0,0]); // boolean probe so 3 buckets, expect 1 result for |0|.
+    }
 
     do_test_finished();
     run_next_test();
   });
   do_test_pending();
 }
--- a/toolkit/components/search/tests/xpcshell/test_location_sync.js
+++ b/toolkit/components/search/tests/xpcshell/test_location_sync.js
@@ -59,20 +59,37 @@ add_task(function* test_simple() {
   // a little wait to check we didn't do the xhr thang.
   yield new Promise(resolve => {
     do_timeout(500, resolve);
   });
 
   deepEqual(getCountryCodePref(), undefined, "didn't do the geoip xhr");
   // and no telemetry evidence of geoip.
   for (let hid of [
-    "SEARCH_SERVICE_COUNTRY_FETCH_MS",
-    "SEARCH_SERVICE_COUNTRY_SUCCESS",
-    "SEARCH_SERVICE_COUNTRY_SUCCESS_WITHOUT_DATA",
-    "SEARCH_SERVICE_COUNTRY_FETCH_TIMEOUT",
+    "SEARCH_SERVICE_COUNTRY_FETCH_RESULT",
+    "SEARCH_SERVICE_COUNTRY_FETCH_TIME_MS",
+    "SEARCH_SERVICE_COUNTRY_TIMEOUT",
     "SEARCH_SERVICE_US_COUNTRY_MISMATCHED_TIMEZONE",
     "SEARCH_SERVICE_US_TIMEZONE_MISMATCHED_COUNTRY",
+    "SEARCH_SERVICE_COUNTRY_FETCH_CAUSED_SYNC_INIT",
     ]) {
       let histogram = Services.telemetry.getHistogramById(hid);
       let snapshot = histogram.snapshot();
-      equal(snapshot.sum, 0);
+      equal(snapshot.sum, 0, hid);
+      switch (snapshot.histogram_type) {
+        case Ci.nsITelemetry.HISTOGRAM_FLAG:
+          // flags are a special case in that they are initialized with a default
+          // of one |0|.
+          deepEqual(snapshot.counts, [1,0,0], hid);
+          break;
+        case Ci.nsITelemetry.HISTOGRAM_BOOLEAN:
+          // booleans aren't initialized at all, so should have all zeros.
+          deepEqual(snapshot.counts, [0,0,0], hid);
+          break;
+        case Ci.nsITelemetry.HISTOGRAM_EXPONENTIAL:
+        case Ci.nsITelemetry.HISTOGRAM_LINEAR:
+          equal(snapshot.counts.reduce((a, b) => a+b), 0, hid);
+          break;
+        default:
+          ok(false, "unknown histogram type " + snapshot.histogram_type + " for " + hid);
+      }
     }
 });
--- a/toolkit/components/search/tests/xpcshell/test_location_timeout.js
+++ b/toolkit/components/search/tests/xpcshell/test_location_timeout.js
@@ -1,28 +1,37 @@
 /* Any copyright is dedicated to the Public Domain.
    http://creativecommons.org/publicdomain/zero/1.0/ */
 
-function startServer() {
+// This is testing the "normal" timer-based timeout for the location search.
+
+function startServer(continuePromise) {
   let srv = new HttpServer();
   function lookupCountry(metadata, response) {
     response.processAsync();
-    // wait 200 ms before writing a valid response - the search service
-    // should timeout before the response is written so the response should
-    // be ignored.
-    do_timeout(200, () => {
+    // wait for our continuePromise to resolve before writing a valid
+    // response.
+    // This will be resolved after the timeout period, so we can check
+    // the behaviour in that case.
+    continuePromise.then(() => {
       response.setStatusLine("1.1", 200, "OK");
       response.write('{"country_code" : "AU"}');
+      response.finish();
     });
   }
   srv.registerPathHandler("/lookup_country", lookupCountry);
   srv.start(-1);
   return srv;
 }
 
+function getProbeSum(probe, sum) {
+  let histogram = Services.telemetry.getHistogramById(probe);
+  return histogram.snapshot().sum;
+}
+
 function run_test() {
   removeMetadata();
   removeCacheFile();
 
   do_check_false(Services.search.isInitialized);
 
   let engineDummyFile = gProfD.clone();
   engineDummyFile.append("searchplugins");
@@ -32,32 +41,55 @@ function run_test() {
 
   do_get_file("data/engine.xml").copyTo(engineDir, "engine.xml");
 
   do_register_cleanup(function() {
     removeMetadata();
     removeCacheFile();
   });
 
-  let server = startServer();
+  let resolveContinuePromise;
+  let continuePromise = new Promise(resolve => {
+    resolveContinuePromise = resolve;
+  });
+
+  let server = startServer(continuePromise);
   let url = "http://localhost:" + server.identity.primaryPort + "/lookup_country";
   Services.prefs.setCharPref("browser.search.geoip.url", url);
   Services.prefs.setIntPref("browser.search.geoip.timeout", 50);
   Services.search.init(() => {
     try {
       Services.prefs.getCharPref("browser.search.countryCode");
       ok(false, "not expecting countryCode to be set");
     } catch (ex) {}
-    // should be no success recorded.
-    let histogram = Services.telemetry.getHistogramById("SEARCH_SERVICE_COUNTRY_SUCCESS");
+    // should be no result recorded at all.
+    checkCountryResultTelemetry(null);
+
+    // should have set the flag indicating we saw a timeout.
+    let histogram = Services.telemetry.getHistogramById("SEARCH_SERVICE_COUNTRY_TIMEOUT");
     let snapshot = histogram.snapshot();
-    equal(snapshot.sum, 0);
+    deepEqual(snapshot.counts, [0,1,0]);
+    // should not yet have SEARCH_SERVICE_COUNTRY_FETCH_TIME_MS recorded as our
+    // test server is still blocked on our promise.
+    equal(getProbeSum("SEARCH_SERVICE_COUNTRY_FETCH_TIME_MS"), 0);
 
-    // should be a timeout.
-    histogram = Services.telemetry.getHistogramById("SEARCH_SERVICE_COUNTRY_FETCH_TIMEOUT");
-    snapshot = histogram.snapshot();
-    equal(snapshot.sum, 1);
+    waitForSearchNotification("geoip-lookup-xhr-complete").then(() => {
+      // now we *should* have a report of how long the response took even though
+      // it timed out.
+      // The telemetry "sum" will be the actual time in ms - just check it's non-zero.
+      ok(getProbeSum("SEARCH_SERVICE_COUNTRY_FETCH_TIME_MS") != 0);
+      // should have reported the fetch ended up being successful
+      checkCountryResultTelemetry(TELEMETRY_RESULT_ENUM.SUCCESS);
 
-    do_test_finished();
-    server.stop(run_next_test);
+      // and should have the result of the response that finally came in, and
+      // everything dependent should also be updated.
+      equal(Services.prefs.getCharPref("browser.search.countryCode"), "AU");
+      equal(Services.prefs.getBoolPref("browser.search.isUS"), false);
+
+      do_test_finished();
+      server.stop(run_next_test);
+    });
+    // now tell the server to send its response.  That will end up causing the
+    // search service to notify of that the response was received.
+    resolveContinuePromise();
   });
   do_test_pending();
 }
new file mode 100644
--- /dev/null
+++ b/toolkit/components/search/tests/xpcshell/test_location_timeout_xhr.js
@@ -0,0 +1,105 @@
+/* Any copyright is dedicated to the Public Domain.
+   http://creativecommons.org/publicdomain/zero/1.0/ */
+
+// This is testing the long, last-resort XHR-based timeout for the location
+// search.
+
+function startServer(continuePromise) {
+  let srv = new HttpServer();
+  function lookupCountry(metadata, response) {
+    response.processAsync();
+    // wait for our continuePromise to resolve before writing a valid
+    // response.
+    // This will be resolved after the timeout period, so we can check
+    // the behaviour in that case.
+    continuePromise.then(() => {
+      response.setStatusLine("1.1", 200, "OK");
+      response.write('{"country_code" : "AU"}');
+      response.finish();
+    });
+  }
+  srv.registerPathHandler("/lookup_country", lookupCountry);
+  srv.start(-1);
+  return srv;
+}
+
+function verifyProbeSum(probe, sum) {
+  let histogram = Services.telemetry.getHistogramById(probe);
+  let snapshot = histogram.snapshot();
+  equal(snapshot.sum, sum, probe);
+}
+
+function run_test() {
+  removeMetadata();
+  removeCacheFile();
+
+  do_check_false(Services.search.isInitialized);
+
+  let engineDummyFile = gProfD.clone();
+  engineDummyFile.append("searchplugins");
+  engineDummyFile.append("test-search-engine.xml");
+  let engineDir = engineDummyFile.parent;
+  engineDir.create(Ci.nsIFile.DIRECTORY_TYPE, FileUtils.PERMS_DIRECTORY);
+
+  do_get_file("data/engine.xml").copyTo(engineDir, "engine.xml");
+
+  do_register_cleanup(function() {
+    removeMetadata();
+    removeCacheFile();
+  });
+
+  let resolveContinuePromise;
+  let continuePromise = new Promise(resolve => {
+    resolveContinuePromise = resolve;
+  });
+
+  let server = startServer(continuePromise);
+  let url = "http://localhost:" + server.identity.primaryPort + "/lookup_country";
+  Services.prefs.setCharPref("browser.search.geoip.url", url);
+  // The timeout for the timer.
+  Services.prefs.setIntPref("browser.search.geoip.timeout", 10);
+  let promiseXHRStarted = waitForSearchNotification("geoip-lookup-xhr-starting");
+  Services.search.init(() => {
+    try {
+      Services.prefs.getCharPref("browser.search.countryCode");
+      ok(false, "not expecting countryCode to be set");
+    } catch (ex) {}
+    // should be no result recorded at all.
+    checkCountryResultTelemetry(null);
+
+    // should have set the flag indicating we saw a timeout.
+    let histogram = Services.telemetry.getHistogramById("SEARCH_SERVICE_COUNTRY_TIMEOUT");
+    let snapshot = histogram.snapshot();
+    deepEqual(snapshot.counts, [0,1,0]);
+
+    // should not have SEARCH_SERVICE_COUNTRY_FETCH_TIME_MS recorded as our
+    // test server is still blocked on our promise.
+    verifyProbeSum("SEARCH_SERVICE_COUNTRY_FETCH_TIME_MS", 0);
+
+    promiseXHRStarted.then(xhr => {
+      // Set the timeout on the xhr object to an extremely low value, so it
+      // should timeout immediately.
+      xhr.timeout = 10;
+      // wait for the xhr timeout to fire.
+      waitForSearchNotification("geoip-lookup-xhr-complete").then(() => {
+        // should have the XHR timeout recorded.
+        checkCountryResultTelemetry(TELEMETRY_RESULT_ENUM.XHRTIMEOUT);
+        // still should not have a report of how long the response took as we
+        // only record that on success responses.
+        verifyProbeSum("SEARCH_SERVICE_COUNTRY_FETCH_TIME_MS", 0);
+        // and we don't know the country code.
+        try {
+          Services.prefs.getCharPref("browser.search.countryCode");
+          ok(false, "not expecting countryCode to be set");
+        } catch (ex) {}
+
+        // unblock the server even though nothing is listening.
+        resolveContinuePromise();
+
+        do_test_finished();
+        server.stop(run_next_test);
+      });
+    });
+  });
+  do_test_pending();
+}
--- a/toolkit/components/search/tests/xpcshell/test_selectedEngine.js
+++ b/toolkit/components/search/tests/xpcshell/test_selectedEngine.js
@@ -42,30 +42,18 @@ function getDefaultEngineName() {
   // Copy the logic from nsSearchService
   let pref = kDefaultenginenamePref;
   if (getIsUS()) {
     pref += ".US";
   }
   return Services.prefs.getComplexValue(pref, nsIPLS).data;
 }
 
-function waitForNotification(aExpectedData) {
-  let deferred = Promise.defer();
-
-  const SEARCH_SERVICE_TOPIC = "browser-search-service";
-  Services.obs.addObserver(function observer(aSubject, aTopic, aData) {
-    if (aData != aExpectedData)
-      return;
-
-    Services.obs.removeObserver(observer, SEARCH_SERVICE_TOPIC);
-    deferred.resolve();
-  }, SEARCH_SERVICE_TOPIC, false);
-
-  return deferred.promise;
-}
+// waitForSearchNotification is in head_search.js
+let waitForNotification = waitForSearchNotification;
 
 function asyncInit() {
   let deferred = Promise.defer();
 
   Services.search.init(function() {
     do_check_true(Services.search.isInitialized);
     deferred.resolve();
   });
--- a/toolkit/components/search/tests/xpcshell/xpcshell.ini
+++ b/toolkit/components/search/tests/xpcshell/xpcshell.ini
@@ -28,16 +28,17 @@ support-files =
 [test_init_async_multiple.js]
 [test_init_async_multiple_then_sync.js]
 [test_json_cache.js]
 [test_location.js]
 [test_location_error.js]
 [test_location_malformed_json.js]
 [test_location_sync.js]
 [test_location_timeout.js]
+[test_location_timeout_xhr.js]
 [test_nodb.js]
 [test_nodb_pluschanges.js]
 [test_save_sorted_engines.js]
 [test_purpose.js]
 [test_defaultEngine.js]
 [test_notifications.js]
 [test_parseSubmissionURL.js]
 [test_SearchStaticData.js]
--- a/toolkit/components/telemetry/Histograms.json
+++ b/toolkit/components/telemetry/Histograms.json
@@ -4538,41 +4538,42 @@
   "SEARCH_SERVICE_BUILD_CACHE_MS": {
     "expires_in_version": "40",
     "kind": "exponential",
     "high": "1000",
     "n_buckets": 15,
     "extended_statistics_ok": true,
     "description": "Time (ms) it takes to build the cache of the search service"
   },
-  "SEARCH_SERVICE_COUNTRY_FETCH_MS": {
+  "SEARCH_SERVICE_COUNTRY_FETCH_TIME_MS": {
     "alert_emails": ["mhammond@mozilla.com", "gavin@mozilla.com"],
     "expires_in_version": "never",
-    "kind": "linear",
-    "n_buckets": 20,
-    "high": 2000,
+    "kind": "exponential",
+    "n_buckets": 30,
+    "high": 100000,
     "description": "Time (ms) it takes to fetch the country code"
   },
-  "SEARCH_SERVICE_COUNTRY_FETCH_TIMEOUT": {
+  "SEARCH_SERVICE_COUNTRY_FETCH_RESULT": {
     "alert_emails": ["mhammond@mozilla.com", "gavin@mozilla.com"],
     "expires_in_version": "never",
-    "kind": "flag",
-    "description": "If we saw a timeout fetching the country-code"
-  },
-  "SEARCH_SERVICE_COUNTRY_SUCCESS": {
+    "kind": "enumerated",
+    "n_values": 8,
+    "description": "Result of XHR request fetching the country-code. 0=SUCCESS, 1=SUCCESS_WITHOUT_DATA, 2=XHRTIMEOUT, 3=ERROR (rest reserved for finer-grained error codes later)"
+  },
+  "SEARCH_SERVICE_COUNTRY_TIMEOUT": {
     "alert_emails": ["mhammond@mozilla.com", "gavin@mozilla.com"],
     "expires_in_version": "never",
     "kind": "boolean",
-    "description": "If we successfully fetched the country-code."
-  },
-  "SEARCH_SERVICE_COUNTRY_SUCCESS_WITHOUT_DATA": {
+    "description": "True if we stopped waiting for the XHR response before it completed"
+  },
+  "SEARCH_SERVICE_COUNTRY_FETCH_CAUSED_SYNC_INIT": {
     "alert_emails": ["mhammond@mozilla.com", "gavin@mozilla.com"],
     "expires_in_version": "never",
-    "kind": "flag",
-    "description": "If we got a success response but no country-code"
+    "kind": "boolean",
+    "description": "True if the search service was synchronously initialized while we were waiting for the XHR response"
   },
   "SEARCH_SERVICE_US_COUNTRY_MISMATCHED_TIMEZONE": {
     "alert_emails": ["mhammond@mozilla.com", "gavin@mozilla.com"],
     "expires_in_version": "never",
     "kind": "flag",
     "description": "Set if the fetched country-code indicates US but the time-zone heuristic doesn't"
   },
   "SEARCH_SERVICE_US_TIMEZONE_MISMATCHED_COUNTRY": {