Bug 1356210 - Clean up TelemetryStopwatch.start calls for FX_TAB_CLOSE_TIME_ANIM_MS and FX_TAB_CLOSE_TIME_NO_ANIM_MS probes. r?mconley,dexter
MozReview-Commit-ID: IvOerEtYY6T
--- a/browser/base/content/tabbrowser.xml
+++ b/browser/base/content/tabbrowser.xml
@@ -2537,49 +2537,31 @@
[]
</field>
<method name="removeTab">
<parameter name="aTab"/>
<parameter name="aParams"/>
<body>
<![CDATA[
- // We collect Telemetry on how long it takes to close a tab.
- // Sometimes, tabs animate closed, and sometimes they don't, and
- // it doesn't really make sense to put timings for both cases in the
- // same bucket.
- //
- // We decide later on whether or not we're actually going to animate
- // the tab closed. In order to capture as much of the time we care
- // about with these stopwatches, but also in order to avoid any
- // unnecessary work (since calculating whether or not we're going
- // to do the animation might involved a style flush), we start
- // stopwatches for both the animating and non-animating case. When
- // we decide that we're animating, we cancel the non-animating case,
- // and vice-versa. Then, in _endRemoveTab, we "finish" both
- // stopwatches, which is a no-op for cancelled stopwatches.
- //
- // Note that removeTab might be re-entrant, as we currently spin an
- // event loop while waiting for remote browsers to tell us whether or
- // not we're allowed to unload them via permitUnload. This means that
- // subsequent calls to removeTab will also have these stopwatches
- // on file. There's also the case that the tab was animating closed,
- // and removeTab was called on it before it completed. In either case,
- // we skip (re)starting the stopwatches.
- if (!aTab._pendingPermitUnload && !aTab.closing) {
- TelemetryStopwatch.start("FX_TAB_CLOSE_TIME_ANIM_MS", aTab);
- TelemetryStopwatch.start("FX_TAB_CLOSE_TIME_NO_ANIM_MS", aTab);
- }
-
if (aParams) {
var animate = aParams.animate;
var byMouse = aParams.byMouse;
var skipPermitUnload = aParams.skipPermitUnload;
}
+ // Telemetry stopwatches may already be running if removeTab gets
+ // called again for an already closing tab.
+ if (!TelemetryStopwatch.running("FX_TAB_CLOSE_TIME_ANIM_MS", aTab) &&
+ !TelemetryStopwatch.running("FX_TAB_CLOSE_TIME_NO_ANIM_MS", aTab)) {
+ // Speculatevely start both stopwatches now. We'll cancel one of
+ // the two later depending on whether we're animating.
+ TelemetryStopwatch.start("FX_TAB_CLOSE_TIME_ANIM_MS", aTab);
+ TelemetryStopwatch.start("FX_TAB_CLOSE_TIME_NO_ANIM_MS", aTab);
+ }
window.maybeRecordAbandonmentTelemetry(aTab, "tabClosed");
// Handle requests for synchronously removing an already
// asynchronously closing tab.
if (!animate &&
aTab.closing) {
this._endRemoveTab(aTab);
return;
--- a/toolkit/components/telemetry/TelemetryStopwatch.jsm
+++ b/toolkit/components/telemetry/TelemetryStopwatch.jsm
@@ -132,22 +132,41 @@ this.TelemetryStopwatch = {
* started again, and the existing one will be cleared in
* order to avoid measurements errors.
*/
start(aHistogram, aObj) {
return TelemetryStopwatchImpl.start(aHistogram, aObj, null);
},
/**
+ * Returns whether a timer associated with a telemetry histogram is currently
+ * running. The timer can be directly associated with a histogram, or with a
+ * pair of a histogram and an object.
+ *
+ * @param {String} aHistogram - a string which must be a valid histogram name.
+ *
+ * @param {Object} aObj - Optional parameter. If specified, the timer is
+ * associated with this object, meaning that multiple
+ * timers for the same histogram may be run
+ * concurrently, as long as they are associated with
+ * different objects.
+ *
+ * @returns {Boolean} True if the timer exists and is currently running.
+ */
+ running(aHistogram, aObj) {
+ return TelemetryStopwatchImpl.running(aHistogram, aObj, null);
+ },
+
+ /**
* Deletes the timer associated with a telemetry histogram. The timer can be
* directly associated with a histogram, or with a pair of a histogram and
* an object. Important: Only use this method when a legitimate cancellation
* should be done.
*
- * @param {String} aHistogram - a string which must be a valid histogram name.
+ * @param {String} aHistogram - a string which must be a valid histogram name.
*
* @param {Object} aObj - Optional parameter. If specified, the timer is
* associated with this object, meaning that multiple
* timers or a same histogram may be run concurrently,
* as long as they are associated with different
* objects.
*
* @returns {Boolean} True if the timer exist and it was cleared, False
@@ -225,16 +244,38 @@ this.TelemetryStopwatch = {
* started again, and the existing one will be cleared in
* order to avoid measurements errors.
*/
startKeyed(aHistogram, aKey, aObj) {
return TelemetryStopwatchImpl.start(aHistogram, aObj, aKey);
},
/**
+ * Returns whether a timer associated with a telemetry histogram is currently
+ * running. Similarly to @see{TelemetryStopwatch.running} the timer and its
+ * key can be associated with an object. Each key may have multiple associated
+ * objects and each object can be associated with multiple keys.
+ *
+ * @param {String} aHistogram - a string which must be a valid histogram name.
+ *
+ * @param {String} aKey - a string which must be a valid histgram key.
+ *
+ * @param {Object} aObj - Optional parameter. If specified, the timer is
+ * associated with this object, meaning that multiple
+ * timers for the same histogram may be run
+ * concurrently, as long as they are associated with
+ * different objects.
+ *
+ * @returns {Boolean} True if the timer exists and is currently running.
+ */
+ runningKeyed(aHistogram, aKey, aObj) {
+ return TelemetryStopwatchImpl.running(aHistogram, aObj, aKey);
+ },
+
+ /**
* Deletes the timer associated with a keyed histogram. Important: Only use
* this method when a legitimate cancellation should be done.
*
* @param {String} aHistogram - a string which must be a valid histogram name.
*
* @param {String} aKey - a string which must be a valid histgram key.
*
* @param {Object} aObj - Optional parameter. If specified, the timer
@@ -299,16 +340,20 @@ this.TelemetryStopwatchImpl = {
Cu.reportError(`TelemetryStopwatch: key "${histogram}" was already ` +
"initialized");
return false;
}
return Timers.put(histogram, object, key, Components.utils.now());
},
+ running(histogram, object, key) {
+ return Timers.has(histogram, object, key);
+ },
+
cancel(histogram, object, key) {
return Timers.delete(histogram, object, key);
},
timeElapsed(histogram, object, key, aCanceledOkay) {
let startTime = Timers.get(histogram, object, key);
if (startTime === null) {
if (!aCanceledOkay) {
--- a/toolkit/components/telemetry/docs/collection/measuring-time.rst
+++ b/toolkit/components/telemetry/docs/collection/measuring-time.rst
@@ -11,26 +11,30 @@ JavaScript can measure elapsed time usin
``TelemetryStopwatch`` is a helper that simplifies recording elapsed time (in milliseconds) into histograms (plain or keyed).
API:
.. code-block:: js
TelemetryStopwatch = {
- // Start, cancel & finish recording elapsed time into a histogram.
+ // Start, check if running, cancel & finish recording elapsed time into a
+ // histogram.
// |aObject| is optional. If specificied, the timer is associated with this
// object, so multiple time measurements can be done concurrently.
start(histogramId, aObject);
+ running(histogramId, aObject);
cancel(histogramId, aObject);
finish(histogramId, aObject);
- // Start, cancel & finished recording elapsed time into a keyed histogram.
+ // Start, check if running, cancel & finish recording elapsed time into a
+ // keyed histogram.
// |key| specificies the key to record into.
// |aObject| is optional and used as above.
startKeyed(histogramId, key, aObject);
+ runningKeyed(histogramId, key, aObject);
cancelKeyed(histogramId, key, aObject);
finishKeyed(histogramId, key, aObject);
};
Example:
.. code-block:: js
@@ -39,16 +43,22 @@ Example:
if (failedToOpenFile) {
// Cancel this if the operation failed early etc.
TelemetryStopwatch.cancel("SAMPLE_FILE_LOAD_TIME_MS");
return;
}
// ... do more work.
TelemetryStopwatch.finish("SAMPLE_FILE_LOAD_TIME_MS");
+ // Another loading attempt? Start stopwatch again if
+ // not already running.
+ if (!TelemetryStopwatch.running("SAMPLE_FILE_LOAD_TIME_MS")) {
+ TelemetryStopwatch.start("SAMPLE_FILE_LOAD_TIME_MS");
+ }
+
// Periodically, it's necessary to attempt to finish a
// TelemetryStopwatch that's already been canceled or
// finished. Normally, that throws a warning to the
// console. If the TelemetryStopwatch being possibly
// cancelled or finished is expected behaviour, the
// warning can be suppressed by passing the optional
// aCanceledOkay argument.
--- a/toolkit/components/telemetry/tests/unit/test_TelemetryStopwatch.js
+++ b/toolkit/components/telemetry/tests/unit/test_TelemetryStopwatch.js
@@ -47,82 +47,121 @@ function run_test() {
do_check_false(TelemetryStopwatch.finish("mark1", refObj));
do_check_true(TelemetryStopwatch.start("NON-EXISTENT_HISTOGRAM"));
do_check_false(TelemetryStopwatch.finish("NON-EXISTENT_HISTOGRAM"));
do_check_true(TelemetryStopwatch.start("NON-EXISTENT_HISTOGRAM", refObj));
do_check_false(TelemetryStopwatch.finish("NON-EXISTENT_HISTOGRAM", refObj));
+ do_check_false(TelemetryStopwatch.running(HIST_NAME));
+ do_check_false(TelemetryStopwatch.running(HIST_NAME2));
+ do_check_false(TelemetryStopwatch.running(HIST_NAME, refObj));
+ do_check_false(TelemetryStopwatch.running(HIST_NAME2, refObj));
+ do_check_false(TelemetryStopwatch.running(HIST_NAME, refObj2));
+ do_check_false(TelemetryStopwatch.running(HIST_NAME2, refObj2));
+
do_check_true(TelemetryStopwatch.start(HIST_NAME));
do_check_true(TelemetryStopwatch.start(HIST_NAME2));
do_check_true(TelemetryStopwatch.start(HIST_NAME, refObj));
do_check_true(TelemetryStopwatch.start(HIST_NAME2, refObj));
do_check_true(TelemetryStopwatch.start(HIST_NAME, refObj2));
do_check_true(TelemetryStopwatch.start(HIST_NAME2, refObj2));
+ do_check_true(TelemetryStopwatch.running(HIST_NAME));
+ do_check_true(TelemetryStopwatch.running(HIST_NAME));
+ do_check_true(TelemetryStopwatch.running(HIST_NAME2));
+ do_check_true(TelemetryStopwatch.running(HIST_NAME, refObj));
+ do_check_true(TelemetryStopwatch.running(HIST_NAME2, refObj));
+ do_check_true(TelemetryStopwatch.running(HIST_NAME, refObj2));
+ do_check_true(TelemetryStopwatch.running(HIST_NAME2, refObj2));
+
do_check_true(TelemetryStopwatch.finish(HIST_NAME));
do_check_true(TelemetryStopwatch.finish(HIST_NAME2));
do_check_true(TelemetryStopwatch.finish(HIST_NAME, refObj));
do_check_true(TelemetryStopwatch.finish(HIST_NAME2, refObj));
do_check_true(TelemetryStopwatch.finish(HIST_NAME, refObj2));
do_check_true(TelemetryStopwatch.finish(HIST_NAME2, refObj2));
+ do_check_false(TelemetryStopwatch.running(HIST_NAME));
+ do_check_false(TelemetryStopwatch.running(HIST_NAME));
+ do_check_false(TelemetryStopwatch.running(HIST_NAME2));
+ do_check_false(TelemetryStopwatch.running(HIST_NAME, refObj));
+ do_check_false(TelemetryStopwatch.running(HIST_NAME2, refObj));
+ do_check_false(TelemetryStopwatch.running(HIST_NAME, refObj2));
+ do_check_false(TelemetryStopwatch.running(HIST_NAME2, refObj2));
+
// Verify that TS.finish deleted the timers
do_check_false(TelemetryStopwatch.finish(HIST_NAME));
do_check_false(TelemetryStopwatch.finish(HIST_NAME, refObj));
// Verify that they can be used again
do_check_true(TelemetryStopwatch.start(HIST_NAME));
do_check_true(TelemetryStopwatch.start(HIST_NAME, refObj));
do_check_true(TelemetryStopwatch.finish(HIST_NAME));
do_check_true(TelemetryStopwatch.finish(HIST_NAME, refObj));
do_check_false(TelemetryStopwatch.finish("unknown-mark")); // Unknown marker
do_check_false(TelemetryStopwatch.finish("unknown-mark", {})); // Unknown object
do_check_false(TelemetryStopwatch.finish(HIST_NAME, {})); // Known mark on unknown object
// Test cancel
+ do_check_false(TelemetryStopwatch.running(HIST_NAME));
+ do_check_false(TelemetryStopwatch.running(HIST_NAME, refObj));
do_check_true(TelemetryStopwatch.start(HIST_NAME));
do_check_true(TelemetryStopwatch.start(HIST_NAME, refObj));
+ do_check_true(TelemetryStopwatch.running(HIST_NAME));
+ do_check_true(TelemetryStopwatch.running(HIST_NAME, refObj));
do_check_true(TelemetryStopwatch.cancel(HIST_NAME));
do_check_true(TelemetryStopwatch.cancel(HIST_NAME, refObj));
// Verify that can not cancel twice
do_check_false(TelemetryStopwatch.cancel(HIST_NAME));
do_check_false(TelemetryStopwatch.cancel(HIST_NAME, refObj));
// Verify that cancel removes the timers
+ do_check_false(TelemetryStopwatch.running(HIST_NAME));
+ do_check_false(TelemetryStopwatch.running(HIST_NAME, refObj));
do_check_false(TelemetryStopwatch.finish(HIST_NAME));
do_check_false(TelemetryStopwatch.finish(HIST_NAME, refObj));
// Verify that keyed stopwatch reject invalid keys.
for (let key of [3, {}, ""]) {
do_check_false(TelemetryStopwatch.startKeyed(KEYED_HIST.id, key));
}
// Verify that keyed histograms can be started.
+ do_check_false(TelemetryStopwatch.runningKeyed("HISTOGRAM", "KEY1"));
+ do_check_false(TelemetryStopwatch.runningKeyed("HISTOGRAM", "KEY2"));
+ do_check_false(TelemetryStopwatch.runningKeyed("HISTOGRAM", "KEY1", refObj));
+ do_check_false(TelemetryStopwatch.runningKeyed("HISTOGRAM", "KEY2", refObj));
+
do_check_true(TelemetryStopwatch.startKeyed("HISTOGRAM", "KEY1"));
do_check_true(TelemetryStopwatch.startKeyed("HISTOGRAM", "KEY2"));
do_check_true(TelemetryStopwatch.startKeyed("HISTOGRAM", "KEY1", refObj));
do_check_true(TelemetryStopwatch.startKeyed("HISTOGRAM", "KEY2", refObj));
+ do_check_true(TelemetryStopwatch.runningKeyed("HISTOGRAM", "KEY1"));
+ do_check_true(TelemetryStopwatch.runningKeyed("HISTOGRAM", "KEY2"));
+ do_check_true(TelemetryStopwatch.runningKeyed("HISTOGRAM", "KEY1", refObj));
+ do_check_true(TelemetryStopwatch.runningKeyed("HISTOGRAM", "KEY2", refObj));
+
// Restarting keyed histograms should fail.
do_check_false(TelemetryStopwatch.startKeyed("HISTOGRAM", "KEY1"));
do_check_false(TelemetryStopwatch.startKeyed("HISTOGRAM", "KEY1", refObj));
// Finishing a stopwatch of a non existing histogram should return false.
do_check_false(TelemetryStopwatch.finishKeyed("HISTOGRAM", "KEY2"));
do_check_false(TelemetryStopwatch.finishKeyed("HISTOGRAM", "KEY2", refObj));
// Starting & finishing a keyed stopwatch for an existing histogram should work.
do_check_true(TelemetryStopwatch.startKeyed(KEYED_HIST.id, KEYED_HIST.key));
do_check_true(TelemetryStopwatch.finishKeyed(KEYED_HIST.id, KEYED_HIST.key));
// Verify that TS.finish deleted the timers
- do_check_false(TelemetryStopwatch.finishKeyed(KEYED_HIST.id, KEYED_HIST.key));
+ do_check_false(TelemetryStopwatch.runningKeyed(KEYED_HIST.id, KEYED_HIST.key));
// Verify that they can be used again
do_check_true(TelemetryStopwatch.startKeyed(KEYED_HIST.id, KEYED_HIST.key));
do_check_true(TelemetryStopwatch.finishKeyed(KEYED_HIST.id, KEYED_HIST.key));
do_check_false(TelemetryStopwatch.finishKeyed("unknown-mark", "unknown-key"));
do_check_false(TelemetryStopwatch.finishKeyed(KEYED_HIST.id, "unknown-key"));
