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
BuildAssociationStatsFromMergeResults(const syncer::SyncMergeResult & local_merge_result,const syncer::SyncMergeResult & syncer_merge_result,const base::TimeDelta & association_wait_time,const base::TimeDelta & association_time)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
ModelAssociationManager(const DataTypeController::TypeMap * controllers,ModelAssociationManagerDelegate * processor)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
~ModelAssociationManager()126 ModelAssociationManager::~ModelAssociationManager() {
127 }
128
Initialize(syncer::ModelTypeSet desired_types)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
StopDatatype(DataTypeController * dtc)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
StopDisabledTypes()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
LoadEnabledTypes()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
StartAssociationAsync(const syncer::ModelTypeSet & types_to_associate)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
ResetForNextAssociation()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
Stop()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
AppendToFailedDatatypesAndLogError(const syncer::SyncError & error)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
ModelLoadCallback(syncer::ModelType type,syncer::SyncError error)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
TypeStartCallback(syncer::ModelType type,base::TimeTicks type_start_time,DataTypeController::StartResult start_result,const syncer::SyncMergeResult & local_merge_result,const syncer::SyncMergeResult & syncer_merge_result)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
ModelAssociationDone()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>*
GetTimerForTesting()460 ModelAssociationManager::GetTimerForTesting() {
461 return &timer_;
462 }
463
464 } // namespace browser_sync
465