Bug 981851 - Add a simple JS logging mechanism to telemetry for recording unusual event data, r=taras
authorBenjamin Smedberg <benjamin@smedbergs.us>
Fri, 14 Mar 2014 09:24:02 -0400
changeset 190856 cd1bb57c45f930ee6d0eb14f78bae84da2ca1a53
parent 190855 8e7dd50fde879b9633a1db115e76d62f0d43c322
child 190857 1e6deb0428f974b9e1ed4d86d03c73a03907ec1b
push idunknown
push userunknown
push dateunknown
reviewerstaras
bugs981851
milestone30.0a1
Bug 981851 - Add a simple JS logging mechanism to telemetry for recording unusual event data, r=taras
toolkit/components/telemetry/Telemetry.cpp
toolkit/components/telemetry/TelemetryLog.jsm
toolkit/components/telemetry/TelemetryPing.jsm
toolkit/components/telemetry/moz.build
toolkit/components/telemetry/nsITelemetry.idl
toolkit/components/telemetry/tests/unit/test_TelemetryLog.js
toolkit/components/telemetry/tests/unit/xpcshell.ini
--- a/toolkit/components/telemetry/Telemetry.cpp
+++ b/toolkit/components/telemetry/Telemetry.cpp
@@ -2553,16 +2553,28 @@ TelemetryImpl::GetFileIOReports(JSContex
     }
     ret.setObject(*obj);
     return NS_OK;
   }
   ret.setNull();
   return NS_OK;
 }
 
