[Sync] USS: Fix race condition in DeviceInfoService + add error handling

components/sync_driver/device_info_service.cc

 // Copyright 2015 The Chromium Authors. All rights reserved.
 // Use of this source code is governed by a BSD-style license that can be
 // found in the LICENSE file.
 
 #include "components/sync_driver/device_info_service.h"
 
 #include <set>
 #include <utility>
 #include <vector>
 
@@ skipping 62 matching lines @@
 DeviceInfoService::~DeviceInfoService() {}
 
 std::unique_ptr<MetadataChangeList>
 DeviceInfoService::CreateMetadataChangeList() {
   return base::WrapUnique(new SimpleMetadataChangeList());
 }
 
 SyncError DeviceInfoService::MergeSyncData(
     std::unique_ptr<MetadataChangeList> metadata_change_list,
     EntityDataMap entity_data_map) {
-  if (!has_provider_initialized_ || !has_metadata_loaded_ ||
-      !change_processor()) {
-    return SyncError(
-        FROM_HERE, SyncError::DATATYPE_ERROR,
-        "Cannot call MergeSyncData without provider, data, and processor.",
-        syncer::DEVICE_INFO);
-  }
+  DCHECK(has_provider_initialized_);
+  DCHECK(has_metadata_loaded_);
+  DCHECK(change_processor());
 
   // Local data should typically be near empty, with the only possible value
   // corresponding to this device. This is because on signout all device info
   // data is blown away. However, this simplification is being ignored here and
   // a full difference is going to be calculated to explore what other service
   // implementations may look like.
   std::set<std::string> local_guids_to_put;
   for (const auto& kv : all_data_) {
     local_guids_to_put.insert(kv.first);
   }
@@ skipping 27 matching lines @@
   }
 
   for (const std::string& guid : local_guids_to_put) {
     change_processor()->Put(DeviceInfoUtil::SpecificsToTag(*all_data_[guid]),
                             CopyToEntityData(*all_data_[guid]),
                             metadata_change_list.get());
   }
 
   CommitAndNotify(std::move(batch), std::move(metadata_change_list),
                   has_changes);
