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
RegisterPrefs(PrefRegistrySimple * registry)29 void ReportingService::RegisterPrefs(PrefRegistrySimple* registry) {
30 DataUseTracker::RegisterPrefs(registry);
31 }
32
ReportingService(MetricsServiceClient * client,PrefService * local_state,size_t max_retransmit_size,MetricsLogsEventManager * logs_event_manager)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
~ReportingService()49 ReportingService::~ReportingService() {
50 DisableReporting();
51 }
52
Initialize()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
Start()64 void ReportingService::Start() {
65 DCHECK_CALLED_ON_VALID_SEQUENCE(sequence_checker_);
66 if (reporting_active_)
67 upload_scheduler_->Start();
68 }
69
Stop()70 void ReportingService::Stop() {
71 DCHECK_CALLED_ON_VALID_SEQUENCE(sequence_checker_);
72 if (upload_scheduler_)
73 upload_scheduler_->Stop();
74 }
75
EnableReporting()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
DisableReporting()84 void ReportingService::DisableReporting() {
85 DCHECK_CALLED_ON_VALID_SEQUENCE(sequence_checker_);
86 reporting_active_ = false;
87 Stop();
88 }
89
reporting_active() const90 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
SendNextLog()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
SendStagedLog()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 = base::HexEncode(log_store()->staged_log_hash());
181
182 std::string signature =
183 base::Base64Encode(log_store()->staged_log_signature());
184
185 if (logs_event_manager_) {
186 logs_event_manager_->NotifyLogEvent(
187 MetricsLogsEventManager::LogEvent::kLogUploading,
188 log_store()->staged_log_hash());
189 }
190 log_uploader_->UploadLog(log_store()->staged_log(),
191 log_store()->staged_log_metadata(), hash, signature,
192 reporting_info_);
193 }
194
OnLogUploadComplete(int response_code,int error_code,bool was_https,bool force_discard,base::StringPiece force_discard_reason)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
301