Sync: Record UMA on duplicate client tag hashes received from the server

Some recent reports indicate that the Sync server might be sending
duplicate client tag hashes. This is considered "invalid data", and is
so far not handled well by the client. These metrics will help us
evaluate how common this case is, and also whether the duplicates are
within a single GetUpdates response, or across multiple responses
(within a full paginated GetUpdates cycle).

Bug: 872360
Change-Id: Id24baa351c80f2eb1ab59f890d50d6603cb89e6b
Reviewed-on: https://chromium-review.googlesource.com/1203935Reviewed-by: Jesse Doherty <jwd@chromium.org>
Reviewed-by: Jan Krcal <jkrcal@chromium.org>
Commit-Queue: Marc Treib <treib@chromium.org>
Cr-Commit-Position: refs/heads/master@{#590328}

components/sync/engine_impl/model_type_worker.cc

@@ -6,6 +6,7 @@
 
 #include <stdint.h>
 
+#include <algorithm>
 #include <utility>
 #include <vector>
 
@@ -13,7 +14,7 @@
 #include "base/format_macros.h"
 #include "base/guid.h"
 #include "base/logging.h"
-#include "base/metrics/histogram_macros.h"
+#include "base/metrics/histogram_functions.h"
 #include "base/strings/stringprintf.h"
 #include "base/trace_event/memory_usage_estimator.h"
 #include "components/sync/base/cancelation_signal.h"
@@ -23,6 +24,15 @@
 #include "components/sync/engine_impl/non_blocking_type_commit_contribution.h"
 #include "components/sync/protocol/proto_memory_estimations.h"
 
+namespace {
+
+bool ContainsDuplicate(std::vector<std::string> values) {
+  std::sort(values.begin(), values.end());
+  return std::adjacent_find(values.begin(), values.end()) != values.end();
+}
+
+}  // namespace
+
 namespace syncer {
 
 ModelTypeWorker::ModelTypeWorker(
@@ -123,6 +133,7 @@ SyncerError ModelTypeWorker::ProcessGetUpdatesResponse(
   UpdateCounters* counters = debug_info_emitter_->GetMutableUpdateCounters();
   counters->num_updates_received += applicable_updates.size();
 
+  std::vector<std::string> client_tag_hashes;
   for (const sync_pb::SyncEntity* update_entity : applicable_updates) {
     if (update_entity->deleted()) {
       status->increment_num_tombstone_updates_downloaded_by(1);
@@ -134,6 +145,9 @@ SyncerError ModelTypeWorker::ProcessGetUpdatesResponse(
                                        &response_data)) {
       case SUCCESS:
         pending_updates_.push_back(response_data);
+        if (!response_data.entity->client_tag_hash.empty()) {
+          client_tag_hashes.push_back(response_data.entity->client_tag_hash);
+        }
         break;
       case DECRYPTION_PENDING:
         entries_pending_decryption_[update_entity->id_string()] = response_data;
@@ -143,6 +157,10 @@ SyncerError ModelTypeWorker::ProcessGetUpdatesResponse(
         break;
     }
   }
+  std::string suffix = ModelTypeToHistogramSuffix(type_);
+  base::UmaHistogramBoolean(
+      "Sync.DuplicateClientTagHashInGetUpdatesResponse." + suffix,
+      ContainsDuplicate(std::move(client_tag_hashes)));
 
   debug_info_emitter_->EmitUpdateCountersUpdate();
   return SYNCER_OK;
@@ -236,6 +254,18 @@ void ModelTypeWorker::ApplyPendingUpdates() {
 
   DCHECK(entries_pending_decryption_.empty());
 
+  // Check for duplicate client tag hashes.
+  std::vector<std::string> client_tag_hashes;
+  for (const UpdateResponseData& update : pending_updates_) {
+    if (!update.entity->client_tag_hash.empty()) {
+      client_tag_hashes.push_back(update.entity->client_tag_hash);
+    }
+  }
+  std::string suffix = ModelTypeToHistogramSuffix(type_);
+  base::UmaHistogramBoolean(
+      "Sync.DuplicateClientTagHashInApplyPendingUpdates." + suffix,
+      ContainsDuplicate(std::move(client_tag_hashes)));
+
   model_type_processor_->OnUpdateReceived(model_type_state_, pending_updates_);
 
   UpdateCounters* counters = debug_info_emitter_->GetMutableUpdateCounters();

components/sync/engine_impl/model_type_worker_unittest.cc

@@ -10,6 +10,7 @@
 
 #include "base/bind.h"
 #include "base/strings/stringprintf.h"
+#include "base/test/metrics/histogram_tester.h"
 #include "base/threading/thread.h"
 #include "components/sync/base/cancelation_signal.h"
 #include "components/sync/base/fake_encryptor.h"
@@ -39,6 +40,9 @@ const char kNigoriKeyName[] = "nigori-key";
 const ModelType kModelType = PREFERENCES;
 
 std::string GenerateTagHash(const std::string& tag) {
+  if (tag.empty()) {
+    return std::string();
+  }
   return GenerateSyncableHash(kModelType, tag);
 }
 
@@ -342,6 +346,28 @@ class ModelTypeWorkerTest : public ::testing::Test {
                                         &status_controller_);
   }
 
+  void TriggerPartialUpdateFromServer(int64_t version_offset,
+                                      const std::string& tag1,
+                                      const std::string& value1,
+                                      const std::string& tag2,
+                                      const std::string& value2) {
+    SyncEntity entity1 = server()->UpdateFromServer(
+        version_offset, GenerateTagHash(tag1), GenerateSpecifics(tag1, value1));
+    SyncEntity entity2 = server()->UpdateFromServer(
+        version_offset, GenerateTagHash(tag2), GenerateSpecifics(tag2, value2));
+
+    if (update_encryption_filter_index_ != 0) {
+      EncryptUpdate(GetNthKeyParams(update_encryption_filter_index_),
+                    entity1.mutable_specifics());
+      EncryptUpdate(GetNthKeyParams(update_encryption_filter_index_),
+                    entity2.mutable_specifics());
+    }
+
+    worker()->ProcessGetUpdatesResponse(
+        server()->GetProgress(), server()->GetContext(), {&entity1, &entity2},
+        &status_controller_);
+  }
+
   void TriggerUpdateFromServer(int64_t version_offset,
                                const std::string& tag,
                                const std::string& value) {
@@ -699,6 +725,90 @@ TEST_F(ModelTypeWorkerTest, ReceiveUpdates) {
   EXPECT_EQ(1, emitter()->GetUpdateCounters().num_updates_applied);
 }
 
+TEST_F(ModelTypeWorkerTest, ReceiveUpdates_NoDuplicateHash) {
+  NormalInitialize();
+
+  base::HistogramTester histograms;
+
+  TriggerPartialUpdateFromServer(10, kTag1, kValue1, kTag2, kValue2);
+  TriggerPartialUpdateFromServer(10, kTag3, kValue3);
+
+  // No duplicates in either of the partial updates.
+  histograms.ExpectUniqueSample(
+      "Sync.DuplicateClientTagHashInGetUpdatesResponse.PREFERENCE",
+      /*sample=*/false, /*count=*/2);
+
+  ApplyUpdates();
+
+  // No duplicate across the partial updates either.
+  histograms.ExpectUniqueSample(
+      "Sync.DuplicateClientTagHashInApplyPendingUpdates.PREFERENCE",
+      /*sample=*/false, /*count=*/1);
+}
+
+TEST_F(ModelTypeWorkerTest, ReceiveUpdates_DuplicateHashWithinPartialUpdate) {
+  NormalInitialize();
+
+  base::HistogramTester histograms;
+
+  // Note that kTag1 appears twice.
+  TriggerPartialUpdateFromServer(10, kTag1, kValue1, kTag1, kValue2);
+
+  // There was a duplicate.
+  histograms.ExpectUniqueSample(
+      "Sync.DuplicateClientTagHashInGetUpdatesResponse.PREFERENCE",
+      /*sample=*/true, /*count=*/1);
+
+  ApplyUpdates();
+
+  histograms.ExpectUniqueSample(
+      "Sync.DuplicateClientTagHashInApplyPendingUpdates.PREFERENCE",
+      /*sample=*/true, /*count=*/1);
+}
+
+TEST_F(ModelTypeWorkerTest, ReceiveUpdates_DuplicateHashAcrossPartialUpdates) {
+  NormalInitialize();
+
+  base::HistogramTester histograms;
+
+  // Note that kTag1 appears in both partial updates.
+  TriggerPartialUpdateFromServer(10, kTag1, kValue1);
+  TriggerPartialUpdateFromServer(10, kTag1, kValue2);
+
+  // Neither of the two partial updates contained duplicates.
+  histograms.ExpectUniqueSample(
+      "Sync.DuplicateClientTagHashInGetUpdatesResponse.PREFERENCE",
+      /*sample=*/false, /*count=*/2);
+
+  ApplyUpdates();
+
+  // But there was a duplicate across the two partial updates.
+  histograms.ExpectUniqueSample(
+      "Sync.DuplicateClientTagHashInApplyPendingUpdates.PREFERENCE",
+      /*sample=*/true, /*count=*/1);
+}
+
+TEST_F(ModelTypeWorkerTest, ReceiveUpdates_EmptyHashNotConsideredDuplicate) {
+  NormalInitialize();
+
+  base::HistogramTester histograms;
+
+  // Some model types (e.g. AUTOFILL_WALLET_DATA) don't have client tag hashes.
+  TriggerPartialUpdateFromServer(10, "", kValue1, "", kValue2);
+  TriggerPartialUpdateFromServer(10, "", kValue3);
+
+  // The missing (empty) tags should not be considered duplicates.
+  histograms.ExpectUniqueSample(
+      "Sync.DuplicateClientTagHashInGetUpdatesResponse.PREFERENCE",
+      /*sample=*/false, /*count=*/2);
+
+  ApplyUpdates();
+
+  histograms.ExpectUniqueSample(
+      "Sync.DuplicateClientTagHashInApplyPendingUpdates.PREFERENCE",
+      /*sample=*/false, /*count=*/1);
+}
+
 // Test that an update download coming in multiple parts gets accumulated into
 // one call to the processor.
 TEST_F(ModelTypeWorkerTest, ReceiveMultiPartUpdates) {

tools/metrics/histograms/histograms.xml

@@ -103120,6 +103120,26 @@ uploading your change for review.
   <summary>Tracks success of failure of sync directory initialization.</summary>
 </histogram>
 
+<histogram base="true" name="Sync.DuplicateClientTagHashInApplyPendingUpdates"
+    enum="BooleanPresent" expires_after="2019-03-31">
+  <owner>treib@chromium.org</owner>
+  <summary>
+    Whether ModelTypeWorker received any duplicate client tag hashes within a
+    full GetUpdates cycle (which, in the case of pagination, might consist of
+    multiple individual GetUpdates responses).
+  </summary>
+</histogram>
+
+<histogram base="true" name="Sync.DuplicateClientTagHashInGetUpdatesResponse"
+    enum="BooleanPresent" expires_after="2019-03-31">
+  <owner>treib@chromium.org</owner>
+  <summary>
+    Whether ModelTypeWorker received any duplicate client tag hashes within a
+    single GetUpdates response (which, in the case of pagination, might be only
+    part of a full GetUpdates cycle).
+  </summary>
+</histogram>
+
 <histogram name="Sync.EncryptAllData">
   <obsolete>
     Deprecated as of m26.
@@ -130763,6 +130783,8 @@ uploading your change for review.
   <suffix name="USER_CONSENT" label="USER_CONSENT"/>
   <suffix name="USER_EVENT" label="USER_EVENT"/>
   <suffix name="WIFI_CREDENTIAL" label="WIFI_CREDENTIAL"/>
+  <affected-histogram name="Sync.DuplicateClientTagHashInApplyPendingUpdates"/>
+  <affected-histogram name="Sync.DuplicateClientTagHashInGetUpdatesResponse"/>
   <affected-histogram name="Sync.ModelTypeCount">
     <obsolete>
       Deprecated 7/2018. Replaced by Sync.ModelTypeCount2.