components/metrics/reporting_service.cc

   1 // Copyright 2017 The Chromium Authors
   2 // Use of this source code is governed by a BSD-style license that can be
   3 // found in the LICENSE file.
   4
   5 // ReportingService handles uploading serialized logs to a server.
   6
   7 #include "components/metrics/reporting_service.h"
   8
   9 #include <cstdio>
  10 #include <memory>
  11
  12 #include "base/base64.h"
  13 #include "base/command_line.h"
  14 #include "base/functional/bind.h"
  15 #include "base/functional/callback.h"
  16 #include "base/logging.h"
  17 #include "base/strings/string_number_conversions.h"
  18 #include "base/strings/stringprintf.h"
  19 #include "components/metrics/data_use_tracker.h"
  20 #include "components/metrics/log_store.h"
  21 #include "components/metrics/metrics_features.h"
  22 #include "components/metrics/metrics_log_uploader.h"
  23 #include "components/metrics/metrics_service_client.h"
  24 #include "components/metrics/metrics_upload_scheduler.h"
  25
  26 namespace metrics {
  27
  28 // static
  29 void ReportingService::RegisterPrefs(PrefRegistrySimple* registry) {
  30   DataUseTracker::RegisterPrefs(registry);
  31 }
  32
  33 ReportingService::ReportingService(MetricsServiceClient* client,
  34                                    PrefService* local_state,
  35                                    size_t max_retransmit_size,
  36                                    MetricsLogsEventManager* logs_event_manager)
  37     : client_(client),
  38       local_state_(local_state),
  39       max_retransmit_size_(max_retransmit_size),
  40       logs_event_manager_(logs_event_manager),
  41       reporting_active_(false),
  42       log_upload_in_progress_(false),
  43       data_use_tracker_(DataUseTracker::Create(local_state)) {
  44   DCHECK_CALLED_ON_VALID_SEQUENCE(sequence_checker_);
  45   DCHECK(client_);
  46   DCHECK(local_state);
  47 }
  48
  49 ReportingService::~ReportingService() {
  50   DisableReporting();
  51 }
  52
  53 void ReportingService::Initialize() {
  54   DCHECK_CALLED_ON_VALID_SEQUENCE(sequence_checker_);
  55   DCHECK(!upload_scheduler_);
  56   log_store()->LoadPersistedUnsentLogs();
  57   base::RepeatingClosure send_next_log_callback = base::BindRepeating(
  58       &ReportingService::SendNextLog, self_ptr_factory_.GetWeakPtr());
  59   bool fast_startup_for_testing = client_->ShouldStartUpFastForTesting();
  60   upload_scheduler_ = std::make_unique<MetricsUploadScheduler>(
  61       send_next_log_callback, fast_startup_for_testing);
  62 }
  63
  64 void ReportingService::Start() {
  65   DCHECK_CALLED_ON_VALID_SEQUENCE(sequence_checker_);
  66   if (reporting_active_)
  67     upload_scheduler_->Start();
  68 }
  69
  70 void ReportingService::Stop() {
  71   DCHECK_CALLED_ON_VALID_SEQUENCE(sequence_checker_);
  72   if (upload_scheduler_)
  73     upload_scheduler_->Stop();
  74 }
  75
  76 void ReportingService::EnableReporting() {
  77   DCHECK_CALLED_ON_VALID_SEQUENCE(sequence_checker_);
  78   if (reporting_active_)
  79     return;
  80   reporting_active_ = true;
  81   Start();
  82 }
  83
  84 void ReportingService::DisableReporting() {
  85   DCHECK_CALLED_ON_VALID_SEQUENCE(sequence_checker_);
  86   reporting_active_ = false;
  87   Stop();
  88 }
  89
  90 bool ReportingService::reporting_active() const {
  91   DCHECK_CALLED_ON_VALID_SEQUENCE(sequence_checker_);
  92   return reporting_active_;
  93 }
  94
  95 //------------------------------------------------------------------------------
  96 // private methods
  97 //------------------------------------------------------------------------------
  98
  99 void ReportingService::SendNextLog() {
 100   DVLOG(1) << "SendNextLog";
 101   DCHECK_CALLED_ON_VALID_SEQUENCE(sequence_checker_);
 102
 103   const base::TimeTicks now = base::TimeTicks::Now();
 104   LogActualUploadInterval(last_upload_finish_time_.is_null()
 105                               ? base::TimeDelta()
 106                               : now - last_upload_finish_time_);
 107   last_upload_finish_time_ = now;
 108
 109   if (!reporting_active()) {
 110     upload_scheduler_->StopAndUploadCancelled();
 111     return;
 112   }
 113   if (!log_store()->has_unsent_logs()) {
 114     // Should only get here if serializing the log failed somehow.
 115     upload_scheduler_->Stop();
 116     // Reset backoff interval
 117     upload_scheduler_->UploadFinished(true);
 118     return;
 119   }
 120   if (!log_store()->has_staged_log()) {
 121     reporting_info_.set_attempt_count(0);
 122     log_store()->StageNextLog();
 123   }
 124
 125   // Check whether the log should be uploaded based on user id. If it should not
 126   // be sent, then discard the log from the store and notify the scheduler.
 127   auto staged_user_id = log_store()->staged_log_user_id();
 128   if (staged_user_id.has_value() &&
 129       !client_->ShouldUploadMetricsForUserId(staged_user_id.value())) {
 130     // Remove the log and update list to disk.
 131     log_store()->DiscardStagedLog();
 132     log_store()->TrimAndPersistUnsentLogs(/*overwrite_in_memory_store=*/true);
 133
 134     // Notify the scheduler that the next log should be uploaded. If there are
 135     // no more logs, then stop the scheduler.
 136     if (!log_store()->has_unsent_logs()) {
 137       DVLOG(1) << "Stopping upload_scheduler_.";
 138       upload_scheduler_->Stop();
 139     }
 140     upload_scheduler_->UploadFinished(true);
 141     return;
 142   }
 143
 144   // Proceed to stage the log for upload if log size satisfies cellular log
 145   // upload constrains.
 146   bool upload_canceled = false;
 147   bool is_cellular_logic = client_->IsOnCellularConnection();
 148   if (is_cellular_logic && data_use_tracker_ &&
 149       !data_use_tracker_->ShouldUploadLogOnCellular(
 150           log_store()->staged_log().size())) {
 151     upload_scheduler_->UploadOverDataUsageCap();
 152     upload_canceled = true;
 153   } else {
 154     SendStagedLog();
 155   }
 156   if (is_cellular_logic) {
 157     LogCellularConstraint(upload_canceled);
 158   }
 159 }
 160
 161 void ReportingService::SendStagedLog() {
 162   DCHECK_CALLED_ON_VALID_SEQUENCE(sequence_checker_);
 163   DCHECK(log_store()->has_staged_log());
 164   if (!log_store()->has_staged_log())
 165     return;
 166
 167   DCHECK(!log_upload_in_progress_);
 168   log_upload_in_progress_ = true;
 169
 170   if (!log_uploader_) {
 171     log_uploader_ = client_->CreateUploader(
 172         GetUploadUrl(), GetInsecureUploadUrl(), upload_mime_type(),
 173         service_type(),
 174         base::BindRepeating(&ReportingService::OnLogUploadComplete,
 175                             self_ptr_factory_.GetWeakPtr()));
 176   }
 177
 178   reporting_info_.set_attempt_count(reporting_info_.attempt_count() + 1);
 179
 180   const std::string hash =
 181       base::HexEncode(log_store()->staged_log_hash().data(),
 182                       log_store()->staged_log_hash().size());
 183   std::string signature;
 184   base::Base64Encode(log_store()->staged_log_signature(), &signature);
 185
 186   if (logs_event_manager_) {
 187     logs_event_manager_->NotifyLogEvent(
 188         MetricsLogsEventManager::LogEvent::kLogUploading,
 189         log_store()->staged_log_hash());
 190   }
 191   log_uploader_->UploadLog(log_store()->staged_log(), hash, signature,
 192                            reporting_info_);
 193 }
 194
 195 void ReportingService::OnLogUploadComplete(
 196     int response_code,
 197     int error_code,
 198     bool was_https,
 199     bool force_discard,
 200     base::StringPiece force_discard_reason) {
 201   DVLOG(1) << "OnLogUploadComplete:" << response_code;
 202   DCHECK_CALLED_ON_VALID_SEQUENCE(sequence_checker_);
 203   DCHECK(log_upload_in_progress_);
 204   log_upload_in_progress_ = false;
 205
 206   reporting_info_.set_last_response_code(response_code);
 207   reporting_info_.set_last_error_code(error_code);
 208   reporting_info_.set_last_attempt_was_https(was_https);
 209
 210   // Log a histogram to track response success vs. failure rates.
 211   LogResponseOrErrorCode(response_code, error_code, was_https);
 212
 213   bool upload_succeeded = response_code == 200;
 214
 215   // Staged log could have been removed already (such as by Purge() in some
 216   // implementations), otherwise we may remove it here.
 217   if (log_store()->has_staged_log()) {
 218     // Provide boolean for error recovery (allow us to ignore response_code).
 219     bool discard_log = false;
 220     base::StringPiece discard_reason;
 221
 222     const std::string& staged_log = log_store()->staged_log();
 223     const size_t log_size = staged_log.length();
 224     if (upload_succeeded) {
 225       LogSuccessLogSize(log_size);
 226       LogSuccessMetadata(staged_log);
 227       discard_log = true;
 228       discard_reason = "Log upload successful.";
 229     } else if (force_discard) {
 230       discard_log = true;
 231       discard_reason = force_discard_reason;
 232     } else if (log_size > max_retransmit_size_) {
 233       LogLargeRejection(log_size);
 234       discard_log = true;
 235       discard_reason =
 236           "Failed to upload, and log is too large. Will not attempt to "
 237           "retransmit.";
 238     } else if (response_code == 400) {
 239       // Bad syntax.  Retransmission won't work.
 240       discard_log = true;
 241       discard_reason =
 242           "Failed to upload because log has bad syntax. Will not attempt to "
 243           "retransmit.";
 244     }
 245
 246     if (!discard_log && logs_event_manager_) {
 247       // The log is not discarded, meaning that it has failed to upload. We will
 248       // try to retransmit it.
 249       logs_event_manager_->NotifyLogEvent(
 250           MetricsLogsEventManager::LogEvent::kLogStaged,
 251           log_store()->staged_log_hash(),
 252           base::StringPrintf("Failed to upload (status code: %d, net error "
 253                              "code: %d). Staged again for retransmission.",
 254                              response_code, error_code));
 255     }
 256
 257     if (discard_log) {
 258       if (upload_succeeded)
 259         log_store()->MarkStagedLogAsSent();
 260
 261       log_store()->DiscardStagedLog(discard_reason);
 262       // Store the updated list to disk now that the removed log is uploaded.
 263       log_store()->TrimAndPersistUnsentLogs(/*overwrite_in_memory_store=*/true);
 264
 265       bool flush_local_state =
 266           base::FeatureList::IsEnabled(features::kReportingServiceAlwaysFlush);
 267 #if BUILDFLAG(IS_ANDROID) || BUILDFLAG(IS_IOS)
 268       // If Chrome is in the background, flush the discarded and trimmed logs
 269       // from |local_state_| immediately because the process may be killed at
 270       // any time from now without persisting the changes. Otherwise, we may end
 271       // up re-uploading the same log in a future session. We do not do this if
 272       // Chrome is in the foreground because of the assumption that
 273       // |local_state_| will be flushed when convenient, and we do not want to
 274       // do more work than necessary on the main thread while Chrome is visible.
 275       flush_local_state = flush_local_state || !is_in_foreground_;
 276 #endif  // BUILDFLAG(IS_ANDROID) || BUILDFLAG(IS_IOS)
 277       if (flush_local_state) {
 278         local_state_->CommitPendingWrite();
 279       }
 280     }
 281   }
 282
 283   // Error 400 indicates a problem with the log, not with the server, so
 284   // don't consider that a sign that the server is in trouble. Similarly, if
 285   // |force_discard| is true, do not delay the sending of other logs. For
 286   // example, if |force_discard| is true because there are no metrics server
 287   // URLs included in this build, do not indicate that the "non-existent server"
 288   // is in trouble, which would delay the sending of other logs and causing the
 289   // accumulation of logs on disk.
 290   bool server_is_healthy =
 291       upload_succeeded || response_code == 400 || force_discard;
 292
 293   if (!log_store()->has_unsent_logs()) {
 294     DVLOG(1) << "Stopping upload_scheduler_.";
 295     upload_scheduler_->Stop();
 296   }
 297   upload_scheduler_->UploadFinished(server_is_healthy);
 298 }
 299
 300 }  // namespace metrics