+NS_IMETHODIMP
+TelemetryImpl::MsSinceProcessStart(double* aResult)
+{
+  bool error;
+  *aResult = (TimeStamp::NowLoRes() -
+              TimeStamp::ProcessCreation(error)).ToMilliseconds();
+  if (error) {
+    return NS_ERROR_NOT_AVAILABLE;
+  }
+  return NS_OK;
+}
+
 size_t
 TelemetryImpl::SizeOfIncludingThis(mozilla::MallocSizeOf aMallocSizeOf)
 {
   size_t n = aMallocSizeOf(this);
   // Ignore the hashtables in mAddonMap; they are not significant.
   n += mAddonMap.SizeOfExcludingThis(nullptr, aMallocSizeOf);
   n += mHistogramMap.SizeOfExcludingThis(nullptr, aMallocSizeOf);
   n += mPrivateSQL.SizeOfExcludingThis(nullptr, aMallocSizeOf);
new file mode 100644
--- /dev/null
+++ b/toolkit/components/telemetry/TelemetryLog.jsm
@@ -0,0 +1,35 @@
+/* This Source Code Form is subject to the terms of the Mozilla Public
+ * License, v. 2.0. If a copy of the MPL was not distributed with this
+ * file, You can obtain one at http://mozilla.org/MPL/2.0/. */
+
+this.EXPORTED_SYMBOLS = ["TelemetryLog"];
+
+const Cc = Components.classes;
+const Ci = Components.interfaces;
+
+const Telemetry = Cc["@mozilla.org/base/telemetry;1"].getService(Ci.nsITelemetry);
+var gLogEntries = [];
+
+this.TelemetryLog = Object.freeze({
+  log: function(id, data) {
+    id = String(id);
+    var ts;
+    try {
+      ts = Math.floor(Telemetry.msSinceProcessStart());
+    } catch(e) {
+      // If timestamp is screwed up, we just give up instead of making up
+      // data.
+      return;
+    }
+
+    var entry = [id, ts];
+    if (data !== undefined) {
+      entry = entry.concat(Array.prototype.map.call(data, String));
+    }
+    gLogEntries.push(entry);
+  },
+
+  entries: function() {
+    return gLogEntries;
+  }
+});
--- a/toolkit/components/telemetry/TelemetryPing.jsm
+++ b/toolkit/components/telemetry/TelemetryPing.jsm
@@ -68,16 +68,18 @@ XPCOMUtils.defineLazyServiceGetter(this,
 XPCOMUtils.defineLazyModuleGetter(this, "UpdateChannel",
                                   "resource://gre/modules/UpdateChannel.jsm");
 XPCOMUtils.defineLazyModuleGetter(this, "AddonManagerPrivate",
                                   "resource://gre/modules/AddonManager.jsm");
 XPCOMUtils.defineLazyModuleGetter(this, "TelemetryFile",
                                   "resource://gre/modules/TelemetryFile.jsm");
 XPCOMUtils.defineLazyModuleGetter(this, "UITelemetry",
                                   "resource://gre/modules/UITelemetry.jsm");
+XPCOMUtils.defineLazyModuleGetter(this, "TelemetryLog",
+                                  "resource://gre/modules/TelemetryLog.jsm");
 
 function generateUUID() {
   let str = Cc["@mozilla.org/uuid-generator;1"].getService(Ci.nsIUUIDGenerator).generateUUID().toString();
   // strip {}
   return str.substring(1, str.length - 1);
 }
 
 /**
@@ -683,16 +685,17 @@ let Impl = {
       slowSQL: Telemetry.slowSQL,
       fileIOReports: Telemetry.fileIOReports,
       chromeHangs: Telemetry.chromeHangs,
       threadHangStats: this.getThreadHangStats(Telemetry.threadHangStats),
       lateWrites: Telemetry.lateWrites,
       addonHistograms: this.getAddonHistograms(),
       addonDetails: AddonManagerPrivate.getTelemetryDetails(),
       UIMeasurements: UITelemetry.getUIMeasurements(),
+      log: TelemetryLog.entries(),
       info: info
     };
 
     if (Object.keys(this._slowSQLStartup).length != 0 &&
         (Object.keys(this._slowSQLStartup.mainThread).length ||
          Object.keys(this._slowSQLStartup.otherThreads).length)) {
       payloadObj.slowSQLStartup = this._slowSQLStartup;
     }
--- a/toolkit/components/telemetry/moz.build
+++ b/toolkit/components/telemetry/moz.build
@@ -24,16 +24,17 @@ SOURCES += [
 
 EXTRA_COMPONENTS += [
     'TelemetryStartup.js',
     'TelemetryStartup.manifest'
 ]
 
 EXTRA_JS_MODULES += [
     'TelemetryFile.jsm',
+    'TelemetryLog.jsm',
     'TelemetryStopwatch.jsm',
     'ThirdPartyCookieProbe.jsm',
 ]
 
 EXTRA_PP_JS_MODULES += [
     'TelemetryPing.jsm',
     'UITelemetry.jsm',
 ]
--- a/toolkit/components/telemetry/nsITelemetry.idl
+++ b/toolkit/components/telemetry/nsITelemetry.idl
@@ -7,17 +7,17 @@
 #include "nsIFile.idl"
 
 [scriptable,function, uuid(3d3b9075-5549-4244-9c08-b64fefa1dd60)]
 interface nsIFetchTelemetryDataCallback : nsISupports
 {
   void complete();
 };
 
-[scriptable, uuid(6c31f68d-4a54-4dca-b6c8-ddb264d5a154)]
+[scriptable, uuid(4e4bfc35-dac6-4b28-ade4-7e45760051d5)]
 interface nsITelemetry : nsISupports
 {
   /**
    * Histogram types:
    * HISTOGRAM_EXPONENTIAL - buckets increase exponentially
    * HISTOGRAM_LINEAR - buckets increase linearly
    * HISTOGRAM_BOOLEAN - For storing 0/1 values
    * HISTOGRAM_FLAG - For storing a single value; its count is always == 1.
@@ -244,9 +244,16 @@ interface nsITelemetry : nsISupports
    * Get statistics of file IO reports, null, if not recorded.
    *
    * The statistics are returned as an object whose propoerties are the names
    * of the files that have been accessed and whose corresponding values are
    * arrays of the form [total_time, #creates, #reads, #writes, #fsyncs, #stats]
    */
   [implicit_jscontext]
   readonly attribute jsval fileIOReports;
+
+  /**
+   * Return the number of seconds since process start using monotonic
+   * timestamps (unaffected by system clock changes).
+   * @throws NS_ERROR_NOT_AVAILABLE if TimeStamp doesn't have the data.
+   */
+  double msSinceProcessStart();
 };
new file mode 100644
--- /dev/null
+++ b/toolkit/components/telemetry/tests/unit/test_TelemetryLog.js
@@ -0,0 +1,38 @@
+const Cc = Components.classes;
+const Ci = Components.interfaces;
+const Cu = Components.utils;
+
+Cu.import("resource://gre/modules/TelemetryLog.jsm", this);
+Cu.import("resource://gre/modules/TelemetryPing.jsm", this);
+
+function check_event(event, id, data)
+{
+  do_print("Checking message " + id);
+  do_check_eq(event[0], id);
+  do_check_true(event[1] > 0);
+
+  if (data === undefined) {
+    do_check_true(event.length == 2);
+  } else {
+    do_check_eq(event.length, data.length + 2);
+    for (var i = 0; i < data.length; ++i) {
+      do_check_eq(typeof(event[i + 2]), "string");
+      do_check_eq(event[i + 2], data[i]);
+    }
+  }
+}
+
+function run_test()
+{
+  TelemetryLog.log("test1", ["val", 123, undefined]);
+  TelemetryLog.log("test2", []);
+  TelemetryLog.log("test3");
+
+  var log = TelemetryPing.getPayload().log;
+  do_check_eq(log.length, 3);
+  check_event(log[0], "test1", ["val", "123", "undefined"]);
+  check_event(log[1], "test2", []);
+  check_event(log[2], "test3", undefined);
+  do_check_true(log[0][1] <= log[1][1]);
+  do_check_true(log[1][1] <= log[2][1]);
+}
--- a/toolkit/components/telemetry/tests/unit/xpcshell.ini
+++ b/toolkit/components/telemetry/tests/unit/xpcshell.ini
@@ -1,15 +1,16 @@
 [DEFAULT]
 head = head.js
 tail = 
 
 [test_nsITelemetry.js]
 [test_TelemetryLateWrites.js]
 [test_TelemetryLockCount.js]
+[test_TelemetryLog.js]
 [test_TelemetryPing.js]
 # Bug 676989: test fails consistently on Android
 # fail-if = os == "android"
 [test_TelemetryPing_idle.js]
 [test_TelemetryStopwatch.js]
 [test_TelemetryPingBuildID.js]
 [test_ThirdPartyCookieProbe.js]
 [test_TelemetrySendOldPings.js]