Bug 1308337 - Part 7: Instrument Crypto Keys stage r=nalexander draft
authorGrigory Kruglov <gkruglov@mozilla.com>
Mon, 29 May 2017 17:20:20 -0400
changeset 588430 c105a2a9b5fb7986c4114af21cb62e2c6abe23bd
parent 588429 5e884830eaf1004e98ec1f6bca923fc4c84d1068
child 588431 2d080f82859f2338aaddd2d557b95d31b560d535
child 588444 fa707e6adbefa016ce05cbe33443cc8d38866ae9
push id62031
push userbmo:gkruglov@mozilla.com
push dateFri, 02 Jun 2017 19:52:26 +0000
reviewersnalexander
bugs1308337
milestone55.0a1
Bug 1308337 - Part 7: Instrument Crypto Keys stage r=nalexander MozReview-Commit-ID: 8a9zKsdhkbv
mobile/android/services/src/main/java/org/mozilla/gecko/sync/stage/EnsureCrypto5KeysStage.java
--- a/mobile/android/services/src/main/java/org/mozilla/gecko/sync/stage/EnsureCrypto5KeysStage.java
+++ b/mobile/android/services/src/main/java/org/mozilla/gecko/sync/stage/EnsureCrypto5KeysStage.java
@@ -1,69 +1,90 @@
 /* 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/. */
 
 package org.mozilla.gecko.sync.stage;
 
+import android.os.SystemClock;
+
 import java.net.URISyntaxException;
 import java.util.HashSet;
 import java.util.Set;
 
 import org.mozilla.gecko.background.common.log.Logger;
 import org.mozilla.gecko.sync.CollectionKeys;
 import org.mozilla.gecko.sync.CryptoRecord;
 import org.mozilla.gecko.sync.ExtendedJSONObject;
+import org.mozilla.gecko.sync.HTTPFailureException;
 import org.mozilla.gecko.sync.InfoCollections;
 import org.mozilla.gecko.sync.NoCollectionKeysSetException;
 import org.mozilla.gecko.sync.crypto.KeyBundle;
 import org.mozilla.gecko.sync.crypto.PersistedCrypto5Keys;
 import org.mozilla.gecko.sync.net.AuthHeaderProvider;
 import org.mozilla.gecko.sync.net.SyncStorageRecordRequest;
 import org.mozilla.gecko.sync.net.SyncStorageRequestDelegate;
 import org.mozilla.gecko.sync.net.SyncStorageResponse;
