Bug 1578217 - remove the sync 'yellow state' telemetry. r=tcsc
authorMark Hammond <mhammond@skippinet.com.au>
Thu, 19 Sep 2019 00:34:04 +0000
changeset 494025 9d31a1c17ef8ceb8195db01088bb635e4f575a0f
parent 494024 b6326259d31e1cc9690d5f994e7fee7a7d7e19be
child 494026 239c106912ab92eceb5e7738f0240dd13c268342
push id36593
push useropoprus@mozilla.com
push dateThu, 19 Sep 2019 09:46:54 +0000
treeherdermozilla-central@6b93a83735ed [default view] [failures only]
perfherder[talos] [build metrics] [platform microbench] (compared to previous push)
reviewerstcsc
bugs1578217
milestone71.0a1
first release with
nightly linux32
nightly linux64
nightly mac
nightly win32
nightly win64
last release without
nightly linux32
nightly linux64
nightly mac
nightly win32
nightly win64
Bug 1578217 - remove the sync 'yellow state' telemetry. r=tcsc Differential Revision: https://phabricator.services.mozilla.com/D45765
services/sync/modules-testing/utils.js
services/sync/modules/browserid_identity.js
services/sync/tests/unit/test_browserid_identity.js
services/sync/tests/unit/test_browserid_identity_telemetry.js
services/sync/tests/unit/xpcshell.ini
toolkit/components/telemetry/Histograms.json
toolkit/components/telemetry/Scalars.yaml
tools/lint/eslint/modules.json
--- a/services/sync/modules-testing/utils.js
+++ b/services/sync/modules-testing/utils.js
@@ -12,17 +12,16 @@ var EXPORTED_SYMBOLS = [
   "configureIdentity",
   "SyncTestingInfrastructure",
   "waitForZeroTimer",
   "promiseZeroTimer",
   "promiseNamedTimer",
   "MockFxaStorageManager",
   "AccountState", // from a module import
   "sumHistogram",
-  "getLoginTelemetryScalar",
   "syncTestLogging",
 ];
 
 const { CommonUtils } = ChromeUtils.import(
   "resource://services-common/utils.js"
 );
 const { CryptoUtils } = ChromeUtils.import(
   "resource://services-crypto/utils.js"
@@ -304,15 +303,8 @@ var sumHistogram = function(name, option
       sum = snapshot[options.key].sum;
     } else {
       sum = snapshot.sum;
     }
   }
   histogram.clear();
   return sum;
 };
