Bug 833612 - More robust recording of sessionRestored value; r=rnewman

services/datareporting/DataReportingService.js

@@ -128,16 +128,6 @@ DataReportingService.prototype = Object.freeze({
         this._os.removeObserver(this, "sessionstore-windows-restored");
         this._os.addObserver(this, "quit-application", false);
 
-        // When the session recorder starts up above, first paint and session
-        // restore times likely aren't available. So, we wait until they are (here)
-        // and record them. In the case of session restore time, that appears
-        // to be set by an observer of this notification. So, we delay
-        // recording until the next tick of the event loop.
-        if (this.sessionRecorder) {
-          CommonUtils.nextTick(this.sessionRecorder.recordStartupFields,
-                               this.sessionRecorder);
-        }
-
         this.policy.startPolling();
 
         // Don't initialize Firefox Health Reporter collection and submission

services/datareporting/sessions.jsm

@@ -22,7 +22,10 @@ Cu.import("resource://services-common/utils.js");
 
 // We automatically prune sessions older than this.
 const MAX_SESSION_AGE_MS = 7 * 24 * 60 * 60 * 1000; // 7 days.
+const STARTUP_RETRY_INTERVAL_MS = 5000;
 
+// Wait up to 5 minutes for startup measurements before giving up.
+const MAX_STARTUP_TRIES = 300000 / STARTUP_RETRY_INTERVAL_MS;
 
 /**
  * Records information about browser sessions.
@@ -72,6 +75,8 @@ this.SessionRecorder = function (branch) {
   this._lastActivityWasInactive = false;
   this._activeTicks = 0;
   this._started = false;
+  this._timer = null;
+  this._startupFieldTries = 0;
 
   this._os = Cc["@mozilla.org/observer-service;1"]
                .getService(Ci.nsIObserverService);
@@ -81,6 +86,8 @@ this.SessionRecorder = function (branch) {
 SessionRecorder.prototype = Object.freeze({
   QueryInterface: XPCOMUtils.generateQI([Ci.nsIObserver]),
 
+  STARTUP_RETRY_INTERVAL_MS: STARTUP_RETRY_INTERVAL_MS,
+
   get _currentIndex() {
     return this._prefs.get("currentIndex", 0);
   },
@@ -204,13 +211,40 @@ SessionRecorder.prototype = Object.freeze({
       throw new Error("Startup info not available.");
     }
 
+    let missing = false;
+
     for (let field of ["main", "firstPaint", "sessionRestored"]) {
       if (!(field in si)) {
+        this._log.debug("Missing startup field: " + field);
+        missing = true;
         continue;
       }
 
       this["_" + field] = si[field].getTime() - si.process.getTime();
     }
+
+    if (!missing || this._startupFieldTries > MAX_STARTUP_TRIES) {
+      this._clearStartupTimer();
+      return;
+    }
+
+    // If we have missing fields, install a timer and keep waiting for
+    // data.
+    this._startupFieldTries++;
+
+    if (!this._timer) {
+      this._timer = Cc["@mozilla.org/timer;1"].createInstance(Ci.nsITimer);
+      this._timer.initWithCallback({
+        notify: this.recordStartupFields.bind(this),
+      }, this.STARTUP_RETRY_INTERVAL_MS, this._timer.TYPE_REPEATING_SLACK);
+    }
+  },
+
+  _clearStartupTimer: function () {
+    if (this._timer) {
+      this._timer.cancel();
+      delete this._timer;
+    }
   },
 
   /**
@@ -263,6 +297,7 @@ SessionRecorder.prototype = Object.freeze({
     this._log.info("Recording clean session shutdown.");
     this._prefs.set("current.clean", true);
     this.updateTotalTime();
+    this._clearStartupTimer();
 
     this._os.removeObserver(this, "profile-before-change");
     this._os.removeObserver(this, "user-interaction-active");

services/datareporting/tests/xpcshell/test_session_recorder.js

@@ -72,6 +72,86 @@ add_task(function test_current_properties() {
   recorder.onShutdown();
 });
 
+// If startup info isn't present yet, we should install a timer and get
+// it eventually.
+add_task(function test_current_availability() {
+  let recorder = new SessionRecorder("testing.current_availability.");
+  let now = new Date();
+
+  Object.defineProperty(recorder, "_getStartupInfo", {
+    value: function _getStartupInfo() {
+      return {
+        process: now,
+        main: new Date(now.getTime() + 500),
+        firstPaint: new Date(now.getTime() + 1000),
+      };
+    },
+    writable: true,
+  });
+
+  Object.defineProperty(recorder, "STARTUP_RETRY_INTERVAL_MS", {
+    value: 100,
+  });
+
+  let oldRecord = recorder.recordStartupFields;
+  let recordCount = 0;
+
+  Object.defineProperty(recorder, "recordStartupFields", {
+    value: function () {
+      recordCount++;
+      return oldRecord.call(recorder);
+    }
+  });
+
+  do_check_null(recorder._timer);
+  recorder.onStartup();
+  do_check_eq(recordCount, 1);
+  do_check_eq(recorder.sessionRestored, -1);
+  do_check_neq(recorder._timer, null);
+
+  yield sleep(125);
+  do_check_eq(recordCount, 2);
+  yield sleep(100);
+  do_check_eq(recordCount, 3);
+  do_check_eq(recorder.sessionRestored, -1);
+
+  monkeypatchStartupInfo(recorder, now);
+  yield sleep(100);
+  do_check_eq(recordCount, 4);
+  do_check_eq(recorder.sessionRestored, 1500);
+
+  // The timer should be removed and we should not fire again.
+  do_check_null(recorder._timer);
+  yield sleep(100);
+  do_check_eq(recordCount, 4);
+
+  recorder.onShutdown();
+});
+
+add_test(function test_timer_clear_on_shutdown() {
+  let recorder = new SessionRecorder("testing.timer_clear_on_shutdown.");
+  let now = new Date();
+
+  Object.defineProperty(recorder, "_getStartupInfo", {
+    value: function _getStartupInfo() {
+      return {
+        process: now,
+        main: new Date(now.getTime() + 500),
+        firstPaint: new Date(now.getTime() + 1000),
+      };
+    },
+  });
+
+  do_check_null(recorder._timer);
+  recorder.onStartup();
+  do_check_neq(recorder._timer, null);
+
+  recorder.onShutdown();
+  do_check_null(recorder._timer);
+
+  run_next_test();
+});
+
 add_task(function test_previous_clean() {
   let now = new Date();
   let recorder = getRecorder("previous_clean", now);