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