Bug 1523311 - Report age of Remote Settings data in Uptake telemetry r=glasserc

Report age of Remote Settings data in Uptake telemetry

Differential Revision: https://phabricator.services.mozilla.com/D23135

--HG--
extra : moz-landing-system : lando

services/common/uptake-telemetry.js

@@ -88,6 +88,7 @@ class UptakeTelemetry {
    * @param {Object} extra         extra values to report
    * @param {string} extra.source  the update source (eg. "recipe-42").
    * @param {string} extra.trigger what triggered the polling/fetching (eg. "broadcast", "timer").
+   * @param {int}    extra.age     age of pulled data in seconds
    */
   static report(component, status, extra = {}) {
     const { source } = extra;

services/settings/Utils.jsm

@@ -110,8 +110,12 @@ var Utils = {
     const currentEtag = response.headers.has("ETag") ? response.headers.get("ETag") : undefined;
     let serverTimeMillis = Date.parse(response.headers.get("Date"));
     // Since the response is served via a CDN, the Date header value could have been cached.
-    const ageSeconds = response.headers.has("Age") ? parseInt(response.headers.get("Age"), 10) : 0;
-    serverTimeMillis += ageSeconds * 1000;
+    const cacheAgeSeconds = response.headers.has("Age") ? parseInt(response.headers.get("Age"), 10) : 0;
+    serverTimeMillis += cacheAgeSeconds * 1000;
+
+    // Age of data (time between publication and now).
+    let lastModifiedMillis = Date.parse(response.headers.get("Last-Modified"));
+    const ageSeconds = (serverTimeMillis - lastModifiedMillis) / 1000;
 
     // Check if the server asked the clients to back off.
     let backoffSeconds;
@@ -122,6 +126,6 @@ var Utils = {
       }
     }
 
-    return { changes, currentEtag, serverTimeMillis, backoffSeconds };
+    return { changes, currentEtag, serverTimeMillis, backoffSeconds, ageSeconds };
   },
 };

services/settings/remote-settings.js

@@ -157,7 +157,7 @@ function remoteSettingsFunction() {
    * @returns {Promise} or throws error if something goes wrong.
    */
   remoteSettings.pollChanges = async ({ expectedTimestamp, trigger = "manual" } = {}) => {
-    const telemetryArgs = {
+    let telemetryArgs = {
       source: TELEMETRY_SOURCE,
       trigger,
     };
@@ -203,7 +203,10 @@ function remoteSettingsFunction() {
       throw new Error(`Polling for changes failed: ${e.message}.`);
     }
 
-    const {serverTimeMillis, changes, currentEtag, backoffSeconds} = pollResult;
+    const { serverTimeMillis, changes, currentEtag, backoffSeconds, ageSeconds } = pollResult;
+
+    // Report age of server data in Telemetry.
+    telemetryArgs = { age: ageSeconds, ...telemetryArgs };
 
     // Report polling success to Uptake Telemetry.
     const reportStatus = changes.length === 0 ? UptakeTelemetry.STATUS.UP_TO_DATE

services/settings/test/unit/test_remote_settings_poll.js

@@ -39,9 +39,11 @@ function serveChangesEntries(serverTime, entries) {
     response.setHeader("Content-Type", "application/json; charset=UTF-8");
     response.setHeader("Date", (new Date(serverTime)).toUTCString());
     if (entries.length) {
-      response.setHeader("ETag", `"${entries[0].last_modified}"`);
+      const latest = entries[0].last_modified;
+      response.setHeader("ETag", `"${latest}"`);
+      response.setHeader("Last-Modified", (new Date(latest)).toGMTString());
     }
-    response.write(JSON.stringify({"data": entries}));
+    response.write(JSON.stringify({ "data": entries }));
   };
 }
 
@@ -284,6 +286,29 @@ add_task(async function test_client_last_check_is_saved() {
 add_task(clear_state);
 
 
+add_task(async function test_age_of_data_is_reported_in_uptake_status() {
+  const serverTime = 1552323900000;
+  server.registerPathHandler(CHANGES_PATH, serveChangesEntries(serverTime, [{
+    id: "b6ba7fab-a40a-4d03-a4af-6b627f3c5b36",
+    last_modified: serverTime - 3600 * 1000,
+    host: "localhost",
+    bucket: "main",
+    collection: "some-entry",
+  }]));
+  const backup = UptakeTelemetry.report;
+  let reportedAge;
+  UptakeTelemetry.report = (component, status, { age }) => {
+    reportedAge = age;
+  };
+
+  await RemoteSettings.pollChanges();
+
+  Assert.equal(reportedAge, 3600);
+  UptakeTelemetry.report = backup;
+});
+add_task(clear_state);
+
+
 add_task(async function test_success_with_partial_list() {
   function partialList(request, response) {
     const entries = [{

toolkit/components/telemetry/Events.yaml

@@ -1012,6 +1012,8 @@ uptake.remotecontent.result:
       trigger: >
         A label to distinguish what triggered the polling/fetching of remote content (eg. "broadcast",
         "timer", "forced", "manual")
+      age: >
+        The age of pulled data in seconds (ie. difference between publication time and fetch time).
     bug_numbers:
       - 1517469
     record_in_processes: ["main"]

toolkit/components/telemetry/docs/collection/uptake.rst

@@ -85,10 +85,11 @@ Additional Event Info
 The Event API allows to report additional information. We support the following optional fields:
 
 - ``trigger``: A label to distinguish what triggered the polling/fetching of remote content (eg. ``"broadcast"``, ``"timer"``, ``"forced"``, ``"manual"``)
+- ``age``: The age of pulled data in seconds (ie. difference between publication time and fetch time).
 
 .. code-block:: js
 
-   UptakeTelemetry.report(component, status, { source, trigger: "timer" });
+   UptakeTelemetry.report(component, status, { source, trigger: "timer", age: 138 });
 
 
 Use-cases