[Sync] Clean up sync logging

Add GetDebugName() method to Profile.  Use it in ProfileSyncServiceHarness,
SyncerThread, and LiveSyncExtensionHelper.

Change VLOG(1)s in SyncerThread to VLOG(2)s.

Turn on logging for the test server if VLOG is enabled for that file, and not just in general.

BUG=
TEST=

Review URL: http://codereview.chromium.org/7024058

git-svn-id: svn://svn.chromium.org/chrome/trunk/src@88355 0039d316-1c4b-4281-b951-d872f2087c98

1 files changed, 101 insertions, 99 deletions

diff --git a/chrome/browser/sync/profile_sync_service_harness.cc b/chrome/browser/sync/profile_sync_service_harness.cc
index cc628ca..79aed37 100644
--- a/chrome/browser/sync/profile_sync_service_harness.cc
+++ b/chrome/browser/sync/profile_sync_service_harness.cc
@@ -9,6 +9,7 @@
 #include <iterator>
 #include <ostream>
 #include <set>
+#include <sstream>
 #include <vector>
 
 #include "base/json/json_writer.h"
@@ -90,8 +91,7 @@ bool StateChangeTimeoutEvent::Abort() {
 ProfileSyncServiceHarness::ProfileSyncServiceHarness(
     Profile* profile,
     const std::string& username,
-    const std::string& password,
-    int id)
+    const std::string& password)
     : waiting_for_encryption_type_(syncable::UNSPECIFIED),
       wait_state_(INITIAL_WAIT_STATE),
       profile_(profile),