-  return syncer::SyncError();
+  return SyncError();
 }
 
 SyncError DeviceInfoService::ApplySyncChanges(
     std::unique_ptr<MetadataChangeList> metadata_change_list,
     EntityChangeList entity_changes) {
-  if (!has_provider_initialized_ || !has_metadata_loaded_) {
-    return SyncError(
-        FROM_HERE, SyncError::DATATYPE_ERROR,
-        "Cannot call ApplySyncChanges before provider and data have loaded.",
-        syncer::DEVICE_INFO);
-  }
+  DCHECK(has_provider_initialized_);
+  DCHECK(has_metadata_loaded_);
 
   std::unique_ptr<WriteBatch> batch = store_->CreateWriteBatch();
   bool has_changes = false;
   for (EntityChange& change : entity_changes) {
     const std::string guid =
         DeviceInfoUtil::TagToCacheGuid(change.client_tag());
     // Each device is the authoritative source for itself, ignore any remote
     // changes that have our local cache guid.
     if (guid == local_device_info_provider_->GetLocalDeviceInfo()->guid()) {
       continue;
@@ skipping 11 matching lines @@
     }
   }
 
   CommitAndNotify(std::move(batch), std::move(metadata_change_list),
                   has_changes);
   return SyncError();
 }
 
 void DeviceInfoService::GetData(ClientTagList client_tags,
                                 DataCallback callback) {
-  if (!has_metadata_loaded_) {
-    callback.Run(
-        SyncError(FROM_HERE, SyncError::DATATYPE_ERROR,
-                  "Should not call GetData before metadata has loaded.",
-                  syncer::DEVICE_INFO),
-        std::unique_ptr<DataBatchImpl>());
-    return;
-  }
+  DCHECK(has_metadata_loaded_);
 
   std::unique_ptr<DataBatchImpl> batch(new DataBatchImpl());
   for (const auto& tag : client_tags) {
     const auto& iter = all_data_.find(DeviceInfoUtil::TagToCacheGuid(tag));
     if (iter != all_data_.end()) {
       DCHECK_EQ(tag, DeviceInfoUtil::SpecificsToTag(*iter->second));
       batch->Put(tag, CopyToEntityData(*iter->second));
     }
   }
-  callback.Run(syncer::SyncError(), std::move(batch));
+
+  callback.Run(SyncError(), std::move(batch));
 }
 
 void DeviceInfoService::GetAllData(DataCallback callback) {
-  if (!has_metadata_loaded_) {
-    callback.Run(
-        SyncError(FROM_HERE, SyncError::DATATYPE_ERROR,
-                  "Should not call GetAllData before metadata has loaded.",
-                  syncer::DEVICE_INFO),
-        std::unique_ptr<DataBatchImpl>());
-    return;
-  }
+  DCHECK(has_metadata_loaded_);
 
   std::unique_ptr<DataBatchImpl> batch(new DataBatchImpl());
   for (const auto& kv : all_data_) {
     batch->Put(DeviceInfoUtil::SpecificsToTag(*kv.second),
                CopyToEntityData(*kv.second));
   }
-  callback.Run(syncer::SyncError(), std::move(batch));
+
+  callback.Run(SyncError(), std::move(batch));
 }
 
 std::string DeviceInfoService::GetClientTag(const EntityData& entity_data) {
   DCHECK(entity_data.specifics.has_device_info());
   return DeviceInfoUtil::SpecificsToTag(entity_data.specifics.device_info());
 }
 
 void DeviceInfoService::OnChangeProcessorSet() {
   // We've recieved a new processor that needs metadata. If we're still in the
   // process of loading data and/or metadata, then |has_metadata_loaded_| is
   // false and we'll wait for those async reads to happen. If we've already
   // loaded metadata and then subsequently we get a new processor, we must not
   // have created the processor ourselves because we had no metadata. So there
   // must not be any metadata on disk.
   if (has_metadata_loaded_) {
-    change_processor()->OnMetadataLoaded(syncer::SyncError(),
+    change_processor()->OnMetadataLoaded(SyncError(),
                                          base::WrapUnique(new MetadataBatch()));
-    TryReconcileLocalAndStored();
+    ReconcileLocalAndStored();
   }
 }
 
 bool DeviceInfoService::IsSyncing() const {
   return !all_data_.empty();
 }
 
 std::unique_ptr<DeviceInfo> DeviceInfoService::GetDeviceInfo(
     const std::string& client_id) const {
   const ClientIdToSpecifics::const_iterator iter = all_data_.find(client_id);
@@ skipping 82 matching lines @@
     store_->DeleteData(batch, guid);
     all_data_.erase(iter);
     return true;
   } else {
     return false;
   }
 }
 
 void DeviceInfoService::OnProviderInitialized() {
   has_provider_initialized_ = true;
-  TryReconcileLocalAndStored();
+  LoadMetadataIfReady();
 }
 
 void DeviceInfoService::OnStoreCreated(Result result,
                                        std::unique_ptr<ModelTypeStore> store) {
   if (result == Result::SUCCESS) {
     std::swap(store_, store);
     store_->ReadAllData(base::Bind(&DeviceInfoService::OnReadAllData,
                                    weak_factory_.GetWeakPtr()));
   } else {
-    LOG(WARNING) << "ModelTypeStore creation failed.";
+    ReportStartupErrorToSync("ModelTypeStore creation failed.");
     // TODO(skym, crbug.com/582460): Handle unrecoverable initialization
     // failure.
   }
 }
 
 void DeviceInfoService::OnReadAllData(Result result,
                                       std::unique_ptr<RecordList> record_list) {
   if (result != Result::SUCCESS) {
-    LOG(WARNING) << "Initial load of data failed.";
+    ReportStartupErrorToSync("Initial load of data failed.");
     // TODO(skym, crbug.com/582460): Handle unrecoverable initialization
     // failure.
     return;
   }
 
   for (const Record& r : *record_list.get()) {
     std::unique_ptr<DeviceInfoSpecifics> specifics(
         base::WrapUnique(new DeviceInfoSpecifics()));
     if (specifics->ParseFromString(r.value)) {
       all_data_[specifics->cache_guid()] = std::move(specifics);
     } else {
-      LOG(WARNING) << "Failed to deserialize specifics.";
+      ReportStartupErrorToSync("Failed to deserialize specifics.");
       // TODO(skym, crbug.com/582460): Handle unrecoverable initialization
       // failure.
     }
   }
-  store_->ReadAllMetadata(base::Bind(&DeviceInfoService::OnReadAllMetadata,
-                                     weak_factory_.GetWeakPtr()));
+
+  has_data_loaded_ = true;
+  LoadMetadataIfReady();
+}
+
+void DeviceInfoService::LoadMetadataIfReady() {
+  if (has_data_loaded_ && has_provider_initialized_) {
+    store_->ReadAllMetadata(base::Bind(&DeviceInfoService::OnReadAllMetadata,
+                                       weak_factory_.GetWeakPtr()));
+  }
 }
 
 void DeviceInfoService::OnReadAllMetadata(
     Result result,
     std::unique_ptr<RecordList> metadata_records,
     const std::string& global_metadata) {
+  DCHECK(!has_metadata_loaded_);
+
   if (result != Result::SUCCESS) {
     // Store has encountered some serious error. We should still be able to
     // continue as a read only service, since if we got this far we must have
-    // loaded all data out succesfully. TODO(skym): Should we communicate this
-    // to sync somehow?
-    LOG(WARNING) << "Load of metadata completely failed.";
+    // loaded all data out succesfully.
+    ReportStartupErrorToSync("Load of metadata completely failed.");
     return;
   }
 
   // If we have no metadata then we don't want to create a processor. The idea
   // is that by not having a processor, the services will suffer less of a
   // performance hit. This isn't terribly applicable for this model type, but
   // we want this class to be as similar to other services as possible so follow
   // the convention.
   if (metadata_records->size() > 0 || !global_metadata.empty()) {
     CreateChangeProcessor();
   }
 
   // Set this after OnChangeProcessorSet so that we can correctly avoid giving
   // the processor empty metadata. We always want to set |has_metadata_loaded_|
   // at this point so that we'll know to give a processor empty metadata if it
   // is created later.
   has_metadata_loaded_ = true;
 
   if (!change_processor()) {
-    // This means we haven't been told to start sycning and we don't have any
-    // local metadata
+    // This means we haven't been told to start syncing and we don't have any
+    // local metadata.
     return;
   }
 
   std::unique_ptr<MetadataBatch> batch(new MetadataBatch());
   DataTypeState state;
   if (state.ParseFromString(global_metadata)) {
     batch->SetDataTypeState(state);
   } else {
     // TODO(skym): How bad is this scenario? We may be able to just give an
     // empty batch to the processor and we'll treat corrupted data type state
     // as no data type state at all. The question is do we want to add any of
     // the entity metadata to the batch or completely skip that step? We're
     // going to have to perform a merge shortly. Does this decision/logic even
     // belong in this service?
-    LOG(WARNING) << "Failed to deserialize global metadata.";
+    change_processor()->OnMetadataLoaded(
+        change_processor()->CreateAndUploadError(
+            FROM_HERE, "Failed to deserialize global metadata."),
+        nullptr);
   }
   for (const Record& r : *metadata_records.get()) {
     sync_pb::EntityMetadata entity_metadata;
     if (entity_metadata.ParseFromString(r.value)) {
       batch->AddMetadata(r.id, entity_metadata);
     } else {
       // TODO(skym): This really isn't too bad. We just want to regenerate
       // metadata for this particular entity. Unfortunately there isn't a
-      // convinient way to tell the processor to do this.
+      // convenient way to tell the processor to do this.
       LOG(WARNING) << "Failed to deserialize entity metadata.";
     }
   }
-  change_processor()->OnMetadataLoaded(syncer::SyncError(), std::move(batch));
-  TryReconcileLocalAndStored();
+  change_processor()->OnMetadataLoaded(SyncError(), std::move(batch));
+  ReconcileLocalAndStored();
 }
 
 void DeviceInfoService::OnCommit(Result result) {
   if (result != Result::SUCCESS) {
     LOG(WARNING) << "Failed a write to store.";
   }
 }
 
