profile_sync_service_harness.cc revision 72a454cd3513ac24fbdd0e0cb9ad70b86a99b801 
1// Copyright (c) 2010 The Chromium Authors. All rights reserved.
2// Use of this source code is governed by a BSD-style license that can be
3// found in the LICENSE file.
4
5#include "chrome/browser/sync/profile_sync_service_harness.h"
6
7#include <algorithm>
8#include <vector>
9
10#include "base/message_loop.h"
11#include "chrome/browser/profiles/profile.h"
12#include "chrome/browser/net/gaia/token_service.h"
13#include "chrome/browser/sync/glue/sync_backend_host.h"
14#include "chrome/browser/sync/sessions/session_state.h"
15#include "chrome/common/net/gaia/gaia_constants.h"
16#include "chrome/common/net/gaia/google_service_auth_error.h"
17#include "chrome/common/notification_source.h"
18
19// The amount of time for which we wait for a live sync operation to complete.
20static const int kLiveSyncOperationTimeoutMs = 45000;
21
22// Simple class to implement a timeout using PostDelayedTask.  If it is not
23// aborted before picked up by a message queue, then it asserts with the message
24// provided.  This class is not thread safe.
25class StateChangeTimeoutEvent
26    : public base::RefCountedThreadSafe<StateChangeTimeoutEvent> {
27 public:
28  StateChangeTimeoutEvent(ProfileSyncServiceHarness* caller,
29                          const std::string& message);
30
31  // The entry point to the class from PostDelayedTask.
32  void Callback();
33
34  // Cancels the actions of the callback.  Returns true if success, false
35  // if the callback has already timed out.
36  bool Abort();
37
38 private:
39  friend class base::RefCountedThreadSafe<StateChangeTimeoutEvent>;
40
41  ~StateChangeTimeoutEvent();
42
43  bool aborted_;
44  bool did_timeout_;
45
46  // Due to synchronization of the IO loop, the caller will always be alive
47  // if the class is not aborted.
48  ProfileSyncServiceHarness* caller_;
49
50  // Informative message to assert in the case of a timeout.
51  std::string message_;
52
53  DISALLOW_COPY_AND_ASSIGN(StateChangeTimeoutEvent);
54};
55
56StateChangeTimeoutEvent::StateChangeTimeoutEvent(
57    ProfileSyncServiceHarness* caller,
58    const std::string& message)
59    : aborted_(false), did_timeout_(false), caller_(caller), message_(message) {
60}
61
62StateChangeTimeoutEvent::~StateChangeTimeoutEvent() {
63}
64
65void StateChangeTimeoutEvent::Callback() {
66  if (!aborted_) {
67    if (!caller_->RunStateChangeMachine()) {
68      // Report the message.
69      did_timeout_ = true;
70      DCHECK(!aborted_) << message_;
71      caller_->SignalStateComplete();
72    }
73  }
74}
75
76bool StateChangeTimeoutEvent::Abort() {
77  aborted_ = true;
78  caller_ = NULL;
79  return !did_timeout_;
80}
81
82ProfileSyncServiceHarness::ProfileSyncServiceHarness(
83    Profile* profile,
84    const std::string& username,
85    const std::string& password,
86    int id)
87    : wait_state_(INITIAL_WAIT_STATE),
88      profile_(profile),
89      service_(NULL),
90      timestamp_match_partner_(NULL),
91      username_(username),
92      password_(password),
93      id_(id) {
94  if (IsSyncAlreadySetup()) {
95    service_ = profile_->GetProfileSyncService();
96    service_->AddObserver(this);
97    wait_state_ = FULLY_SYNCED;
98  }
99}
100
101// static
102ProfileSyncServiceHarness* ProfileSyncServiceHarness::CreateAndAttach(
103    Profile* profile) {
104  if (!profile->HasProfileSyncService()) {
105    NOTREACHED() << "Profile has never signed into sync.";
106    return NULL;
107  }
108  return new ProfileSyncServiceHarness(profile, "", "", 0);
109}
110
111void ProfileSyncServiceHarness::SetCredentials(const std::string& username,
112                                               const std::string& password) {
113  username_ = username;
114  password_ = password;
115}
116
117bool ProfileSyncServiceHarness::IsSyncAlreadySetup() {
118  return profile_->HasProfileSyncService();
119}
120
121bool ProfileSyncServiceHarness::SetupSync() {
122  syncable::ModelTypeSet synced_datatypes;
123  for (int i = syncable::FIRST_REAL_MODEL_TYPE;
124      i < syncable::MODEL_TYPE_COUNT; ++i) {
125    synced_datatypes.insert(syncable::ModelTypeFromInt(i));
126  }
127  return SetupSync(synced_datatypes);
128}
129
130bool ProfileSyncServiceHarness::SetupSync(
131    const syncable::ModelTypeSet& synced_datatypes) {
132  // Initialize the sync client's profile sync service object.
133  service_ = profile_->GetProfileSyncService("");
134  if (service_ == NULL) {
135    LOG(ERROR) << "SetupSync(): service_ is null.";
136    return false;
137  }
138
139  // Subscribe sync client to notifications from the profile sync service.
140  if (!service_->HasObserver(this))
141    service_->AddObserver(this);
142
143  // Authenticate sync client using GAIA credentials.
144  service_->signin()->StartSignIn(username_, password_, "", "");
145
146  // Wait for the OnBackendInitialized() callback.
147  wait_state_ = WAITING_FOR_ON_BACKEND_INITIALIZED;
148  if (!AwaitStatusChangeWithTimeout(kLiveSyncOperationTimeoutMs,
149      "Waiting for OnBackendInitialized().")) {
150    LOG(ERROR) << "OnBackendInitialized() not seen after "
151               << kLiveSyncOperationTimeoutMs / 1000
152               << " seconds.";
153    return false;
154  }
155
156  // Choose the datatypes to be synced. If all datatypes are to be synced,
157  // set sync_everything to true; otherwise, set it to false.
158  bool sync_everything = (synced_datatypes.size() ==
159      (syncable::MODEL_TYPE_COUNT - syncable::FIRST_REAL_MODEL_TYPE));
160  service()->OnUserChoseDatatypes(sync_everything, synced_datatypes);
161
162  // Wait for a passphrase to be required.
163  DCHECK_EQ(wait_state_, WAITING_FOR_PASSPHRASE_REQUIRED);
164  if (!AwaitStatusChangeWithTimeout(kLiveSyncOperationTimeoutMs,
165      "Waiting for Passphrase required.")) {
166    LOG(ERROR) << "Passphrase required not seen after "
167               << kLiveSyncOperationTimeoutMs / 1000
168               << " seconds.";
169    return false;
170  }
171
172  // Wait for initial gaia passphrase to be accepted.
173  DCHECK_EQ(wait_state_, WAITING_FOR_PASSPHRASE_ACCEPTED);
174  if (!AwaitStatusChangeWithTimeout(kLiveSyncOperationTimeoutMs,
175      "Waiting for Passphrase accept.")) {
176    LOG(ERROR) << "Passphrase accept not seen after "
177               << kLiveSyncOperationTimeoutMs / 1000
178               << " seconds.";
179    return false;
180  }
181
182  DCHECK_EQ(wait_state_, WAITING_FOR_INITIAL_SYNC);
183  // Wait for initial sync cycle to be completed.
184  if (!AwaitStatusChangeWithTimeout(kLiveSyncOperationTimeoutMs,
185      "Waiting for initial sync cycle to complete.")) {
186    LOG(ERROR) << "Initial sync cycle did not complete after "
187               << kLiveSyncOperationTimeoutMs / 1000
188               << " seconds.";
189    return false;
190  }
191
192  // Indicate to the browser that sync setup is complete.
193  service()->SetSyncSetupCompleted();
194
195  return true;
196}
197
198void ProfileSyncServiceHarness::SignalStateCompleteWithNextState(
199    WaitState next_state) {
200  wait_state_ = next_state;
201  SignalStateComplete();
202}
203
204void ProfileSyncServiceHarness::SignalStateComplete() {
205  MessageLoop::current()->Quit();
206}
207
208bool ProfileSyncServiceHarness::RunStateChangeMachine() {
209  WaitState original_wait_state = wait_state_;
210  switch (wait_state_) {
211    case WAITING_FOR_ON_BACKEND_INITIALIZED: {
212      LogClientInfo("WAITING_FOR_ON_BACKEND_INITIALIZED");
213      if (service()->sync_initialized()) {
214        // The sync backend is initialized. We now wait for passphrase events.
215        SignalStateCompleteWithNextState(WAITING_FOR_PASSPHRASE_REQUIRED);
216      }
217      break;
218    }
219    case WAITING_FOR_PASSPHRASE_REQUIRED: {
220      LogClientInfo("WAITING_FOR_PASSPHRASE_REQUIRED");
221      if (service()->observed_passphrase_required()) {
222        // Special case when the first client signs in to sync.
223        if (id_ == 0)
224          DCHECK(!service()->passphrase_required_for_decryption());
225        // The SYNC_PASSPHRASE_REQUIRED notification has been seen.
226        SignalStateCompleteWithNextState(WAITING_FOR_PASSPHRASE_ACCEPTED);
227      }
228      break;
229    }
230    case WAITING_FOR_PASSPHRASE_ACCEPTED: {
231      LogClientInfo("WAITING_FOR_PASSPHRASE_ACCEPTED");
232      if (service()->ShouldPushChanges())
233        // The SYNC_PASSPHRASE_ACCEPTED notification has been seen.
234        SignalStateCompleteWithNextState(WAITING_FOR_INITIAL_SYNC);
235      break;
236    }
237    case WAITING_FOR_INITIAL_SYNC: {
238      LogClientInfo("WAITING_FOR_INITIAL_SYNC");
239      if (IsSynced()) {
240        // The first sync cycle is now complete. We can start running tests.
241        SignalStateCompleteWithNextState(FULLY_SYNCED);
242      }
243      break;
244    }
245    case WAITING_FOR_SYNC_TO_FINISH: {
246      LogClientInfo("WAITING_FOR_SYNC_TO_FINISH");
247      if (!IsSynced()) {
248        // The client is not yet fully synced. Continue waiting.
249        if (!GetStatus().server_reachable) {
250          // The client cannot reach the sync server because the network is
251          // disabled. There is no need to wait anymore.
252          SignalStateCompleteWithNextState(SERVER_UNREACHABLE);
253        }
254        break;
255      }
256      SignalStateCompleteWithNextState(FULLY_SYNCED);
257      break;
258    }
259    case WAITING_FOR_UPDATES: {
260      LogClientInfo("WAITING_FOR_UPDATES");
261      DCHECK(timestamp_match_partner_);
262      if (!MatchesOtherClient(timestamp_match_partner_)) {
263        // The client is not yet fully synced; keep waiting until we converge.
264        break;
265      }
266      timestamp_match_partner_->service()->RemoveObserver(this);
267      timestamp_match_partner_ = NULL;
268
269      SignalStateCompleteWithNextState(FULLY_SYNCED);
270      break;
271    }
272    case SERVER_UNREACHABLE: {
273      LogClientInfo("SERVER_UNREACHABLE");
274      if (GetStatus().server_reachable) {
275        // The client was offline due to the network being disabled, but is now
276        // back online. Wait for the pending sync cycle to complete.
277        SignalStateCompleteWithNextState(WAITING_FOR_SYNC_TO_FINISH);
278      }
279      break;
280    }
281    case FULLY_SYNCED: {
282      // The client is online and fully synced. There is nothing to do.
283      LogClientInfo("FULLY_SYNCED");
284      break;
285    }
286    case SYNC_DISABLED: {
287      // Syncing is disabled for the client. There is nothing to do.
288      LogClientInfo("SYNC_DISABLED");
289      break;
290    }
291    default:
292      // Invalid state during observer callback which may be triggered by other
293      // classes using the the UI message loop.  Defer to their handling.
294      break;
295  }
296  return original_wait_state != wait_state_;
297}
298
299void ProfileSyncServiceHarness::OnStateChanged() {
300  RunStateChangeMachine();
301}
302
303bool ProfileSyncServiceHarness::AwaitPassphraseAccepted() {
304  LogClientInfo("AwaitPassphraseAccepted");
305  if (wait_state_ == SYNC_DISABLED) {
306    LOG(ERROR) << "Sync disabled for Client " << id_ << ".";
307    return false;
308  }
309  wait_state_ = WAITING_FOR_PASSPHRASE_ACCEPTED;
310  return AwaitStatusChangeWithTimeout(kLiveSyncOperationTimeoutMs,
311                                      "Waiting for passphrase accepted.");
312}
313
314bool ProfileSyncServiceHarness::AwaitSyncCycleCompletion(
315    const std::string& reason) {
316  LogClientInfo("AwaitSyncCycleCompletion");
317  if (wait_state_ == SYNC_DISABLED) {
318    LOG(ERROR) << "Sync disabled for Client " << id_ << ".";
319    return false;
320  }
321  if (!IsSynced()) {
322    if (wait_state_ == SERVER_UNREACHABLE) {
323      // Client was offline; wait for it to go online, and then wait for sync.
324      AwaitStatusChangeWithTimeout(kLiveSyncOperationTimeoutMs, reason);
325      DCHECK_EQ(wait_state_, WAITING_FOR_SYNC_TO_FINISH);
326      return AwaitStatusChangeWithTimeout(kLiveSyncOperationTimeoutMs, reason);
327    } else {
328      DCHECK(service()->sync_initialized());
329      wait_state_ = WAITING_FOR_SYNC_TO_FINISH;
330      AwaitStatusChangeWithTimeout(kLiveSyncOperationTimeoutMs, reason);
331      if (wait_state_ == FULLY_SYNCED) {
332        // Client is online; sync was successful.
333        return true;
334      } else if (wait_state_ == SERVER_UNREACHABLE) {
335        // Client is offline; sync was unsuccessful.
336        return false;
337      } else {
338        LOG(ERROR) << "Invalid wait state:" << wait_state_;
339        return false;
340      }
341    }
342  } else {
343    // Client is already synced; don't wait.
344    return true;
345  }
346}
347
348bool ProfileSyncServiceHarness::AwaitMutualSyncCycleCompletion(
349    ProfileSyncServiceHarness* partner) {
350  LogClientInfo("AwaitMutualSyncCycleCompletion");
351  if (!AwaitSyncCycleCompletion("Sync cycle completion on active client."))
352    return false;
353  return partner->WaitUntilTimestampMatches(this,
354      "Sync cycle completion on passive client.");
355}
356
357bool ProfileSyncServiceHarness::AwaitGroupSyncCycleCompletion(
358    std::vector<ProfileSyncServiceHarness*>& partners) {
359  LogClientInfo("AwaitGroupSyncCycleCompletion");
360  if (!AwaitSyncCycleCompletion("Sync cycle completion on active client."))
361    return false;
362  bool return_value = true;
363  for (std::vector<ProfileSyncServiceHarness*>::iterator it =
364      partners.begin(); it != partners.end(); ++it) {
365    if ((this != *it) && ((*it)->wait_state_ != SYNC_DISABLED)) {
366      return_value = return_value &&
367          (*it)->WaitUntilTimestampMatches(this,
368          "Sync cycle completion on partner client.");
369    }
370  }
371  return return_value;
372}
373
374// static
375bool ProfileSyncServiceHarness::AwaitQuiescence(
376    std::vector<ProfileSyncServiceHarness*>& clients) {
377  VLOG(1) << "AwaitQuiescence.";
378  bool return_value = true;
379  for (std::vector<ProfileSyncServiceHarness*>::iterator it =
380      clients.begin(); it != clients.end(); ++it) {
381    if ((*it)->wait_state_ != SYNC_DISABLED)
382      return_value = return_value &&
383          (*it)->AwaitGroupSyncCycleCompletion(clients);
384  }
385  return return_value;
386}
387
388bool ProfileSyncServiceHarness::WaitUntilTimestampMatches(
389    ProfileSyncServiceHarness* partner, const std::string& reason) {
390  LogClientInfo("WaitUntilTimestampMatches");
391  if (wait_state_ == SYNC_DISABLED) {
392    LOG(ERROR) << "Sync disabled for Client " << id_ << ".";
393    return false;
394  }
395  DCHECK(!timestamp_match_partner_);
396  if (MatchesOtherClient(partner))
397    return true;
398
399  timestamp_match_partner_ = partner;
400  partner->service()->AddObserver(this);
401  wait_state_ = WAITING_FOR_UPDATES;
402  return AwaitStatusChangeWithTimeout(kLiveSyncOperationTimeoutMs, reason);
403}
404
405bool ProfileSyncServiceHarness::AwaitStatusChangeWithTimeout(
406    int timeout_milliseconds,
407    const std::string& reason) {
408  LogClientInfo("AwaitStatusChangeWithTimeout");
409  if (wait_state_ == SYNC_DISABLED) {
410    LOG(ERROR) << "Sync disabled for Client " << id_ << ".";
411    return false;
412  }
413  scoped_refptr<StateChangeTimeoutEvent> timeout_signal(
414      new StateChangeTimeoutEvent(this, reason));
415  MessageLoop* loop = MessageLoop::current();
416  bool did_allow_nestable_tasks = loop->NestableTasksAllowed();
417  loop->SetNestableTasksAllowed(true);
418  loop->PostDelayedTask(
419      FROM_HERE,
420      NewRunnableMethod(timeout_signal.get(),
421                        &StateChangeTimeoutEvent::Callback),
422      timeout_milliseconds);
423  loop->Run();
424  loop->SetNestableTasksAllowed(did_allow_nestable_tasks);
425  if (timeout_signal->Abort()) {
426    LogClientInfo("AwaitStatusChangeWithTimeout succeeded");
427    return true;
428  } else {
429    LogClientInfo("AwaitStatusChangeWithTimeout timed out");
430    return false;
431  }
432}
433
434ProfileSyncService::Status ProfileSyncServiceHarness::GetStatus() {
435  DCHECK(service() != NULL) << "GetStatus(): service() is NULL.";
436  return service()->QueryDetailedSyncStatus();
437}
438
439bool ProfileSyncServiceHarness::IsSynced() {
440  LogClientInfo("IsSynced");
441  if (service() == NULL)
442    return false;
443  const SyncSessionSnapshot* snap = GetLastSessionSnapshot();
444  // TODO(rsimha): Remove additional checks of snap->has_more_to_sync and
445  // snap->unsynced_count once http://crbug.com/48989 is fixed.
446  return (snap &&
447          snap->num_conflicting_updates == 0 &&  // We can decrypt everything.
448          ServiceIsPushingChanges() &&
449          GetStatus().notifications_enabled &&
450          !service()->HasUnsyncedItems() &&
451          !snap->has_more_to_sync &&
452          snap->unsynced_count == 0);
453}
454
455bool ProfileSyncServiceHarness::MatchesOtherClient(
456    ProfileSyncServiceHarness* partner) {
457  if (!IsSynced())
458    return false;
459
460  // Only look for a match if we have at least one enabled datatype in
461  // common with the partner client.
462  syncable::ModelTypeSet types, other_types, intersection_types;
463  service()->GetPreferredDataTypes(&types);
464  partner->service()->GetPreferredDataTypes(&other_types);
465  std::set_intersection(types.begin(), types.end(), other_types.begin(),
466                        other_types.end(),
467                        inserter(intersection_types,
468                                 intersection_types.begin()));
469  for (syncable::ModelTypeSet::iterator i = intersection_types.begin();
470       i != intersection_types.end();
471       ++i) {
472    if (!partner->IsSynced() ||
473        partner->GetUpdatedTimestamp(*i) != GetUpdatedTimestamp(*i)) {
474      return false;
475    }
476  }
477  return true;
478}
479
480const SyncSessionSnapshot*
481    ProfileSyncServiceHarness::GetLastSessionSnapshot() const {
482  DCHECK(service_ != NULL) << "Sync service has not yet been set up.";
483  if (service_->sync_initialized()) {
484    return service_->GetLastSessionSnapshot();
485  }
486  return NULL;
487}
488
489void ProfileSyncServiceHarness::EnableSyncForDatatype(
490    syncable::ModelType datatype) {
491  LogClientInfo("EnableSyncForDatatype");
492  syncable::ModelTypeSet synced_datatypes;
493  if (wait_state_ == SYNC_DISABLED) {
494    wait_state_ = WAITING_FOR_ON_BACKEND_INITIALIZED;
495    synced_datatypes.insert(datatype);
496    DCHECK(SetupSync(synced_datatypes)) << "Reinitialization of Client " << id_
497                                        << " failed.";
498  } else {
499    DCHECK(service() != NULL) << "EnableSyncForDatatype(): service() is null.";
500    service()->GetPreferredDataTypes(&synced_datatypes);
501    syncable::ModelTypeSet::iterator it = synced_datatypes.find(
502        syncable::ModelTypeFromInt(datatype));
503    if (it == synced_datatypes.end()) {
504      synced_datatypes.insert(syncable::ModelTypeFromInt(datatype));
505      service()->OnUserChoseDatatypes(false, synced_datatypes);
506      wait_state_ = WAITING_FOR_SYNC_TO_FINISH;
507      AwaitSyncCycleCompletion("Waiting for datatype configuration.");
508      VLOG(1) << "EnableSyncForDatatype(): Enabled sync for datatype "
509              << syncable::ModelTypeToString(datatype) << " on Client " << id_;
510    } else {
511      VLOG(1) << "EnableSyncForDatatype(): Sync already enabled for datatype "
512              << syncable::ModelTypeToString(datatype) << " on Client " << id_;
513    }
514  }
515}
516
517void ProfileSyncServiceHarness::DisableSyncForDatatype(
518    syncable::ModelType datatype) {
519  LogClientInfo("DisableSyncForDatatype");
520  syncable::ModelTypeSet synced_datatypes;
521  DCHECK(service() != NULL) << "DisableSyncForDatatype(): service() is null.";
522  service()->GetPreferredDataTypes(&synced_datatypes);
523  syncable::ModelTypeSet::iterator it = synced_datatypes.find(datatype);
524  if (it != synced_datatypes.end()) {
525    synced_datatypes.erase(it);
526    service()->OnUserChoseDatatypes(false, synced_datatypes);
527    AwaitSyncCycleCompletion("Waiting for datatype configuration.");
528    VLOG(1) << "DisableSyncForDatatype(): Disabled sync for datatype "
529            << syncable::ModelTypeToString(datatype) << " on Client " << id_;
530  } else {
531    VLOG(1) << "DisableSyncForDatatype(): Sync already disabled for datatype "
532            << syncable::ModelTypeToString(datatype) << " on Client " << id_;
533  }
534}
535
536void ProfileSyncServiceHarness::EnableSyncForAllDatatypes() {
537  LogClientInfo("EnableSyncForAllDatatypes");
538  if (wait_state_ == SYNC_DISABLED) {
539    wait_state_ = WAITING_FOR_ON_BACKEND_INITIALIZED;
540    DCHECK(SetupSync()) << "Reinitialization of Client " << id_ << " failed.";
541  } else {
542    syncable::ModelTypeSet synced_datatypes;
543    for (int i = syncable::FIRST_REAL_MODEL_TYPE;
544        i < syncable::MODEL_TYPE_COUNT; ++i) {
545      synced_datatypes.insert(syncable::ModelTypeFromInt(i));
546    }
547    DCHECK(service() != NULL) << "EnableSyncForAllDatatypes(): service() is "
548                                 " null.";
549    service()->OnUserChoseDatatypes(true, synced_datatypes);
550    wait_state_ = WAITING_FOR_SYNC_TO_FINISH;
551    AwaitSyncCycleCompletion("Waiting for datatype configuration.");
552    VLOG(1) << "EnableSyncForAllDatatypes(): Enabled sync for all datatypes on "
553               "Client " << id_;
554  }
555}
556
557void ProfileSyncServiceHarness::DisableSyncForAllDatatypes() {
558  LogClientInfo("DisableSyncForAllDatatypes");
559  DCHECK(service() != NULL) << "EnableSyncForAllDatatypes(): service() is "
560                               "null.";
561  service()->DisableForUser();
562  wait_state_ = SYNC_DISABLED;
563  VLOG(1) << "DisableSyncForAllDatatypes(): Disabled sync for all datatypes on "
564             "Client " << id_;
565}
566
567std::string ProfileSyncServiceHarness::GetUpdatedTimestamp(
568    syncable::ModelType model_type) {
569  const SyncSessionSnapshot* snap = GetLastSessionSnapshot();
570  DCHECK(snap != NULL) << "GetUpdatedTimestamp(): Sync snapshot is NULL.";
571  return snap->download_progress_markers[model_type];
572}
573
574void ProfileSyncServiceHarness::LogClientInfo(std::string message) {
575  if (service()) {
576    const SyncSessionSnapshot* snap = GetLastSessionSnapshot();
577    if (snap) {
578      VLOG(1) << "Client " << id_ << ": " << message
579              << ": num_updates_downloaded : "
580              << snap->syncer_status.num_updates_downloaded_total
581              << ", has_more_to_sync: " << snap->has_more_to_sync
582              << ", unsynced_count: " << snap->unsynced_count
583              << ", num_conflicting_updates: " << snap->num_conflicting_updates
584              << ", has_unsynced_items: "
585              << service()->HasUnsyncedItems()
586              << ", observed_passphrase_required: "
587              << service()->observed_passphrase_required()
588              << ", notifications_enabled: "
589              << GetStatus().notifications_enabled
590              << ", service_is_pushing_changes: " << ServiceIsPushingChanges();
591    } else {
592      VLOG(1) << "Client " << id_ << ": " << message
593              << ": Sync session snapshot not available.";
594    }
595  } else {
596    VLOG(1) << "Client " << id_ << ": " << message
597            << ": Sync service not available.";
598  }
599}
600