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/glue/model_association_manager.h"
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"
16 using content::BrowserThread;
17 using syncer::ModelTypeSet;
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;
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::MANAGED_USERS, // Syncing managed users on initial login might
34 // block creating a new managed user, so we
35 // want to do it early.
37 syncer::PRIORITY_PREFERENCES,
41 syncer::SEARCH_ENGINES,
43 syncer::APP_NOTIFICATIONS,
45 syncer::FAVICON_IMAGES,
46 syncer::FAVICON_TRACKING,
47 syncer::MANAGED_USER_SETTINGS,
49 syncer::AUTOFILL, // Non-UI thread datatypes.
50 syncer::AUTOFILL_PROFILE,
51 syncer::EXTENSION_SETTINGS,
55 syncer::HISTORY_DELETE_DIRECTIVES,
56 syncer::SYNCED_NOTIFICATIONS,
59 COMPILE_ASSERT(arraysize(kStartOrder) ==
60 syncer::MODEL_TYPE_COUNT - syncer::FIRST_REAL_MODEL_TYPE,
61 kStartOrder_IncorrectSize);
63 // Comparator used when sorting data type controllers.
64 class SortComparator : public std::binary_function<DataTypeController*,
68 explicit SortComparator(std::map<syncer::ModelType, int>* order)
71 // Returns true if lhs precedes rhs.
72 bool operator() (DataTypeController* lhs, DataTypeController* rhs) {
73 return (*order_)[lhs->type()] < (*order_)[rhs->type()];
77 std::map<syncer::ModelType, int>* order_;
80 syncer::DataTypeAssociationStats BuildAssociationStatsFromMergeResults(
81 const syncer::SyncMergeResult& local_merge_result,
82 const syncer::SyncMergeResult& syncer_merge_result,
83 const base::TimeDelta& association_wait_time,
84 const base::TimeDelta& association_time) {
85 DCHECK_EQ(local_merge_result.model_type(), syncer_merge_result.model_type());
86 syncer::DataTypeAssociationStats stats;
87 stats.had_error = local_merge_result.error().IsSet() ||
88 syncer_merge_result.error().IsSet();
89 stats.num_local_items_before_association =
90 local_merge_result.num_items_before_association();
91 stats.num_sync_items_before_association =
92 syncer_merge_result.num_items_before_association();
93 stats.num_local_items_after_association =
94 local_merge_result.num_items_after_association();
95 stats.num_sync_items_after_association =
96 syncer_merge_result.num_items_after_association();
97 stats.num_local_items_added =
98 local_merge_result.num_items_added();
99 stats.num_local_items_deleted =
100 local_merge_result.num_items_deleted();
101 stats.num_local_items_modified =
102 local_merge_result.num_items_modified();
103 stats.local_version_pre_association =
104 local_merge_result.pre_association_version();
105 stats.num_sync_items_added =
106 syncer_merge_result.num_items_added();
107 stats.num_sync_items_deleted =
108 syncer_merge_result.num_items_deleted();
109 stats.num_sync_items_modified =
110 syncer_merge_result.num_items_modified();
111 stats.sync_version_pre_association =
112 syncer_merge_result.pre_association_version();
113 stats.association_wait_time = association_wait_time;
114 stats.association_time = association_time;
120 ModelAssociationManager::ModelAssociationManager(
121 const DataTypeController::TypeMap* controllers,
122 ModelAssociationResultProcessor* processor)
124 currently_associating_(NULL),
125 controllers_(controllers),
126 result_processor_(processor),
127 weak_ptr_factory_(this) {
129 // Ensure all data type controllers are stopped.
130 for (DataTypeController::TypeMap::const_iterator it = controllers_->begin();
131 it != controllers_->end(); ++it) {
132 DCHECK_EQ(DataTypeController::NOT_RUNNING, (*it).second->state());
135 // Build a ModelType -> order map for sorting.
136 for (int i = 0; i < static_cast<int>(arraysize(kStartOrder)); i++)
137 start_order_[kStartOrder[i]] = i;
140 ModelAssociationManager::~ModelAssociationManager() {
143 void ModelAssociationManager::Initialize(syncer::ModelTypeSet desired_types) {
144 // TODO(tim): Bug 134550. CHECKing to ensure no reentrancy on dev channel.
146 CHECK_EQ(state_, IDLE);
147 needs_start_.clear();
149 failed_data_types_info_.clear();
150 associating_types_.Clear();
151 needs_crypto_types_.Clear();
152 state_ = INITIALIZED_TO_CONFIGURE;
154 DVLOG(1) << "ModelAssociationManager: Initializing for "
155 << syncer::ModelTypeSetToString(desired_types);
157 // Stop the types that are still loading from the previous configuration.
158 // If they are enabled we will start them here once again.
159 for (std::vector<DataTypeController*>::const_iterator it =
160 pending_model_load_.begin();
161 it != pending_model_load_.end();
163 DVLOG(1) << "ModelAssociationManager: Stopping "
165 << " before initialization";
169 pending_model_load_.clear();
170 waiting_to_associate_.clear();
171 currently_associating_ = NULL;
173 // Add any data type controllers into that needs_stop_ list that are
174 // currently MODEL_STARTING, ASSOCIATING, RUNNING or DISABLED.
175 for (DataTypeController::TypeMap::const_iterator it = controllers_->begin();
176 it != controllers_->end(); ++it) {
177 DataTypeController* dtc = (*it).second.get();
178 if (!desired_types.Has(dtc->type()) &&
179 (dtc->state() == DataTypeController::MODEL_STARTING ||
180 dtc->state() == DataTypeController::ASSOCIATING ||
181 dtc->state() == DataTypeController::RUNNING ||
182 dtc->state() == DataTypeController::DISABLED)) {
183 needs_stop_.push_back(dtc);
184 DVLOG(1) << "ModelTypeToString: Will stop " << dtc->name();
187 // Sort these according to kStartOrder.
188 std::sort(needs_stop_.begin(),
190 SortComparator(&start_order_));
193 void ModelAssociationManager::StartAssociationAsync(
194 const syncer::ModelTypeSet& types_to_associate) {
195 DCHECK(state_ == INITIALIZED_TO_CONFIGURE || state_ == IDLE);
196 state_ = CONFIGURING;
198 // Calculate |needs_start_| list.
199 associating_types_ = types_to_associate;
200 GetControllersNeedingStart(&needs_start_);
201 // Sort these according to kStartOrder.
202 std::sort(needs_start_.begin(),
204 SortComparator(&start_order_));
206 DVLOG(1) << "ModelAssociationManager: Going to start model association";
207 association_start_time_ = base::Time::Now();
208 LoadModelForNextType();
211 void ModelAssociationManager::ResetForReconfiguration() {
213 DVLOG(1) << "ModelAssociationManager: Reseting for reconfiguration";
214 needs_start_.clear();
216 associating_types_.Clear();
217 failed_data_types_info_.clear();
218 needs_crypto_types_.Clear();
221 void ModelAssociationManager::StopDisabledTypes() {
222 DVLOG(1) << "ModelAssociationManager: Stopping disabled types.";
223 // Stop requested data types.
224 for (size_t i = 0; i < needs_stop_.size(); ++i) {
225 DVLOG(1) << "ModelAssociationManager: Stopping " << needs_stop_[i]->name();
226 needs_stop_[i]->Stop();
231 void ModelAssociationManager::Stop() {
232 bool need_to_call_model_association_done = false;
233 DVLOG(1) << "ModelAssociationManager: Stopping MAM";
234 if (state_ == CONFIGURING) {
235 DVLOG(1) << "ModelAssociationManager: In the middle of configuration while"
238 DCHECK(currently_associating_ != NULL ||
239 needs_start_.size() > 0 ||
240 pending_model_load_.size() > 0 ||
241 waiting_to_associate_.size() > 0);
243 if (currently_associating_) {
244 TRACE_EVENT_ASYNC_END1("sync", "ModelAssociation",
245 currently_associating_,
247 ModelTypeToString(currently_associating_->type()));
248 DVLOG(1) << "ModelAssociationManager: stopping "
249 << currently_associating_->name();
250 currently_associating_->Stop();
252 // DTCs in other lists would be stopped below.
256 DCHECK_EQ(IDLE, state_);
258 // We are in the midle of model association. We need to inform the caller
259 // so the caller can send notificationst to PSS layer.
260 need_to_call_model_association_done = true;
263 // Now continue stopping any types that have already started.
264 DCHECK(state_ == IDLE ||
265 state_ == INITIALIZED_TO_CONFIGURE);
266 for (DataTypeController::TypeMap::const_iterator it = controllers_->begin();
267 it != controllers_->end(); ++it) {
268 DataTypeController* dtc = (*it).second.get();
269 if (dtc->state() != DataTypeController::NOT_RUNNING &&
270 dtc->state() != DataTypeController::STOPPING) {
272 DVLOG(1) << "ModelAssociationManager: Stopped " << dtc->name();
276 DataTypeManager::ConfigureResult result(DataTypeManager::ABORTED,
278 failed_data_types_info_,
279 syncer::ModelTypeSet(),
280 needs_crypto_types_);
281 failed_data_types_info_.clear();
282 needs_crypto_types_.Clear();
283 if (need_to_call_model_association_done) {
284 DVLOG(1) << "ModelAssociationManager: Calling OnModelAssociationDone";
285 result_processor_->OnModelAssociationDone(result);
289 bool ModelAssociationManager::GetControllersNeedingStart(
290 std::vector<DataTypeController*>* needs_start) {
291 DVLOG(1) << "ModelAssociationManager: GetControllersNeedingStart";
292 // Add any data type controllers into the needs_start_ list that are
293 // currently NOT_RUNNING or STOPPING.
294 bool found_any = false;
295 for (ModelTypeSet::Iterator it = associating_types_.First();
296 it.Good(); it.Inc()) {
297 DataTypeController::TypeMap::const_iterator dtc =
298 controllers_->find(it.Get());
299 if (dtc != controllers_->end() &&
300 (dtc->second->state() == DataTypeController::NOT_RUNNING ||
301 dtc->second->state() == DataTypeController::STOPPING)) {
304 needs_start->push_back(dtc->second.get());
305 if (dtc->second->state() == DataTypeController::DISABLED) {
306 DVLOG(1) << "ModelAssociationManager: Found "\
307 << syncer::ModelTypeToString(dtc->second->type())
308 << " in disabled state.";
315 void ModelAssociationManager::AppendToFailedDatatypesAndLogError(
316 DataTypeController::StartResult result,
317 const syncer::SyncError& error) {
318 failed_data_types_info_[error.model_type()] = error;
319 LOG(ERROR) << "Failed to associate models for "
320 << syncer::ModelTypeToString(error.model_type());
321 UMA_HISTOGRAM_ENUMERATION("Sync.ConfigureFailed",
322 ModelTypeToHistogramInt(error.model_type()),
323 syncer::MODEL_TYPE_COUNT);
326 void ModelAssociationManager::TypeStartCallback(
327 DataTypeController::StartResult start_result,
328 const syncer::SyncMergeResult& local_merge_result,
329 const syncer::SyncMergeResult& syncer_merge_result) {
330 DCHECK(BrowserThread::CurrentlyOn(BrowserThread::UI));
331 TRACE_EVENT_ASYNC_END1("sync", "ModelAssociation",
332 currently_associating_,
334 ModelTypeToString(currently_associating_->type()));
336 DVLOG(1) << "ModelAssociationManager: TypeStartCallback";
337 if (state_ == ABORTED) {
338 // Now that we have finished with the current type we can stop
339 // if abort was called.
340 DVLOG(1) << "ModelAssociationManager: Doing an early return"
341 << " because of abort";
346 DCHECK(state_ == CONFIGURING);
348 // We are done with this type. Clear it.
349 DataTypeController* started_dtc = currently_associating_;
350 currently_associating_ = NULL;
352 if (start_result == DataTypeController::ASSOCIATION_FAILED) {
353 DVLOG(1) << "ModelAssociationManager: Encountered a failed type";
354 AppendToFailedDatatypesAndLogError(start_result,
355 local_merge_result.error());
356 } else if (start_result == DataTypeController::NEEDS_CRYPTO) {
357 DVLOG(1) << "ModelAssociationManager: Encountered an undecryptable type";
358 needs_crypto_types_.Put(started_dtc->type());
361 // Track the merge results if we succeeded or an association failure
363 if ((DataTypeController::IsSuccessfulResult(start_result) ||
364 start_result == DataTypeController::ASSOCIATION_FAILED) &&
365 syncer::ProtocolTypes().Has(local_merge_result.model_type())) {
366 base::TimeDelta association_wait_time =
367 current_type_association_start_time_ - association_start_time_;
368 base::TimeDelta association_time =
369 base::Time::Now() - current_type_association_start_time_;
370 syncer::DataTypeAssociationStats stats =
371 BuildAssociationStatsFromMergeResults(local_merge_result,
373 association_wait_time,
375 result_processor_->OnSingleDataTypeAssociationDone(
376 local_merge_result.model_type(), stats);
379 // If the type started normally, continue to the next type.
380 // If the type is waiting for the cryptographer, continue to the next type.
381 // Once the cryptographer is ready, we'll attempt to restart this type.
382 // If this type encountered a type specific error continue to the next type.
383 if (start_result == DataTypeController::NEEDS_CRYPTO ||
384 DataTypeController::IsSuccessfulResult(start_result) ||
385 start_result == DataTypeController::ASSOCIATION_FAILED) {
387 DVLOG(1) << "ModelAssociationManager: type start callback returned "
388 << start_result << " so calling LoadModelForNextType";
389 LoadModelForNextType();
393 // Any other result requires reconfiguration. Pass it on through the callback.
394 LOG(ERROR) << "Failed to configure " << started_dtc->name();
395 DCHECK(local_merge_result.error().IsSet());
396 DCHECK_EQ(started_dtc->type(), local_merge_result.error().model_type());
397 DataTypeManager::ConfigureStatus configure_status =
398 DataTypeManager::ABORTED;
399 switch (start_result) {
400 case DataTypeController::ABORTED:
401 configure_status = DataTypeManager::ABORTED;
403 case DataTypeController::UNRECOVERABLE_ERROR:
404 configure_status = DataTypeManager::UNRECOVERABLE_ERROR;
411 std::map<syncer::ModelType, syncer::SyncError> errors;
412 errors[local_merge_result.model_type()] = local_merge_result.error();
414 // Put our state to idle.
417 DataTypeManager::ConfigureResult configure_result(configure_status,
420 syncer::ModelTypeSet(),
421 needs_crypto_types_);
422 result_processor_->OnModelAssociationDone(configure_result);
425 void ModelAssociationManager::LoadModelForNextType() {
426 DVLOG(1) << "ModelAssociationManager: LoadModelForNextType";
427 if (!needs_start_.empty()) {
428 DVLOG(1) << "ModelAssociationManager: Starting " << needs_start_[0]->name();
430 DataTypeController* dtc = needs_start_[0];
431 needs_start_.erase(needs_start_.begin());
432 // Move from |needs_start_| to |pending_model_load_|.
433 pending_model_load_.insert(pending_model_load_.begin(), dtc);
434 timer_.Start(FROM_HERE,
435 base::TimeDelta::FromSeconds(kDataTypeLoadWaitTimeInSeconds),
437 &ModelAssociationManager::LoadModelForNextType);
438 dtc->LoadModels(base::Bind(
439 &ModelAssociationManager::ModelLoadCallback,
440 weak_ptr_factory_.GetWeakPtr()));
445 DVLOG(1) << "ModelAssociationManager: All types have models loaded. "
446 << "Moving on to StartAssociatingNextType.";
448 // If all controllers have their |LoadModels| invoked then pass onto
449 // |StartAssociatingNextType|.
450 StartAssociatingNextType();
453 void ModelAssociationManager::ModelLoadCallback(
454 syncer::ModelType type, syncer::SyncError error) {
455 DVLOG(1) << "ModelAssociationManager: ModelLoadCallback for "
456 << syncer::ModelTypeToString(type);
457 if (state_ == CONFIGURING) {
458 DVLOG(1) << "ModelAssociationManager: ModelLoadCallback while configuring";
459 for (std::vector<DataTypeController*>::iterator it =
460 pending_model_load_.begin();
461 it != pending_model_load_.end();
463 if ((*it)->type() == type) {
464 // Each type is given |kDataTypeLoadWaitTimeInSeconds| time to load
465 // (as controlled by the timer.). If the type does not load in that
466 // time we move on to the next type. However if the type does
467 // finish loading in that time we want to stop the timer. We stop
468 // the timer, if the type that loaded is the same as the type that
469 // we started the timer for(as indicated by the type on the head
471 // Note: Regardless of this timer value the associations will always
472 // take place serially. The only thing this timer controls is how serial
473 // the model load is. If this timer has a value of zero seconds then
474 // the model loads will all be parallel.
475 if (it == pending_model_load_.begin()) {
476 DVLOG(1) << "ModelAssociationManager: Stopping timer";
479 DataTypeController* dtc = *it;
480 pending_model_load_.erase(it);
481 if (!error.IsSet()) {
482 DVLOG(1) << "ModelAssociationManager:"
483 << " Calling StartAssociatingNextType";
484 waiting_to_associate_.push_back(dtc);
485 StartAssociatingNextType();
487 DVLOG(1) << "ModelAssociationManager: Encountered error loading";
488 syncer::SyncMergeResult local_merge_result(type);
489 local_merge_result.set_error(error);
490 TypeStartCallback(DataTypeController::ASSOCIATION_FAILED,
492 syncer::SyncMergeResult(type));
499 } else if (state_ == IDLE) {
500 DVLOG(1) << "ModelAssociationManager: Models loaded after configure cycle. "
502 // This datatype finished loading after the deadline imposed by the
503 // originating configuration cycle. Inform the DataTypeManager that the
504 // type has loaded, so that association may begin.
505 result_processor_->OnTypesLoaded();
507 // If we're not IDLE or CONFIGURING, we're being invoked as part of an abort
508 // process (possibly a reconfiguration, or disabling of a broken data type).
509 DVLOG(1) << "ModelAssociationManager: ModelLoadCallback occurred while "
510 << "not IDLE or CONFIGURING. Doing nothing.";
515 void ModelAssociationManager::StartAssociatingNextType() {
516 DCHECK_EQ(state_, CONFIGURING);
517 DCHECK_EQ(currently_associating_, static_cast<DataTypeController*>(NULL));
519 DVLOG(1) << "ModelAssociationManager: StartAssociatingNextType";
520 if (!waiting_to_associate_.empty()) {
521 DVLOG(1) << "ModelAssociationManager: Starting "
522 << waiting_to_associate_[0]->name();
523 DataTypeController* dtc = waiting_to_associate_[0];
524 waiting_to_associate_.erase(waiting_to_associate_.begin());
525 currently_associating_ = dtc;
526 current_type_association_start_time_ = base::Time::Now();
527 TRACE_EVENT_ASYNC_BEGIN1("sync", "ModelAssociation",
528 currently_associating_,
530 ModelTypeToString(currently_associating_->type()));
531 dtc->StartAssociating(base::Bind(
532 &ModelAssociationManager::TypeStartCallback,
533 weak_ptr_factory_.GetWeakPtr()));
537 // We are done with this cycle of association. Stop any failed types now.
539 for (DataTypeController::TypeMap::const_iterator it = controllers_->begin();
540 it != controllers_->end(); ++it) {
541 DataTypeController* dtc = (*it).second.get();
542 if (failed_data_types_info_.count(dtc->type()) > 0 &&
543 dtc->state() != DataTypeController::NOT_RUNNING) {
544 needs_stop_.push_back(dtc);
545 DVLOG(1) << "ModelTypeToString: Will stop " << dtc->name();
552 DataTypeManager::ConfigureStatus configure_status = DataTypeManager::OK;
554 if (!failed_data_types_info_.empty() ||
555 !GetTypesWaitingToLoad().Empty() ||
556 !needs_crypto_types_.Empty()) {
557 // We have not configured all types that we have been asked to configure.
558 // Either we have failed types or types that have not completed loading
560 DVLOG(1) << "ModelAssociationManager: setting partial success";
561 configure_status = DataTypeManager::PARTIAL_SUCCESS;
564 DataTypeManager::ConfigureResult result(configure_status,
566 failed_data_types_info_,
567 GetTypesWaitingToLoad(),
568 needs_crypto_types_);
569 result_processor_->OnModelAssociationDone(result);
573 syncer::ModelTypeSet ModelAssociationManager::GetTypesWaitingToLoad() {
574 syncer::ModelTypeSet result;
575 for (std::vector<DataTypeController*>::const_iterator it =
576 pending_model_load_.begin();
577 it != pending_model_load_.end();
579 result.Put((*it)->type());
584 base::OneShotTimer<ModelAssociationManager>*
585 ModelAssociationManager::GetTimerForTesting() {
589 } // namespace browser_sync