+import org.mozilla.gecko.sync.telemetry.TelemetryCollector;
 
 public class EnsureCrypto5KeysStage
 extends AbstractNonRepositorySyncStage
 implements SyncStorageRequestDelegate {
 
   private static final String LOG_TAG = "EnsureC5KeysStage";
   private static final String CRYPTO_COLLECTION = "crypto";
   protected boolean retrying = false;
 
+  private static final String TELEMETRY_ERROR_NAME = "keys";
+  private static final String TELEMETRY_ERROR_NO_COLLECTIONS = "nocollections";
+  private static final String TELEMETRY_ERROR_BAD_URI = "baduri";
+  private static final String TELEMETRY_ERROR_INVALID_WBO = "invalidwbo";
+  private static final String TELEMETRY_ERROR_REDOWNLOADING = "redownloading";
+  // While this isn't strictly an error, marking it as one is currently our best avenue for
+  // tracking these types of events given the current sync telemetry.
+  private static final String TELEMETRY_ERROR_KEYS_CHANGED = "changed";
+
   @Override
   public void execute() throws NoSuchStageException {
     InfoCollections infoCollections = session.config.infoCollections;
     if (infoCollections == null) {
+      telemetryStageCollector.finished = SystemClock.elapsedRealtime();
+      telemetryStageCollector.error = new TelemetryCollector
+              .StageErrorBuilder(TELEMETRY_ERROR_NAME, TELEMETRY_ERROR_NO_COLLECTIONS)
+              .build();
       session.abort(null, "No info/collections set in EnsureCrypto5KeysStage.");
       return;
     }
 
     PersistedCrypto5Keys pck = session.config.persistedCryptoKeys();
     long lastModified = pck.lastModified();
     if (retrying || !infoCollections.updateNeeded(CRYPTO_COLLECTION, lastModified)) {
       // Try to use our local collection keys for this session.
       Logger.debug(LOG_TAG, "Trying to use persisted collection keys for this session.");
       CollectionKeys keys = pck.keys();
       if (keys != null) {
         Logger.trace(LOG_TAG, "Using persisted collection keys for this session.");
         session.config.setCollectionKeys(keys);
-        session.advance();
+        doAdvance();
         return;
       }
       Logger.trace(LOG_TAG, "Failed to use persisted collection keys for this session.");
     }
 
     // We need an update: fetch fresh keys.
     Logger.debug(LOG_TAG, "Fetching fresh collection keys for this session.");
     try {
       SyncStorageRecordRequest request = new SyncStorageRecordRequest(session.wboURI(CRYPTO_COLLECTION, "keys"));
       request.delegate = this;
       request.get();
     } catch (URISyntaxException e) {
+      telemetryStageCollector.finished = SystemClock.elapsedRealtime();
+      telemetryStageCollector.error = new TelemetryCollector
+              .StageErrorBuilder(TELEMETRY_ERROR_NAME, TELEMETRY_ERROR_BAD_URI)
+              .build();
       session.abort(e, "Invalid URI.");
     }
   }
 
   @Override
   public AuthHeaderProvider getAuthHeaderProvider() {
     return session.getAuthHeaderProvider();
   }
@@ -119,74 +140,101 @@ implements SyncStorageRequestDelegate {
       }
     }
 
     return changedKeys;
   }
 
   @Override
   public void handleRequestSuccess(SyncStorageResponse response) {
+    telemetryStageCollector.finished = SystemClock.elapsedRealtime();
+
     // Take the timestamp from the response since it is later than the timestamp from info/collections.
     long responseTimestamp = response.normalizedWeaveTimestamp();
     CollectionKeys keys = new CollectionKeys();
     try {
       ExtendedJSONObject body = response.jsonObjectBody();
       if (Logger.LOG_PERSONAL_INFORMATION) {
         Logger.pii(LOG_TAG, "Fetched keys: " + body.toJSONString());
       }
       keys.setKeyPairsFromWBO(CryptoRecord.fromJSONRecord(body), session.config.syncKeyBundle);
     } catch (Exception e) {
+      telemetryStageCollector.error = new TelemetryCollector
+              .StageErrorBuilder(TELEMETRY_ERROR_NAME, TELEMETRY_ERROR_INVALID_WBO)
+              .build();
       session.abort(e, "Invalid keys WBO.");
       return;
     }
 
     PersistedCrypto5Keys pck = session.config.persistedCryptoKeys();
     if (!pck.persistedKeysExist()) {
       // New keys, and no old keys! Persist keys and server timestamp.
       Logger.trace(LOG_TAG, "Setting fetched keys for this session; persisting fetched keys and last modified.");
       setAndPersist(pck, keys, responseTimestamp);
-      session.advance();
+      doAdvance();
       return;
     }
 
     // New keys, but we had old keys.  Check for differences.
     CollectionKeys oldKeys = pck.keys();
     Set<String> changedCollections = collectionsToUpdate(oldKeys, keys);
     if (!changedCollections.isEmpty()) {
       // New keys, different from old keys.
       Logger.trace(LOG_TAG, "Fetched keys are not the same as persisted keys; " +
           "setting fetched keys for this session before resetting changed engines.");
       setAndPersist(pck, keys, responseTimestamp);
       session.resetStagesByName(changedCollections);
+      telemetryStageCollector.error = new TelemetryCollector
+              .StageErrorBuilder(TELEMETRY_ERROR_NAME, TELEMETRY_ERROR_KEYS_CHANGED)
+              .build();
       session.abort(null, "crypto/keys changed on server.");
       return;
     }
 
     // New keys don't differ from old keys; persist timestamp and move on.
     Logger.trace(LOG_TAG, "Fetched keys are the same as persisted keys; persisting only last modified.");
     session.config.setCollectionKeys(oldKeys);
     pck.persistLastModified(response.normalizedWeaveTimestamp());
-    session.advance();
+    doAdvance();
   }
 
   @Override
   public void handleRequestFailure(SyncStorageResponse response) {
+    telemetryStageCollector.finished = SystemClock.elapsedRealtime();
+
     if (retrying) {
       // Should happen very rarely -- this means we uploaded our crypto/keys
       // successfully, but failed to re-download.
       session.handleHTTPError(response, "Failure while re-downloading already uploaded keys.");
+      telemetryStageCollector.error = new TelemetryCollector
+              .StageErrorBuilder(TELEMETRY_ERROR_NAME, TELEMETRY_ERROR_REDOWNLOADING)
+              .setLastException(new HTTPFailureException(response))
+              .build();
       return;
     }
 
     int statusCode = response.getStatusCode();
     if (statusCode == 404) {
       Logger.info(LOG_TAG, "Got 404 fetching keys.  Fresh starting since keys are missing on server.");
       session.freshStart();
       return;
     }
+
+    telemetryStageCollector.error = new TelemetryCollector.StageErrorBuilder()
+            .setLastException(new HTTPFailureException(response))
+            .build();
     session.handleHTTPError(response, "Failure fetching keys: got response status code " + statusCode);
   }
 
   @Override
   public void handleRequestError(Exception ex) {
+    telemetryStageCollector.finished = SystemClock.elapsedRealtime();
+    telemetryStageCollector.error = new TelemetryCollector.StageErrorBuilder()
+            .setLastException(ex)
+            .build();
     session.abort(ex, "Failure fetching keys.");
   }
+
+  private void doAdvance() {
+    telemetryStageCollector.finished = SystemClock.elapsedRealtime();
+    session.advance();
+  }
 }