chrome/browser/sync/glue/model_association_manager.cc

   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.
   4
   5 #include "chrome/browser/sync/glue/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.h"
  13 #include "base/metrics/histogram.h"
  14 #include "sync/internal_api/public/base/model_type.h"
  15
  16 using content::BrowserThread;
  17 using syncer::ModelTypeSet;
  18
  19 namespace browser_sync {
  20 // The amount of time we wait for a datatype to load. If the type has
  21 // not finished loading we move on to the next type. Once this type
  22 // finishes loading we will do a configure to associate this type. Note
  23 // that in most cases types finish loading before this timeout.
  24 const int64 kDataTypeLoadWaitTimeInSeconds = 120;
  25 namespace {
  26
  27 static const syncer::ModelType kStartOrder[] = {
  28   syncer::NIGORI,               //  Listed for completeness.
  29   syncer::DEVICE_INFO,          //  Listed for completeness.
  30   syncer::EXPERIMENTS,          //  Listed for completeness.
  31   syncer::PROXY_TABS,           //  Listed for completeness.
  32   syncer::BOOKMARKS,            //  UI thread datatypes.
  33   syncer::PREFERENCES,
  34   syncer::PRIORITY_PREFERENCES,
  35   syncer::EXTENSIONS,
  36   syncer::APPS,
  37   syncer::THEMES,
  38   syncer::SEARCH_ENGINES,
  39   syncer::SESSIONS,
  40   syncer::APP_NOTIFICATIONS,
  41   syncer::DICTIONARY,
  42   syncer::FAVICON_IMAGES,
  43   syncer::FAVICON_TRACKING,
  44   syncer::AUTOFILL,             // Non-UI thread datatypes.
  45   syncer::AUTOFILL_PROFILE,
  46   syncer::EXTENSION_SETTINGS,
  47   syncer::APP_SETTINGS,
  48   syncer::TYPED_URLS,
  49   syncer::PASSWORDS,
  50   syncer::HISTORY_DELETE_DIRECTIVES,
  51   syncer::SYNCED_NOTIFICATIONS,
  52 };
  53
  54 COMPILE_ASSERT(arraysize(kStartOrder) ==
  55                syncer::MODEL_TYPE_COUNT - syncer::FIRST_REAL_MODEL_TYPE,
  56                kStartOrder_IncorrectSize);
  57
  58 // Comparator used when sorting data type controllers.
  59 class SortComparator : public std::binary_function<DataTypeController*,
  60                                                    DataTypeController*,
  61                                                    bool> {
  62  public:
  63   explicit SortComparator(std::map<syncer::ModelType, int>* order)
  64       : order_(order) { }
  65
  66   // Returns true if lhs precedes rhs.
  67   bool operator() (DataTypeController* lhs, DataTypeController* rhs) {
  68     return (*order_)[lhs->type()] < (*order_)[rhs->type()];
  69   }
  70
  71  private:
  72   std::map<syncer::ModelType, int>* order_;
  73 };
  74
  75 syncer::DataTypeAssociationStats BuildAssociationStatsFromMergeResults(
  76     const syncer::SyncMergeResult& local_merge_result,
  77     const syncer::SyncMergeResult& syncer_merge_result) {
  78   DCHECK_EQ(local_merge_result.model_type(), syncer_merge_result.model_type());
  79   syncer::DataTypeAssociationStats stats;
  80   stats.model_type = local_merge_result.model_type();
  81   stats.had_error = local_merge_result.error().IsSet() ||
  82                     syncer_merge_result.error().IsSet();
  83   stats.num_local_items_before_association =
  84       local_merge_result.num_items_before_association();
  85   stats.num_sync_items_before_association =
  86       syncer_merge_result.num_items_before_association();
  87   stats.num_local_items_after_association =
  88       local_merge_result.num_items_after_association();
  89   stats.num_sync_items_after_association =
  90       syncer_merge_result.num_items_after_association();
  91   stats.num_local_items_added =
  92       local_merge_result.num_items_added();
  93   stats.num_local_items_deleted =
  94       local_merge_result.num_items_deleted();
  95   stats.num_local_items_modified =
  96       local_merge_result.num_items_modified();
  97   stats.num_sync_items_added =
  98       syncer_merge_result.num_items_added();
  99   stats.num_sync_items_deleted =
 100       syncer_merge_result.num_items_deleted();
 101   stats.num_sync_items_modified =
 102       syncer_merge_result.num_items_modified();
 103   return stats;
 104 }
 105
 106 }  // namespace
 107
 108 ModelAssociationManager::ModelAssociationManager(
 109     const syncer::WeakHandle<syncer::DataTypeDebugInfoListener>&
 110         debug_info_listener,
 111     const DataTypeController::TypeMap* controllers,
 112     ModelAssociationResultProcessor* processor)
 113     : state_(IDLE),
 114       currently_associating_(NULL),
 115       controllers_(controllers),
 116       result_processor_(processor),
 117       debug_info_listener_(debug_info_listener),
 118       weak_ptr_factory_(ALLOW_THIS_IN_INITIALIZER_LIST(this)) {
 119
 120   // Ensure all data type controllers are stopped.
 121   for (DataTypeController::TypeMap::const_iterator it = controllers_->begin();
 122        it != controllers_->end(); ++it) {
 123     DCHECK_EQ(DataTypeController::NOT_RUNNING, (*it).second->state());
 124   }
 125
 126   // Build a ModelType -> order map for sorting.
 127   for (int i = 0; i < static_cast<int>(arraysize(kStartOrder)); i++)
 128     start_order_[kStartOrder[i]] = i;
 129 }
 130
 131 ModelAssociationManager::~ModelAssociationManager() {
 132 }
 133
 134 void ModelAssociationManager::Initialize(syncer::ModelTypeSet desired_types) {
 135   // TODO(tim): Bug 134550.  CHECKing to ensure no reentrancy on dev channel.
 136   // Remove this.
 137   CHECK_EQ(state_, IDLE);
 138   needs_start_.clear();
 139   needs_stop_.clear();
 140   failed_datatypes_info_.clear();
 141   desired_types_ = desired_types;
 142   state_ = INITIALIZED_TO_CONFIGURE;
 143
 144   DVLOG(1) << "ModelAssociationManager: Initializing";
 145
 146   // Stop the types that are still loading from the previous configuration.
 147   // If they are enabled we will start them here once again.
 148   for (std::vector<DataTypeController*>::const_iterator it =
 149            pending_model_load_.begin();
 150        it != pending_model_load_.end();
 151        ++it) {
 152     DVLOG(1) << "ModelAssociationManager: Stopping "
 153              << (*it)->name()
 154              << " before initialization";
 155     (*it)->Stop();
 156   }
 157
 158   pending_model_load_.clear();
 159   waiting_to_associate_.clear();
 160   currently_associating_ = NULL;
 161
 162   // We need to calculate our |needs_start_| and |needs_stop_| list.
 163   GetControllersNeedingStart(&needs_start_);
 164   // Sort these according to kStartOrder.
 165   std::sort(needs_start_.begin(),
 166             needs_start_.end(),
 167             SortComparator(&start_order_));
 168
 169   // Add any data type controllers into that needs_stop_ list that are
 170   // currently MODEL_STARTING, ASSOCIATING, RUNNING or DISABLED.
 171   for (DataTypeController::TypeMap::const_iterator it = controllers_->begin();
 172        it != controllers_->end(); ++it) {
 173     DataTypeController* dtc = (*it).second;
 174     if (!desired_types.Has(dtc->type()) && (
 175             dtc->state() == DataTypeController::MODEL_STARTING ||
 176             dtc->state() == DataTypeController::ASSOCIATING ||
 177             dtc->state() == DataTypeController::RUNNING ||
 178             dtc->state() == DataTypeController::DISABLED)) {
 179       needs_stop_.push_back(dtc);
 180       DVLOG(1) << "ModelTypeToString: Will stop " << dtc->name();
 181     }
 182   }
 183   // Sort these according to kStartOrder.
 184   std::sort(needs_stop_.begin(),
 185             needs_stop_.end(),
 186             SortComparator(&start_order_));
 187 }
 188
 189 void ModelAssociationManager::StartAssociationAsync() {
 190   DCHECK_EQ(state_, INITIALIZED_TO_CONFIGURE);
 191   state_ = CONFIGURING;
 192   DVLOG(1) << "ModelAssociationManager: Going to start model association";
 193   LoadModelForNextType();
 194 }
 195
 196 void ModelAssociationManager::ResetForReconfiguration() {
 197   DCHECK_EQ(state_, INITIALIZED_TO_CONFIGURE);
 198   state_ = IDLE;
 199   DVLOG(1) << "ModelAssociationManager: Reseting for reconfiguration";
 200   needs_start_.clear();
 201   needs_stop_.clear();
 202   failed_datatypes_info_.clear();
 203 }
 204
 205 void ModelAssociationManager::StopDisabledTypes() {
 206   DCHECK_EQ(state_, INITIALIZED_TO_CONFIGURE);
 207   DVLOG(1) << "ModelAssociationManager: Stopping disabled types.";
 208   // Stop requested data types.
 209   for (size_t i = 0; i < needs_stop_.size(); ++i) {
 210     DVLOG(1) << "ModelAssociationManager: Stopping " << needs_stop_[i]->name();
 211     needs_stop_[i]->Stop();
 212   }
 213   needs_stop_.clear();
 214 }
 215
 216 void ModelAssociationManager::Stop() {
 217   bool need_to_call_model_association_done = false;
 218   DVLOG(1) << "ModelAssociationManager: Stopping MAM";
 219   if (state_ == CONFIGURING) {
 220     DVLOG(1) << "ModelAssociationManager: In the middle of configuratio while"
 221              << " stopping";
 222     state_ = ABORTED;
 223     DCHECK(currently_associating_ != NULL ||
 224            needs_start_.size() > 0 ||
 225            pending_model_load_.size() > 0 ||
 226            waiting_to_associate_.size() > 0);
 227
 228     if (currently_associating_) {
 229       TRACE_EVENT_END0("sync", "ModelAssociation");
 230       DVLOG(1) << "ModelAssociationManager: stopping "
 231                << currently_associating_->name();
 232       currently_associating_->Stop();
 233     } else {
 234       // DTCs in other lists would be stopped below.
 235       state_ = IDLE;
 236     }
 237
 238     DCHECK_EQ(IDLE, state_);
 239
 240     // We are in the midle of model association. We need to inform the caller
 241     // so the caller can send notificationst to PSS layer.
 242     need_to_call_model_association_done = true;
 243   }
 244
 245   // Now continue stopping any types that have already started.
 246   DCHECK(state_ == IDLE ||
 247          state_ == INITIALIZED_TO_CONFIGURE);
 248   for (DataTypeController::TypeMap::const_iterator it = controllers_->begin();
 249        it != controllers_->end(); ++it) {
 250     DataTypeController* dtc = (*it).second;
 251     if (dtc->state() != DataTypeController::NOT_RUNNING &&
 252         dtc->state() != DataTypeController::STOPPING) {
 253       dtc->Stop();
 254       DVLOG(1) << "ModelAssociationManager: Stopped " << dtc->name();
 255     }
 256   }
 257
 258   if (need_to_call_model_association_done) {
 259     DVLOG(1) << "ModelAssociationManager: Calling OnModelAssociationDone";
 260     DataTypeManager::ConfigureResult result(DataTypeManager::ABORTED,
 261                                             desired_types_,
 262                                             failed_datatypes_info_,
 263                                             syncer::ModelTypeSet());
 264     result_processor_->OnModelAssociationDone(result);
 265   }
 266
 267   failed_datatypes_info_.clear();
 268 }
 269
 270 bool ModelAssociationManager::GetControllersNeedingStart(
 271     std::vector<DataTypeController*>* needs_start) {
 272   DVLOG(1) << "ModelAssociationManager: GetControllersNeedingStart";
 273   // Add any data type controllers into the needs_start_ list that are
 274   // currently NOT_RUNNING or STOPPING.
 275   bool found_any = false;
 276   for (ModelTypeSet::Iterator it = desired_types_.First();
 277        it.Good(); it.Inc()) {
 278     DataTypeController::TypeMap::const_iterator dtc =
 279         controllers_->find(it.Get());
 280     if (dtc != controllers_->end() &&
 281         (dtc->second->state() == DataTypeController::NOT_RUNNING ||
 282          dtc->second->state() == DataTypeController::STOPPING)) {
 283       found_any = true;
 284       if (needs_start)
 285         needs_start->push_back(dtc->second.get());
 286       if (dtc->second->state() == DataTypeController::DISABLED) {
 287         DVLOG(1) << "ModelAssociationManager: Found "\
 288                 << syncer::ModelTypeToString(dtc->second->type())
 289                  << " in disabled state.";
 290       }
 291     }
 292   }
 293   return found_any;
 294 }
 295
 296 void ModelAssociationManager::AppendToFailedDatatypesAndLogError(
 297     DataTypeController::StartResult result,
 298     const syncer::SyncError& error) {
 299   failed_datatypes_info_.push_back(error);
 300   LOG(ERROR) << "Failed to associate models for "
 301              << syncer::ModelTypeToString(error.type());
 302   UMA_HISTOGRAM_ENUMERATION("Sync.ConfigureFailed",
 303                             ModelTypeToHistogramInt(error.type()),
 304                             syncer::MODEL_TYPE_COUNT);
 305 }
 306
 307 void ModelAssociationManager::TypeStartCallback(
 308     DataTypeController::StartResult start_result,
 309     const syncer::SyncMergeResult& local_merge_result,
 310     const syncer::SyncMergeResult& syncer_merge_result) {
 311   DCHECK(BrowserThread::CurrentlyOn(BrowserThread::UI));
 312   TRACE_EVENT_END0("sync", "ModelAssociation");
 313
 314   DVLOG(1) << "ModelAssociationManager: TypeStartCallback";
 315   if (state_ == ABORTED) {
 316     // Now that we have finished with the current type we can stop
 317     // if abort was called.
 318     DVLOG(1) << "ModelAssociationManager: Doing an early return"
 319              << " because of abort";
 320     state_ = IDLE;
 321     return;
 322   }
 323
 324   DCHECK(state_ == CONFIGURING);
 325
 326   // We are done with this type. Clear it.
 327   DataTypeController* started_dtc = currently_associating_;
 328   currently_associating_ = NULL;
 329
 330   if (start_result == DataTypeController::ASSOCIATION_FAILED) {
 331     DVLOG(1) << "ModelAssociationManager: Encountered a failed type";
 332     AppendToFailedDatatypesAndLogError(start_result,
 333                                        local_merge_result.error());
 334   }
 335
 336   // Track the merge results if we succeeded or an association failure
 337   // occurred.
 338   if ((DataTypeController::IsSuccessfulResult(start_result) ||
 339        start_result == DataTypeController::ASSOCIATION_FAILED) &&
 340       debug_info_listener_.IsInitialized() &&
 341       syncer::ProtocolTypes().Has(local_merge_result.model_type())) {
 342     syncer::DataTypeAssociationStats stats =
 343         BuildAssociationStatsFromMergeResults(local_merge_result,
 344                                               syncer_merge_result);
 345     debug_info_listener_.Call(
 346         FROM_HERE,
 347         &syncer::DataTypeDebugInfoListener::OnDataTypeAssociationComplete,
 348         stats);
 349   }
 350
 351   // If the type started normally, continue to the next type.
 352   // If the type is waiting for the cryptographer, continue to the next type.
 353   // Once the cryptographer is ready, we'll attempt to restart this type.
 354   // If this type encountered a type specific error continue to the next type.
 355   if (start_result == DataTypeController::NEEDS_CRYPTO ||
 356       DataTypeController::IsSuccessfulResult(start_result) ||
 357       start_result == DataTypeController::ASSOCIATION_FAILED) {
 358
 359     DVLOG(1) << "ModelAssociationManager: type start callback returned "
 360              << start_result << " so calling LoadModelForNextType";
 361     LoadModelForNextType();
 362     return;
 363   }
 364
 365   // Any other result requires reconfiguration. Pass it on through the callback.
 366   LOG(ERROR) << "Failed to configure " << started_dtc->name();
 367   DCHECK(local_merge_result.error().IsSet());
 368   DCHECK_EQ(started_dtc->type(), local_merge_result.error().type());
 369   DataTypeManager::ConfigureStatus configure_status =
 370       DataTypeManager::ABORTED;
 371   switch (start_result) {
 372     case DataTypeController::ABORTED:
 373       configure_status = DataTypeManager::ABORTED;
 374       break;
 375     case DataTypeController::UNRECOVERABLE_ERROR:
 376       configure_status = DataTypeManager::UNRECOVERABLE_ERROR;
 377       break;
 378     default:
 379       NOTREACHED();
 380       break;
 381   }
 382
 383   std::list<syncer::SyncError> errors;
 384   errors.push_back(local_merge_result.error());
 385
 386   // Put our state to idle.
 387   state_ = IDLE;
 388
 389   DataTypeManager::ConfigureResult configure_result(configure_status,
 390                                                     desired_types_,
 391                                                     errors,
 392                                                     syncer::ModelTypeSet());
 393   result_processor_->OnModelAssociationDone(configure_result);
 394 }
 395
 396 void ModelAssociationManager::LoadModelForNextType() {
 397   DVLOG(1) << "ModelAssociationManager: LoadModelForNextType";
 398   if (!needs_start_.empty()) {
 399     DVLOG(1) << "ModelAssociationManager: Starting " << needs_start_[0]->name();
 400
 401     DataTypeController* dtc = needs_start_[0];
 402     needs_start_.erase(needs_start_.begin());
 403     // Move from |needs_start_| to |pending_model_load_|.
 404     pending_model_load_.insert(pending_model_load_.begin(), dtc);
 405     timer_.Start(FROM_HERE,
 406                  base::TimeDelta::FromSeconds(kDataTypeLoadWaitTimeInSeconds),
 407                  this,
 408                  &ModelAssociationManager::LoadModelForNextType);
 409     dtc->LoadModels(base::Bind(
 410         &ModelAssociationManager::ModelLoadCallback,
 411         weak_ptr_factory_.GetWeakPtr()));
 412
 413     return;
 414   }
 415
 416   DVLOG(1) << "ModelAssociationManager: All types have models loaded."
 417           << "Moving on to StartAssociatingNextType.";
 418
 419   // If all controllers have their |LoadModels| invoked then pass onto
 420   // |StartAssociatingNextType|.
 421   StartAssociatingNextType();
 422 }
 423
 424 void ModelAssociationManager::ModelLoadCallback(
 425     syncer::ModelType type, syncer::SyncError error) {
 426   DVLOG(1) << "ModelAssociationManager: ModelLoadCallback for "
 427           << syncer::ModelTypeToString(type);
 428   if (state_ == CONFIGURING) {
 429     DVLOG(1) << "ModelAssociationManager: ModelLoadCallback while configuring";
 430     for (std::vector<DataTypeController*>::iterator it =
 431              pending_model_load_.begin();
 432           it != pending_model_load_.end();
 433           ++it) {
 434       if ((*it)->type() == type) {
 435         // Each type is given |kDataTypeLoadWaitTimeInSeconds| time to load
 436         // (as controlled by the timer.). If the type does not load in that
 437         // time we move on to the next type. However if the type does
 438         // finish loading in that time we want to stop the timer. We stop
 439         // the timer, if the type that loaded is the same as the type that
 440         // we started the timer for(as indicated by the type on the head
 441         // of the list).
 442         // Note: Regardless of this timer value the associations will always
 443         // take place serially. The only thing this timer controls is how serial
 444         // the model load is. If this timer has a value of zero seconds then
 445         // the model loads will all be parallel.
 446         if (it == pending_model_load_.begin()) {
 447           DVLOG(1) << "ModelAssociationManager: Stopping timer";
 448           timer_.Stop();
 449         }
 450         DataTypeController* dtc = *it;
 451         pending_model_load_.erase(it);
 452         if (!error.IsSet()) {
 453           DVLOG(1) << "ModelAssociationManager:"
 454                   << " Calling StartAssociatingNextType";
 455           waiting_to_associate_.push_back(dtc);
 456           StartAssociatingNextType();
 457         } else {
 458           DVLOG(1) << "ModelAssociationManager: Encountered error loading";
 459           syncer::SyncMergeResult local_merge_result(type);
 460           local_merge_result.set_error(error);
 461           TypeStartCallback(DataTypeController::ASSOCIATION_FAILED,
 462                             local_merge_result,
 463                             syncer::SyncMergeResult(type));
 464        }
 465        return;
 466       }
 467     }
 468     NOTREACHED();
 469     return;
 470   } else if (state_ == IDLE) {
 471     DVLOG(1) << "ModelAssociationManager: Models loaded after configure cycle"
 472             << "Informing DTM";
 473     // This datatype finished loading after the deadline imposed by the
 474     // originating configuration cycle. Inform the DataTypeManager that the
 475     // type has loaded, so that association may begin.
 476     result_processor_->OnTypesLoaded();
 477   } else {
 478     // If we're not IDLE or CONFIGURING, we're being invoked as part of an abort
 479     // process (possibly a reconfiguration, or disabling of a broken data type).
 480     DVLOG(1) << "ModelAssociationManager: ModelLoadCallback occurred while "
 481              << "not IDLE or CONFIGURING. Doing nothing.";
 482   }
 483
 484 }
 485
 486 void ModelAssociationManager::StartAssociatingNextType() {
 487   DCHECK_EQ(state_, CONFIGURING);
 488   DCHECK_EQ(currently_associating_, static_cast<DataTypeController*>(NULL));
 489
 490   DVLOG(1) << "ModelAssociationManager: StartAssociatingNextType";
 491   if (!waiting_to_associate_.empty()) {
 492     DVLOG(1) << "ModelAssociationManager: Starting "
 493             << waiting_to_associate_[0]->name();
 494     TRACE_EVENT_BEGIN1("sync", "ModelAssociation",
 495                        "DataType",
 496                        ModelTypeToString(waiting_to_associate_[0]->type()));
 497     DataTypeController* dtc = waiting_to_associate_[0];
 498     waiting_to_associate_.erase(waiting_to_associate_.begin());
 499     currently_associating_ = dtc;
 500     dtc->StartAssociating(base::Bind(
 501         &ModelAssociationManager::TypeStartCallback,
 502         weak_ptr_factory_.GetWeakPtr()));
 503     return;
 504   }
 505
 506   // We are done with this cycle of association.
 507   state_ = IDLE;
 508   // Do a fresh calculation to see if controllers need starting to account for
 509   // things like encryption, which may still need to be sorted out before we
 510   // can announce we're "Done" configuration entirely.
 511   if (GetControllersNeedingStart(NULL)) {
 512     DVLOG(1) << "ModelAssociationManager: GetControllersNeedingStart"
 513              << " returned true. Blocking DataTypeManager";
 514
 515     DataTypeManager::ConfigureResult configure_result(
 516         DataTypeManager::CONFIGURE_BLOCKED,
 517         desired_types_,
 518         failed_datatypes_info_,
 519         syncer::ModelTypeSet());
 520     state_ = IDLE;
 521     result_processor_->OnModelAssociationDone(configure_result);
 522     return;
 523   }
 524
 525   DataTypeManager::ConfigureStatus configure_status = DataTypeManager::OK;
 526
 527   if (!failed_datatypes_info_.empty() ||
 528       !GetTypesWaitingToLoad().Empty()) {
 529     // We have not configured all types that we have been asked to configure.
 530     // Either we have failed types or types that have not completed loading
 531     // yet.
 532     DVLOG(1) << "ModelAssociationManager: setting partial success";
 533     configure_status = DataTypeManager::PARTIAL_SUCCESS;
 534   }
 535
 536   DataTypeManager::ConfigureResult result(configure_status,
 537                                           desired_types_,
 538                                           failed_datatypes_info_,
 539                                           GetTypesWaitingToLoad());
 540   result_processor_->OnModelAssociationDone(result);
 541   return;
 542 }
 543
 544 syncer::ModelTypeSet ModelAssociationManager::GetTypesWaitingToLoad() {
 545   syncer::ModelTypeSet result;
 546   for (std::vector<DataTypeController*>::const_iterator it =
 547            pending_model_load_.begin();
 548        it != pending_model_load_.end();
 549        ++it) {
 550     result.Put((*it)->type());
 551   }
 552   return result;
 553 }
 554
 555 base::OneShotTimer<ModelAssociationManager>*
 556     ModelAssociationManager::GetTimerForTesting() {
 557   return &timer_;
 558 }
 559
 560 }  // namespace browser_sync