[Sync] Make BackendMigrator not wait for full sync cycles

chrome/browser/sync/profile_sync_service_harness.cc

Index: chrome/browser/sync/profile_sync_service_harness.cc
diff --git a/chrome/browser/sync/profile_sync_service_harness.cc b/chrome/browser/sync/profile_sync_service_harness.cc
index dcd5ed51a4eacbf710283a58f2c3814e4bcd1b2b..4b0205cc87ce60daaa63f94b39bc6fb75cff0a68 100644
--- a/chrome/browser/sync/profile_sync_service_harness.cc
+++ b/chrome/browser/sync/profile_sync_service_harness.cc
@@ -12,6 +12,7 @@
 #include <sstream>
 #include <vector>
 
+#include "base/base64.h"
 #include "base/json/json_writer.h"
 #include "base/logging.h"
 #include "base/memory/ref_counted.h"
@@ -220,6 +221,37 @@ void ProfileSyncServiceHarness::SignalStateComplete() {
   MessageLoop::current()->Quit();
 }
 
+void ProfileSyncServiceHarness::UpdateMigrationState() {
+  if (service()->HasPendingBackendMigration()) {
+    // Merge current pending migration types into
+    // |pending_migration_types_|.

[Raghu Simha, 2011/09/01 03:53:06]

Should we not simply replace pending_migration_types_ with
new_pending_migration_types?

For instance: What if pending_migration_types_ was originally {BOOKMARKS,
PREFERENCES}, and then, AUTOFILL was added to the list via
GetPendingMigrationTypesForTest(), but in the meantime, BOOKMARKS was already
migrated?

Will we not end up with {BOOKMARKS, PREFERENCES, AUTOFILL} when we should in
fact end up with {PREFERENCES, AUTOFILL}?

Or is something like the above not possible?

[akalin, 2011/09/01 04:03:24]

The idea is to accumulate all migrated types instead of just the one in the
current migration "session".  But in practice, all the pending types get
migrated at the same time (since the migrator waits until the configuration is
complete for all of them).

So in a nutshell, simply assigning would work, but I'm merging to be defensive,
since the intended end result is an accumulation.

[Raghu Simha, 2011/09/01 04:23:58]

SGTM.

+    syncable::ModelTypeSet new_pending_migration_types =
+        service()->GetPendingMigrationTypesForTest();
+    syncable::ModelTypeSet temp;
+    std::set_union(pending_migration_types_.begin(),
+                   pending_migration_types_.end(),
+                   new_pending_migration_types.begin(),
+                   new_pending_migration_types.end(),
+                   std::inserter(temp, temp.end()));
+    std::swap(pending_migration_types_, temp);
+    VLOG(1) << profile_debug_name_ << ": new pending migration types "
+            << syncable::ModelTypeSetToString(pending_migration_types_);
+  } else {
+    // Merge just-finished pending migration types into
+    // |migration_types_|.
+    syncable::ModelTypeSet temp;
+    std::set_union(pending_migration_types_.begin(),
+                   pending_migration_types_.end(),
+                   migrated_types_.begin(),
+                   migrated_types_.end(),
+                   std::inserter(temp, temp.end()));
+    std::swap(migrated_types_, temp);
+    pending_migration_types_.clear();
+    VLOG(1) << profile_debug_name_ << ": new migrated types "
+            << syncable::ModelTypeSetToString(migrated_types_);
+  }
+}
+
 bool ProfileSyncServiceHarness::RunStateChangeMachine() {
   WaitState original_wait_state = wait_state_;
   switch (wait_state_) {
@@ -344,6 +376,20 @@ bool ProfileSyncServiceHarness::RunStateChangeMachine() {
         SignalStateCompleteWithNextState(WAITING_FOR_NOTHING);
       break;
     }
+    case WAITING_FOR_MIGRATION_TO_START: {
+      VLOG(1) << GetClientInfoString("WAITING_FOR_MIGRATION_TO_START");
+      if (service()->HasPendingBackendMigration()) {
+        SignalStateCompleteWithNextState(WAITING_FOR_MIGRATION_TO_FINISH);
+      }
+      break;
+    }
+    case WAITING_FOR_MIGRATION_TO_FINISH: {
+      VLOG(1) << GetClientInfoString("WAITING_FOR_MIGRATION_TO_FINISH");
+      if (!service()->HasPendingBackendMigration()) {
+        SignalStateCompleteWithNextState(WAITING_FOR_NOTHING);
+      }
+      break;
+    }
     case SERVER_UNREACHABLE: {
       VLOG(1) << GetClientInfoString("SERVER_UNREACHABLE");
       if (GetStatus().server_reachable) {
@@ -384,6 +430,7 @@ bool ProfileSyncServiceHarness::RunStateChangeMachine() {
 }
 
 void ProfileSyncServiceHarness::OnStateChanged() {
+  UpdateMigrationState();

[Raghu Simha, 2011/09/01 03:53:06]

Any particular reason for calling UpdateMigrationState() here, where it will be
run after every single state change? Would it not be sufficient to call it in
RunStateChangeMachine() only when we are in either
WAITING_FOR_MIGRATION_TO_START or WAITING_FOR_MIGRATION_TO_FINISH? (where it
will be run a much smaller percentage of the time)

[akalin, 2011/09/01 04:03:24]

Addressed in latest patch.

   RunStateChangeMachine();
 }
 
@@ -469,17 +516,6 @@ bool ProfileSyncServiceHarness::AwaitSyncCycleCompletion(
     return true;
   }
 
-  return AwaitSyncCycleCompletionHelper(reason);
-}
-
-bool ProfileSyncServiceHarness::AwaitNextSyncCycleCompletion(
-    const std::string& reason) {
-  VLOG(1) << GetClientInfoString("AwaitNextSyncCycleCompletion");
-  return AwaitSyncCycleCompletionHelper(reason);
-}
-
-bool ProfileSyncServiceHarness::AwaitSyncCycleCompletionHelper(
-    const std::string& reason) {
   if (wait_state_ == SERVER_UNREACHABLE) {
     // Client was offline; wait for it to go online, and then wait for sync.
     AwaitStatusChangeWithTimeout(kLiveSyncOperationTimeoutMs, reason);
@@ -522,6 +558,53 @@ bool ProfileSyncServiceHarness::AwaitExponentialBackoffVerification() {
   return (retry_verifier_.Succeeded());
 }
 
+bool ProfileSyncServiceHarness::AwaitMigration(
+    const syncable::ModelTypeSet& expected_migrated_types) {
+  VLOG(1) << GetClientInfoString("AwaitMigration");
+  VLOG(1) << profile_debug_name_ << ": waiting until migration is done for "
+          << syncable::ModelTypeSetToString(expected_migrated_types);
+  while (true) {
+    bool migration_finished =
+        std::includes(migrated_types_.begin(), migrated_types_.end(),
+                      expected_migrated_types.begin(),
+                      expected_migrated_types.end());
+    VLOG(1) << "Migrated types "
+            << syncable::ModelTypeSetToString(migrated_types_)
+            << (migration_finished ? " contains " : " does not contain ")
+            << syncable::ModelTypeSetToString(expected_migrated_types);
+    if (migration_finished) {
+      return true;
+    }
+
+    if (service()->HasPendingBackendMigration()) {
+      wait_state_ = WAITING_FOR_MIGRATION_TO_FINISH;
+    } else {
+      wait_state_ = WAITING_FOR_MIGRATION_TO_START;
+      AwaitStatusChangeWithTimeout(kLiveSyncOperationTimeoutMs,
+                                   "Wait for migration to start");
+      if (wait_state_ != WAITING_FOR_MIGRATION_TO_FINISH) {
+        VLOG(1) << profile_debug_name_
+                << ": wait state = " << wait_state_
+                << " after migration start is not "
+                << "WAITING_FOR_MIGRATION_TO_FINISH";
+        return false;
+      }
+    }
+    AwaitStatusChangeWithTimeout(kLiveSyncOperationTimeoutMs,
+                                 "Wait for migration to finish");
+    if (wait_state_ != WAITING_FOR_NOTHING) {
+      VLOG(1) << profile_debug_name_
+              << ": wait state = " << wait_state_
+              << " after migration finish is not WAITING_FOR_NOTHING";
+      return false;
+    }
+    if (!AwaitSyncCycleCompletion(
+            "Config sync cycle after migration cycle")) {
+      return false;
+    }
+  }
+}
+
 bool ProfileSyncServiceHarness::AwaitMutualSyncCycleCompletion(
     ProfileSyncServiceHarness* partner) {
   VLOG(1) << GetClientInfoString("AwaitMutualSyncCycleCompletion");
@@ -641,8 +724,12 @@ bool ProfileSyncServiceHarness::IsSynced() {
 
 bool ProfileSyncServiceHarness::MatchesOtherClient(
     ProfileSyncServiceHarness* partner) {
-  if (!IsSynced())
+  // TODO(akalin): Shouldn't this with the intersection check?

[Raghu Simha, 2011/09/01 03:53:06]

Is this comment Yoda-speak? :)

[akalin, 2011/09/01 04:03:24]

Fixed!

+  // Otherwise, this function isn't symmetric.
+  if (!IsSynced()) {
+    VLOG(1) << profile_debug_name_ << ": not synced, assuming doesn't match";

[Raghu Simha, 2011/09/01 03:53:06]

This should probably be a VLOG(2), since it's a genuine possibility that the
client is not yet fully synced, and we don't want to pollute the logs with
several reps of this statement. (Ignore this comment if you've run the
integration tests with --v=1 and feel that this is really useful while
debugging)

[akalin, 2011/09/01 04:03:24]

Done.

     return false;
+  }
 
   // Only look for a match if we have at least one enabled datatype in
   // common with the partner client.
@@ -653,11 +740,38 @@ bool ProfileSyncServiceHarness::MatchesOtherClient(
                         other_types.end(),
                         inserter(intersection_types,
                                  intersection_types.begin()));
+
+  VLOG(1) << profile_debug_name_ << ", " << partner->profile_debug_name_
+          << ": common types are "
+          << syncable::ModelTypeSetToString(intersection_types);
+
+  if (!intersection_types.empty() && !partner->IsSynced()) {
+    VLOG(1) << "non-empty common types and "

[Raghu Simha, 2011/09/01 03:53:06]

Same as above. This too should probably be a VLOG(2).

[akalin, 2011/09/01 04:03:24]

Done.

+            << partner->profile_debug_name_ << " isn't synced";
+    return false;
+  }
+
   for (syncable::ModelTypeSet::iterator i = intersection_types.begin();
-       i != intersection_types.end();
-       ++i) {
-    if (!partner->IsSynced() ||
-        partner->GetUpdatedTimestamp(*i) != GetUpdatedTimestamp(*i)) {
+       i != intersection_types.end(); ++i) {
+    const std::string timestamp = GetUpdatedTimestamp(*i);
+    const std::string partner_timestamp = partner->GetUpdatedTimestamp(*i);
+    if (timestamp != partner_timestamp) {
+      if (VLOG_IS_ON(1)) {
+        std::string timestamp_base64, partner_timestamp_base64;
+        if (!base::Base64Encode(timestamp, &timestamp_base64)) {
+          NOTREACHED();
+        }
+        if (!base::Base64Encode(
+                partner_timestamp, &partner_timestamp_base64)) {
+          NOTREACHED();
+        }
+        VLOG(1) << syncable::ModelTypeToString(*i) << ": "
+                << profile_debug_name_ << " timestamp = "
+                << timestamp_base64 << ", "
+                << partner->profile_debug_name_
+                << " partner timestamp = "
+                << partner_timestamp_base64;
+      }
       return false;
     }
   }