Bug 1338439 - Sync event telemetry should use the same flowID when sending a command to multiple clients, and should include a reason for some commands. r?tcsc draft
authorMark Hammond <mhammond@skippinet.com.au>
Fri, 10 Feb 2017 16:49:33 +1100
changeset 481614 2e1d3235e25313f2f3dbb32056a069d09c2e31b9
parent 481595 25a94c1047e793ef096d8556fa3c26dd72bd37d7
child 482557 ae52876a31d13ba3b74f10e926c2d7f7ce1c8db0
push id44875
push userbmo:markh@mozilla.com
push dateFri, 10 Feb 2017 05:51:56 +0000
reviewerstcsc
bugs1338439
milestone54.0a1
Bug 1338439 - Sync event telemetry should use the same flowID when sending a command to multiple clients, and should include a reason for some commands. r?tcsc MozReview-Commit-ID: 7a6qjRUswGL
services/sync/modules/engines/bookmarks.js
services/sync/modules/engines/clients.js
services/sync/modules/service.js
services/sync/tests/unit/test_clients_engine.js
--- a/services/sync/modules/engines/bookmarks.js
+++ b/services/sync/modules/engines/bookmarks.js
@@ -978,17 +978,18 @@ BookmarksTracker.prototype = {
         this._log.debug("Ignoring changes from importing bookmarks.");
         break;
       case "bookmarks-restore-success":
         this._log.debug("Tracking all items on successful import.");
 
         this._log.debug("Restore succeeded: wiping server and other clients.");
         this.engine.service.resetClient([this.name]);
         this.engine.service.wipeServer([this.name]);
-        this.engine.service.clientsEngine.sendCommand("wipeEngine", [this.name]);
+        this.engine.service.clientsEngine.sendCommand("wipeEngine", [this.name],
+                                                      null, { reason: "bookmark-restore" });
         break;
       case "bookmarks-restore-failed":
         this._log.debug("Tracking all items on failed import.");
         break;
     }
   },
 
   QueryInterface: XPCOMUtils.generateQI([
--- a/services/sync/modules/engines/clients.js
+++ b/services/sync/modules/engines/clients.js
@@ -484,42 +484,43 @@ ClientEngine.prototype = {
 
   /**
    * Sends a command+args pair to a specific client.
    *
    * @param command Command string
    * @param args Array of arguments/data for command
    * @param clientId Client to send command to
    */
-  _sendCommandToClient: function sendCommandToClient(command, args, clientId, flowID = null) {
+  _sendCommandToClient(command, args, clientId, telemetryExtra) {
     this._log.trace("Sending " + command + " to " + clientId);
 
     let client = this._store._remoteClients[clientId];
     if (!client) {
       throw new Error("Unknown remote client ID: '" + clientId + "'.");
     }
     if (client.stale) {
       throw new Error("Stale remote client ID: '" + clientId + "'.");
     }
 
     let action = {
       command,
       args,
-      flowID: flowID || Utils.makeGUID(), // used for telemetry.
+      // We send the flowID to the other client so *it* can report it in its
+      // telemetry - we record it in ours below.
+      flowID: telemetryExtra.flowID,
     };
 
     if (this._addClientCommand(clientId, action)) {
       this._log.trace(`Client ${clientId} got a new action`, [command, args]);
       this._tracker.addChangedID(clientId);
-      let deviceID;
       try {
-        deviceID = this.service.identity.hashedDeviceID(clientId);
+        telemetryExtra.deviceID = this.service.identity.hashedDeviceID(clientId);
       } catch (_) {}
-      this.service.recordTelemetryEvent("sendcommand", command, undefined,
-                                        { flowID: action.flowID, deviceID });
+
+      this.service.recordTelemetryEvent("sendcommand", command, undefined, telemetryExtra);
     } else {
       this._log.trace(`Client ${clientId} got a duplicate action`, [command, args]);
     }
   },
 
   /**
    * Check if the local client has any remote commands and perform them.
    *
@@ -594,35 +595,41 @@ ClientEngine.prototype = {
    *        Array of arguments to give to the command
    * @param clientId
    *        Client ID to send command to. If undefined, send to all remote
    *        clients.
    * @param flowID
    *        A unique identifier used to track success for this operation across
    *        devices.
    */
-  sendCommand: function sendCommand(command, args, clientId, flowID = null) {
+  sendCommand(command, args, clientId = null, telemetryExtra = {}) {
     let commandData = this._commands[command];
     // Don't send commands that we don't know about.
     if (!commandData) {
       this._log.error("Unknown command to send: " + command);
       return;
     } else if (!args || args.length != commandData.args) {
       // Don't send a command with the wrong number of arguments.
       this._log.error("Expected " + commandData.args + " args for '" +
                       command + "', but got " + args);
       return;
     }
 
+    // We allocate a "flowID" here, so it is used for each client.
+    telemetryExtra = Object.assign({}, telemetryExtra); // don't clobber the caller's object
+    if (!telemetryExtra.flowID) {
+      telemetryExtra.flowID = Utils.makeGUID();
+    }
+
     if (clientId) {
-      this._sendCommandToClient(command, args, clientId, flowID);
+      this._sendCommandToClient(command, args, clientId, telemetryExtra);
     } else {
       for (let [id, record] of Object.entries(this._store._remoteClients)) {
         if (!record.stale) {
-          this._sendCommandToClient(command, args, id, flowID);
+          this._sendCommandToClient(command, args, id, telemetryExtra);
         }
       }
     }
   },
 
   /**
    * Send a URI to another client for display.
    *
--- a/services/sync/modules/service.js
+++ b/services/sync/modules/service.js
@@ -1288,23 +1288,24 @@ Sync11Service.prototype = {
     try {
       // Make sure stuff gets uploaded.
       this.resetClient(engines);
 
       // Clear out any server data.
       this.wipeServer(engines);
 
       // Only wipe the engines provided.
+      let extra = { reason: "wipe-remote" };
       if (engines) {
         engines.forEach(function(e) {
-            this.clientsEngine.sendCommand("wipeEngine", [e]);
+            this.clientsEngine.sendCommand("wipeEngine", [e], null, extra);
           }, this);
       } else {
         // Tell the remote machines to wipe themselves.
-        this.clientsEngine.sendCommand("wipeAll", []);
+        this.clientsEngine.sendCommand("wipeAll", [], null, extra);
       }
 
       // Make sure the changed clients get updated.
       this.clientsEngine.sync();
     } catch (ex) {
       this.errorHandler.checkServerError(ex);
       throw ex;
     }
--- a/services/sync/tests/unit/test_clients_engine.js
+++ b/services/sync/tests/unit/test_clients_engine.js
@@ -374,18 +374,19 @@ add_task(async function test_send_comman
   let remoteId = Utils.makeGUID();
   let rec = new ClientsRec("clients", remoteId);
 
   store.create(rec);
   store.createRecord(remoteId, "clients");
 
   let action = "testCommand";
   let args = ["foo", "bar"];
+  let extra = { flowID: "flowy" }
 
-  engine._sendCommandToClient(action, args, remoteId);
+  engine._sendCommandToClient(action, args, remoteId, extra);
 
   let newRecord = store._remoteClients[remoteId];
   let clientCommands = engine._readCommands()[remoteId];
   notEqual(newRecord, undefined);
   equal(clientCommands.length, 1);
 
   let command = clientCommands[0];
   equal(command.command, action);
@@ -1421,13 +1422,96 @@ add_task(async function test_command_syn
     try {
       server.deleteCollections("foo");
     } finally {
       await promiseStopServer(server);
     }
   }
 });
 
+add_task(async function ensureSameFlowIDs() {
+  let events = []
+  let origRecordTelemetryEvent = Service.recordTelemetryEvent;
+  Service.recordTelemetryEvent = (object, method, value, extra) => {
+    events.push({ object, method, value, extra });
+  }
+
+  try {
+    // Setup 2 clients, send them a command, and ensure we get to events
+    // written, both with the same flowID.
+    let contents = {
+      meta: {global: {engines: {clients: {version: engine.version,
+                                          syncID: engine.syncID}}}},
+      clients: {},
+      crypto: {}
+    };
+    let server    = serverForUsers({"foo": "password"}, contents);
+    await SyncTestingInfrastructure(server);
+
+    let collection = server.getCollection("foo", "clients");
+    let remoteId   = Utils.makeGUID();
+    let remoteId2  = Utils.makeGUID();
+
+    _("Create remote client record 1");
+    server.insertWBO("foo", "clients", new ServerWBO(remoteId, encryptPayload({
+      id: remoteId,
+      name: "Remote client",
+      type: "desktop",
+      commands: [],
+      version: "48",
+      protocols: ["1.5"]
+    }), Date.now() / 1000));
+
+    _("Create remote client record 2");
+    server.insertWBO("foo", "clients", new ServerWBO(remoteId2, encryptPayload({
+      id: remoteId2,
+      name: "Remote client 2",
+      type: "mobile",
+      commands: [],
+      version: "48",
+      protocols: ["1.5"]
+    }), Date.now() / 1000));
+
+    engine._sync();
+    engine.sendCommand("wipeAll", []);
+    engine._sync();
+    equal(events.length, 2);
+    // we don't know what the flowID is, but do know it should be the same.
+    equal(events[0].extra.flowID, events[1].extra.flowID);
+
+    // check it's correctly used when we specify a flow ID
+    events.length = 0;
+    let flowID = Utils.makeGUID();
+    engine.sendCommand("wipeAll", [], null, { flowID });
+    engine._sync();
+    equal(events.length, 2);
+    equal(events[0].extra.flowID, flowID);
+    equal(events[1].extra.flowID, flowID);
+
+    // and that it works when something else is in "extra"
+    events.length = 0;
+    engine.sendCommand("wipeAll", [], null, { reason: "testing" });
+    engine._sync();
+    equal(events.length, 2);
+    equal(events[0].extra.flowID, events[1].extra.flowID);
+    equal(events[0].extra.reason, "testing");
+    equal(events[1].extra.reason, "testing");
+
+    // and when both are specified.
+    events.length = 0;
+    engine.sendCommand("wipeAll", [], null, { reason: "testing", flowID });
+    engine._sync();
+    equal(events.length, 2);
+    equal(events[0].extra.flowID, flowID);
+    equal(events[1].extra.flowID, flowID);
+    equal(events[0].extra.reason, "testing");
+    equal(events[1].extra.reason, "testing");
+
+  } finally {
+    Service.recordTelemetryEvent = origRecordTelemetryEvent;
+  }
+});
+
 function run_test() {
   initTestLogging("Trace");
   Log.repository.getLogger("Sync.Engine.Clients").level = Log.Level.Trace;
   run_next_test();
 }