components/rappor/log_uploader.cc

   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/rappor/log_uploader.h"
   6
   7 #include "base/metrics/histogram.h"
   8 #include "base/metrics/sparse_histogram.h"
   9 #include "net/base/load_flags.h"
  10 #include "net/base/net_errors.h"
  11 #include "net/url_request/url_fetcher.h"
  12
  13 namespace {
  14
  15 // The delay, in seconds, between uploading when there are queued logs to send.
  16 const int kUnsentLogsIntervalSeconds = 3;
  17
  18 // When uploading metrics to the server fails, we progressively wait longer and
  19 // longer before sending the next log. This backoff process helps reduce load
  20 // on a server that is having issues.
  21 // The following is the multiplier we use to expand that inter-log duration.
  22 const double kBackoffMultiplier = 1.1;
  23
  24 // The maximum backoff multiplier.
  25 const int kMaxBackoffIntervalSeconds = 60 * 60;
  26
  27 // The maximum number of unsent logs we will keep.
  28 // TODO(holte): Limit based on log size instead.
  29 const size_t kMaxQueuedLogs = 10;
  30
  31 enum DiscardReason {
  32   UPLOAD_SUCCESS,
  33   UPLOAD_REJECTED,
  34   QUEUE_OVERFLOW,
  35   NUM_DISCARD_REASONS
  36 };
  37
  38 void RecordDiscardReason(DiscardReason reason) {
  39   UMA_HISTOGRAM_ENUMERATION("Rappor.DiscardReason",
  40                             reason,
  41                             NUM_DISCARD_REASONS);
  42 }
  43
  44 }  // namespace
  45
  46 namespace rappor {
  47
  48 LogUploader::LogUploader(const GURL& server_url,
  49                          const std::string& mime_type,
  50                          net::URLRequestContextGetter* request_context)
  51     : server_url_(server_url),
  52       mime_type_(mime_type),
  53       request_context_(request_context),
  54       is_running_(false),
  55       has_callback_pending_(false),
  56       upload_interval_(base::TimeDelta::FromSeconds(
  57           kUnsentLogsIntervalSeconds)) {
  58 }
  59
  60 LogUploader::~LogUploader() {}
  61
  62 void LogUploader::Start() {
  63   is_running_ = true;
  64   StartScheduledUpload();
  65 }
  66
  67 void LogUploader::Stop() {
  68   is_running_ = false;
  69   // Rather than interrupting the current upload, just let it finish/fail and
  70   // then inhibit any retry attempts.
  71 }
  72
  73 void LogUploader::QueueLog(const std::string& log) {
  74   queued_logs_.push(log);
  75   // Don't drop logs yet if an upload is in progress.  They will be dropped
  76   // when it finishes.
  77   if (!has_callback_pending_)
  78     DropExcessLogs();
  79   StartScheduledUpload();
  80 }
  81
  82 void LogUploader::DropExcessLogs() {
  83   while (queued_logs_.size() > kMaxQueuedLogs) {
  84     DVLOG(2) << "Dropping excess log.";
  85     RecordDiscardReason(QUEUE_OVERFLOW);
  86     queued_logs_.pop();
  87   }
  88 }
  89
  90 bool LogUploader::IsUploadScheduled() const {
  91   return upload_timer_.IsRunning();
  92 }
  93
  94 void LogUploader::ScheduleNextUpload(base::TimeDelta interval) {
  95   upload_timer_.Start(
  96       FROM_HERE, interval, this, &LogUploader::StartScheduledUpload);
  97 }
  98
  99 bool LogUploader::CanStartUpload() const {
 100   return is_running_ &&
 101          !queued_logs_.empty() &&
 102          !IsUploadScheduled() &&
 103          !has_callback_pending_;
 104 }
 105
 106 void LogUploader::StartScheduledUpload() {
 107   if (!CanStartUpload())
 108     return;
 109   DVLOG(2) << "Upload to " << server_url_.spec() << " starting.";
 110   has_callback_pending_ = true;
 111   current_fetch_.reset(
 112       net::URLFetcher::Create(server_url_, net::URLFetcher::POST, this));
 113   current_fetch_->SetRequestContext(request_context_.get());
 114   current_fetch_->SetUploadData(mime_type_, queued_logs_.front());
 115
 116   // We already drop cookies server-side, but we might as well strip them out
 117   // client-side as well.
 118   current_fetch_->SetLoadFlags(net::LOAD_DO_NOT_SAVE_COOKIES |
 119                                net::LOAD_DO_NOT_SEND_COOKIES);
 120   current_fetch_->Start();
 121 }
 122
 123 // static
 124 base::TimeDelta LogUploader::BackOffUploadInterval(base::TimeDelta interval) {
 125   DCHECK_GT(kBackoffMultiplier, 1.0);
 126   interval = base::TimeDelta::FromMicroseconds(static_cast<int64>(
 127       kBackoffMultiplier * interval.InMicroseconds()));
 128
 129   base::TimeDelta max_interval =
 130       base::TimeDelta::FromSeconds(kMaxBackoffIntervalSeconds);
 131   return interval > max_interval ? max_interval : interval;
 132 }
 133
 134 void LogUploader::OnURLFetchComplete(const net::URLFetcher* source) {
 135   // We're not allowed to re-use the existing |URLFetcher|s, so free them here.
 136   // Note however that |source| is aliased to the fetcher, so we should be
 137   // careful not to delete it too early.
 138   DCHECK_EQ(current_fetch_.get(), source);
 139   scoped_ptr<net::URLFetcher> fetch(current_fetch_.Pass());
 140
 141   const net::URLRequestStatus& request_status = source->GetStatus();
 142
 143   const int response_code = source->GetResponseCode();
 144   DVLOG(2) << "Upload fetch complete response code: " << response_code;
 145
 146   if (request_status.status() != net::URLRequestStatus::SUCCESS) {
 147     UMA_HISTOGRAM_SPARSE_SLOWLY("Rappor.FailedUploadErrorCode",
 148                                 -request_status.error());
 149     DVLOG(1) << "Rappor server upload failed with error: "
 150              << request_status.error() << ": "
 151              << net::ErrorToString(request_status.error());
 152     DCHECK_EQ(-1, response_code);
 153   } else {
 154     // Log a histogram to track response success vs. failure rates.
 155     UMA_HISTOGRAM_SPARSE_SLOWLY("Rappor.UploadResponseCode", response_code);
 156   }
 157
 158   const bool upload_succeeded = response_code == 200;
 159
 160   // Determine whether this log should be retransmitted.
 161   DiscardReason reason = NUM_DISCARD_REASONS;
 162   if (upload_succeeded) {
 163     reason = UPLOAD_SUCCESS;
 164   } else if (response_code == 400) {
 165     reason = UPLOAD_REJECTED;
 166   }
 167
 168   if (reason != NUM_DISCARD_REASONS) {
 169     DVLOG(2) << "Log discarded.";
 170     RecordDiscardReason(reason);
 171     queued_logs_.pop();
 172   }
 173
 174   DropExcessLogs();
 175
 176   // Error 400 indicates a problem with the log, not with the server, so
 177   // don't consider that a sign that the server is in trouble.
 178   const bool server_is_healthy = upload_succeeded || response_code == 400;
 179   OnUploadFinished(server_is_healthy);
 180 }
 181
 182 void LogUploader::OnUploadFinished(bool server_is_healthy) {
 183   DCHECK(has_callback_pending_);
 184   has_callback_pending_ = false;
 185   // If the server is having issues, back off. Otherwise, reset to default.
 186   if (!server_is_healthy)
 187     upload_interval_ = BackOffUploadInterval(upload_interval_);
 188   else
 189     upload_interval_ = base::TimeDelta::FromSeconds(kUnsentLogsIntervalSeconds);
 190
 191   if (CanStartUpload())
 192     ScheduleNextUpload(upload_interval_);
 193 }
 194
 195 }  // namespace rappor