Fix build break
[chromium-blink-merge.git] / chrome / browser / sync / profile_sync_service_harness.cc
blobeb0b074d9cdf8b373bbd3b1bc90c56a7717765b7
1 // Copyright (c) 2012 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.
5 #include "chrome/browser/sync/profile_sync_service_harness.h"
7 #include <cstddef>
8 #include <iterator>
9 #include <ostream>
10 #include <set>
11 #include <sstream>
12 #include <vector>
14 #include "base/base64.h"
15 #include "base/bind.h"
16 #include "base/command_line.h"
17 #include "base/compiler_specific.h"
18 #include "base/json/json_writer.h"
19 #include "base/location.h"
20 #include "base/logging.h"
21 #include "base/memory/ref_counted.h"
22 #include "base/message_loop.h"
23 #include "chrome/browser/profiles/profile.h"
24 #include "chrome/browser/signin/signin_manager.h"
25 #include "chrome/browser/sync/about_sync_util.h"
26 #include "chrome/browser/sync/glue/data_type_controller.h"
27 #include "chrome/browser/sync/profile_sync_service_factory.h"
28 #include "chrome/common/chrome_switches.h"
29 #include "sync/internal_api/public/base/progress_marker_map.h"
30 #include "sync/internal_api/public/sessions/sync_session_snapshot.h"
31 #include "sync/internal_api/public/util/sync_string_conversions.h"
33 using syncer::sessions::SyncSessionSnapshot;
35 // TODO(rsimha): Remove the following lines once crbug.com/91863 is fixed.
36 // The amount of time for which we wait for a live sync operation to complete.
37 static const int kLiveSyncOperationTimeoutMs = 45000;
39 // The amount of time we wait for test cases that verify exponential backoff.
40 static const int kExponentialBackoffVerificationTimeoutMs = 60000;
42 // Simple class to implement a timeout using PostDelayedTask. If it is not
43 // aborted before picked up by a message queue, then it asserts with the message
44 // provided. This class is not thread safe.
45 class StateChangeTimeoutEvent
46 : public base::RefCountedThreadSafe<StateChangeTimeoutEvent> {
47 public:
48 StateChangeTimeoutEvent(ProfileSyncServiceHarness* caller,
49 const std::string& message);
51 // The entry point to the class from PostDelayedTask.
52 void Callback();
54 // Cancels the actions of the callback. Returns true if success, false
55 // if the callback has already timed out.
56 bool Abort();
58 private:
59 friend class base::RefCountedThreadSafe<StateChangeTimeoutEvent>;
61 ~StateChangeTimeoutEvent();
63 bool aborted_;
64 bool did_timeout_;
66 // Due to synchronization of the IO loop, the caller will always be alive
67 // if the class is not aborted.
68 ProfileSyncServiceHarness* caller_;
70 // Informative message to assert in the case of a timeout.
71 std::string message_;
73 DISALLOW_COPY_AND_ASSIGN(StateChangeTimeoutEvent);
76 StateChangeTimeoutEvent::StateChangeTimeoutEvent(
77 ProfileSyncServiceHarness* caller,
78 const std::string& message)
79 : aborted_(false), did_timeout_(false), caller_(caller), message_(message) {
82 StateChangeTimeoutEvent::~StateChangeTimeoutEvent() {
85 void StateChangeTimeoutEvent::Callback() {
86 if (!aborted_) {
87 if (!caller_->RunStateChangeMachine()) {
88 // Report the message.
89 did_timeout_ = true;
90 DCHECK(!aborted_) << message_;
91 caller_->SignalStateComplete();
96 bool StateChangeTimeoutEvent::Abort() {
97 aborted_ = true;
98 caller_ = NULL;
99 return !did_timeout_;
102 ProfileSyncServiceHarness::ProfileSyncServiceHarness(
103 Profile* profile,
104 const std::string& username,
105 const std::string& password)
106 : waiting_for_encryption_type_(syncer::UNSPECIFIED),
107 wait_state_(INITIAL_WAIT_STATE),
108 profile_(profile),
109 service_(NULL),
110 progress_marker_partner_(NULL),
111 username_(username),
112 password_(password),
113 profile_debug_name_(profile->GetDebugName()),
114 waiting_for_status_change_(false) {
115 if (IsSyncAlreadySetup()) {
116 service_ = ProfileSyncServiceFactory::GetInstance()->GetForProfile(
117 profile_);
118 service_->AddObserver(this);
119 ignore_result(TryListeningToMigrationEvents());
120 wait_state_ = FULLY_SYNCED;
124 ProfileSyncServiceHarness::~ProfileSyncServiceHarness() {
125 if (service_->HasObserver(this))
126 service_->RemoveObserver(this);
129 // static
130 ProfileSyncServiceHarness* ProfileSyncServiceHarness::CreateAndAttach(
131 Profile* profile) {
132 ProfileSyncServiceFactory* f = ProfileSyncServiceFactory::GetInstance();
133 if (!f->HasProfileSyncService(profile)) {
134 NOTREACHED() << "Profile has never signed into sync.";
135 return NULL;
137 return new ProfileSyncServiceHarness(profile, std::string(), std::string());
140 void ProfileSyncServiceHarness::SetCredentials(const std::string& username,
141 const std::string& password) {
142 username_ = username;
143 password_ = password;
146 bool ProfileSyncServiceHarness::IsSyncAlreadySetup() {
147 return ProfileSyncServiceFactory::GetInstance()->HasProfileSyncService(
148 profile_);
151 bool ProfileSyncServiceHarness::SetupSync() {
152 bool result = SetupSync(syncer::ModelTypeSet::All());
153 if (result == false) {
154 std::string status = GetServiceStatus();
155 LOG(ERROR) << profile_debug_name_
156 << ": SetupSync failed. Syncer status:\n" << status;
157 } else {
158 DVLOG(1) << profile_debug_name_ << ": SetupSync successful.";
160 return result;
163 bool ProfileSyncServiceHarness::SetupSync(
164 syncer::ModelTypeSet synced_datatypes) {
165 // Initialize the sync client's profile sync service object.
166 service_ =
167 ProfileSyncServiceFactory::GetInstance()->GetForProfile(profile_);
168 if (service_ == NULL) {
169 LOG(ERROR) << "SetupSync(): service_ is null.";
170 return false;
173 // Subscribe sync client to notifications from the profile sync service.
174 if (!service_->HasObserver(this))
175 service_->AddObserver(this);
177 // Tell the sync service that setup is in progress so we don't start syncing
178 // until we've finished configuration.
179 service_->SetSetupInProgress(true);
181 // Authenticate sync client using GAIA credentials.
182 service_->signin()
183 ->StartSignIn(username_, password_, std::string(), std::string());
185 // Wait for the OnBackendInitialized() callback.
186 if (!AwaitBackendInitialized()) {
187 LOG(ERROR) << "OnBackendInitialized() not seen after "
188 << kLiveSyncOperationTimeoutMs / 1000
189 << " seconds.";
190 return false;
193 // Make sure that initial sync wasn't blocked by a missing passphrase.
194 if (wait_state_ == SET_PASSPHRASE_FAILED) {
195 LOG(ERROR) << "A passphrase is required for decryption. Sync cannot proceed"
196 " until SetDecryptionPassphrase is called.";
197 return false;
200 // Make sure that initial sync wasn't blocked by rejected credentials.
201 if (wait_state_ == CREDENTIALS_REJECTED) {
202 LOG(ERROR) << "Credentials were rejected. Sync cannot proceed.";
203 return false;
206 // Choose the datatypes to be synced. If all datatypes are to be synced,
207 // set sync_everything to true; otherwise, set it to false.
208 bool sync_everything =
209 synced_datatypes.Equals(syncer::ModelTypeSet::All());
210 service()->OnUserChoseDatatypes(sync_everything, synced_datatypes);
212 // Notify ProfileSyncService that we are done with configuration.
213 service_->SetSetupInProgress(false);
215 // Subscribe sync client to notifications from the backend migrator
216 // (possible only after choosing data types).
217 if (!TryListeningToMigrationEvents()) {
218 NOTREACHED();
219 return false;
222 // Set an implicit passphrase for encryption if an explicit one hasn't already
223 // been set. If an explicit passphrase has been set, immediately return false,
224 // since a decryption passphrase is required.
225 if (!service_->IsUsingSecondaryPassphrase()) {
226 service_->SetEncryptionPassphrase(password_, ProfileSyncService::IMPLICIT);
227 } else {
228 LOG(ERROR) << "A passphrase is required for decryption. Sync cannot proceed"
229 " until SetDecryptionPassphrase is called.";
230 return false;
233 // Wait for initial sync cycle to be completed.
234 DCHECK_EQ(wait_state_, WAITING_FOR_INITIAL_SYNC);
235 if (!AwaitStatusChangeWithTimeout(kLiveSyncOperationTimeoutMs,
236 "Waiting for initial sync cycle to complete.")) {
237 LOG(ERROR) << "Initial sync cycle did not complete after "
238 << kLiveSyncOperationTimeoutMs / 1000
239 << " seconds.";
240 return false;
243 // Make sure that initial sync wasn't blocked by a missing passphrase.
244 if (wait_state_ == SET_PASSPHRASE_FAILED) {
245 LOG(ERROR) << "A passphrase is required for decryption. Sync cannot proceed"
246 " until SetDecryptionPassphrase is called.";
247 return false;
250 // Make sure that initial sync wasn't blocked by rejected credentials.
251 if (wait_state_ == CREDENTIALS_REJECTED) {
252 LOG(ERROR) << "Credentials were rejected. Sync cannot proceed.";
253 return false;
256 // Indicate to the browser that sync setup is complete.
257 service()->SetSyncSetupCompleted();
259 return true;
262 bool ProfileSyncServiceHarness::TryListeningToMigrationEvents() {
263 browser_sync::BackendMigrator* migrator =
264 service_->GetBackendMigratorForTest();
265 if (migrator && !migrator->HasMigrationObserver(this)) {
266 migrator->AddMigrationObserver(this);
267 return true;
269 return false;
272 void ProfileSyncServiceHarness::SignalStateCompleteWithNextState(
273 WaitState next_state) {
274 wait_state_ = next_state;
275 SignalStateComplete();
278 void ProfileSyncServiceHarness::SignalStateComplete() {
279 if (waiting_for_status_change_)
280 MessageLoop::current()->QuitWhenIdle();
283 bool ProfileSyncServiceHarness::RunStateChangeMachine() {
284 WaitState original_wait_state = wait_state_;
285 switch (wait_state_) {
286 case WAITING_FOR_ON_BACKEND_INITIALIZED: {
287 DVLOG(1) << GetClientInfoString("WAITING_FOR_ON_BACKEND_INITIALIZED");
288 if (service()->GetAuthError().state() ==
289 GoogleServiceAuthError::INVALID_GAIA_CREDENTIALS) {
290 // Our credentials were rejected. Do not wait any more.
291 SignalStateCompleteWithNextState(CREDENTIALS_REJECTED);
292 break;
294 if (service()->sync_initialized()) {
295 // The sync backend is initialized.
296 SignalStateCompleteWithNextState(WAITING_FOR_INITIAL_SYNC);
298 break;
300 case WAITING_FOR_INITIAL_SYNC: {
301 DVLOG(1) << GetClientInfoString("WAITING_FOR_INITIAL_SYNC");
302 if (IsFullySynced()) {
303 // The first sync cycle is now complete. We can start running tests.
304 SignalStateCompleteWithNextState(FULLY_SYNCED);
305 break;
307 if (service()->passphrase_required_reason() ==
308 syncer::REASON_DECRYPTION) {
309 // A passphrase is required for decryption and we don't have it. Do not
310 // wait any more.
311 SignalStateCompleteWithNextState(SET_PASSPHRASE_FAILED);
312 break;
314 if (service()->GetAuthError().state() ==
315 GoogleServiceAuthError::INVALID_GAIA_CREDENTIALS) {
316 // Our credentials were rejected. Do not wait any more.
317 SignalStateCompleteWithNextState(CREDENTIALS_REJECTED);
318 break;
320 break;
322 case WAITING_FOR_FULL_SYNC: {
323 DVLOG(1) << GetClientInfoString("WAITING_FOR_FULL_SYNC");
324 if (IsFullySynced()) {
325 // The sync cycle we were waiting for is complete.
326 SignalStateCompleteWithNextState(FULLY_SYNCED);
327 break;
329 break;
331 case WAITING_FOR_DATA_SYNC: {
332 if (IsDataSynced()) {
333 SignalStateCompleteWithNextState(FULLY_SYNCED);
334 break;
336 break;
338 case WAITING_FOR_UPDATES: {
339 DVLOG(1) << GetClientInfoString("WAITING_FOR_UPDATES");
340 DCHECK(progress_marker_partner_);
341 if (!MatchesOtherClient(progress_marker_partner_)) {
342 // The client is not yet fully synced; keep waiting until we converge.
343 break;
346 SignalStateCompleteWithNextState(FULLY_SYNCED);
347 break;
349 case WAITING_FOR_PASSPHRASE_REQUIRED: {
350 DVLOG(1) << GetClientInfoString("WAITING_FOR_PASSPHRASE_REQUIRED");
351 if (service()->IsPassphraseRequired()) {
352 // A passphrase is now required. Wait for it to be accepted.
353 SignalStateCompleteWithNextState(WAITING_FOR_PASSPHRASE_ACCEPTED);
355 break;
357 case WAITING_FOR_PASSPHRASE_ACCEPTED: {
358 DVLOG(1) << GetClientInfoString("WAITING_FOR_PASSPHRASE_ACCEPTED");
359 if (service()->ShouldPushChanges() &&
360 !service()->IsPassphraseRequired() &&
361 service()->IsUsingSecondaryPassphrase()) {
362 // The passphrase has been accepted, and sync has been restarted.
363 SignalStateCompleteWithNextState(FULLY_SYNCED);
365 break;
367 case WAITING_FOR_ENCRYPTION: {
368 DVLOG(1) << GetClientInfoString("WAITING_FOR_ENCRYPTION");
369 // The correctness of this if condition may depend on the ordering of its
370 // sub-expressions. See crbug.com/98607, crbug.com/95619.
371 // TODO(rlarocque): Figure out a less brittle way of detecting this.
372 if (IsTypeEncrypted(waiting_for_encryption_type_) &&
373 IsFullySynced() &&
374 GetLastSessionSnapshot().num_encryption_conflicts() == 0) {
375 // Encryption is now complete for the the type in which we were waiting.
376 SignalStateCompleteWithNextState(FULLY_SYNCED);
377 break;
379 break;
381 case WAITING_FOR_SYNC_CONFIGURATION: {
382 DVLOG(1) << GetClientInfoString("WAITING_FOR_SYNC_CONFIGURATION");
383 if (service()->ShouldPushChanges()) {
384 // The Datatype manager is configured and sync is fully initialized.
385 SignalStateCompleteWithNextState(FULLY_SYNCED);
387 break;
389 case WAITING_FOR_SYNC_DISABLED: {
390 DVLOG(1) << GetClientInfoString("WAITING_FOR_SYNC_DISABLED");
391 if (service()->HasSyncSetupCompleted() == false) {
392 // Sync has been disabled.
393 SignalStateCompleteWithNextState(SYNC_DISABLED);
395 break;
397 case WAITING_FOR_EXPONENTIAL_BACKOFF_VERIFICATION: {
398 DVLOG(1) << GetClientInfoString(
399 "WAITING_FOR_EXPONENTIAL_BACKOFF_VERIFICATION");
400 const SyncSessionSnapshot& snap = GetLastSessionSnapshot();
401 retry_verifier_.VerifyRetryInterval(snap);
402 if (retry_verifier_.done()) {
403 // Retry verifier is done verifying exponential backoff.
404 SignalStateCompleteWithNextState(WAITING_FOR_NOTHING);
406 break;
408 case WAITING_FOR_MIGRATION_TO_START: {
409 DVLOG(1) << GetClientInfoString("WAITING_FOR_MIGRATION_TO_START");
410 if (HasPendingBackendMigration()) {
411 // There are pending migrations. Wait for them.
412 SignalStateCompleteWithNextState(WAITING_FOR_MIGRATION_TO_FINISH);
414 break;
416 case WAITING_FOR_MIGRATION_TO_FINISH: {
417 DVLOG(1) << GetClientInfoString("WAITING_FOR_MIGRATION_TO_FINISH");
418 if (!HasPendingBackendMigration()) {
419 // Done migrating.
420 SignalStateCompleteWithNextState(WAITING_FOR_NOTHING);
422 break;
424 case WAITING_FOR_ACTIONABLE_ERROR: {
425 DVLOG(1) << GetClientInfoString("WAITING_FOR_ACTIONABLE_ERROR");
426 ProfileSyncService::Status status = GetStatus();
427 if (status.sync_protocol_error.action != syncer::UNKNOWN_ACTION &&
428 service_->HasUnrecoverableError() == true) {
429 // An actionable error has been detected.
430 SignalStateCompleteWithNextState(WAITING_FOR_NOTHING);
432 break;
434 case SET_PASSPHRASE_FAILED: {
435 // A passphrase is required for decryption. There is nothing the sync
436 // client can do until SetDecryptionPassphrase() is called.
437 DVLOG(1) << GetClientInfoString("SET_PASSPHRASE_FAILED");
438 break;
440 case FULLY_SYNCED: {
441 // The client is online and fully synced. There is nothing to do.
442 DVLOG(1) << GetClientInfoString("FULLY_SYNCED");
443 break;
445 case SYNC_DISABLED: {
446 // Syncing is disabled for the client. There is nothing to do.
447 DVLOG(1) << GetClientInfoString("SYNC_DISABLED");
448 break;
450 case WAITING_FOR_NOTHING: {
451 // We don't care about the state of the syncer for the rest of the test
452 // case.
453 DVLOG(1) << GetClientInfoString("WAITING_FOR_NOTHING");
454 break;
456 default:
457 // Invalid state during observer callback which may be triggered by other
458 // classes using the the UI message loop. Defer to their handling.
459 break;
461 return original_wait_state != wait_state_;
464 void ProfileSyncServiceHarness::OnStateChanged() {
465 RunStateChangeMachine();
468 void ProfileSyncServiceHarness::OnMigrationStateChange() {
469 // Update migration state.
470 if (HasPendingBackendMigration()) {
471 // Merge current pending migration types into
472 // |pending_migration_types_|.
473 pending_migration_types_.PutAll(
474 service()->GetBackendMigratorForTest()->
475 GetPendingMigrationTypesForTest());
476 DVLOG(1) << profile_debug_name_ << ": new pending migration types "
477 << syncer::ModelTypeSetToString(pending_migration_types_);
478 } else {
479 // Merge just-finished pending migration types into
480 // |migration_types_|.
481 migrated_types_.PutAll(pending_migration_types_);
482 pending_migration_types_.Clear();
483 DVLOG(1) << profile_debug_name_ << ": new migrated types "
484 << syncer::ModelTypeSetToString(migrated_types_);
486 RunStateChangeMachine();
489 bool ProfileSyncServiceHarness::AwaitPassphraseRequired() {
490 DVLOG(1) << GetClientInfoString("AwaitPassphraseRequired");
491 if (wait_state_ == SYNC_DISABLED) {
492 LOG(ERROR) << "Sync disabled for " << profile_debug_name_ << ".";
493 return false;
496 if (service()->IsPassphraseRequired()) {
497 // It's already true that a passphrase is required; don't wait.
498 return true;
501 wait_state_ = WAITING_FOR_PASSPHRASE_REQUIRED;
502 return AwaitStatusChangeWithTimeout(kLiveSyncOperationTimeoutMs,
503 "Waiting for passphrase to be required.");
506 bool ProfileSyncServiceHarness::AwaitPassphraseAccepted() {
507 DVLOG(1) << GetClientInfoString("AwaitPassphraseAccepted");
508 if (wait_state_ == SYNC_DISABLED) {
509 LOG(ERROR) << "Sync disabled for " << profile_debug_name_ << ".";
510 return false;
513 if (service()->ShouldPushChanges() &&
514 !service()->IsPassphraseRequired() &&
515 service()->IsUsingSecondaryPassphrase()) {
516 // Passphrase is already accepted; don't wait.
517 return true;
520 wait_state_ = WAITING_FOR_PASSPHRASE_ACCEPTED;
521 return AwaitStatusChangeWithTimeout(kLiveSyncOperationTimeoutMs,
522 "Waiting for passphrase to be accepted.");
525 bool ProfileSyncServiceHarness::AwaitBackendInitialized() {
526 DVLOG(1) << GetClientInfoString("AwaitBackendInitialized");
527 if (service()->sync_initialized()) {
528 // The sync backend host has already been initialized; don't wait.
529 return true;
532 wait_state_ = WAITING_FOR_ON_BACKEND_INITIALIZED;
533 return AwaitStatusChangeWithTimeout(kLiveSyncOperationTimeoutMs,
534 "Waiting for OnBackendInitialized().");
537 bool ProfileSyncServiceHarness::AwaitSyncRestart() {
538 DVLOG(1) << GetClientInfoString("AwaitSyncRestart");
539 if (service()->ShouldPushChanges()) {
540 // Sync has already been restarted; don't wait.
541 return true;
544 // Wait for the sync backend to be initialized.
545 if (!AwaitBackendInitialized()) {
546 LOG(ERROR) << "OnBackendInitialized() not seen after "
547 << kLiveSyncOperationTimeoutMs / 1000
548 << " seconds.";
549 return false;
552 // Wait for sync configuration to complete.
553 wait_state_ = WAITING_FOR_SYNC_CONFIGURATION;
554 return AwaitStatusChangeWithTimeout(kLiveSyncOperationTimeoutMs,
555 "Waiting for sync configuration.");
558 bool ProfileSyncServiceHarness::AwaitDataSyncCompletion(
559 const std::string& reason) {
560 DVLOG(1) << GetClientInfoString("AwaitDataSyncCompletion");
562 CHECK(service()->sync_initialized());
563 CHECK_NE(wait_state_, SYNC_DISABLED);
565 if (IsDataSynced()) {
566 // Client is already synced; don't wait.
567 return true;
570 wait_state_ = WAITING_FOR_DATA_SYNC;
571 AwaitStatusChangeWithTimeout(kLiveSyncOperationTimeoutMs, reason);
572 if (wait_state_ == FULLY_SYNCED) {
573 return true;
574 } else {
575 LOG(ERROR) << "AwaitDataSyncCompletion failed, state is now: "
576 << wait_state_;
577 return false;
581 bool ProfileSyncServiceHarness::AwaitFullSyncCompletion(
582 const std::string& reason) {
583 DVLOG(1) << GetClientInfoString("AwaitFullSyncCompletion");
584 if (wait_state_ == SYNC_DISABLED) {
585 LOG(ERROR) << "Sync disabled for " << profile_debug_name_ << ".";
586 return false;
589 if (IsFullySynced()) {
590 // Client is already synced; don't wait.
591 return true;
594 DCHECK(service()->sync_initialized());
595 wait_state_ = WAITING_FOR_FULL_SYNC;
596 AwaitStatusChangeWithTimeout(kLiveSyncOperationTimeoutMs, reason);
597 if (wait_state_ == FULLY_SYNCED) {
598 // Client is online; sync was successful.
599 return true;
600 } else {
601 LOG(ERROR) << "Invalid wait state: " << wait_state_;
602 return false;
606 bool ProfileSyncServiceHarness::AwaitSyncDisabled(const std::string& reason) {
607 DCHECK(service()->HasSyncSetupCompleted());
608 DCHECK_NE(wait_state_, SYNC_DISABLED);
609 wait_state_ = WAITING_FOR_SYNC_DISABLED;
610 AwaitStatusChangeWithTimeout(kLiveSyncOperationTimeoutMs, reason);
611 return wait_state_ == SYNC_DISABLED;
614 bool ProfileSyncServiceHarness::AwaitExponentialBackoffVerification() {
615 const SyncSessionSnapshot& snap = GetLastSessionSnapshot();
616 retry_verifier_.Initialize(snap);
617 wait_state_ = WAITING_FOR_EXPONENTIAL_BACKOFF_VERIFICATION;
618 AwaitStatusChangeWithTimeout(kExponentialBackoffVerificationTimeoutMs,
619 "Verify Exponential backoff");
620 return (retry_verifier_.Succeeded());
623 bool ProfileSyncServiceHarness::AwaitActionableError() {
624 ProfileSyncService::Status status = GetStatus();
625 CHECK(status.sync_protocol_error.action == syncer::UNKNOWN_ACTION);
626 wait_state_ = WAITING_FOR_ACTIONABLE_ERROR;
627 AwaitStatusChangeWithTimeout(kLiveSyncOperationTimeoutMs,
628 "Waiting for actionable error");
629 status = GetStatus();
630 return (status.sync_protocol_error.action != syncer::UNKNOWN_ACTION &&
631 service_->HasUnrecoverableError());
634 bool ProfileSyncServiceHarness::AwaitMigration(
635 syncer::ModelTypeSet expected_migrated_types) {
636 DVLOG(1) << GetClientInfoString("AwaitMigration");
637 DVLOG(1) << profile_debug_name_ << ": waiting until migration is done for "
638 << syncer::ModelTypeSetToString(expected_migrated_types);
639 while (true) {
640 bool migration_finished = migrated_types_.HasAll(expected_migrated_types);
641 DVLOG(1) << "Migrated types "
642 << syncer::ModelTypeSetToString(migrated_types_)
643 << (migration_finished ? " contains " : " does not contain ")
644 << syncer::ModelTypeSetToString(expected_migrated_types);
645 if (migration_finished) {
646 return true;
649 if (HasPendingBackendMigration()) {
650 wait_state_ = WAITING_FOR_MIGRATION_TO_FINISH;
651 } else {
652 wait_state_ = WAITING_FOR_MIGRATION_TO_START;
653 AwaitStatusChangeWithTimeout(kLiveSyncOperationTimeoutMs,
654 "Wait for migration to start");
655 if (wait_state_ != WAITING_FOR_MIGRATION_TO_FINISH) {
656 DVLOG(1) << profile_debug_name_
657 << ": wait state = " << wait_state_
658 << " after migration start is not "
659 << "WAITING_FOR_MIGRATION_TO_FINISH";
660 return false;
663 AwaitStatusChangeWithTimeout(kLiveSyncOperationTimeoutMs,
664 "Wait for migration to finish");
665 if (wait_state_ != WAITING_FOR_NOTHING) {
666 DVLOG(1) << profile_debug_name_
667 << ": wait state = " << wait_state_
668 << " after migration finish is not WAITING_FOR_NOTHING";
669 return false;
671 // We must use AwaitDataSyncCompletion rather than the more common
672 // AwaitFullSyncCompletion. As long as crbug.com/97780 is open, we will
673 // rely on self-notifications to ensure that progress markers are updated,
674 // which allows AwaitFullSyncCompletion to return. However, in some
675 // migration tests these notifications are completely disabled, so the
676 // progress markers do not get updated. This is why we must use the less
677 // strict condition, AwaitDataSyncCompletion.
678 if (!AwaitDataSyncCompletion(
679 "Config sync cycle after migration cycle")) {
680 return false;
685 bool ProfileSyncServiceHarness::AwaitMutualSyncCycleCompletion(
686 ProfileSyncServiceHarness* partner) {
687 DVLOG(1) << GetClientInfoString("AwaitMutualSyncCycleCompletion");
688 if (!AwaitFullSyncCompletion("Sync cycle completion on active client."))
689 return false;
690 return partner->WaitUntilProgressMarkersMatch(this,
691 "Sync cycle completion on passive client.");
694 bool ProfileSyncServiceHarness::AwaitGroupSyncCycleCompletion(
695 std::vector<ProfileSyncServiceHarness*>& partners) {
696 DVLOG(1) << GetClientInfoString("AwaitGroupSyncCycleCompletion");
697 if (!AwaitFullSyncCompletion("Sync cycle completion on active client."))
698 return false;
699 bool return_value = true;
700 for (std::vector<ProfileSyncServiceHarness*>::iterator it =
701 partners.begin(); it != partners.end(); ++it) {
702 if ((this != *it) && ((*it)->wait_state_ != SYNC_DISABLED)) {
703 return_value = return_value &&
704 (*it)->WaitUntilProgressMarkersMatch(this,
705 "Sync cycle completion on partner client.");
708 return return_value;
711 // static
712 bool ProfileSyncServiceHarness::AwaitQuiescence(
713 std::vector<ProfileSyncServiceHarness*>& clients) {
714 DVLOG(1) << "AwaitQuiescence.";
715 bool return_value = true;
716 for (std::vector<ProfileSyncServiceHarness*>::iterator it =
717 clients.begin(); it != clients.end(); ++it) {
718 if ((*it)->wait_state_ != SYNC_DISABLED)
719 return_value = return_value &&
720 (*it)->AwaitGroupSyncCycleCompletion(clients);
722 return return_value;
725 bool ProfileSyncServiceHarness::WaitUntilProgressMarkersMatch(
726 ProfileSyncServiceHarness* partner, const std::string& reason) {
727 DVLOG(1) << GetClientInfoString("WaitUntilProgressMarkersMatch");
728 if (wait_state_ == SYNC_DISABLED) {
729 LOG(ERROR) << "Sync disabled for " << profile_debug_name_ << ".";
730 return false;
733 if (MatchesOtherClient(partner)) {
734 // Progress markers already match; don't wait.
735 return true;
738 DCHECK(!progress_marker_partner_);
739 progress_marker_partner_ = partner;
740 partner->service()->AddObserver(this);
741 wait_state_ = WAITING_FOR_UPDATES;
742 bool return_value =
743 AwaitStatusChangeWithTimeout(kLiveSyncOperationTimeoutMs, reason);
744 partner->service()->RemoveObserver(this);
745 progress_marker_partner_ = NULL;
746 return return_value;
749 bool ProfileSyncServiceHarness::AwaitStatusChangeWithTimeout(
750 int timeout_milliseconds,
751 const std::string& reason) {
752 DVLOG(1) << GetClientInfoString("AwaitStatusChangeWithTimeout");
753 if (wait_state_ == SYNC_DISABLED) {
754 LOG(ERROR) << "Sync disabled for " << profile_debug_name_ << ".";
755 return false;
757 scoped_refptr<StateChangeTimeoutEvent> timeout_signal(
758 new StateChangeTimeoutEvent(this, reason));
760 // Set the flag to tell SignalStateComplete() that it's OK to quit out of
761 // the MessageLoop if we hit a state transition.
762 waiting_for_status_change_ = true;
763 MessageLoop* loop = MessageLoop::current();
764 MessageLoop::ScopedNestableTaskAllower allow(loop);
765 loop->PostDelayedTask(
766 FROM_HERE,
767 base::Bind(&StateChangeTimeoutEvent::Callback,
768 timeout_signal.get()),
769 base::TimeDelta::FromMilliseconds(timeout_milliseconds));
770 loop->Run();
771 waiting_for_status_change_ = false;
774 if (timeout_signal->Abort()) {
775 DVLOG(1) << GetClientInfoString("AwaitStatusChangeWithTimeout succeeded");
776 return true;
777 } else {
778 DVLOG(0) << GetClientInfoString("AwaitStatusChangeWithTimeout timed out");
779 return false;
783 ProfileSyncService::Status ProfileSyncServiceHarness::GetStatus() {
784 DCHECK(service() != NULL) << "GetStatus(): service() is NULL.";
785 ProfileSyncService::Status result;
786 service()->QueryDetailedSyncStatus(&result);
787 return result;
790 // We use this function to share code between IsFullySynced and IsDataSynced
791 // while ensuring that all conditions are evaluated using on the same snapshot.
792 bool ProfileSyncServiceHarness::IsDataSyncedImpl(
793 const SyncSessionSnapshot& snap) {
794 return ServiceIsPushingChanges() &&
795 GetStatus().notifications_enabled &&
796 !service()->HasUnsyncedItems() &&
797 !HasPendingBackendMigration();
800 bool ProfileSyncServiceHarness::IsDataSynced() {
801 if (service() == NULL) {
802 DVLOG(1) << GetClientInfoString("IsDataSynced(): false");
803 return false;
806 const SyncSessionSnapshot& snap = GetLastSessionSnapshot();
807 bool is_data_synced = IsDataSyncedImpl(snap);
809 DVLOG(1) << GetClientInfoString(
810 is_data_synced ? "IsDataSynced: true" : "IsDataSynced: false");
811 return is_data_synced;
814 bool ProfileSyncServiceHarness::IsFullySynced() {
815 if (service() == NULL) {
816 DVLOG(1) << GetClientInfoString("IsFullySynced: false");
817 return false;
819 const SyncSessionSnapshot& snap = GetLastSessionSnapshot();
820 // If we didn't try to commit anything in the previous cycle, there's a
821 // good chance that we're now fully up to date.
822 bool is_fully_synced =
823 snap.model_neutral_state().num_successful_commits == 0
824 && snap.model_neutral_state().commit_result == syncer::SYNCER_OK
825 && IsDataSyncedImpl(snap);
827 DVLOG(1) << GetClientInfoString(
828 is_fully_synced ? "IsFullySynced: true" : "IsFullySynced: false");
829 return is_fully_synced;
832 bool ProfileSyncServiceHarness::HasPendingBackendMigration() {
833 browser_sync::BackendMigrator* migrator =
834 service()->GetBackendMigratorForTest();
835 return migrator && migrator->state() != browser_sync::BackendMigrator::IDLE;
838 bool ProfileSyncServiceHarness::AutoStartEnabled() {
839 return service_->auto_start_enabled();
842 bool ProfileSyncServiceHarness::MatchesOtherClient(
843 ProfileSyncServiceHarness* partner) {
844 // TODO(akalin): Shouldn't this belong with the intersection check?
845 // Otherwise, this function isn't symmetric.
846 if (!IsFullySynced()) {
847 DVLOG(2) << profile_debug_name_ << ": not synced, assuming doesn't match";
848 return false;
851 // Only look for a match if we have at least one enabled datatype in
852 // common with the partner client.
853 const syncer::ModelTypeSet common_types =
854 Intersection(service()->GetPreferredDataTypes(),
855 partner->service()->GetPreferredDataTypes());
857 DVLOG(2) << profile_debug_name_ << ", " << partner->profile_debug_name_
858 << ": common types are "
859 << syncer::ModelTypeSetToString(common_types);
861 if (!common_types.Empty() && !partner->IsFullySynced()) {
862 DVLOG(2) << "non-empty common types and "
863 << partner->profile_debug_name_ << " isn't synced";
864 return false;
867 for (syncer::ModelTypeSet::Iterator i = common_types.First();
868 i.Good(); i.Inc()) {
869 const std::string marker = GetSerializedProgressMarker(i.Get());
870 const std::string partner_marker =
871 partner->GetSerializedProgressMarker(i.Get());
872 if (marker != partner_marker) {
873 if (VLOG_IS_ON(2)) {
874 std::string marker_base64, partner_marker_base64;
875 if (!base::Base64Encode(marker, &marker_base64)) {
876 NOTREACHED();
878 if (!base::Base64Encode(
879 partner_marker, &partner_marker_base64)) {
880 NOTREACHED();
882 DVLOG(2) << syncer::ModelTypeToString(i.Get()) << ": "
883 << profile_debug_name_ << " progress marker = "
884 << marker_base64 << ", "
885 << partner->profile_debug_name_
886 << " partner progress marker = "
887 << partner_marker_base64;
889 return false;
892 return true;
895 SyncSessionSnapshot ProfileSyncServiceHarness::GetLastSessionSnapshot() const {
896 DCHECK(service_ != NULL) << "Sync service has not yet been set up.";
897 if (service_->sync_initialized()) {
898 return service_->GetLastSessionSnapshot();
900 return SyncSessionSnapshot();
903 bool ProfileSyncServiceHarness::EnableSyncForDatatype(
904 syncer::ModelType datatype) {
905 DVLOG(1) << GetClientInfoString(
906 "EnableSyncForDatatype("
907 + std::string(syncer::ModelTypeToString(datatype)) + ")");
909 if (wait_state_ == SYNC_DISABLED) {
910 return SetupSync(syncer::ModelTypeSet(datatype));
913 if (service() == NULL) {
914 LOG(ERROR) << "EnableSyncForDatatype(): service() is null.";
915 return false;
918 syncer::ModelTypeSet synced_datatypes = service()->GetPreferredDataTypes();
919 if (synced_datatypes.Has(datatype)) {
920 DVLOG(1) << "EnableSyncForDatatype(): Sync already enabled for datatype "
921 << syncer::ModelTypeToString(datatype)
922 << " on " << profile_debug_name_ << ".";
923 return true;
926 synced_datatypes.Put(syncer::ModelTypeFromInt(datatype));
927 service()->OnUserChoseDatatypes(false, synced_datatypes);
928 if (AwaitDataSyncCompletion("Datatype configuration.")) {
929 DVLOG(1) << "EnableSyncForDatatype(): Enabled sync for datatype "
930 << syncer::ModelTypeToString(datatype)
931 << " on " << profile_debug_name_ << ".";
932 return true;
935 DVLOG(0) << GetClientInfoString("EnableSyncForDatatype failed");
936 return false;
939 bool ProfileSyncServiceHarness::DisableSyncForDatatype(
940 syncer::ModelType datatype) {
941 DVLOG(1) << GetClientInfoString(
942 "DisableSyncForDatatype("
943 + std::string(syncer::ModelTypeToString(datatype)) + ")");
945 if (service() == NULL) {
946 LOG(ERROR) << "DisableSyncForDatatype(): service() is null.";
947 return false;
950 syncer::ModelTypeSet synced_datatypes = service()->GetPreferredDataTypes();
951 if (!synced_datatypes.Has(datatype)) {
952 DVLOG(1) << "DisableSyncForDatatype(): Sync already disabled for datatype "
953 << syncer::ModelTypeToString(datatype)
954 << " on " << profile_debug_name_ << ".";
955 return true;
958 synced_datatypes.RetainAll(syncer::UserSelectableTypes());
959 synced_datatypes.Remove(datatype);
960 service()->OnUserChoseDatatypes(false, synced_datatypes);
961 if (AwaitFullSyncCompletion("Datatype reconfiguration.")) {
962 DVLOG(1) << "DisableSyncForDatatype(): Disabled sync for datatype "
963 << syncer::ModelTypeToString(datatype)
964 << " on " << profile_debug_name_ << ".";
965 return true;
968 DVLOG(0) << GetClientInfoString("DisableSyncForDatatype failed");
969 return false;
972 bool ProfileSyncServiceHarness::EnableSyncForAllDatatypes() {
973 DVLOG(1) << GetClientInfoString("EnableSyncForAllDatatypes");
975 if (wait_state_ == SYNC_DISABLED) {
976 return SetupSync();
979 if (service() == NULL) {
980 LOG(ERROR) << "EnableSyncForAllDatatypes(): service() is null.";
981 return false;
984 service()->OnUserChoseDatatypes(true, syncer::ModelTypeSet::All());
985 if (AwaitFullSyncCompletion("Datatype reconfiguration.")) {
986 DVLOG(1) << "EnableSyncForAllDatatypes(): Enabled sync for all datatypes "
987 << "on " << profile_debug_name_ << ".";
988 return true;
991 DVLOG(0) << GetClientInfoString("EnableSyncForAllDatatypes failed");
992 return false;
995 bool ProfileSyncServiceHarness::DisableSyncForAllDatatypes() {
996 DVLOG(1) << GetClientInfoString("DisableSyncForAllDatatypes");
998 if (service() == NULL) {
999 LOG(ERROR) << "DisableSyncForAllDatatypes(): service() is null.";
1000 return false;
1003 service()->DisableForUser();
1004 wait_state_ = SYNC_DISABLED;
1005 DVLOG(1) << "DisableSyncForAllDatatypes(): Disabled sync for all "
1006 << "datatypes on " << profile_debug_name_;
1007 return true;
1010 std::string ProfileSyncServiceHarness::GetSerializedProgressMarker(
1011 syncer::ModelType model_type) const {
1012 const SyncSessionSnapshot& snap = GetLastSessionSnapshot();
1013 const syncer::ProgressMarkerMap& markers_map =
1014 snap.download_progress_markers();
1016 syncer::ProgressMarkerMap::const_iterator it =
1017 markers_map.find(model_type);
1018 return (it != markers_map.end()) ? it->second : std::string();
1021 std::string ProfileSyncServiceHarness::GetClientInfoString(
1022 const std::string& message) {
1023 std::stringstream os;
1024 os << profile_debug_name_ << ": " << message << ": ";
1025 if (service()) {
1026 const SyncSessionSnapshot& snap = GetLastSessionSnapshot();
1027 const ProfileSyncService::Status& status = GetStatus();
1028 // Capture select info from the sync session snapshot and syncer status.
1029 os << ", has_unsynced_items: "
1030 << (service()->sync_initialized() ? service()->HasUnsyncedItems() : 0)
1031 << ", did_commit: "
1032 << (snap.model_neutral_state().num_successful_commits == 0 &&
1033 snap.model_neutral_state().commit_result == syncer::SYNCER_OK)
1034 << ", encryption conflicts: "
1035 << snap.num_encryption_conflicts()
1036 << ", hierarchy conflicts: "
1037 << snap.num_hierarchy_conflicts()
1038 << ", server conflicts: "
1039 << snap.num_server_conflicts()
1040 << ", num_updates_downloaded : "
1041 << snap.model_neutral_state().num_updates_downloaded_total
1042 << ", passphrase_required_reason: "
1043 << syncer::PassphraseRequiredReasonToString(
1044 service()->passphrase_required_reason())
1045 << ", notifications_enabled: "
1046 << status.notifications_enabled
1047 << ", service_is_pushing_changes: "
1048 << ServiceIsPushingChanges()
1049 << ", has_pending_backend_migration: "
1050 << HasPendingBackendMigration();
1051 } else {
1052 os << "Sync service not available";
1054 return os.str();
1057 // TODO(zea): Rename this EnableEncryption, since we no longer turn on
1058 // encryption for individual types but for all.
1059 bool ProfileSyncServiceHarness::EnableEncryptionForType(
1060 syncer::ModelType type) {
1061 const syncer::ModelTypeSet encrypted_types =
1062 service_->GetEncryptedDataTypes();
1063 if (encrypted_types.Has(type))
1064 return true;
1065 service_->EnableEncryptEverything();
1067 // In order to kick off the encryption we have to reconfigure. Just grab the
1068 // currently synced types and use them.
1069 const syncer::ModelTypeSet synced_datatypes =
1070 service_->GetPreferredDataTypes();
1071 bool sync_everything =
1072 synced_datatypes.Equals(syncer::ModelTypeSet::All());
1073 service_->OnUserChoseDatatypes(sync_everything, synced_datatypes);
1075 // Wait some time to let the enryption finish.
1076 return WaitForTypeEncryption(type);
1079 bool ProfileSyncServiceHarness::WaitForTypeEncryption(syncer::ModelType type) {
1080 // The correctness of this if condition depends on the ordering of its
1081 // sub-expressions. See crbug.com/95619.
1082 // TODO(rlarocque): Figure out a less brittle way of detecting this.
1083 if (IsTypeEncrypted(type) &&
1084 IsFullySynced() &&
1085 GetLastSessionSnapshot().num_encryption_conflicts() == 0) {
1086 // Encryption is already complete for |type|; do not wait.
1087 return true;
1090 std::string reason = "Waiting for encryption.";
1091 wait_state_ = WAITING_FOR_ENCRYPTION;
1092 waiting_for_encryption_type_ = type;
1093 if (!AwaitStatusChangeWithTimeout(kLiveSyncOperationTimeoutMs, reason)) {
1094 LOG(ERROR) << "Did not receive EncryptionComplete notification after"
1095 << kLiveSyncOperationTimeoutMs / 1000
1096 << " seconds.";
1097 return false;
1099 return IsTypeEncrypted(type);
1102 bool ProfileSyncServiceHarness::IsTypeEncrypted(syncer::ModelType type) {
1103 const syncer::ModelTypeSet encrypted_types =
1104 service_->GetEncryptedDataTypes();
1105 bool is_type_encrypted = service_->GetEncryptedDataTypes().Has(type);
1106 DVLOG(2) << syncer::ModelTypeToString(type) << " is "
1107 << (is_type_encrypted ? "" : "not ") << "encrypted; "
1108 << "encrypted types = "
1109 << syncer::ModelTypeSetToString(encrypted_types);
1110 return is_type_encrypted;
1113 bool ProfileSyncServiceHarness::IsTypeRunning(syncer::ModelType type) {
1114 browser_sync::DataTypeController::StateMap state_map;
1115 service_->GetDataTypeControllerStates(&state_map);
1116 return (state_map.count(type) != 0 &&
1117 state_map[type] == browser_sync::DataTypeController::RUNNING);
1120 bool ProfileSyncServiceHarness::IsTypePreferred(syncer::ModelType type) {
1121 return service_->GetPreferredDataTypes().Has(type);
1124 size_t ProfileSyncServiceHarness::GetNumEntries() const {
1125 return GetLastSessionSnapshot().num_entries();
1128 size_t ProfileSyncServiceHarness::GetNumDatatypes() const {
1129 browser_sync::DataTypeController::StateMap state_map;
1130 service_->GetDataTypeControllerStates(&state_map);
1131 return state_map.size();
1134 std::string ProfileSyncServiceHarness::GetServiceStatus() {
1135 scoped_ptr<DictionaryValue> value(
1136 sync_ui_util::ConstructAboutInformation(service_));
1137 std::string service_status;
1138 base::JSONWriter::WriteWithOptions(value.get(),
1139 base::JSONWriter::OPTIONS_PRETTY_PRINT,
1140 &service_status);
1141 return service_status;