@@ -99,7 +99,7 @@ ProfileSyncServiceHarness::ProfileSyncServiceHarness(
       timestamp_match_partner_(NULL),
       username_(username),
       password_(password),
-      id_(id) {
+      profile_debug_name_(profile->GetDebugName()) {
   if (IsSyncAlreadySetup()) {
     service_ = profile_->GetProfileSyncService();
     service_->AddObserver(this);
@@ -114,7 +114,7 @@ ProfileSyncServiceHarness* ProfileSyncServiceHarness::CreateAndAttach(
     NOTREACHED() << "Profile has never signed into sync.";
     return NULL;
   }
-  return new ProfileSyncServiceHarness(profile, "", "", 0);
+  return new ProfileSyncServiceHarness(profile, "", "");
 }
 
 void ProfileSyncServiceHarness::SetCredentials(const std::string& username,
@@ -136,10 +136,10 @@ bool ProfileSyncServiceHarness::SetupSync() {
   bool result = SetupSync(synced_datatypes);
   if (result == false) {
     std::string status = GetServiceStatus();
-    LOG(ERROR) << "Client " << id_ << ": SetupSync failed. Syncer status:\n"
-               << status;
+    LOG(ERROR) << profile_debug_name_
+               << ": SetupSync failed. Syncer status:\n" << status;
   } else {
-    VLOG(1) << "Client " << id_ << ": SetupSync successful.";
+    VLOG(1) << profile_debug_name_ << ": SetupSync successful.";
   }
   return result;
 }
@@ -210,7 +210,7 @@ bool ProfileSyncServiceHarness::RunStateChangeMachine() {
   WaitState original_wait_state = wait_state_;
   switch (wait_state_) {
     case WAITING_FOR_ON_BACKEND_INITIALIZED: {
-      LogClientInfo("WAITING_FOR_ON_BACKEND_INITIALIZED", 1);
+      VLOG(1) << "WAITING_FOR_ON_BACKEND_INITIALIZED: " << GetClientInfo();
       if (service()->sync_initialized()) {
         // The sync backend is initialized.
         SignalStateCompleteWithNextState(WAITING_FOR_INITIAL_SYNC);
@@ -218,7 +218,7 @@ bool ProfileSyncServiceHarness::RunStateChangeMachine() {
       break;
     }
     case WAITING_FOR_INITIAL_SYNC: {
-      LogClientInfo("WAITING_FOR_INITIAL_SYNC", 1);
+      VLOG(1) << "WAITING_FOR_INITIAL_SYNC: " << GetClientInfo();
       if (IsSynced()) {
         // The first sync cycle is now complete. We can start running tests.
         SignalStateCompleteWithNextState(FULLY_SYNCED);
@@ -234,7 +234,7 @@ bool ProfileSyncServiceHarness::RunStateChangeMachine() {
       break;
     }
     case WAITING_FOR_SYNC_TO_FINISH: {
-      LogClientInfo("WAITING_FOR_SYNC_TO_FINISH", 1);
+      VLOG(1) << "WAITING_FOR_SYNC_TO_FINISH: " << GetClientInfo();
       if (IsSynced()) {
         // The sync cycle we were waiting for is complete.
         SignalStateCompleteWithNextState(FULLY_SYNCED);
@@ -256,7 +256,7 @@ bool ProfileSyncServiceHarness::RunStateChangeMachine() {
       break;
     }
     case WAITING_FOR_UPDATES: {
-      LogClientInfo("WAITING_FOR_UPDATES", 1);
+      VLOG(1) << "WAITING_FOR_UPDATES: " << GetClientInfo();
       DCHECK(timestamp_match_partner_);
       if (!MatchesOtherClient(timestamp_match_partner_)) {
         // The client is not yet fully synced; keep waiting until we converge.
@@ -269,7 +269,7 @@ bool ProfileSyncServiceHarness::RunStateChangeMachine() {
       break;
     }
     case WAITING_FOR_PASSPHRASE_REQUIRED: {
-      LogClientInfo("WAITING_FOR_PASSPHRASE_REQUIRED", 1);
+      VLOG(1) << "WAITING_FOR_PASSPHRASE_REQUIRED: " << GetClientInfo();
       if (service()->IsPassphraseRequired()) {
         // A passphrase is now required. Wait for it to be accepted.
         SignalStateCompleteWithNextState(WAITING_FOR_PASSPHRASE_ACCEPTED);
@@ -277,7 +277,7 @@ bool ProfileSyncServiceHarness::RunStateChangeMachine() {
       break;
     }
     case WAITING_FOR_PASSPHRASE_ACCEPTED: {
-      LogClientInfo("WAITING_FOR_PASSPHRASE_ACCEPTED", 1);
+      VLOG(1) << "WAITING_FOR_PASSPHRASE_ACCEPTED: " << GetClientInfo();
       if (service()->ShouldPushChanges() &&
           !service()->IsPassphraseRequired() &&
           service()->IsUsingSecondaryPassphrase()) {
@@ -287,7 +287,7 @@ bool ProfileSyncServiceHarness::RunStateChangeMachine() {
       break;
     }
     case WAITING_FOR_ENCRYPTION: {
-      LogClientInfo("WAITING_FOR_ENCRYPTION", 1);
+      VLOG(1) << "WAITING_FOR_ENCRYPTION: " << GetClientInfo();
       if (IsSynced() &&
           IsTypeEncrypted(waiting_for_encryption_type_) &&
           GetLastSessionSnapshot()->num_conflicting_updates == 0) {
@@ -304,7 +304,7 @@ bool ProfileSyncServiceHarness::RunStateChangeMachine() {
       break;
     }
     case WAITING_FOR_SYNC_CONFIGURATION: {
-      LogClientInfo("WAITING_FOR_SYNC_CONFIGURATION", 1);
+      VLOG(1) << "WAITING_FOR_SYNC_CONFIGURATION: " << GetClientInfo();
       if (service()->ShouldPushChanges()) {
         // The Datatype manager is configured and sync is fully initialized.
         SignalStateCompleteWithNextState(FULLY_SYNCED);
@@ -312,7 +312,7 @@ bool ProfileSyncServiceHarness::RunStateChangeMachine() {
       break;
     }
     case SERVER_UNREACHABLE: {
-      LogClientInfo("SERVER_UNREACHABLE", 1);
+      VLOG(1) << "SERVER_UNREACHABLE: " << GetClientInfo();
       if (GetStatus().server_reachable) {
         // The client was offline due to the network being disabled, but is now
         // back online. Wait for the pending sync cycle to complete.
@@ -323,17 +323,17 @@ bool ProfileSyncServiceHarness::RunStateChangeMachine() {
     case SET_PASSPHRASE_FAILED: {
       // A passphrase is required for decryption. There is nothing the sync
       // client can do until SetPassphrase() is called.
-      LogClientInfo("SET_PASSPHRASE_FAILED", 1);
+      VLOG(1) << "SET_PASSPHRASE_FAILED: " << GetClientInfo();
       break;
     }
     case FULLY_SYNCED: {
       // The client is online and fully synced. There is nothing to do.
-      LogClientInfo("FULLY_SYNCED", 1);
+      VLOG(1) << "FULLY_SYNCED: " << GetClientInfo();
       break;
     }
     case SYNC_DISABLED: {
       // Syncing is disabled for the client. There is nothing to do.
-      LogClientInfo("SYNC_DISABLED", 1);
+      VLOG(1) << "SYNC_DISABLED: " << GetClientInfo();
       break;
     }
     default:
@@ -349,9 +349,9 @@ void ProfileSyncServiceHarness::OnStateChanged() {
 }
 
 bool ProfileSyncServiceHarness::AwaitPassphraseRequired() {
-  LogClientInfo("AwaitPassphraseRequired", 1);
+  VLOG(1) << "AwaitPassphraseRequired: " << GetClientInfo();
   if (wait_state_ == SYNC_DISABLED) {
-    LOG(ERROR) << "Sync disabled for Client " << id_ << ".";
+    LOG(ERROR) << "Sync disabled for " << profile_debug_name_ << ".";
     return false;
   }
 
@@ -366,9 +366,9 @@ bool ProfileSyncServiceHarness::AwaitPassphraseRequired() {
 }
 
 bool ProfileSyncServiceHarness::AwaitPassphraseAccepted() {
-  LogClientInfo("AwaitPassphraseAccepted", 1);
+  VLOG(1) << "AwaitPassphraseAccepted: " << GetClientInfo();
   if (wait_state_ == SYNC_DISABLED) {
-    LOG(ERROR) << "Sync disabled for Client " << id_ << ".";
+    LOG(ERROR) << "Sync disabled for " << profile_debug_name_ << ".";
     return false;
   }
 
@@ -385,7 +385,7 @@ bool ProfileSyncServiceHarness::AwaitPassphraseAccepted() {
 }
 
 bool ProfileSyncServiceHarness::AwaitBackendInitialized() {
-  LogClientInfo("AwaitBackendInitialized", 1);
+  VLOG(1) << "AwaitBackendInitialized: " << GetClientInfo();
   if (service()->sync_initialized()) {
     // The sync backend host has already been initialized; don't wait.
     return true;
@@ -397,7 +397,7 @@ bool ProfileSyncServiceHarness::AwaitBackendInitialized() {
 }
 
 bool ProfileSyncServiceHarness::AwaitSyncRestart() {
-  LogClientInfo("AwaitSyncRestart", 1);
+  VLOG(1) << "AwaitSyncRestart: " << GetClientInfo();
   if (service()->ShouldPushChanges()) {
     // Sync has already been restarted; don't wait.
     return true;
@@ -419,9 +419,9 @@ bool ProfileSyncServiceHarness::AwaitSyncRestart() {
 
 bool ProfileSyncServiceHarness::AwaitSyncCycleCompletion(
     const std::string& reason) {
-  LogClientInfo("AwaitSyncCycleCompletion", 1);
+  VLOG(1) << "AwaitSyncCycleCompletion: " << GetClientInfo();
   if (wait_state_ == SYNC_DISABLED) {
-    LOG(ERROR) << "Sync disabled for Client " << id_ << ".";
+    LOG(ERROR) << "Sync disabled for " << profile_debug_name_ << ".";
     return false;
   }
 
@@ -435,26 +435,27 @@ bool ProfileSyncServiceHarness::AwaitSyncCycleCompletion(
     AwaitStatusChangeWithTimeout(kLiveSyncOperationTimeoutMs, reason);
     DCHECK_EQ(wait_state_, WAITING_FOR_SYNC_TO_FINISH);
     return AwaitStatusChangeWithTimeout(kLiveSyncOperationTimeoutMs, reason);
+  }
+
+  DCHECK(service()->sync_initialized());
+  wait_state_ = WAITING_FOR_SYNC_TO_FINISH;
+  AwaitStatusChangeWithTimeout(kLiveSyncOperationTimeoutMs, reason);
+  if (wait_state_ == FULLY_SYNCED) {
+    // Client is online; sync was successful.
+    return true;
+  } else if (wait_state_ == SERVER_UNREACHABLE) {
+    // Client is offline; sync was unsuccessful.
+    LOG(ERROR) << "Client went offline after waiting for sync to finish";
+    return false;
   } else {
-    DCHECK(service()->sync_initialized());
-    wait_state_ = WAITING_FOR_SYNC_TO_FINISH;
-    AwaitStatusChangeWithTimeout(kLiveSyncOperationTimeoutMs, reason);
-    if (wait_state_ == FULLY_SYNCED) {
-      // Client is online; sync was successful.
-      return true;
-    } else if (wait_state_ == SERVER_UNREACHABLE) {
-      // Client is offline; sync was unsuccessful.
-      return false;
-    } else {
-      LOG(ERROR) << "Invalid wait state:" << wait_state_;
-      return false;
-    }
+    LOG(ERROR) << "Invalid wait state: " << wait_state_;
+    return false;
   }
 }
 
 bool ProfileSyncServiceHarness::AwaitMutualSyncCycleCompletion(
     ProfileSyncServiceHarness* partner) {
-  LogClientInfo("AwaitMutualSyncCycleCompletion", 1);
+  VLOG(1) << "AwaitMutualSyncCycleCompletion: " << GetClientInfo();
   if (!AwaitSyncCycleCompletion("Sync cycle completion on active client."))
     return false;
   return partner->WaitUntilTimestampMatches(this,
@@ -463,7 +464,7 @@ bool ProfileSyncServiceHarness::AwaitMutualSyncCycleCompletion(
 
 bool ProfileSyncServiceHarness::AwaitGroupSyncCycleCompletion(
     std::vector<ProfileSyncServiceHarness*>& partners) {
-  LogClientInfo("AwaitGroupSyncCycleCompletion", 1);
+  VLOG(1) << "AwaitGroupSyncCycleCompletion: " << GetClientInfo();
   if (!AwaitSyncCycleCompletion("Sync cycle completion on active client."))
     return false;
   bool return_value = true;
@@ -494,9 +495,9 @@ bool ProfileSyncServiceHarness::AwaitQuiescence(
 
 bool ProfileSyncServiceHarness::WaitUntilTimestampMatches(
     ProfileSyncServiceHarness* partner, const std::string& reason) {
-  LogClientInfo("WaitUntilTimestampMatches", 1);
+  VLOG(1) << "WaitUntilTimestampMatches: " << GetClientInfo();
   if (wait_state_ == SYNC_DISABLED) {
-    LOG(ERROR) << "Sync disabled for Client " << id_ << ".";
+    LOG(ERROR) << "Sync disabled for " << profile_debug_name_ << ".";
     return false;
   }
 
@@ -515,9 +516,9 @@ bool ProfileSyncServiceHarness::WaitUntilTimestampMatches(
 bool ProfileSyncServiceHarness::AwaitStatusChangeWithTimeout(
     int timeout_milliseconds,
     const std::string& reason) {
-  LogClientInfo("AwaitStatusChangeWithTimeout", 1);
+  VLOG(1) << "AwaitStatusChangeWithTimeout: " << GetClientInfo();
   if (wait_state_ == SYNC_DISABLED) {
-    LOG(ERROR) << "Sync disabled for Client " << id_ << ".";
+    LOG(ERROR) << "Sync disabled for " << profile_debug_name_ << ".";
     return false;
   }
   scoped_refptr<StateChangeTimeoutEvent> timeout_signal(
@@ -533,10 +534,10 @@ bool ProfileSyncServiceHarness::AwaitStatusChangeWithTimeout(
   loop->Run();
   loop->SetNestableTasksAllowed(did_allow_nestable_tasks);
   if (timeout_signal->Abort()) {
-    LogClientInfo("AwaitStatusChangeWithTimeout succeeded", 1);
+    VLOG(1) << "AwaitStatusChangeWithTimeout succeeded: " << GetClientInfo();
     return true;
   } else {
-    LogClientInfo("AwaitStatusChangeWithTimeout timed out", 0);
+    VLOG(0) << "AwaitStatusChangeWithTimeout timed out: " << GetClientInfo();
     return false;
   }
 }
@@ -547,22 +548,26 @@ ProfileSyncService::Status ProfileSyncServiceHarness::GetStatus() {
 }
 
 bool ProfileSyncServiceHarness::IsSynced() {
-  LogClientInfo("IsSynced", 1);
-  if (service() == NULL)
+  VLOG(1) << "IsSynced: " << GetClientInfo();
+  if (service() == NULL) {
+    VLOG(1) << "NULL service; assuming not synced";
     return false;
+  }
   const SyncSessionSnapshot* snap = GetLastSessionSnapshot();
   // TODO(rsimha): Remove additional checks of snap->has_more_to_sync and
   // snap->unsynced_count once http://crbug.com/48989 is fixed.
-  return (snap &&
-          snap->num_blocking_conflicting_updates == 0 &&
-          ServiceIsPushingChanges() &&
-          GetStatus().notifications_enabled &&
-          !service()->HasUnsyncedItems() &&
-          !snap->has_more_to_sync &&
-          snap->unsynced_count == 0 &&
-          !service()->HasPendingBackendMigration() &&
-          service()->passphrase_required_reason() !=
-              sync_api::REASON_SET_PASSPHRASE_FAILED);
+  bool is_synced = snap &&
+      snap->num_blocking_conflicting_updates == 0 &&
+      ServiceIsPushingChanges() &&
+      GetStatus().notifications_enabled &&
+      !service()->HasUnsyncedItems() &&
+      !snap->has_more_to_sync &&
+      snap->unsynced_count == 0 &&
+      !service()->HasPendingBackendMigration() &&
+      service()->passphrase_required_reason() !=
+      sync_api::REASON_SET_PASSPHRASE_FAILED;
+  VLOG(1) << "IsSynced: " << is_synced;
+  return is_synced;
 }
 
 bool ProfileSyncServiceHarness::MatchesOtherClient(
@@ -601,7 +606,7 @@ const SyncSessionSnapshot*
 
 bool ProfileSyncServiceHarness::EnableSyncForDatatype(
     syncable::ModelType datatype) {
-  LogClientInfo("EnableSyncForDatatype", 1);
+  VLOG(1) << "EnableSyncForDatatype: " << GetClientInfo();
 
   syncable::ModelTypeSet synced_datatypes;
   if (wait_state_ == SYNC_DISABLED) {
@@ -619,7 +624,7 @@ bool ProfileSyncServiceHarness::EnableSyncForDatatype(
   if (it != synced_datatypes.end()) {
     VLOG(1) << "EnableSyncForDatatype(): Sync already enabled for datatype "
             << syncable::ModelTypeToString(datatype)
-            << " on Client " << id_ << ".";
+            << " on " << profile_debug_name_ << ".";
     return true;
   }
 
@@ -628,17 +633,17 @@ bool ProfileSyncServiceHarness::EnableSyncForDatatype(
   if (AwaitSyncCycleCompletion("Datatype configuration.")) {
     VLOG(1) << "EnableSyncForDatatype(): Enabled sync for datatype "
             << syncable::ModelTypeToString(datatype)
-            << " on Client " << id_ << ".";
+            << " on " << profile_debug_name_ << ".";
     return true;
   }
 
-  LogClientInfo("EnableSyncForDatatype failed", 0);
+  VLOG(0) << "EnableSyncForDatatype failed: " << GetClientInfo();
   return false;
 }
 
 bool ProfileSyncServiceHarness::DisableSyncForDatatype(
     syncable::ModelType datatype) {
-  LogClientInfo("DisableSyncForDatatype", 1);
+  VLOG(1) << "DisableSyncForDatatype: " << GetClientInfo();
 
   syncable::ModelTypeSet synced_datatypes;
   if (service() == NULL) {
@@ -651,7 +656,7 @@ bool ProfileSyncServiceHarness::DisableSyncForDatatype(
   if (it == synced_datatypes.end()) {
     VLOG(1) << "DisableSyncForDatatype(): Sync already disabled for datatype "
             << syncable::ModelTypeToString(datatype)
-            << " on Client " << id_ << ".";
+            << " on " << profile_debug_name_ << ".";
     return true;
   }
 
@@ -660,16 +665,16 @@ bool ProfileSyncServiceHarness::DisableSyncForDatatype(
   if (AwaitSyncCycleCompletion("Datatype reconfiguration.")) {
     VLOG(1) << "DisableSyncForDatatype(): Disabled sync for datatype "
             << syncable::ModelTypeToString(datatype)
-            << " on Client " << id_ << ".";
+            << " on " << profile_debug_name_ << ".";
     return true;
   }
 
-  LogClientInfo("DisableSyncForDatatype failed", 0);
+  VLOG(0) << "DisableSyncForDatatype failed: " << GetClientInfo();
   return false;
 }
 
 bool ProfileSyncServiceHarness::EnableSyncForAllDatatypes() {
-  LogClientInfo("EnableSyncForAllDatatypes", 1);
+  VLOG(1) << "EnableSyncForAllDatatypes: " << GetClientInfo();
 
   if (wait_state_ == SYNC_DISABLED) {
     return SetupSync();
@@ -689,16 +694,16 @@ bool ProfileSyncServiceHarness::EnableSyncForAllDatatypes() {
   service()->OnUserChoseDatatypes(true, synced_datatypes);
   if (AwaitSyncCycleCompletion("Datatype reconfiguration.")) {
     VLOG(1) << "EnableSyncForAllDatatypes(): Enabled sync for all datatypes on "
-               "Client " << id_ << ".";
+            << profile_debug_name_ << ".";
     return true;
   }
 
-  LogClientInfo("EnableSyncForAllDatatypes failed", 0);
+  VLOG(0) << "EnableSyncForAllDatatypes failed: " << GetClientInfo();
   return false;
 }
 
 bool ProfileSyncServiceHarness::DisableSyncForAllDatatypes() {
-  LogClientInfo("DisableSyncForAllDatatypes", 1);
+  VLOG(1) << "DisableSyncForAllDatatypes: " << GetClientInfo();
 
   if (service() == NULL) {
     LOG(ERROR) << "DisableSyncForAllDatatypes(): service() is null.";
@@ -708,7 +713,7 @@ bool ProfileSyncServiceHarness::DisableSyncForAllDatatypes() {
   service()->DisableForUser();
   wait_state_ = SYNC_DISABLED;
   VLOG(1) << "DisableSyncForAllDatatypes(): Disabled sync for all datatypes on "
-             "Client " << id_;
+          << profile_debug_name_;
   return true;
 }
 
@@ -719,39 +724,36 @@ std::string ProfileSyncServiceHarness::GetUpdatedTimestamp(
   return snap->download_progress_markers[model_type];
 }
 
-void ProfileSyncServiceHarness::LogClientInfo(const std::string& message,
-                                              int log_level) {
+std::string ProfileSyncServiceHarness::GetClientInfo() {
+  std::stringstream os;
+  os << profile_debug_name_ << ": ";
   if (service()) {
     const SyncSessionSnapshot* snap = GetLastSessionSnapshot();
+    const ProfileSyncService::Status& status = GetStatus();
     if (snap) {
-      VLOG(log_level) << "Client " << id_ << ": " << message
-                      << ": num_updates_downloaded : "
-                      << snap->syncer_status.num_updates_downloaded_total
-                      << ", has_more_to_sync: " << snap->has_more_to_sync
-                      << ", unsynced_count: " << snap->unsynced_count
-                      << ", num_blocking_conflicting_updates: "
-                      << snap->num_blocking_conflicting_updates
-                      << ", num_conflicting_updates: "
-                      << snap->num_conflicting_updates
-                      << ", has_unsynced_items: "
-                      << service()->HasUnsyncedItems()
-                      << ", passphrase_required_reason: "
-                      << sync_api::PassphraseRequiredReasonToString(
-                            service()->passphrase_required_reason())
-                      << ", notifications_enabled: "
-                      << GetStatus().notifications_enabled
-                      << ", service_is_pushing_changes: "
-                      << ServiceIsPushingChanges()
-                      << ", has_pending_backend_migration: "
-                      << service()->HasPendingBackendMigration();
+      os << "snapshot: " << snap->ToString()
+         << ", has_unsynced_items: "
+         << service()->HasUnsyncedItems()
+         << ", passphrase_required_reason: "
+         << sync_api::PassphraseRequiredReasonToString(
+             service()->passphrase_required_reason())
+         << ", notifications_enabled: "
+         << status.notifications_enabled
+         << ", local_overwrites_total: "
+         << status.num_local_overwrites_total
+         << ", server_overwrites_total: "
+         << status.num_server_overwrites_total
+         << ", service_is_pushing_changes: "
+         << ServiceIsPushingChanges()
+         << ", has_pending_backend_migration: "
+         << service()->HasPendingBackendMigration();
     } else {
-      VLOG(log_level) << "Client " << id_ << ": " << message
-                      << ": Sync session snapshot not available.";
+      os << "Sync session snapshot not available";
     }
   } else {
-    VLOG(log_level) << "Client " << id_ << ": " << message
-                    << ": Sync service not available.";
+    os << "Sync service not available";
   }
+  return os.str();
 }
 
 bool ProfileSyncServiceHarness::EnableEncryptionForType(