[Nearby] Start the cert/contact/local-device-data managers

When the Nearby Share service is created, start the certificate,
contact, and local-device-data managers. No manager tasks are run until
the managers are started.

We also add logging.

Change-Id: I9ee592d181f1fbe670318d364b3a5fec4dec45b8
Reviewed-on: https://chromium-review.googlesource.com/c/chromium/src/+/2370924
Commit-Queue: Josh Nohle <nohle@chromium.org>
Reviewed-by: James Vecore <vecore@google.com>
Auto-Submit: Josh Nohle <nohle@chromium.org>
Cr-Commit-Position: refs/heads/master@{#805829}

chrome/browser/nearby_sharing/certificates/nearby_share_certificate_manager.cc

@@ -17,13 +17,17 @@ void NearbyShareCertificateManager::RemoveObserver(Observer* observer) {
 }
 
 void NearbyShareCertificateManager::Start() {
-  DCHECK(!is_running_);
+  if (is_running_)
+    return;
+
   is_running_ = true;
   OnStart();
 }
 
 void NearbyShareCertificateManager::Stop() {
-  DCHECK(is_running_);
+  if (!is_running_)
+    return;
+
   is_running_ = false;
   OnStop();
 }

chrome/browser/nearby_sharing/contacts/nearby_share_contact_manager.cc

@@ -17,13 +17,17 @@ void NearbyShareContactManager::RemoveObserver(Observer* observer) {
 }
 
 void NearbyShareContactManager::Start() {
-  DCHECK(!is_running_);
+  if (is_running_)
+    return;
+
   is_running_ = true;
   OnStart();
 }
 
 void NearbyShareContactManager::Stop() {
-  DCHECK(is_running_);
+  if (!is_running_)
+    return;
+
   is_running_ = false;
   OnStop();
 }

chrome/browser/nearby_sharing/contacts/nearby_share_contact_manager_impl.cc

@@ -13,6 +13,7 @@
 #include "chrome/browser/nearby_sharing/contacts/nearby_share_contact_downloader.h"
 #include "chrome/browser/nearby_sharing/contacts/nearby_share_contact_downloader_impl.h"
 #include "chrome/browser/nearby_sharing/local_device_data/nearby_share_local_device_data_manager.h"
+#include "chrome/browser/nearby_sharing/logging/logging.h"
 #include "chrome/browser/nearby_sharing/proto/device_rpc.pb.h"
 #include "chrome/browser/nearby_sharing/proto/rpc_resources.pb.h"
 #include "chrome/browser/nearby_sharing/scheduling/nearby_share_scheduler.h"
@@ -151,6 +152,8 @@ std::set<std::string> NearbyShareContactManagerImpl::GetAllowedContacts()
 }
 
 void NearbyShareContactManagerImpl::OnContactsDownloadRequested() {
+  NS_LOG(VERBOSE) << __func__ << ": Nearby Share contacts download requested.";
+
   DCHECK(!contact_downloader_);
   contact_downloader_ = NearbyShareContactDownloaderImpl::Factory::Create(
       only_download_if_changed_, local_device_data_manager_->GetId(),
@@ -167,6 +170,13 @@ void NearbyShareContactManagerImpl::OnContactsDownloadSuccess(
     base::Optional<std::vector<nearbyshare::proto::ContactRecord>> contacts) {
   contact_downloader_.reset();
 
+  NS_LOG(VERBOSE) << __func__ << ": Nearby Share contacts download succeeded."
+                  << "\n  Did contacts change since last upload? "
+                  << (did_contacts_change_since_last_upload ? "Yes." : "No.")
+                  << "\n  Were contacts returned? "
+                  << (contacts.has_value() ? "Yes." : "No.")
+                  << "\n  Number of contacts returned: "
+                  << (contacts.has_value() ? contacts->size() : 0u);
   if (contacts) {
     // A complete list of contacts was returned. Do not download list again
     // until contacts change or until explicitly requested.
@@ -217,9 +227,13 @@ void NearbyShareContactManagerImpl::OnContactsDownloadFailure() {
 void NearbyShareContactManagerImpl::OnContactsUploadRequested() {
   DCHECK_EQ(UploadState::kIdle, upload_state_);
 
+  NS_LOG(VERBOSE) << __func__
+                  << ": Nearby Share contact upload requested. Waiting to "
+                  << "download full contact list.";
+
   // Because the user's contact list is not persisted locally, we have to
-  // retrieve the full contact list ContactRecord protos from the server before
-  // uploading the list of Contact protos to the server.
+  // retrieve the full contact list ContactRecord protos from the server
+  // before uploading the list of Contact protos to the server.
   upload_state_ = UploadState::kWaitingForDownload;
   DownloadContacts(/*only_download_if_changed=*/false);
 }
@@ -227,6 +241,8 @@ void NearbyShareContactManagerImpl::OnContactsUploadRequested() {
 void NearbyShareContactManagerImpl::StartContactsUpload(
     bool did_contacts_change_since_last_upload,
     const std::vector<nearbyshare::proto::ContactRecord>& contacts) {
+  NS_LOG(VERBOSE) << __func__
+                  << ": Starting contacts upload to Nearby Share server.";
   upload_state_ = UploadState::kInProgress;
   local_device_data_manager_->UploadContacts(
       ContactRecordsToContacts(GetAllowedContacts(), contacts),
@@ -238,6 +254,10 @@ void NearbyShareContactManagerImpl::StartContactsUpload(
 void NearbyShareContactManagerImpl::OnContactsUploadFinished(
     bool did_contacts_change_since_last_upload,
     bool success) {
+  NS_LOG(VERBOSE) << __func__ << ": Upload of contacts to Nearby Share server "
+                  << (success ? "succeeded." : "failed.")
+                  << " Did contacts change since last upload? "
+                  << (did_contacts_change_since_last_upload ? "Yes." : "No.");
   if (success) {
     NotifyContactsUploaded(did_contacts_change_since_last_upload);
   }

chrome/browser/nearby_sharing/local_device_data/nearby_share_local_device_data_manager.cc

@@ -19,13 +19,17 @@ void NearbyShareLocalDeviceDataManager::RemoveObserver(Observer* observer) {
 }
 
 void NearbyShareLocalDeviceDataManager::Start() {
-  DCHECK(!is_running_);
+  if (is_running_)
+    return;
+
   is_running_ = true;
   OnStart();
 }
 
 void NearbyShareLocalDeviceDataManager::Stop() {
-  DCHECK(is_running_);
+  if (!is_running_)
+    return;
+
   is_running_ = false;
   OnStop();
 }

chrome/browser/nearby_sharing/nearby_sharing_service_impl.cc

@@ -237,6 +237,12 @@ NearbySharingServiceImpl::NearbySharingServiceImpl(
 
   nearby_notification_manager_ = std::make_unique<NearbyNotificationManager>(
       notification_display_service, this, prefs, profile_);
+
+  if (settings_.GetEnabled()) {
+    local_device_data_manager_->Start();
+    contact_manager_->Start();
+    certificate_manager_->Start();
+  }
 }
 
 NearbySharingServiceImpl::~NearbySharingServiceImpl() {
@@ -287,6 +293,12 @@ void NearbySharingServiceImpl::Shutdown() {
 
   settings_receiver_.reset();
 
+  if (settings_.GetEnabled()) {
+    local_device_data_manager_->Stop();
+    contact_manager_->Stop();
+    certificate_manager_->Stop();
+  }
+
   // |profile_| has now been shut down so we shouldn't use it anymore.
   profile_ = nullptr;
 }
@@ -789,11 +801,17 @@ void NearbySharingServiceImpl::OnEnabledChanged(bool enabled) {
   DCHECK_CALLED_ON_VALID_SEQUENCE(sequence_checker_);
   if (enabled) {
     NS_LOG(VERBOSE) << __func__ << ": Nearby sharing enabled!";
+    local_device_data_manager_->Start();
+    contact_manager_->Start();
+    certificate_manager_->Start();
   } else {
     NS_LOG(VERBOSE) << __func__ << ": Nearby sharing disabled!";
     StopAdvertising();
     StopScanning();
     nearby_connections_manager_->Shutdown();
+    local_device_data_manager_->Stop();
+    contact_manager_->Stop();
+    certificate_manager_->Stop();
   }
   InvalidateSurfaceState();
 }

chrome/browser/nearby_sharing/scheduling/BUILD.gn

@@ -21,6 +21,7 @@ source_set("scheduling") {
   deps = [
     "//base",
     "//base/util/values:values_util",
+    "//chrome/browser/nearby_sharing/logging",
     "//components/prefs",
     "//content/public/browser",
     "//services/network/public/cpp",

chrome/browser/nearby_sharing/scheduling/nearby_share_scheduler_base.cc

@@ -5,12 +5,15 @@
 #include "chrome/browser/nearby_sharing/scheduling/nearby_share_scheduler_base.h"
 
 #include <algorithm>
+#include <sstream>
 #include <utility>
 
+#include "base/i18n/time_formatting.h"
 #include "base/numerics/clamped_math.h"
 #include "base/strings/string_number_conversions.h"
 #include "base/time/clock.h"
 #include "base/util/values/values_util.h"
+#include "chrome/browser/nearby_sharing/logging/logging.h"
 #include "components/prefs/pref_service.h"
 #include "components/prefs/scoped_user_pref_update.h"
 #include "content/public/browser/network_service_instance.h"
@@ -67,6 +70,9 @@ void NearbyShareSchedulerBase::HandleResult(bool success) {
   base::Time now = clock_->Now();
   SetLastAttemptTime(now);
 
+  NS_LOG(VERBOSE) << "Nearby Share scheduler \"" << pref_name_
+                  << "\" latest attempt " << (success ? "succeeded" : "failed");
+
   if (success) {
     SetLastSuccessTime(now);
     SetNumConsecutiveFailures(0);
@@ -76,6 +82,7 @@ void NearbyShareSchedulerBase::HandleResult(bool success) {
 
   SetIsWaitingForResult(false);
   Reschedule();
+  PrintSchedulerState();
 }
 
 void NearbyShareSchedulerBase::Reschedule() {
@@ -139,6 +146,8 @@ size_t NearbyShareSchedulerBase::GetNumConsecutiveFailures() const {
 
 void NearbyShareSchedulerBase::OnStart() {
   Reschedule();
+  NS_LOG(VERBOSE) << "Starting Nearby Share scheduler \"" << pref_name_ << "\"";
+  PrintSchedulerState();
 }
 
 void NearbyShareSchedulerBase::OnStop() {
@@ -241,3 +250,46 @@ void NearbyShareSchedulerBase::OnTimerFired() {
   SetHasPendingImmediateRequest(false);
   NotifyOfRequest();
 }
+
+void NearbyShareSchedulerBase::PrintSchedulerState() const {
+  base::Optional<base::Time> last_attempt_time = GetLastAttemptTime();
+  base::Optional<base::Time> last_success_time = GetLastSuccessTime();
+  base::Optional<base::TimeDelta> time_until_next_request =
+      GetTimeUntilNextRequest();
+
+  std::stringstream ss;
+  ss << "State of Nearby Share scheduler \"" << pref_name_ << "\":"
+     << "\n  Last attempt time: ";
+  if (last_attempt_time) {
+    ss << base::TimeFormatShortDateAndTimeWithTimeZone(*last_attempt_time);
+  } else {
+    ss << "Never";
+  }
+
+  ss << "\n  Last success time: ";
+  if (last_success_time) {
+    ss << base::TimeFormatShortDateAndTimeWithTimeZone(*last_success_time);
+  } else {
+    ss << "Never";
+  }
+
+  ss << "\n  Time until next request: ";
+  if (time_until_next_request) {
+    base::string16 next_request_delay;
+    bool success = base::TimeDurationFormatWithSeconds(
+        *time_until_next_request,
+        base::DurationFormatWidth::DURATION_WIDTH_NARROW, &next_request_delay);
+    if (success) {
+      ss << next_request_delay;
+    }
+  } else {
+    ss << "Never";
+  }
+
+  ss << "\n  Is waiting for result? " << (IsWaitingForResult() ? "Yes" : "No");
+  ss << "\n  Pending immediate request? "
+     << (HasPendingImmediateRequest() ? "Yes" : "No");
+  ss << "\n  Num consecutive failures: " << GetNumConsecutiveFailures();
+
+  NS_LOG(VERBOSE) << ss.str();
+}

chrome/browser/nearby_sharing/scheduling/nearby_share_scheduler_base.h

@@ -101,6 +101,8 @@ class NearbyShareSchedulerBase
   // connectivity is restored.
   void OnTimerFired();
 
+  void PrintSchedulerState() const;
+
   bool retry_failures_;
   bool require_connectivity_;
   std::string pref_name_;