-
-var getLoginTelemetryScalar = function() {
-  let snapshot = Services.telemetry.getSnapshotForKeyedScalars("main", true);
-  return snapshot.parent
-    ? snapshot.parent["services.sync.sync_login_state_transitions"]
-    : {};
-};
--- a/services/sync/modules/browserid_identity.js
+++ b/services/sync/modules/browserid_identity.js
@@ -71,108 +71,16 @@ ChromeUtils.import(
 
 const OBSERVER_TOPICS = [
   fxAccountsCommon.ONLOGIN_NOTIFICATION,
   fxAccountsCommon.ONVERIFIED_NOTIFICATION,
   fxAccountsCommon.ONLOGOUT_NOTIFICATION,
   fxAccountsCommon.ON_ACCOUNT_STATE_CHANGE_NOTIFICATION,
 ];
 
-// A telemetry helper that records how long a user was in a "bad" state.
-// It is recorded in the *main* ping, *not* the Sync ping.
-// These bad states may persist across browser restarts, and may never change
-// (eg, users may *never* validate)
-var telemetryHelper = {
-  // These are both the "status" values passed to maybeRecordLoginState and
-  // the key we use for our keyed scalar.
-  STATES: {
-    SUCCESS: "SUCCESS",
-    NOTVERIFIED: "NOTVERIFIED",
-    REJECTED: "REJECTED",
-  },
-
-  PREFS: {
-    REJECTED_AT: "identity.telemetry.loginRejectedAt",
-    APPEARS_PERMANENTLY_REJECTED:
-      "identity.telemetry.loginAppearsPermanentlyRejected",
-    LAST_RECORDED_STATE: "identity.telemetry.lastRecordedState",
-  },
-
-  // How long, in minutes, that we continue to wait for a user to transition
-  // from a "bad" state to a success state. After this has expired, we record
-  // the "how long were they rejected for?" histogram.
-  NUM_MINUTES_TO_RECORD_REJECTED_TELEMETRY: 20160, // 14 days in minutes.
-
-  SCALAR: "services.sync.sync_login_state_transitions", // The scalar we use to report
-
-  maybeRecordLoginState(status) {
-    try {
-      this._maybeRecordLoginState(status);
-    } catch (ex) {
-      log.error("Failed to record login telemetry", ex);
-    }
-  },
-
-  _maybeRecordLoginState(status) {
-    let key = this.STATES[status];
-    if (!key) {
-      throw new Error(`invalid state ${status}`);
-    }
-
-    let when = Svc.Prefs.get(this.PREFS.REJECTED_AT);
-    let howLong = when ? this.nowInMinutes() - when : 0; // minutes.
-    let isNewState = Svc.Prefs.get(this.PREFS.LAST_RECORDED_STATE) != status;
-
-    if (status == this.STATES.SUCCESS) {
-      if (isNewState) {
-        Services.telemetry.keyedScalarSet(this.SCALAR, key, true);
-        Svc.Prefs.set(this.PREFS.LAST_RECORDED_STATE, status);
-      }
-      // If we previously recorded an error state, report how long they were
-      // in the bad state for (in minutes)
-      if (when) {
-        // If we are "permanently rejected" we've already recorded for how
-        // long, so don't do it again.
-        if (!Svc.Prefs.get(this.PREFS.APPEARS_PERMANENTLY_REJECTED)) {
-          Services.telemetry
-            .getHistogramById("WEAVE_LOGIN_FAILED_FOR")
-            .add(howLong);
-        }
-      }
-      Svc.Prefs.reset(this.PREFS.REJECTED_AT);
-      Svc.Prefs.reset(this.PREFS.APPEARS_PERMANENTLY_REJECTED);
-    } else {
-      // We are in a failure state.
-      if (Svc.Prefs.get(this.PREFS.APPEARS_PERMANENTLY_REJECTED)) {
-        return; // we've given up, so don't record errors.
-      }
-      if (isNewState) {
-        Services.telemetry.keyedScalarSet(this.SCALAR, key, true);
-        Svc.Prefs.set(this.PREFS.LAST_RECORDED_STATE, status);
-      }
-      if (howLong > this.NUM_MINUTES_TO_RECORD_REJECTED_TELEMETRY) {
-        // We are giving up for this user, so report this "max time" as how
-        // long they were in this state for.
-        Services.telemetry
-          .getHistogramById("WEAVE_LOGIN_FAILED_FOR")
-          .add(howLong);
-        Svc.Prefs.set(this.PREFS.APPEARS_PERMANENTLY_REJECTED, true);
-      }
-      if (!Svc.Prefs.has(this.PREFS.REJECTED_AT)) {
-        Svc.Prefs.set(this.PREFS.REJECTED_AT, this.nowInMinutes());
-      }
-    }
-  },
-
-  // hookable by tests.
-  nowInMinutes() {
-    return Math.floor(Date.now() / 1000 / 60);
-  },
-};
-
 /*
   General authentication error for abstracting authentication
   errors from multiple sources (e.g., from FxAccounts, TokenServer).
   details is additional details about the error - it might be a string, or
   some other error object (which should do the right thing when toString() is
   called on it)
 */
 function AuthenticationError(details, source) {
@@ -410,25 +318,23 @@ this.BrowserIDManager.prototype = {
     if (!data) {
       log.debug("unlockAndVerifyAuthState has no user");
       return LOGIN_FAILED_NO_USERNAME;
     }
     if (!data.verified) {
       // Treat not verified as if the user needs to re-auth, so the browser
       // UI reflects the state.
       log.debug("unlockAndVerifyAuthState has an unverified user");
-      telemetryHelper.maybeRecordLoginState(telemetryHelper.STATES.NOTVERIFIED);
       return LOGIN_FAILED_LOGIN_REJECTED;
     }
     this._updateSignedInUser(data);
     if (await this._fxaService.keys.canGetKeys()) {
       log.debug(
         "unlockAndVerifyAuthState already has (or can fetch) sync keys"
       );
-      telemetryHelper.maybeRecordLoginState(telemetryHelper.STATES.SUCCESS);
       return STATUS_OK;
     }
     // so no keys - ensure MP unlocked.
     if (!Utils.ensureMPUnlocked()) {
       // user declined to unlock, so we don't know if they are stored there.
       log.debug(
         "unlockAndVerifyAuthState: user declined to unlock master-password"
       );
@@ -437,20 +343,18 @@ this.BrowserIDManager.prototype = {
     // now we are unlocked we must re-fetch the user data as we may now have
     // the details that were previously locked away.
     this._updateSignedInUser(await this._fxaService.getSignedInUser());
     // If we still can't get keys it probably means the user authenticated
     // without unlocking the MP or cleared the saved logins, so we've now
     // lost them - the user will need to reauth before continuing.
     let result;
     if (await this._fxaService.keys.canGetKeys()) {
-      telemetryHelper.maybeRecordLoginState(telemetryHelper.STATES.SUCCESS);
       result = STATUS_OK;
     } else {
-      telemetryHelper.maybeRecordLoginState(telemetryHelper.STATES.REJECTED);
       result = LOGIN_FAILED_LOGIN_REJECTED;
     }
     log.debug(
       "unlockAndVerifyAuthState re-fetched credentials and is returning",
       result
     );
     return result;
   },
@@ -549,17 +453,16 @@ this.BrowserIDManager.prototype = {
       // otherwise, we may briefly enter a "needs reauthentication" state.
       // (XXX - the above may no longer be true - someone should check ;)
       token.expiration = this._now() + token.duration * 1000 * 0.8;
       if (!this._syncKeyBundle) {
         this._syncKeyBundle = BulkKeyBundle.fromHexKey(
           this._signedInUser.kSync
         );
       }
-      telemetryHelper.maybeRecordLoginState(telemetryHelper.STATES.SUCCESS);
       Weave.Status.login = LOGIN_SUCCEEDED;
       this._token = token;
       return token;
     } catch (caughtErr) {
       let err = caughtErr; // The error we will rethrow.
       // TODO: unify these errors - we need to handle errors thrown by
       // both tokenserverclient and hawkclient.
       // A tokenserver error thrown based on a bad response.
@@ -575,17 +478,16 @@ this.BrowserIDManager.prototype = {
 
       // TODO: write tests to make sure that different auth error cases are handled here
       // properly: auth error getting assertion, auth error getting token (invalid generation
       // and client-state error)
       if (err instanceof AuthenticationError) {
         this._log.error("Authentication error in _fetchTokenForUser", err);
         // set it to the "fatal" LOGIN_FAILED_LOGIN_REJECTED reason.
         Weave.Status.login = LOGIN_FAILED_LOGIN_REJECTED;
-        telemetryHelper.maybeRecordLoginState(telemetryHelper.STATES.REJECTED);
       } else {
         this._log.error("Non-authentication error in _fetchTokenForUser", err);
         // for now assume it is just a transient network related problem
         // (although sadly, it might also be a regular unhandled exception)
         Weave.Status.login = LOGIN_FAILED_NETWORK_ERROR;
       }
       throw err;
     }
--- a/services/sync/tests/unit/test_browserid_identity.js
+++ b/services/sync/tests/unit/test_browserid_identity.js
@@ -84,17 +84,16 @@ add_test(function test_initial_state() {
   run_next_test();
 });
 
 add_task(async function test_initialialize() {
   _("Verify start after fetching token");
   await globalBrowseridManager._ensureValidToken();
   Assert.ok(!!globalBrowseridManager._token);
   Assert.ok(globalBrowseridManager._hasValidToken());
-  Assert.deepEqual(getLoginTelemetryScalar(), { SUCCESS: 1 });
 });
 
 add_task(async function test_initialializeWithAuthErrorAndDeletedAccount() {
   _("Verify sync state with auth error + account deleted");
 
   var identityConfig = makeIdentityConfig();
   var browseridManager = new BrowserIDManager();
 
@@ -135,17 +134,16 @@ add_task(async function test_initialiali
     AuthenticationError,
     "should reject due to an auth error"
   );
 
   Assert.ok(signCertificateCalled);
   Assert.ok(accountStatusCalled);
   Assert.ok(!browseridManager._token);
   Assert.ok(!browseridManager._hasValidToken());
-  Assert.deepEqual(getLoginTelemetryScalar(), { REJECTED: 1 });
 });
 
 add_task(async function test_getResourceAuthenticator() {
   _(
     "BrowserIDManager supplies a Resource Authenticator callback which returns a Hawk header."
   );
   configureFxAccountIdentity(globalBrowseridManager);
   let authenticator = globalBrowseridManager.getResourceAuthenticator();
deleted file mode 100644
--- a/services/sync/tests/unit/test_browserid_identity_telemetry.js
+++ /dev/null
@@ -1,133 +0,0 @@
-const { Preferences } = ChromeUtils.import(
-  "resource://gre/modules/Preferences.jsm"
-);
-let { telemetryHelper } = ChromeUtils.import(
-  "resource://services-sync/browserid_identity.js",
-  null
-);
-
-const prefs = new Preferences("services.sync.");
-
-function cleanup() {
-  prefs.resetBranch();
-}
-
-add_test(function test_success() {
-  telemetryHelper.maybeRecordLoginState(telemetryHelper.STATES.SUCCESS);
-  Assert.deepEqual(getLoginTelemetryScalar(), { SUCCESS: 1 });
-  // doing it again should not bump the count.
-  telemetryHelper.maybeRecordLoginState(telemetryHelper.STATES.SUCCESS);
-  Assert.deepEqual(getLoginTelemetryScalar(), {});
-
-  // check the prefs.
-  Assert.equal(prefs.get(telemetryHelper.PREFS.REJECTED_AT), undefined);
-  Assert.equal(
-    prefs.get(telemetryHelper.PREFS.APPEARS_PERMANENTLY_REJECTED),
-    undefined
-  );
-  Assert.equal(
-    prefs.get(telemetryHelper.PREFS.LAST_RECORDED_STATE),
-    telemetryHelper.STATES.SUCCESS
-  );
-
-  cleanup();
-  run_next_test();
-});
-
-add_test(function test_success_to_error() {
-  telemetryHelper.maybeRecordLoginState(telemetryHelper.STATES.SUCCESS);
-  Assert.deepEqual(getLoginTelemetryScalar(), { SUCCESS: 1 });
-  // transition to an error state
-  telemetryHelper.maybeRecordLoginState(telemetryHelper.STATES.NOTVERIFIED);
-  Assert.deepEqual(getLoginTelemetryScalar(), { NOTVERIFIED: 1 });
-
-  cleanup();
-  run_next_test();
-});
-
-add_test(function test_unverified() {
-  telemetryHelper.nowInMinutes = () => 10000;
-  telemetryHelper.maybeRecordLoginState(telemetryHelper.STATES.NOTVERIFIED);
-  Assert.deepEqual(getLoginTelemetryScalar(), { NOTVERIFIED: 1 });
-
-  Assert.equal(prefs.get(telemetryHelper.PREFS.REJECTED_AT), 10000);
-
-  // doing it again should not bump the count and should not change the
-  // original time it was rejected at.
-  telemetryHelper.nowInMinutes = () => 10010;
-  telemetryHelper.maybeRecordLoginState(telemetryHelper.STATES.NOTVERIFIED);
-  Assert.deepEqual(getLoginTelemetryScalar(), {});
-  Assert.equal(sumHistogram("WEAVE_LOGIN_FAILED_FOR"), 0);
-
-  Assert.equal(prefs.get(telemetryHelper.PREFS.REJECTED_AT), 10000);
-
-  // record unverified again - should not record telemetry as it's the same state.
-  telemetryHelper.maybeRecordLoginState(telemetryHelper.STATES.NOTVERIFIED);
-  Assert.deepEqual(getLoginTelemetryScalar(), {});
-  Assert.equal(sumHistogram("WEAVE_LOGIN_FAILED_FOR"), 0);
-
-  // now record success - should get the new state recorded and the duration.
-  telemetryHelper.maybeRecordLoginState(telemetryHelper.STATES.SUCCESS);
-  Assert.deepEqual(getLoginTelemetryScalar(), { SUCCESS: 1 });
-
-  // we are now at 10010 minutes, so should have recorded it took 10.
-  Assert.equal(sumHistogram("WEAVE_LOGIN_FAILED_FOR"), 10);
-
-  cleanup();
-  run_next_test();
-});
-
-add_test(function test_unverified_give_up() {
-  telemetryHelper.nowInMinutes = () => 10000;
-  telemetryHelper.maybeRecordLoginState(telemetryHelper.STATES.NOTVERIFIED);
-  Assert.deepEqual(getLoginTelemetryScalar(), { NOTVERIFIED: 1 });
-
-  Assert.equal(prefs.get(telemetryHelper.PREFS.REJECTED_AT), 10000);
-
-  // bump our timestamp to 50k minutes, which is past our "give up" period.
-  telemetryHelper.nowInMinutes = () => 50000;
-  telemetryHelper.maybeRecordLoginState(telemetryHelper.STATES.NOTVERIFIED);
-
-  // We've already recorded the unverified state, so shouldn't again.
-  Assert.deepEqual(getLoginTelemetryScalar(), {});
-  // But we *should* have recorded how long it failed for even though it still
-  // fails.
-  Assert.equal(sumHistogram("WEAVE_LOGIN_FAILED_FOR"), 40000);
-
-  // Record failure again - we should *not* have any telemetry recorded.
-  telemetryHelper.nowInMinutes = () => 50001;
-  telemetryHelper.maybeRecordLoginState(telemetryHelper.STATES.NOTVERIFIED);
-  Assert.deepEqual(getLoginTelemetryScalar(), {});
-  Assert.equal(sumHistogram("WEAVE_LOGIN_FAILED_FOR"), 0);
-
-  // Now record success - it also should *not* again record the failure duration.
-  telemetryHelper.nowInMinutes = () => 60000;
-  telemetryHelper.maybeRecordLoginState(telemetryHelper.STATES.SUCCESS);
-  Assert.deepEqual(getLoginTelemetryScalar(), { SUCCESS: 1 });
-  Assert.equal(sumHistogram("WEAVE_LOGIN_FAILED_FOR"), 0);
-
-  // Even though we were permanently rejected, the SUCCESS recording should
-  // have reset that state, so new error states should work as normal.
-  telemetryHelper.maybeRecordLoginState(telemetryHelper.STATES.NOTVERIFIED);
-  Assert.deepEqual(getLoginTelemetryScalar(), { NOTVERIFIED: 1 });
-  Assert.equal(sumHistogram("WEAVE_LOGIN_FAILED_FOR"), 0);
-
-  telemetryHelper.nowInMinutes = () => 60001;
-  telemetryHelper.maybeRecordLoginState(telemetryHelper.STATES.SUCCESS);
-  Assert.deepEqual(getLoginTelemetryScalar(), { SUCCESS: 1 });
-  Assert.equal(sumHistogram("WEAVE_LOGIN_FAILED_FOR"), 1);
-
-  cleanup();
-  run_next_test();
-});
-
-add_test(function test_bad_state() {
-  // We call the internal implementation to check it throws as the public
-  // method catches and logs.
-  Assert.throws(
-    () => telemetryHelper._maybeRecordLoginState("foo"),
-    /invalid state/
-  );
-  cleanup();
-  run_next_test();
-});
--- a/services/sync/tests/unit/xpcshell.ini
+++ b/services/sync/tests/unit/xpcshell.ini
@@ -40,17 +40,16 @@ tags = addons
 
 # HTTP layers.
 [test_resource.js]
 [test_resource_header.js]
 [test_resource_ua.js]
 
 # Generic Sync types.
 [test_browserid_identity.js]
-[test_browserid_identity_telemetry.js]
 [test_collection_getBatched.js]
 [test_collections_recovery.js]
 [test_keys.js]
 [test_records_crypto.js]
 [test_records_wbo.js]
 
 # Engine APIs.
 [test_engine.js]
--- a/toolkit/components/telemetry/Histograms.json
+++ b/toolkit/components/telemetry/Histograms.json
@@ -12135,28 +12135,16 @@
     "record_in_processes": ["main", "content"],
     "products": ["firefox", "fennec", "geckoview"],
     "expires_in_version": "default",
     "kind": "exponential",
     "high": 1000,
     "n_buckets": 10,
     "description": "The number of times a sync successfully completed in this session"
   },
-  "WEAVE_LOGIN_FAILED_FOR": {
-    "record_in_processes": ["main"],
-    "products": ["firefox", "fennec", "geckoview"],
-    "expires_in_version": "72",
-    "alert_emails": ["sync-dev@mozilla.org"],
-    "kind": "exponential",
-    "high": 20000,
-    "n_buckets": 100,
-    "releaseChannelCollection": "opt-out",
-    "bug_numbers": [1375635, 1523644],
-    "description": "The number of minutes the user was in a bad login state."
-  },
   "WEAVE_WIPE_SERVER_SUCCEEDED": {
     "record_in_processes": ["main", "content"],
     "products": ["firefox", "fennec", "geckoview"],
     "expires_in_version": "55",
     "alert_emails": ["sync-dev@mozilla.org"],
     "kind": "boolean",
     "bug_numbers": [1241699],
     "description": "Stores 1 if a wipeServer call succeeded, and 0 if it failed."
--- a/toolkit/components/telemetry/Scalars.yaml
+++ b/toolkit/components/telemetry/Scalars.yaml
@@ -520,37 +520,16 @@ storage.sync.api.usage:
     release_channel_collection: opt-out
     products:
       - 'firefox'
       - 'fennec'
       - 'geckoview'
     record_in_processes:
       - main
 
-services.sync:
-  sync_login_state_transitions:
-    bug_numbers:
-      - 1375635
-      - 1523644
-    description: >
-      Records transitions between login states of "success", "unverified"
-      and "rejected.
-    expires: "72"
-    kind: boolean
-    keyed: true
-    notification_emails:
-      - sync-staff@mozilla.com
-    release_channel_collection: opt-out
-    products:
-      - 'firefox'
-      - 'fennec'
-      - 'geckoview'
-    record_in_processes:
-      - main
-
 identity.fxaccounts:
   missed_commands_fetched:
     bug_numbers:
       - 1496638
     description: >
       The number of missed FxA commands we have recovered.
     expires: "68"
     kind: uint
--- a/tools/lint/eslint/modules.json
+++ b/tools/lint/eslint/modules.json
@@ -177,17 +177,17 @@
   "reflect.jsm": ["Reflect"],
   "remote-settings.js": ["RemoteSettings", "jexlFilterFunc", "remoteSettingsBroadcastHandler"],
   "RemotePageManagerChild.jsm": ["ChildMessagePort"],
   "RemotePageManagerParent.jsm": ["RemotePages", "RemotePageManager"],
   "RemoteWebProgress.jsm": ["RemoteWebProgressManager"],
   "resource.js": ["AsyncResource", "Resource"],
   "resource://services-common/utils.js": ["CommonUtils"],
   "resource://services-crypto/utils.js": ["CryptoUtils"],
-  "resource://testing-common/services/sync/utils.js": ["AccountState", "MockFxaStorageManager", "SyncTestingInfrastructure", "configureFxAccountIdentity", "configureIdentity", "encryptPayload", "getLoginTelemetryScalar", "makeFxAccountsInternalMock", "makeIdentityConfig", "promiseNamedTimer", "promiseZeroTimer", "sumHistogram", "syncTestLogging", "waitForZeroTimer"],
+  "resource://testing-common/services/sync/utils.js": ["AccountState", "MockFxaStorageManager", "SyncTestingInfrastructure", "configureFxAccountIdentity", "configureIdentity", "encryptPayload", "makeFxAccountsInternalMock", "makeIdentityConfig", "promiseNamedTimer", "promiseZeroTimer", "sumHistogram", "syncTestLogging", "waitForZeroTimer"],
   "rest.js": ["RESTRequest", "RESTResponse", "TokenAuthenticatedRESTRequest"],
   "rotaryengine.js": ["RotaryEngine", "RotaryRecord", "RotaryStore", "RotaryTracker"],
   "RTCStatsReport.jsm": ["convertToRTCStatsReport"],
   "Schemas.jsm": ["SchemaRoot", "Schemas"],
   "scratchpad-manager.jsm": ["ScratchpadManager"],
   "SearchShortcuts.jsm": ["checkHasSearchEngine", "getSearchProvider", "SEARCH_SHORTCUTS", "CUSTOM_SEARCH_SHORTCUTS", "SEARCH_SHORTCUTS_EXPERIMENT", "SEARCH_SHORTCUTS_SEARCH_ENGINES_PREF", "SEARCH_SHORTCUTS_HAVE_PINNED_PREF"],
   "SectionsManager.jsm": ["SectionsFeed", "SectionsManager"],
   "service.js": ["Service"],