# HG changeset patch # User Edouard Oger # Date 1510783845 18000 # Node ID 79e949bc0f7b19e3181580c698ee3cae4d5c2999 # Parent e6a1e013e6df32e8fd8d15dd714f8d3141bf1a52 Bug 1304898 - Include why in sync ping. r=tcsc MozReview-Commit-ID: G9WnHhuWD7Z diff --git a/browser/base/content/browser-pageActions.js b/browser/base/content/browser-pageActions.js --- a/browser/base/content/browser-pageActions.js +++ b/browser/base/content/browser-pageActions.js @@ -706,17 +706,17 @@ BrowserPageActions.sendToDevice = { bodyNode.removeAttribute("state"); // In the first ~10 sec after startup, Sync may not be loaded and the list // of devices will be empty. if (gSync.syncConfiguredAndLoading) { bodyNode.setAttribute("state", "notready"); // Force a background Sync Services.tm.dispatchToMainThread(async () => { - await Weave.Service.sync([]); // [] = clients engine only + await Weave.Service.sync({why: "pageactions", engines: []}); // [] = clients engine only // There's no way Sync is still syncing at this point, but we check // anyway to avoid infinite looping. if (!window.closed && !gSync.syncConfiguredAndLoading) { this.onShowingSubview(panelViewNode); } }); } }, diff --git a/services/sync/modules/SyncedTabs.jsm b/services/sync/modules/SyncedTabs.jsm --- a/services/sync/modules/SyncedTabs.jsm +++ b/services/sync/modules/SyncedTabs.jsm @@ -154,17 +154,17 @@ let SyncedTabsInternal = { // of a login failure. if (Weave.Status.checkSetup() == Weave.CLIENT_NOT_CONFIGURED) { log.info("Sync client is not configured, so not attempting a tab sync"); return false; } // Ask Sync to just do the tabs engine if it can. try { log.info("Doing a tab sync."); - await Weave.Service.sync(["tabs"]); + await Weave.Service.sync({why: "tabs", engines: ["tabs"]}); return true; } catch (ex) { log.error("Sync failed", ex); throw ex; } }, observe(subject, topic, data) { diff --git a/services/sync/modules/service.js b/services/sync/modules/service.js --- a/services/sync/modules/service.js +++ b/services/sync/modules/service.js @@ -429,17 +429,17 @@ Sync11Service.prototype = { case "sync:collection_changed": // We check if we're running TPS here to avoid TPS failing because it // couldn't get to get the sync lock, due to us currently syncing the // clients engine. if (data.includes("clients") && !Svc.Prefs.get("testing.tps", false)) { // Sync in the background (it's fine not to wait on the returned promise // because sync() has a lock). // [] = clients collection only - this.sync([]).catch(e => { + this.sync({why: "collection_changed", engines: []}).catch(e => { this._log.error(e); }); } break; case "fxaccounts:device_disconnected": data = JSON.parse(data); if (!data.isLocalDevice) { Async.promiseSpinningly(this.clientsEngine.updateKnownStaleClients()); @@ -1074,41 +1074,41 @@ Sync11Service.prototype = { reason = kFirstSyncChoiceNotMade; if (ignore && ignore.includes(reason)) return ""; return reason; }, - async sync(engineNamesToSync) { + async sync({engines, why} = {}) { let dateStr = Utils.formatTimestamp(new Date()); this._log.debug("User-Agent: " + Utils.userAgent); this._log.info(`Starting sync at ${dateStr} in browser session ${browserSessionID}`); return this._catch(async function() { // Make sure we're logged in. if (this._shouldLogin()) { this._log.debug("In sync: should login."); if (!(await this.login())) { this._log.debug("Not syncing: login returned false."); return; } } else { this._log.trace("In sync: no need to login."); } - await this._lockedSync(engineNamesToSync); + await this._lockedSync(engines, why); })(); }, /** * Sync up engines with the server. */ - async _lockedSync(engineNamesToSync) { + async _lockedSync(engineNamesToSync, why) { return this._lock("service.js: sync", - this._notify("sync", "", async function onNotify() { + this._notify("sync", JSON.stringify({why}), async function onNotify() { let histogram = Services.telemetry.getHistogramById("WEAVE_START_COUNT"); histogram.add(1); let synchronizer = new EngineSynchronizer(this); await synchronizer.sync(engineNamesToSync); // Might throw! histogram = Services.telemetry.getHistogramById("WEAVE_COMPLETE_SUCCESS_COUNT"); diff --git a/services/sync/modules/telemetry.js b/services/sync/modules/telemetry.js --- a/services/sync/modules/telemetry.js +++ b/services/sync/modules/telemetry.js @@ -211,41 +211,45 @@ class EngineRecord { sent: counts.sent || undefined, failed: counts.failed || undefined, }); } } } class TelemetryRecord { - constructor(allowedEngines) { + constructor(allowedEngines, why) { this.allowedEngines = allowedEngines; // Our failure reason. This property only exists in the generated ping if an // error actually occurred. this.failureReason = undefined; this.uid = ""; this.when = Date.now(); this.startTime = tryGetMonotonicTimestamp(); this.took = 0; // will be set later. + this.why = why; // All engines that have finished (ie, does not include the "current" one) // We omit this from the ping if it's empty. this.engines = []; // The engine that has started but not yet stopped. this.currentEngine = null; } toJSON() { let result = { when: this.when, took: this.took, failureReason: this.failureReason, status: this.status, devices: this.devices, }; + if (this.why) { + result.why = this.why; + } let engines = []; for (let engine of this.engines) { engines.push(engine.toJSON()); } if (engines.length > 0) { result.engines = engines; } return result; @@ -489,23 +493,24 @@ class SyncTelemetryImpl { log.trace(`submitting ${record.syncs.length} sync record(s) to telemetry`); TelemetryController.submitExternalPing("sync", record); return true; } return false; } - onSyncStarted() { + onSyncStarted(data) { + const why = data && JSON.parse(data).why; if (this.current) { log.warn("Observed weave:service:sync:start, but we're already recording a sync!"); // Just discard the old record, consistent with our handling of engines, above. this.current = null; } - this.current = new TelemetryRecord(this.allowedEngines); + this.current = new TelemetryRecord(this.allowedEngines, why); } _checkCurrent(topic) { if (!this.current) { log.warn(`Observed notification ${topic} but no current sync is being recorded.`); return false; } return true; @@ -597,17 +602,17 @@ class SyncTelemetryImpl { switch (topic) { case "profile-before-change": this.shutdown(); break; /* sync itself state changes */ case "weave:service:sync:start": - this.onSyncStarted(); + this.onSyncStarted(data); break; case "weave:service:sync:finish": if (this._checkCurrent(topic)) { this.onSyncFinished(null); } break; diff --git a/services/sync/tests/unit/sync_ping_schema.json b/services/sync/tests/unit/sync_ping_schema.json --- a/services/sync/tests/unit/sync_ping_schema.json +++ b/services/sync/tests/unit/sync_ping_schema.json @@ -48,17 +48,17 @@ { "required": ["service"] } ], "additionalProperties": false, "properties": { "sync": { "type": "string" }, "service": { "type": "string" } } }, - "why": { "enum": ["startup", "schedule", "score", "user", "tabs"] }, + "why": { "type": "string" }, "took": { "type": "integer", "minimum": -1 }, "failureReason": { "$ref": "#/definitions/error" }, "engines": { "type": "array", "minItems": 1, "items": { "$ref": "#/definitions/engine" } } } diff --git a/services/sync/tests/unit/test_engine_changes_during_sync.js b/services/sync/tests/unit/test_engine_changes_during_sync.js --- a/services/sync/tests/unit/test_engine_changes_during_sync.js +++ b/services/sync/tests/unit/test_engine_changes_during_sync.js @@ -389,17 +389,17 @@ add_task(async function test_bookmark_ch "toolbar", "unfiled", ].sort(), "Should track bookmark and folder created before first sync"); // Unlike the tests above, we can't use `sync_engine_and_validate_telem` // because the bookmarks engine will automatically schedule a follow-up // sync for us. _("Perform first sync and immediate follow-up sync"); - Service.sync(["bookmarks"]); + Service.sync({engines: ["bookmarks"]}); let pings = await pingsPromise; equal(pings.length, 2, "Should submit two pings"); ok(pings.every(p => { assert_success_ping(p); return p.syncs.length == 1; }), "Should submit 1 sync per ping"); diff --git a/services/sync/tests/unit/test_service_sync_specified.js b/services/sync/tests/unit/test_service_sync_specified.js --- a/services/sync/tests/unit/test_service_sync_specified.js +++ b/services/sync/tests/unit/test_service_sync_specified.js @@ -85,17 +85,17 @@ add_task(async function setup() { add_task(async function test_noEngines() { enableValidationPrefs(); _("Test: An empty array of engines to sync does nothing."); let server = await setUp(); try { _("Sync with no engines specified."); - await Service.sync([]); + await Service.sync({engines: []}); deepEqual(syncedEngines, [], "no engines were synced"); } finally { await Service.startOver(); await promiseStopServer(server); } }); @@ -103,51 +103,51 @@ add_task(async function test_oneEngine() enableValidationPrefs(); _("Test: Only one engine is synced."); let server = await setUp(); try { _("Sync with 1 engine specified."); - await Service.sync(["steam"]); + await Service.sync({engines: ["steam"]}); deepEqual(syncedEngines, ["steam"]); } finally { await Service.startOver(); await promiseStopServer(server); } }); add_task(async function test_bothEnginesSpecified() { enableValidationPrefs(); _("Test: All engines are synced when specified in the correct order (1)."); let server = await setUp(); try { _("Sync with both engines specified."); - await Service.sync(["steam", "stirling"]); + await Service.sync({engines: ["steam", "stirling"]}); deepEqual(syncedEngines, ["steam", "stirling"]); } finally { await Service.startOver(); await promiseStopServer(server); } }); add_task(async function test_bothEnginesSpecified() { enableValidationPrefs(); _("Test: All engines are synced when specified in the correct order (2)."); let server = await setUp(); try { _("Sync with both engines specified."); - await Service.sync(["stirling", "steam"]); + await Service.sync({engines: ["stirling", "steam"]}); deepEqual(syncedEngines, ["stirling", "steam"]); } finally { await Service.startOver(); await promiseStopServer(server); } });