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