-void DeviceInfoService::TryReconcileLocalAndStored() {
+void DeviceInfoService::ReconcileLocalAndStored() {
   // On initial syncing we will have a change processor here, but it will not be
   // tracking changes. We need to persist a copy of our local device info to
   // disk, but the Put call to the processor will be ignored. That should be
   // fine however, as the discrepancy will be picked up later in merge. We don't
   // bother trying to track this case and act intelligently because simply not
   // much of a benefit in doing so.
-  if (has_provider_initialized_ && has_metadata_loaded_ && change_processor()) {
-    const DeviceInfo* current_info =
-        local_device_info_provider_->GetLocalDeviceInfo();
-    auto iter = all_data_.find(current_info->guid());
+  DCHECK(has_provider_initialized_);
+  DCHECK(has_metadata_loaded_);
+  DCHECK(change_processor());
+  const DeviceInfo* current_info =
+      local_device_info_provider_->GetLocalDeviceInfo();
+  auto iter = all_data_.find(current_info->guid());
 
-    // Convert to DeviceInfo for Equals function.
-    if (iter != all_data_.end() &&
-        current_info->Equals(*CopyToModel(*iter->second))) {
-      const TimeDelta pulse_delay(DeviceInfoUtil::CalculatePulseDelay(
-          GetLastUpdateTime(*iter->second), Time::Now()));
-      if (!pulse_delay.is_zero()) {
-        pulse_timer_.Start(FROM_HERE, pulse_delay,
-                           base::Bind(&DeviceInfoService::SendLocalData,
-                                      base::Unretained(this)));
-        return;
-      }
+  // Convert to DeviceInfo for Equals function.
+  if (iter != all_data_.end() &&
+      current_info->Equals(*CopyToModel(*iter->second))) {
+    const TimeDelta pulse_delay(DeviceInfoUtil::CalculatePulseDelay(
+        GetLastUpdateTime(*iter->second), Time::Now()));
+    if (!pulse_delay.is_zero()) {
+      pulse_timer_.Start(FROM_HERE, pulse_delay,
+                         base::Bind(&DeviceInfoService::SendLocalData,
+                                    base::Unretained(this)));
+      return;
     }
-    SendLocalData();
   }
+  SendLocalData();
 }
 
 void DeviceInfoService::SendLocalData() {
   DCHECK(has_provider_initialized_);
   // TODO(skym): Handle disconnecting and reconnecting, this will currently halt
   // the pulse timer and never restart it.
-  if (change_processor()) {
-    std::unique_ptr<DeviceInfoSpecifics> specifics =
-        CopyToSpecifics(*local_device_info_provider_->GetLocalDeviceInfo());
-    specifics->set_last_updated_timestamp(syncer::TimeToProtoTime(Time::Now()));
+  if (!change_processor()) {
+    return;
+  }
 
-    std::unique_ptr<MetadataChangeList> metadata_change_list =
-        CreateMetadataChangeList();
-    change_processor()->Put(DeviceInfoUtil::SpecificsToTag(*specifics),
-                            CopyToEntityData(*specifics),
-                            metadata_change_list.get());
+  std::unique_ptr<DeviceInfoSpecifics> specifics =
+      CopyToSpecifics(*local_device_info_provider_->GetLocalDeviceInfo());
+  specifics->set_last_updated_timestamp(syncer::TimeToProtoTime(Time::Now()));
 
-    std::unique_ptr<WriteBatch> batch = store_->CreateWriteBatch();
-    StoreSpecifics(std::move(specifics), batch.get());
+  std::unique_ptr<MetadataChangeList> metadata_change_list =
+      CreateMetadataChangeList();
+  change_processor()->Put(DeviceInfoUtil::SpecificsToTag(*specifics),
+                          CopyToEntityData(*specifics),
+                          metadata_change_list.get());
 
-    CommitAndNotify(std::move(batch), std::move(metadata_change_list), true);
-    pulse_timer_.Start(
-        FROM_HERE, DeviceInfoUtil::kPulseInterval,
-        base::Bind(&DeviceInfoService::SendLocalData, base::Unretained(this)));
-  }
+  std::unique_ptr<WriteBatch> batch = store_->CreateWriteBatch();
+  StoreSpecifics(std::move(specifics), batch.get());
+
+  CommitAndNotify(std::move(batch), std::move(metadata_change_list), true);
+  pulse_timer_.Start(
+      FROM_HERE, DeviceInfoUtil::kPulseInterval,
+      base::Bind(&DeviceInfoService::SendLocalData, base::Unretained(this)));
 }
 
 void DeviceInfoService::CommitAndNotify(
     std::unique_ptr<WriteBatch> batch,
     std::unique_ptr<MetadataChangeList> metadata_change_list,
     bool should_notify) {
   static_cast<SimpleMetadataChangeList*>(metadata_change_list.get())
       ->TransferChanges(store_.get(), batch.get());
   store_->CommitWriteBatch(
       std::move(batch),
       base::Bind(&DeviceInfoService::OnCommit, weak_factory_.GetWeakPtr()));
   if (should_notify) {
     NotifyObservers();
   }
 }
 
 int DeviceInfoService::CountActiveDevices(const Time now) const {
   return std::count_if(all_data_.begin(), all_data_.end(),
                        [now](ClientIdToSpecifics::const_reference pair) {
                          return DeviceInfoUtil::IsActive(
                              GetLastUpdateTime(*pair.second), now);
                        });
 }
 
+void DeviceInfoService::ReportStartupErrorToSync(const std::string& msg) {
+  DCHECK(!has_metadata_loaded_);
+  LOG(WARNING) << msg;
+
+  // Create a processor and give it the error in case sync tries to start.
+  if (!change_processor()) {
+    CreateChangeProcessor();
+  }
+  change_processor()->OnMetadataLoaded(
+      change_processor()->CreateAndUploadError(FROM_HERE, msg), nullptr);
+}
+
 // static
 Time DeviceInfoService::GetLastUpdateTime(
     const DeviceInfoSpecifics& specifics) {
   if (specifics.has_last_updated_timestamp()) {
     return syncer::ProtoTimeToTime(specifics.last_updated_timestamp());
   } else {
     return Time();
   }
 }
 
 }  // namespace sync_driver_v2