Bug 1743885 - Add latency telemetry for search suggestions. r=Standard8 (8d6e7c2b) · Commits · The Tor Project / Applications / Tor Browser

browser/components/search/docs/telemetry.rst

+6 −1

Original line number	Diff line number	Diff line
		@@ -2,7 +2,12 @@ Telemetry
		=========

		This section describes existing telemetry probes measuring interaction with
		search engines.
		search engines from the browser UI.

		Other search-related telemetry is recorded by Toolkit such as search service
		telemetry and telemetry related to fetching search suggestions. Toolkit search
		telemetry is relevant to Firefox as well as other consumers of Toolkit. See
		:doc:`/toolkit/search/Telemetry` in the Toolkit documentation for details.

		.. toctree::
		:caption: Table of Contents

toolkit/components/search/SearchSuggestionController.jsm

+57 −4

Original line number	Diff line number	Diff line
		@@ -26,6 +26,8 @@ const SEARCH_DATA_TRANSFERRED_SCALAR = "browser.search.data_transferred";
		const SEARCH_TELEMETRY_KEY_PREFIX = "sggt";
		const SEARCH_TELEMETRY_PRIVATE_BROWSING_KEY_SUFFIX = "pb";

		const SEARCH_TELEMETRY_LATENCY = "SEARCH_SUGGESTIONS_LATENCY_MS";

		/**
		* Generates an UUID.
		*
		@@ -363,6 +365,37 @@ SearchSuggestionController.prototype = {
		});
		},

		/**
		* Records per-engine telemetry after a search has finished.
		*
		* @param {string} engineId
		* @param {boolean} privateMode
		* Whether the search was in a private context.
		* @param {boolean} [aborted]
		* Whether the search was aborted.
		*/
		_reportTelemetryForEngine(engineId, privateMode, aborted = false) {
		this._reportBandwidthForEngine(engineId, privateMode);

		// Stop the latency stopwatch.
		if (this._requestStopwatchToken) {
		if (aborted) {
		TelemetryStopwatch.cancelKeyed(
		SEARCH_TELEMETRY_LATENCY,
		engineId,
		this._requestStopwatchToken
		);
		} else {
		TelemetryStopwatch.finishKeyed(
		SEARCH_TELEMETRY_LATENCY,
		engineId,
		this._requestStopwatchToken
		);
		}
		this._requestStopwatchToken = null;
		}
		},

		/**
		* Report bandwidth used by search activities. It only reports when it matches
		* search provider information.
		@@ -450,13 +483,13 @@ SearchSuggestionController.prototype = {
		this._onRemoteLoaded.bind(this, deferredResponse, engineId, privateMode)
		);
		this._request.addEventListener("error", evt => {
		this._reportBandwidthForEngine(engineId, privateMode);
		this._reportTelemetryForEngine(engineId, privateMode);
		deferredResponse.resolve("HTTP error");
		});
		// Reject for an abort assuming it's always from .stop() in which case we shouldn't return local
		// or remote results for existing searches.
		this._request.addEventListener("abort", evt => {
		this._reportBandwidthForEngine(engineId, privateMode);
		this._reportTelemetryForEngine(engineId, privateMode, true);
		deferredResponse.reject("HTTP request aborted");
		});

		@@ -466,6 +499,24 @@ SearchSuggestionController.prototype = {
		this._request.send();
		}

		// Start the latency stopwatch, but first cancel the current one if any.
		// `_requestStopwatchToken` is used to associate a stopwatch with each new
		// remote fetch. It also keeps track of the engine ID that was used for the
		// fetch, which is useful since the histogram is keyed on it.
		if (this._requestStopwatchToken) {
		TelemetryStopwatch.cancelKeyed(
		SEARCH_TELEMETRY_LATENCY,
		this._requestStopwatchToken.engineId,
		this._requestStopwatchToken
		);
		}
		this._requestStopwatchToken = { engineId };
		TelemetryStopwatch.startKeyed(
		SEARCH_TELEMETRY_LATENCY,
		engineId,
		this._requestStopwatchToken
		);

		return deferredResponse;
		},

		@@ -482,6 +533,8 @@ SearchSuggestionController.prototype = {
		* @private
		*/
		_onRemoteLoaded(deferredResponse, engineId, privateMode) {
		this._reportTelemetryForEngine(engineId, privateMode);

		if (!this._request) {
		deferredResponse.resolve(
		"Got HTTP response after the request was cancelled"
		@@ -489,8 +542,6 @@ SearchSuggestionController.prototype = {
		return;
		}

		this._reportBandwidthForEngine(engineId, privateMode);

		let status, serverResults;
		try {
		status = this._request.status;
		@@ -733,6 +784,8 @@ SearchSuggestionController.engineOffersSuggestions = function(engine) {
		*/
		SearchSuggestionController.SEARCH_HISTORY_MAX_VALUE_LENGTH = 255;

		SearchSuggestionController.REMOTE_TIMEOUT_DEFAULT = REMOTE_TIMEOUT_DEFAULT;

		/**
		* The maximum time (ms) to wait before giving up on a remote suggestions.
		*/

toolkit/components/search/docs/Telemetry.rst

+17 −0

Original line number	Diff line number	Diff line
		@@ -2,6 +2,12 @@
		Telemetry
		=========

		This document describes search telemetry recorded by Toolkit such as search
		service telemetry and telemetry related to fetching search suggestions.

		Other important search-related telemetry is recorded by Firefox and is
		documented in :doc:`/browser/search/telemetry` in the Firefox documentation.

		Scalars
		-------

		@@ -21,3 +27,14 @@ browser.searchinit.engine_invalid_webextension
		1. Associated WebExtension is not installed.
		2. Associated WebExtension is disabled.
		3. The submission URL of the associated WebExtension is different to that of the saved settings.

		Histograms
		----------

		SEARCH_SUGGESTIONS_LATENCY_MS
		This histogram records the latency in milliseconds of fetches to the
		suggestions endpoints of search engines, or in other words, the time from
		Firefox's request to a suggestions endpoint to the time Firefox receives a
		response. It is a keyed exponential histogram with 50 buckets and values
		between 0 and 30000 (0s and 30s). Keys in this histogram are search engine IDs
		for built-in search engines and 'other' for non-built-in search engines.

toolkit/components/search/tests/xpcshell/data/searchSuggestions.sjs

+5 −3

Original line number	Diff line number	Diff line
		@@ -142,11 +142,13 @@ function handleRequest(request, response) {
		response.setStatusLine(request.httpVersion, q.replace("HTTP ", ""), q);
		writeSuggestions(q, [q]);
		} else if (q && q.startsWith("delay")) {
		// Delay the response by 200 milliseconds (less than the timeout but hopefully enough to abort
		// before completion).
		// Delay the response by delayMs milliseconds. 200ms is the default, less
		// than the timeout but hopefully enough to abort before completion.
		let match = /^delay([0-9]+)/.exec(q);
		let delayMs = match ? parseInt(match[1]) : 200;
		response.processAsync();
		writeSuggestions(q, [q]);
		setTimeout(() => response.finish(), 200);
		setTimeout(() => response.finish(), delayMs);
		} else if (q && q.startsWith("slow ")) {
		// Delay the response by 10 seconds so the client timeout is reached.
		response.processAsync();

toolkit/components/search/tests/xpcshell/test_searchSuggest.js

+231 −28

Original line number	Diff line number	Diff line
		@@ -8,6 +8,9 @@

		"use strict";

		const { AppConstants } = ChromeUtils.import(
		"resource://gre/modules/AppConstants.jsm"
		);
		const { FormHistory } = ChromeUtils.import(
		"resource://gre/modules/FormHistory.jsm"
		);
		@@ -17,6 +20,12 @@ const { SearchSuggestionController } = ChromeUtils.import(
		const { PromiseUtils } = ChromeUtils.import(
		"resource://gre/modules/PromiseUtils.jsm"
		);
		const { TelemetryTestUtils } = ChromeUtils.import(
		"resource://testing-common/TelemetryTestUtils.jsm"
		);

		const ENGINE_NAME = "other";
		const SEARCH_TELEMETRY_LATENCY = "SEARCH_SUGGESTIONS_LATENCY_MS";

		// We must make sure the FormHistoryStartup component is
		// initialized in order for it to respond to FormHistory
		@@ -88,6 +97,10 @@ add_task(async function add_test_engines() {
		// Begin tests

		add_task(async function simple_no_result_callback() {
		let histogram = TelemetryTestUtils.getAndClearKeyedHistogram(
		SEARCH_TELEMETRY_LATENCY
		);

		await new Promise(resolve => {
		let controller = new SearchSuggestionController(result => {
		Assert.equal(result.term, "no remote");
		@@ -98,9 +111,15 @@ add_task(async function simple_no_result_callback() {

		controller.fetch("no remote", false, getEngine);
		});

		assertLatencyHistogram(histogram, true);
		});

		add_task(async function simple_no_result_callback_and_promise() {
		let histogram = TelemetryTestUtils.getAndClearKeyedHistogram(
		SEARCH_TELEMETRY_LATENCY
		);

		// Make sure both the callback and promise get results
		let deferred = PromiseUtils.defer();
		let controller = new SearchSuggestionController(result => {
		@@ -116,17 +135,29 @@ add_task(async function simple_no_result_callback_and_promise() {
		Assert.equal(result.remote.length, 0);

		await deferred.promise;

		assertLatencyHistogram(histogram, true);
		});

		add_task(async function simple_no_result_promise() {
		let histogram = TelemetryTestUtils.getAndClearKeyedHistogram(
		SEARCH_TELEMETRY_LATENCY
		);

		let controller = new SearchSuggestionController();
		let result = await controller.fetch("no remote", false, getEngine);
		Assert.equal(result.term, "no remote");
		Assert.equal(result.local.length, 0);
		Assert.equal(result.remote.length, 0);

		assertLatencyHistogram(histogram, true);
		});

		add_task(async function simple_remote_no_local_result() {
		let histogram = TelemetryTestUtils.getAndClearKeyedHistogram(
		SEARCH_TELEMETRY_LATENCY
		);

		let controller = new SearchSuggestionController();
		let result = await controller.fetch("mo", false, getEngine);
		Assert.equal(result.term, "mo");
		@@ -135,11 +166,17 @@ add_task(async function simple_remote_no_local_result() {
		Assert.equal(result.remote[0].value, "Mozilla");
		Assert.equal(result.remote[1].value, "modern");
		Assert.equal(result.remote[2].value, "mom");

		assertLatencyHistogram(histogram, true);
		});

		add_task(async function simple_remote_no_local_result_telemetry() {
		Services.telemetry.clearScalars();

		let histogram = TelemetryTestUtils.getAndClearKeyedHistogram(
		SEARCH_TELEMETRY_LATENCY
		);

		let controller = new SearchSuggestionController();
		await controller.fetch("mo", false, getEngine);

		@@ -153,8 +190,10 @@ add_task(async function simple_remote_no_local_result_telemetry() {
		}, "should have the expected keyed scalars");

		const scalar = scalars[key];
		Assert.ok("sggt-other" in scalar, "correct telemetry category");
		Assert.notEqual(scalar["sggt-other"], 0, "bandwidth logged");
		Assert.ok(`sggt-${ENGINE_NAME}` in scalar, "correct telemetry category");
		Assert.notEqual(scalar[`sggt-${ENGINE_NAME}`], 0, "bandwidth logged");

		assertLatencyHistogram(histogram, true);
		});

		add_task(async function simple_remote_no_local_result_alternative_type() {
		@@ -350,6 +389,10 @@ add_task(async function tail_offset_index() {
		});

		add_task(async function fetch_twice_in_a_row() {
		let histogram = TelemetryTestUtils.getAndClearKeyedHistogram(
		SEARCH_TELEMETRY_LATENCY
		);

		// Two entries since the first will match the first fetch but not the second.
		await updateSearchHistory("bump", "delay local");
		await updateSearchHistory("bump", "delayed local");
		@@ -367,6 +410,10 @@ add_task(async function fetch_twice_in_a_row() {
		Assert.equal(result.local[0].value, "delayed local");
		Assert.equal(result.remote.length, 1);
		Assert.equal(result.remote[0].value, "delayed ");

		// Only the second fetch's latency should be recorded since the first fetch
		// was aborted and latencies for aborted fetches are not recorded.
		assertLatencyHistogram(histogram, true);
		});

		add_task(async function fetch_twice_subset_reuse_formHistoryResult() {
		@@ -431,6 +478,10 @@ add_task(async function both_identical_with_more_than_max_results() {
		});

		add_task(async function noremote_maxLocal() {
		let histogram = TelemetryTestUtils.getAndClearKeyedHistogram(
		SEARCH_TELEMETRY_LATENCY
		);

		let controller = new SearchSuggestionController();
		controller.maxLocalResults = 2; // (should be ignored because no remote results)
		controller.maxRemoteResults = 0;
		@@ -444,9 +495,15 @@ add_task(async function noremote_maxLocal() {
		);
		}
		Assert.equal(result.remote.length, 0);

		assertLatencyHistogram(histogram, false);
		});

		add_task(async function someremote_maxLocal() {
		let histogram = TelemetryTestUtils.getAndClearKeyedHistogram(
		SEARCH_TELEMETRY_LATENCY
		);

		let controller = new SearchSuggestionController();
		controller.maxLocalResults = 2;
		controller.maxRemoteResults = 4;
		@@ -467,6 +524,8 @@ add_task(async function someremote_maxLocal() {
		"letter " + String.fromCharCode("C".charCodeAt() + i)
		);
		}

		assertLatencyHistogram(histogram, true);
		});

		add_task(async function one_of_each() {
		@@ -482,6 +541,10 @@ add_task(async function one_of_each() {
		});

		add_task(async function local_result_returned_remote_result_disabled() {
		let histogram = TelemetryTestUtils.getAndClearKeyedHistogram(
		SEARCH_TELEMETRY_LATENCY
		);

		Services.prefs.setBoolPref("browser.search.suggest.enabled", false);
		let controller = new SearchSuggestionController();
		controller.maxLocalResults = 1;
		@@ -496,11 +559,15 @@ add_task(async function local_result_returned_remote_result_disabled() {
		);
		}
		Assert.equal(result.remote.length, 0);
		assertLatencyHistogram(histogram, false);
		Services.prefs.setBoolPref("browser.search.suggest.enabled", true);
		});

		add_task(
		async function local_result_returned_remote_result_disabled_after_creation_of_controller() {
		let histogram = TelemetryTestUtils.getAndClearKeyedHistogram(
		SEARCH_TELEMETRY_LATENCY
		);
		let controller = new SearchSuggestionController();
		controller.maxLocalResults = 1;
		controller.maxRemoteResults = 1;
		@@ -515,12 +582,17 @@ add_task(
		);
		}
		Assert.equal(result.remote.length, 0);
		assertLatencyHistogram(histogram, false);
		Services.prefs.setBoolPref("browser.search.suggest.enabled", true);
		}
		);

		add_task(
		async function one_of_each_disabled_before_creation_enabled_after_creation_of_controller() {
		let histogram = TelemetryTestUtils.getAndClearKeyedHistogram(
		SEARCH_TELEMETRY_LATENCY
		);

		Services.prefs.setBoolPref("browser.search.suggest.enabled", false);
		let controller = new SearchSuggestionController();
		controller.maxLocalResults = 1;
		@@ -533,11 +605,16 @@ add_task(
		Assert.equal(result.remote.length, 1);
		Assert.equal(result.remote[0].value, "letter B");

		assertLatencyHistogram(histogram, true);

		Services.prefs.setBoolPref("browser.search.suggest.enabled", true);
		}
		);

		add_task(async function one_local_zero_remote() {
		let histogram = TelemetryTestUtils.getAndClearKeyedHistogram(
		SEARCH_TELEMETRY_LATENCY
		);
		let controller = new SearchSuggestionController();
		controller.maxLocalResults = 1;
		controller.maxRemoteResults = 0;
		@@ -551,9 +628,13 @@ add_task(async function one_local_zero_remote() {
		);
		}
		Assert.equal(result.remote.length, 0);
		assertLatencyHistogram(histogram, false);
		});

		add_task(async function zero_local_one_remote() {
		let histogram = TelemetryTestUtils.getAndClearKeyedHistogram(
		SEARCH_TELEMETRY_LATENCY
		);
		let controller = new SearchSuggestionController();
		controller.maxLocalResults = 0;
		controller.maxRemoteResults = 1;
		@@ -562,9 +643,13 @@ add_task(async function zero_local_one_remote() {
		Assert.equal(result.local.length, 0);
		Assert.equal(result.remote.length, 1);
		Assert.equal(result.remote[0].value, "letter A");
		assertLatencyHistogram(histogram, true);
		});

		add_task(async function stop_search() {
		let histogram = TelemetryTestUtils.getAndClearKeyedHistogram(
		SEARCH_TELEMETRY_LATENCY
		);
		let controller = new SearchSuggestionController(result => {
		do_throw("The callback shouldn't be called after stop()");
		});
		@@ -573,52 +658,122 @@ add_task(async function stop_search() {
		await resultPromise.then(result => {
		Assert.equal(null, result);
		});
		assertLatencyHistogram(histogram, false);
		});

		add_task(async function empty_searchTerm() {
		// Empty searches don't go to the server but still get form history.
		let histogram = TelemetryTestUtils.getAndClearKeyedHistogram(
		SEARCH_TELEMETRY_LATENCY
		);
		let controller = new SearchSuggestionController();
		let result = await controller.fetch("", false, getEngine);
		Assert.equal(result.term, "");
		Assert.ok(!!result.local.length);
		Assert.equal(result.remote.length, 0);
		assertLatencyHistogram(histogram, false);
		});

		add_task(async function slow_timeout() {
		let d = PromiseUtils.defer();
		function check_result(result) {
		Assert.equal(result.term, "slow ");
		let histogram = TelemetryTestUtils.getAndClearKeyedHistogram(
		SEARCH_TELEMETRY_LATENCY
		);

		// Make the server return suggestions on a delay longer than the timeout of
		// the suggestion controller.
		let delayMs = 3 * SearchSuggestionController.REMOTE_TIMEOUT_DEFAULT;
		let searchString = `delay${delayMs} `;

		// Add a local result.
		let localValue = searchString + " local result";
		await updateSearchHistory("bump", localValue);

		// Do a search. The remote fetch should time out but the local result should
		// be returned.
		let controller = new SearchSuggestionController();
		let result = await controller.fetch(searchString, false, getEngine);
		Assert.equal(result.term, searchString);
		Assert.equal(result.local.length, 1);
		Assert.equal(result.local[0].value, "slow local result");
		Assert.equal(result.local[0].value, localValue);
		Assert.equal(result.remote.length, 0);
		}
		await updateSearchHistory("bump", "slow local result");

		// The remote fetch isn't done yet, so the latency histogram should not be
		// updated.
		assertLatencyHistogram(histogram, false);

		// Wait for the remote fetch to finish.
		await new Promise(r => setTimeout(r, delayMs));

		// Now the latency histogram should be updated.
		assertLatencyHistogram(histogram, true);
		});

		add_task(async function slow_timeout_2() {
		let histogram = TelemetryTestUtils.getAndClearKeyedHistogram(
		SEARCH_TELEMETRY_LATENCY
		);

		// Make the server return suggestions on a delay longer the timeout of the
		// suggestion controller.
		let delayMs = 3 * SearchSuggestionController.REMOTE_TIMEOUT_DEFAULT;
		let searchString = `delay${delayMs} `;

		// Add a local result.
		let localValue = searchString + " local result";
		await updateSearchHistory("bump", localValue);

		// Do two searches using the same controller. Both times, the remote fetches
		// should time out and only the local result should be returned. The second
		// search should abort the remote fetch of the first search, and the remote
		// fetch of the second search should be ongoing when the second search
		// finishes.
		let controller = new SearchSuggestionController();
		setTimeout(function check_timeout() {
		// The HTTP response takes 10 seconds so check that we already have results after 2 seconds.
		check_result(result);
		d.resolve();
		}, 2000);
		let result = await controller.fetch("slow ", false, getEngine);
		check_result(result);
		await d.promise;
		for (let i = 0; i < 2; i++) {
		let result = await controller.fetch(searchString, false, getEngine);
		Assert.equal(result.term, searchString);
		Assert.equal(result.local.length, 1);
		Assert.equal(result.local[0].value, localValue);
		Assert.equal(result.remote.length, 0);
		}

		// The remote fetch of the second search isn't done yet, so the latency
		// histogram should not be updated.
		assertLatencyHistogram(histogram, false);

		// Wait for the second remote fetch to finish.
		await new Promise(r => setTimeout(r, delayMs));

		// Now the latency histogram should be updated, and only the remote fetch of
		// the second search should be recorded.
		assertLatencyHistogram(histogram, true);
		});

		add_task(async function slow_stop() {
		let d = PromiseUtils.defer();
		let histogram = TelemetryTestUtils.getAndClearKeyedHistogram(
		SEARCH_TELEMETRY_LATENCY
		);

		// Make the server return suggestions on a delay longer the timeout of the
		// suggestion controller.
		let delayMs = 3 * SearchSuggestionController.REMOTE_TIMEOUT_DEFAULT;
		let searchString = `delay${delayMs} `;

		// Do a search but stop it before it finishes. Wait a tick before stopping it
		// to better simulate the real world.
		let controller = new SearchSuggestionController();
		let resultPromise = controller.fetch("slow ", false, getEngine);
		setTimeout(function check_timeout() {
		// The HTTP response takes 10 seconds but we timeout in less than a second so just use 0.
		let resultPromise = controller.fetch(searchString, false, getEngine);
		await TestUtils.waitForTick();
		controller.stop();
		d.resolve();
		}, 0);
		await resultPromise.then(result => {
		Assert.equal(null, result);
		});
		let result = await resultPromise;
		Assert.equal(result, null, "No result should be returned");

		await d.promise;
		// The remote fetch should have been aborted by stopping the controller, but
		// wait for the timeout period just to make sure it's done.
		await new Promise(r => setTimeout(r, delayMs));

		// Since the latencies of aborted fetches are not recorded, the latency
		// histogram should not be updated.
		assertLatencyHistogram(histogram, false);
		});

		// Error handling
		@@ -626,39 +781,61 @@ add_task(async function slow_stop() {
		add_task(async function remote_term_mismatch() {
		await updateSearchHistory("bump", "Query Mismatch Entry");

		let histogram = TelemetryTestUtils.getAndClearKeyedHistogram(
		SEARCH_TELEMETRY_LATENCY
		);

		let controller = new SearchSuggestionController();
		let result = await controller.fetch("Query Mismatch", false, getEngine);
		Assert.equal(result.term, "Query Mismatch");
		Assert.equal(result.local.length, 1);
		Assert.equal(result.local[0].value, "Query Mismatch Entry");
		Assert.equal(result.remote.length, 0);

		assertLatencyHistogram(histogram, true);
		});

		add_task(async function http_404() {
		await updateSearchHistory("bump", "HTTP 404 Entry");

		let histogram = TelemetryTestUtils.getAndClearKeyedHistogram(
		SEARCH_TELEMETRY_LATENCY
		);

		let controller = new SearchSuggestionController();
		let result = await controller.fetch("HTTP 404", false, getEngine);
		Assert.equal(result.term, "HTTP 404");
		Assert.equal(result.local.length, 1);
		Assert.equal(result.local[0].value, "HTTP 404 Entry");
		Assert.equal(result.remote.length, 0);

		assertLatencyHistogram(histogram, true);
		});

		add_task(async function http_500() {
		await updateSearchHistory("bump", "HTTP 500 Entry");

		let histogram = TelemetryTestUtils.getAndClearKeyedHistogram(
		SEARCH_TELEMETRY_LATENCY
		);

		let controller = new SearchSuggestionController();
		let result = await controller.fetch("HTTP 500", false, getEngine);
		Assert.equal(result.term, "HTTP 500");
		Assert.equal(result.local.length, 1);
		Assert.equal(result.local[0].value, "HTTP 500 Entry");
		Assert.equal(result.remote.length, 0);

		assertLatencyHistogram(histogram, true);
		});

		add_task(async function unresolvable_server() {
		await updateSearchHistory("bump", "Unresolvable Server Entry");

		let histogram = TelemetryTestUtils.getAndClearKeyedHistogram(
		SEARCH_TELEMETRY_LATENCY
		);

		let controller = new SearchSuggestionController();
		let result = await controller.fetch(
		"Unresolvable Server",
		@@ -669,6 +846,11 @@ add_task(async function unresolvable_server() {
		Assert.equal(result.local.length, 1);
		Assert.equal(result.local[0].value, "Unresolvable Server Entry");
		Assert.equal(result.remote.length, 0);

		// This latency assert fails on Windows 7 (NT version 6.1), so skip it there.
		if (!AppConstants.isPlatformAndVersionAtMost("win", "6.1")) {
		assertLatencyHistogram(histogram, true);
		}
		});

		// Exception handling
		@@ -762,3 +944,24 @@ function updateSearchHistory(operation, value) {
		);
		});
		}

		function assertLatencyHistogram(histogram, shouldRecord) {
		let snapshot = histogram.snapshot();
		info("Checking latency snapshot: " + JSON.stringify(snapshot));

		// Build a map from engine ID => number of non-zero values recorded for it.
		let valueCountByEngineId = Object.entries(snapshot).reduce(
		(memo, [key, data]) => {
		memo[key] = Object.values(data.values).filter(v => v != 0);
		return memo;
		},
		{}
		);

		let expected = shouldRecord ? { [ENGINE_NAME]: [1] } : {};
		Assert.deepEqual(
		valueCountByEngineId,
		expected,
		shouldRecord ? "Latency histogram updated" : "Latency histogram not updated"
		);
		}