Home | History | Annotate | Download | only in sync_driver 
      1 // Copyright 2014 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 "components/sync_driver/model_association_manager.h"
      6 
      7 #include <algorithm>
      8 #include <functional>
      9 
     10 #include "base/debug/trace_event.h"
     11 #include "base/logging.h"
     12 #include "base/message_loop/message_loop.h"
     13 #include "base/metrics/histogram.h"
     14 #include "sync/internal_api/public/base/model_type.h"
     15 
     16 using syncer::ModelTypeSet;
     17 
     18 namespace browser_sync {
     19 
     20 namespace {
     21 
     22 static const syncer::ModelType kStartOrder[] = {
     23   syncer::NIGORI,               //  Listed for completeness.
     24   syncer::DEVICE_INFO,          //  Listed for completeness.
     25   syncer::EXPERIMENTS,          //  Listed for completeness.
     26   syncer::PROXY_TABS,           //  Listed for completeness.
     27 
     28   // Kick off the association of the non-UI types first so they can associate
     29   // in parallel with the UI types.
     30   syncer::PASSWORDS,
     31   syncer::AUTOFILL,
     32   syncer::AUTOFILL_PROFILE,
     33   syncer::EXTENSION_SETTINGS,
     34   syncer::APP_SETTINGS,
     35   syncer::TYPED_URLS,
     36   syncer::HISTORY_DELETE_DIRECTIVES,
     37   syncer::SYNCED_NOTIFICATIONS,
     38   syncer::SYNCED_NOTIFICATION_APP_INFO,
     39 
     40   // UI thread data types.
     41   syncer::BOOKMARKS,
     42   syncer::SUPERVISED_USERS,     //  Syncing supervised users on initial login
     43                                 //  might block creating a new supervised user,
     44                                 //  so we want to do it early.
     45   syncer::PREFERENCES,
     46   syncer::PRIORITY_PREFERENCES,
     47   syncer::EXTENSIONS,
     48   syncer::APPS,
     49   syncer::APP_LIST,
     50   syncer::THEMES,
     51   syncer::SEARCH_ENGINES,
     52   syncer::SESSIONS,
     53   syncer::APP_NOTIFICATIONS,
     54   syncer::DICTIONARY,
     55   syncer::FAVICON_IMAGES,
     56   syncer::FAVICON_TRACKING,
     57   syncer::SUPERVISED_USER_SETTINGS,
     58   syncer::SUPERVISED_USER_SHARED_SETTINGS,
     59   syncer::ARTICLES,
     60 };
     61 
     62 COMPILE_ASSERT(arraysize(kStartOrder) ==
     63                syncer::MODEL_TYPE_COUNT - syncer::FIRST_REAL_MODEL_TYPE,
     64                kStartOrder_IncorrectSize);
     65 
     66 // The amount of time we wait for association to finish. If some types haven't
     67 // finished association by the time, configuration result will be
     68 // PARTIAL_SUCCESS and DataTypeManager is notified of the unfinished types.
     69 const int64 kAssociationTimeOutInSeconds = 600;
     70 
     71 syncer::DataTypeAssociationStats BuildAssociationStatsFromMergeResults(
     72     const syncer::SyncMergeResult& local_merge_result,
     73     const syncer::SyncMergeResult& syncer_merge_result,
     74     const base::TimeDelta& association_wait_time,
     75     const base::TimeDelta& association_time) {
     76   DCHECK_EQ(local_merge_result.model_type(), syncer_merge_result.model_type());
     77   syncer::DataTypeAssociationStats stats;
     78   stats.had_error = local_merge_result.error().IsSet() ||
     79                     syncer_merge_result.error().IsSet();
     80   stats.num_local_items_before_association =
     81       local_merge_result.num_items_before_association();
     82   stats.num_sync_items_before_association =
     83       syncer_merge_result.num_items_before_association();
     84   stats.num_local_items_after_association =
     85       local_merge_result.num_items_after_association();
     86   stats.num_sync_items_after_association =
     87       syncer_merge_result.num_items_after_association();
     88   stats.num_local_items_added =
     89       local_merge_result.num_items_added();
     90   stats.num_local_items_deleted =
     91       local_merge_result.num_items_deleted();
     92   stats.num_local_items_modified =
     93       local_merge_result.num_items_modified();
     94   stats.local_version_pre_association =
     95       local_merge_result.pre_association_version();
     96   stats.num_sync_items_added =
     97       syncer_merge_result.num_items_added();
     98   stats.num_sync_items_deleted =
     99       syncer_merge_result.num_items_deleted();
    100   stats.num_sync_items_modified =
    101       syncer_merge_result.num_items_modified();
    102   stats.sync_version_pre_association =
    103       syncer_merge_result.pre_association_version();
    104   stats.association_wait_time = association_wait_time;
    105   stats.association_time = association_time;
    106   return stats;
    107 }
    108 
    109 }  // namespace
    110 
    111 ModelAssociationManager::ModelAssociationManager(
    112     const DataTypeController::TypeMap* controllers,
    113     ModelAssociationManagerDelegate* processor)
    114     : state_(IDLE),
    115       controllers_(controllers),
    116       delegate_(processor),
    117       weak_ptr_factory_(this),
    118       configure_status_(DataTypeManager::UNKNOWN) {
    119   // Ensure all data type controllers are stopped.
    120   for (DataTypeController::TypeMap::const_iterator it = controllers_->begin();
    121        it != controllers_->end(); ++it) {
    122     DCHECK_EQ(DataTypeController::NOT_RUNNING, (*it).second->state());
    123   }
    124 }
    125 
    126 ModelAssociationManager::~ModelAssociationManager() {
    127 }
    128 
    129 void ModelAssociationManager::Initialize(syncer::ModelTypeSet desired_types) {
    130   // state_ can be INITIALIZED_TO_CONFIGURE if types are reconfigured when
    131   // data is being downloaded, so StartAssociationAsync() is never called for
    132   // the first configuration.
    133   DCHECK_NE(CONFIGURING, state_);
    134 
    135   // Only keep types that have controllers.
    136   desired_types_.Clear();
    137   slow_types_.Clear();
    138   for (syncer::ModelTypeSet::Iterator it = desired_types.First();
    139       it.Good(); it.Inc()) {
    140     if (controllers_->find(it.Get()) != controllers_->end())
    141       desired_types_.Put(it.Get());
    142   }
    143 
    144   DVLOG(1) << "ModelAssociationManager: Initializing for "
    145            << syncer::ModelTypeSetToString(desired_types_);
    146 
    147   state_ = INITIALIZED_TO_CONFIGURE;
    148 
    149   StopDisabledTypes();
    150   LoadEnabledTypes();
    151 }
    152 
    153 void ModelAssociationManager::StopDatatype(DataTypeController* dtc) {
    154   // First tell the sync backend that we no longer want to listen to
    155   // changes for this type.
    156   delegate_->OnSingleDataTypeWillStop(dtc->type());
    157 
    158   // Then tell all data type specific logic to shut down.
    159   dtc->Stop();
    160 }
    161 
    162 void ModelAssociationManager::StopDisabledTypes() {
    163   DVLOG(1) << "ModelAssociationManager: Stopping disabled types.";
    164   for (DataTypeController::TypeMap::const_iterator it = controllers_->begin();
    165        it != controllers_->end(); ++it) {
    166     DataTypeController* dtc = (*it).second.get();
    167     if (dtc->state() != DataTypeController::NOT_RUNNING &&
    168         (!desired_types_.Has(dtc->type()) ||
    169             failed_data_types_info_.count(dtc->type()) > 0)) {
    170       DVLOG(1) << "ModelTypeToString: stop " << dtc->name();
    171       StopDatatype(dtc);
    172       loaded_types_.Remove(dtc->type());
    173       associated_types_.Remove(dtc->type());
    174     }
    175   }
    176 }
    177 
    178 void ModelAssociationManager::LoadEnabledTypes() {
    179   // Load in kStartOrder.
    180   for (size_t i = 0; i < arraysize(kStartOrder); i++) {
    181     syncer::ModelType type = kStartOrder[i];
    182     if (!desired_types_.Has(type))
    183       continue;
    184 
    185     DCHECK(controllers_->find(type) != controllers_->end());
    186     DataTypeController* dtc = controllers_->find(type)->second.get();
    187     if (dtc->state() == DataTypeController::NOT_RUNNING) {
    188       DCHECK(!loaded_types_.Has(dtc->type()));
    189       DCHECK(!associated_types_.Has(dtc->type()));
    190       dtc->LoadModels(base::Bind(&ModelAssociationManager::ModelLoadCallback,
    191                                  weak_ptr_factory_.GetWeakPtr()));
    192     }
    193   }
    194 }
    195 
    196 void ModelAssociationManager::StartAssociationAsync(
    197     const syncer::ModelTypeSet& types_to_associate) {
    198   DCHECK_NE(CONFIGURING, state_);
    199   state_ = CONFIGURING;
    200 
    201   association_start_time_ = base::TimeTicks::Now();
    202 
    203   requested_types_ = types_to_associate;
    204 
    205   associating_types_ = types_to_associate;
    206   associating_types_.RetainAll(desired_types_);
    207   associating_types_.RemoveAll(associated_types_);
    208 
    209   // Assume success.
    210   configure_status_ = DataTypeManager::OK;
    211 
    212   // Remove types that already failed.
    213   for (std::map<syncer::ModelType, syncer::SyncError>::const_iterator it =
    214           failed_data_types_info_.begin();
    215       it != failed_data_types_info_.end(); ++it) {
    216     associating_types_.Remove(it->first);
    217   }
    218 
    219   // Done if no types to associate.
    220   if (associating_types_.Empty()) {
    221     ModelAssociationDone();
    222     return;
    223   }
    224 
    225   timer_.Start(FROM_HERE,
    226                base::TimeDelta::FromSeconds(kAssociationTimeOutInSeconds),
    227                this,
    228                &ModelAssociationManager::ModelAssociationDone);
    229 
    230   // Start association of types that are loaded in specified order.
    231   for (size_t i = 0; i < arraysize(kStartOrder); i++) {
    232     syncer::ModelType type = kStartOrder[i];
    233     if (!associating_types_.Has(type) || !loaded_types_.Has(type))
    234       continue;
    235 
    236     DataTypeController* dtc = controllers_->find(type)->second.get();
    237     DCHECK(DataTypeController::MODEL_LOADED == dtc->state() ||
    238            DataTypeController::ASSOCIATING == dtc->state());
    239     if (dtc->state() == DataTypeController::MODEL_LOADED) {
    240       TRACE_EVENT_ASYNC_BEGIN1("sync", "ModelAssociation",
    241                                dtc,
    242                                "DataType",
    243                                ModelTypeToString(type));
    244 
    245       dtc->StartAssociating(
    246           base::Bind(&ModelAssociationManager::TypeStartCallback,
    247                      weak_ptr_factory_.GetWeakPtr(),
    248                      type, base::TimeTicks::Now()));
    249     }
    250   }
    251 }
    252 
    253 void ModelAssociationManager::ResetForNextAssociation() {
    254   DVLOG(1) << "ModelAssociationManager: Reseting for next configuration";
    255   // |loaded_types_| and |associated_types_| are not cleared. So
    256   // reconfiguration won't restart types that are already started.
    257   requested_types_.Clear();
    258   failed_data_types_info_.clear();
    259   associating_types_.Clear();
    260   needs_crypto_types_.Clear();
    261 }
    262 
    263 void ModelAssociationManager::Stop() {
    264   // Ignore callbacks from controllers.
    265   weak_ptr_factory_.InvalidateWeakPtrs();
    266 
    267   // Stop started data types.
    268   for (DataTypeController::TypeMap::const_iterator it = controllers_->begin();
    269        it != controllers_->end(); ++it) {
    270     DataTypeController* dtc = (*it).second.get();
    271     if (dtc->state() != DataTypeController::NOT_RUNNING) {
    272       StopDatatype(dtc);
    273       DVLOG(1) << "ModelAssociationManager: Stopped " << dtc->name();
    274     }
    275   }
    276 
    277   desired_types_.Clear();
    278   loaded_types_.Clear();
    279   associated_types_.Clear();
    280   slow_types_.Clear();
    281 
    282   if (state_ == CONFIGURING) {
    283     if (configure_status_ == DataTypeManager::OK)
    284       configure_status_ = DataTypeManager::ABORTED;
    285     DVLOG(1) << "ModelAssociationManager: Calling OnModelAssociationDone";
    286     ModelAssociationDone();
    287   }
    288 
    289   ResetForNextAssociation();
    290 
    291   state_ = IDLE;
    292 }
    293 
    294 void ModelAssociationManager::AppendToFailedDatatypesAndLogError(
    295     const syncer::SyncError& error) {
    296   failed_data_types_info_[error.model_type()] = error;
    297   LOG(ERROR) << "Failed to associate models for "
    298              << syncer::ModelTypeToString(error.model_type());
    299   UMA_HISTOGRAM_ENUMERATION("Sync.ConfigureFailed",
    300                             ModelTypeToHistogramInt(error.model_type()),
    301                             syncer::MODEL_TYPE_COUNT);
    302 }
    303 
    304 void ModelAssociationManager::ModelLoadCallback(syncer::ModelType type,
    305                                                 syncer::SyncError error) {
    306   DVLOG(1) << "ModelAssociationManager: ModelLoadCallback for "
    307       << syncer::ModelTypeToString(type);
    308 
    309   // TODO(haitaol): temporary fix for 335606.
    310   if (slow_types_.Has(type))
    311     return;
    312 
    313   // This happens when slow loading type is disabled by new configuration.
    314   if (!desired_types_.Has(type))
    315     return;
    316 
    317   DCHECK(!loaded_types_.Has(type));
    318   if (error.IsSet()) {
    319     syncer::SyncMergeResult local_merge_result(type);
    320     local_merge_result.set_error(error);
    321     TypeStartCallback(type,
    322                       base::TimeTicks::Now(),
    323                       DataTypeController::ASSOCIATION_FAILED,
    324                       local_merge_result,
    325                       syncer::SyncMergeResult(type));
    326     return;
    327   }
    328 
    329   loaded_types_.Put(type);
    330   if (associating_types_.Has(type) || slow_types_.Has(type)) {
    331     DataTypeController* dtc = controllers_->find(type)->second.get();
    332     dtc->StartAssociating(
    333         base::Bind(&ModelAssociationManager::TypeStartCallback,
    334                    weak_ptr_factory_.GetWeakPtr(),
    335                    type, base::TimeTicks::Now()));
    336   }
    337 }
    338 
    339 void ModelAssociationManager::TypeStartCallback(
    340     syncer::ModelType type,
    341     base::TimeTicks type_start_time,
    342     DataTypeController::StartResult start_result,
    343     const syncer::SyncMergeResult& local_merge_result,
    344     const syncer::SyncMergeResult& syncer_merge_result) {
    345   // TODO(haitaol): temporary fix for 335606.
    346   if (slow_types_.Has(type))
    347     return;
    348 
    349   // This happens when slow associating type is disabled by new configuration.
    350   if (!desired_types_.Has(type))
    351     return;
    352 
    353   slow_types_.Remove(type);
    354 
    355   DCHECK(!associated_types_.Has(type));
    356   if (DataTypeController::IsSuccessfulResult(start_result)) {
    357     associated_types_.Put(type);
    358   } else if (state_ == IDLE) {
    359     // For type that failed in IDLE mode, simply stop the controller. Next
    360     // configuration will try to restart from scratch if the type is still
    361     // enabled.
    362     DataTypeController* dtc = controllers_->find(type)->second.get();
    363     if (dtc->state() != DataTypeController::NOT_RUNNING)
    364       StopDatatype(dtc);
    365     loaded_types_.Remove(type);
    366   } else {
    367     // Record error in CONFIGURING or INITIALIZED_TO_CONFIGURE mode. The error
    368     // will be reported when data types association finishes.
    369     if (start_result == DataTypeController::NEEDS_CRYPTO) {
    370       DVLOG(1) << "ModelAssociationManager: Encountered an undecryptable type";
    371       needs_crypto_types_.Put(type);
    372     } else {
    373       DVLOG(1) << "ModelAssociationManager: Encountered a failed type";
    374       AppendToFailedDatatypesAndLogError(local_merge_result.error());
    375     }
    376   }
    377 
    378   if (state_ != CONFIGURING)
    379     return;
    380 
    381   TRACE_EVENT_ASYNC_END1("sync", "ModelAssociation",
    382                          controllers_->find(type)->second.get(),
    383                          "DataType",
    384                          ModelTypeToString(type));
    385 
    386   // Track the merge results if we succeeded or an association failure
    387   // occurred.
    388   if ((DataTypeController::IsSuccessfulResult(start_result) ||
    389        start_result == DataTypeController::ASSOCIATION_FAILED) &&
    390       syncer::ProtocolTypes().Has(type)) {
    391     base::TimeDelta association_wait_time =
    392         std::max(base::TimeDelta(), type_start_time - association_start_time_);
    393     base::TimeDelta association_time =
    394         base::TimeTicks::Now() - type_start_time;;
    395     syncer::DataTypeAssociationStats stats =
    396         BuildAssociationStatsFromMergeResults(local_merge_result,
    397                                               syncer_merge_result,
    398                                               association_wait_time,
    399                                               association_time);
    400     delegate_->OnSingleDataTypeAssociationDone(type, stats);
    401   }
    402 
    403   // Update configuration result.
    404   if (configure_status_ == DataTypeManager::OK &&
    405       start_result == DataTypeController::ASSOCIATION_FAILED) {
    406     configure_status_ = DataTypeManager::PARTIAL_SUCCESS;
    407   }
    408   if (start_result == DataTypeController::UNRECOVERABLE_ERROR)
    409     configure_status_ = DataTypeManager::UNRECOVERABLE_ERROR;
    410 
    411   associating_types_.Remove(type);
    412 
    413   if (associating_types_.Empty())
    414     ModelAssociationDone();
    415 }
    416 
    417 void ModelAssociationManager::ModelAssociationDone() {
    418   CHECK_EQ(CONFIGURING, state_);
    419 
    420   timer_.Stop();
    421 
    422   slow_types_.PutAll(associating_types_);
    423 
    424   // TODO(haitaol): temporary fix for 335606.
    425   for (syncer::ModelTypeSet::Iterator it = associating_types_.First();
    426       it.Good(); it.Inc()) {
    427     AppendToFailedDatatypesAndLogError(
    428         syncer::SyncError(FROM_HERE, syncer::SyncError::DATATYPE_ERROR,
    429                           "Association timed out.", it.Get()));
    430   }
    431 
    432   // Stop controllers of failed types.
    433   StopDisabledTypes();
    434 
    435   if (configure_status_ == DataTypeManager::OK &&
    436       (!associating_types_.Empty() || !failed_data_types_info_.empty() ||
    437           !needs_crypto_types_.Empty())) {
    438     // We have not configured all types that we have been asked to configure.
    439     // Either we have failed types or types that have not completed loading
    440     // yet.
    441     DVLOG(1) << "ModelAssociationManager: setting partial success";
    442     configure_status_ = DataTypeManager::PARTIAL_SUCCESS;
    443   }
    444 
    445   DataTypeManager::ConfigureResult result(configure_status_,
    446                                           requested_types_,
    447                                           failed_data_types_info_,
    448                                           associating_types_,
    449                                           needs_crypto_types_);
    450 
    451   // Reset state before notifying |delegate_| because that might
    452   // trigger a new round of configuration.
    453   ResetForNextAssociation();
    454   state_ = IDLE;
    455 
    456   delegate_->OnModelAssociationDone(result);
    457 }
    458 
    459 base::OneShotTimer<ModelAssociationManager>*
    460     ModelAssociationManager::GetTimerForTesting() {
    461   return &timer_;
    462 }
    463 
    464 }  // namespace browser_sync
    465