1 // Copyright 2014 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 //------------------------------------------------------------------------------
6 // Description of a MetricsService instance's life cycle.
7 //
8 // OVERVIEW
9 //
10 // A MetricsService instance is typically created at application startup. It is
11 // the central controller for the acquisition of log data, and the automatic
12 // transmission of that log data to an external server. Its major job is to
13 // manage logs, grouping them for transmission, and transmitting them. As part
14 // of its grouping, MS finalizes logs by including some just-in-time gathered
15 // memory statistics, snapshotting the current stats of numerous histograms,
16 // closing the logs, translating to protocol buffer format, and compressing the
17 // results for transmission. Transmission includes submitting a compressed log
18 // as data in a URL-post, and retransmitting (or retaining at process
19 // termination) if the attempted transmission failed. Retention across process
20 // terminations is done using the PrefServices facilities. The retained logs
21 // (the ones that never got transmitted) are compressed and base64-encoded
22 // before being persisted.
23 //
24 // Logs fall into one of two categories: "initial logs," and "ongoing logs."
25 // There is at most one initial log sent for each complete run of Chrome (from
26 // startup, to browser shutdown). An initial log is generally transmitted some
27 // short time (1 minute?) after startup, and includes stats such as recent crash
28 // info, the number and types of plugins, etc. The external server's response
29 // to the initial log conceptually tells this MS if it should continue
30 // transmitting logs (during this session). The server response can actually be
31 // much more detailed, and always includes (at a minimum) how often additional
32 // ongoing logs should be sent.
33 //
34 // After the above initial log, a series of ongoing logs will be transmitted.
35 // The first ongoing log actually begins to accumulate information stating when
36 // the MS was first constructed. Note that even though the initial log is
37 // commonly sent a full minute after startup, the initial log does not include
38 // much in the way of user stats. The most common interlog period (delay)
39 // is 30 minutes. That time period starts when the first user action causes a
40 // logging event. This means that if there is no user action, there may be long
41 // periods without any (ongoing) log transmissions. Ongoing logs typically
42 // contain very detailed records of user activities (ex: opened tab, closed
43 // tab, fetched URL, maximized window, etc.) In addition, just before an
44 // ongoing log is closed out, a call is made to gather memory statistics. Those
45 // memory statistics are deposited into a histogram, and the log finalization
46 // code is then called. In the finalization, a call to a Histogram server
47 // acquires a list of all local histograms that have been flagged for upload
48 // to the UMA server. The finalization also acquires the most recent number
49 // of page loads, along with any counts of renderer or plugin crashes.
50 //
51 // When the browser shuts down, there will typically be a fragment of an ongoing
52 // log that has not yet been transmitted. At shutdown time, that fragment is
53 // closed (including snapshotting histograms), and persisted, for potential
54 // transmission during a future run of the product.
55 //
56 // There are two slightly abnormal shutdown conditions. There is a
57 // "disconnected scenario," and a "really fast startup and shutdown" scenario.
58 // In the "never connected" situation, the user has (during the running of the
59 // process) never established an internet connection. As a result, attempts to
60 // transmit the initial log have failed, and a lot(?) of data has accumulated in
61 // the ongoing log (which didn't yet get closed, because there was never even a
62 // contemplation of sending it). There is also a kindred "lost connection"
63 // situation, where a loss of connection prevented an ongoing log from being
64 // transmitted, and a (still open) log was stuck accumulating a lot(?) of data,
65 // while the earlier log retried its transmission. In both of these
66 // disconnected situations, two logs need to be, and are, persistently stored
67 // for future transmission.
68 //
69 // The other unusual shutdown condition, termed "really fast startup and
70 // shutdown," involves the deliberate user termination of the process before
71 // the initial log is even formed or transmitted. In that situation, no logging
72 // is done, but the historical crash statistics remain (unlogged) for inclusion
73 // in a future run's initial log. (i.e., we don't lose crash stats).
74 //
75 // With the above overview, we can now describe the state machine's various
76 // states, based on the State enum specified in the state_ member. Those states
77 // are:
78 //
79 // CONSTRUCTED, // Constructor was called.
80 // INITIALIZED, // InitializeMetricsRecordingState() was called.
81 // INIT_TASK_SCHEDULED, // Waiting for deferred init tasks to finish.
82 // INIT_TASK_DONE, // Waiting for timer to send the first ongoing log.
83 // SENDING_LOGS, // Sending logs and creating new ones when we run out.
84 //
85 // In more detail, we have:
86 //
87 // INIT_TASK_SCHEDULED, // Waiting for deferred init tasks to finish.
88 // Typically about 30 seconds after startup, a task is sent to a background
89 // thread to perform deferred (lower priority and slower) initialization steps
90 // such as getting the list of plugins. That task will (when complete) make an
91 // async callback (via a Task) to indicate the completion.
92 //
93 // INIT_TASK_DONE, // Waiting for timer to send first ongoing log.
94 // The callback has arrived, and it is now possible for an ongoing log to be
95 // created. This callback typically arrives back less than one second after
96 // the deferred init task is dispatched.
97 //
98 // SENDING_LOGS, // Sending logs and creating new ones when we run out.
99 // Logs from previous sessions have been loaded, and an optional initial
100 // stability log has been created. We will send all of these logs, and when
101 // they run out, we will start cutting new logs to send. We will also cut a new
102 // log if we expect a shutdown.
103 //
104 // The progression through the above states is simple, and sequential.
105 // States proceed from INITIALIZED to SENDING_LOGS, and remain in the latter
106 // until shutdown.
107 //
108 // Also note that whenever we successfully send a log, we mirror the list
109 // of logs into the PrefService. This ensures that IF we crash, we won't start
110 // up and retransmit our old logs again.
111 //
112 // Due to race conditions, it is always possible that a log file could be sent
113 // twice. For example, if a log file is sent, but not yet acknowledged by
114 // the external server, and the user shuts down, then a copy of the log may be
115 // saved for re-transmission. These duplicates could be filtered out server
116 // side, but are not expected to be a significant problem.
117 //
118 //
119 //------------------------------------------------------------------------------
120
121 #include "components/metrics/metrics_service.h"
122
123 #include <stddef.h>
124
125 #include <algorithm>
126 #include <memory>
127 #include <utility>
128
129 #include "base/callback_list.h"
130 #include "base/functional/bind.h"
131 #include "base/functional/callback.h"
132 #include "base/location.h"
133 #include "base/metrics/histogram_base.h"
134 #include "base/metrics/histogram_flattener.h"
135 #include "base/metrics/histogram_functions.h"
136 #include "base/metrics/histogram_macros.h"
137 #include "base/metrics/histogram_samples.h"
138 #include "base/metrics/persistent_histogram_allocator.h"
139 #include "base/process/process_handle.h"
140 #include "base/rand_util.h"
141 #include "base/strings/string_piece.h"
142 #include "base/task/sequenced_task_runner.h"
143 #include "base/task/single_thread_task_runner.h"
144 #include "base/task/thread_pool.h"
145 #include "base/time/time.h"
146 #include "build/build_config.h"
147 #include "build/chromeos_buildflags.h"
148 #include "components/metrics/clean_exit_beacon.h"
149 #include "components/metrics/environment_recorder.h"
150 #include "components/metrics/field_trials_provider.h"
151 #include "components/metrics/metrics_features.h"
152 #include "components/metrics/metrics_log.h"
153 #include "components/metrics/metrics_log_manager.h"
154 #include "components/metrics/metrics_log_uploader.h"
155 #include "components/metrics/metrics_logs_event_manager.h"
156 #include "components/metrics/metrics_pref_names.h"
157 #include "components/metrics/metrics_rotation_scheduler.h"
158 #include "components/metrics/metrics_service_client.h"
159 #include "components/metrics/metrics_service_observer.h"
160 #include "components/metrics/metrics_state_manager.h"
161 #include "components/metrics/metrics_switches.h"
162 #include "components/metrics/persistent_system_profile.h"
163 #include "components/metrics/stability_metrics_provider.h"
164 #include "components/metrics/url_constants.h"
165 #include "components/prefs/pref_registry_simple.h"
166 #include "components/prefs/pref_service.h"
167 #include "components/variations/entropy_provider.h"
168
169 #if BUILDFLAG(IS_CHROMEOS_ASH)
170 #include "components/metrics/structured/neutrino_logging.h" // nogncheck
171 #endif // BUILDFLAG(IS_CHROMEOS_ASH)
172
173 namespace metrics {
174 namespace {
175
176 // Used to write histogram data to a log. Does not take ownership of the log.
177 class IndependentFlattener : public base::HistogramFlattener {
178 public:
IndependentFlattener(MetricsLog * log)179 explicit IndependentFlattener(MetricsLog* log) : log_(log) {}
180
181 IndependentFlattener(const IndependentFlattener&) = delete;
182 IndependentFlattener& operator=(const IndependentFlattener&) = delete;
183
184 ~IndependentFlattener() override = default;
185
186 // base::HistogramFlattener:
RecordDelta(const base::HistogramBase & histogram,const base::HistogramSamples & snapshot)187 void RecordDelta(const base::HistogramBase& histogram,
188 const base::HistogramSamples& snapshot) override {
189 log_->RecordHistogramDelta(histogram.histogram_name(), snapshot);
190 }
191
192 private:
193 const raw_ptr<MetricsLog, DanglingUntriaged> log_;
194 };
195
196 // Used to mark histogram samples as reported so that they are not included in
197 // the next log. A histogram's snapshot samples are simply discarded/ignored
198 // when attempting to record them through this |HistogramFlattener|.
199 class DiscardingFlattener : public base::HistogramFlattener {
200 public:
201 DiscardingFlattener() = default;
202
203 DiscardingFlattener(const DiscardingFlattener&) = delete;
204 DiscardingFlattener& operator=(const DiscardingFlattener&) = delete;
205
206 ~DiscardingFlattener() override = default;
207
RecordDelta(const base::HistogramBase & histogram,const base::HistogramSamples & snapshot)208 void RecordDelta(const base::HistogramBase& histogram,
209 const base::HistogramSamples& snapshot) override {
210 // No-op. We discard the samples.
211 }
212 };
213
214 // The delay, in seconds, after starting recording before doing expensive
215 // initialization work.
216 #if BUILDFLAG(IS_ANDROID) || BUILDFLAG(IS_IOS)
217 // On mobile devices, a significant portion of sessions last less than a minute.
218 // Use a shorter timer on these platforms to avoid losing data.
219 // TODO(dfalcantara): To avoid delaying startup, tighten up initialization so
220 // that it occurs after the user gets their initial page.
221 const int kInitializationDelaySeconds = 5;
222 #else
223 const int kInitializationDelaySeconds = 30;
224 #endif
225
226 // The browser last live timestamp is updated every 15 minutes.
227 const int kUpdateAliveTimestampSeconds = 15 * 60;
228
229 #if BUILDFLAG(IS_CHROMEOS_ASH)
230 enum UserLogStoreState {
231 kSetPostSendLogsState = 0,
232 kSetPreSendLogsState = 1,
233 kUnsetPostSendLogsState = 2,
234 kUnsetPreSendLogsState = 3,
235 kMaxValue = kUnsetPreSendLogsState,
236 };
237
RecordUserLogStoreState(UserLogStoreState state)238 void RecordUserLogStoreState(UserLogStoreState state) {
239 base::UmaHistogramEnumeration("UMA.CrosPerUser.UserLogStoreState", state);
240 }
241 #endif // BUILDFLAG(IS_CHROMEOS_ASH)
242
243 } // namespace
244
245 // static
RegisterPrefs(PrefRegistrySimple * registry)246 void MetricsService::RegisterPrefs(PrefRegistrySimple* registry) {
247 CleanExitBeacon::RegisterPrefs(registry);
248 MetricsStateManager::RegisterPrefs(registry);
249 MetricsLog::RegisterPrefs(registry);
250 StabilityMetricsProvider::RegisterPrefs(registry);
251 MetricsReportingService::RegisterPrefs(registry);
252
253 registry->RegisterIntegerPref(prefs::kMetricsSessionID, -1);
254 }
255
MetricsService(MetricsStateManager * state_manager,MetricsServiceClient * client,PrefService * local_state)256 MetricsService::MetricsService(MetricsStateManager* state_manager,
257 MetricsServiceClient* client,
258 PrefService* local_state)
259 : reporting_service_(client, local_state, &logs_event_manager_),
260 state_manager_(state_manager),
261 client_(client),
262 local_state_(local_state),
263 recording_state_(UNSET),
264 test_mode_active_(false),
265 state_(CONSTRUCTED),
266 idle_since_last_transmission_(false),
267 session_id_(-1) {
268 DCHECK_CALLED_ON_VALID_SEQUENCE(sequence_checker_);
269 DCHECK(state_manager_);
270 DCHECK(client_);
271 DCHECK(local_state_);
272
273 bool create_logs_event_observer;
274 #ifdef NDEBUG
275 // For non-debug builds, we only create |logs_event_observer_| if the
276 // |kExportUmaLogsToFile| command line flag is passed. This is mostly for
277 // performance reasons: 1) we don't want to have to notify an observer in
278 // non-debug circumstances (there may be heavy work like copying large
279 // strings), and 2) we don't want logs to be lingering in memory.
280 create_logs_event_observer =
281 base::CommandLine::ForCurrentProcess()->HasSwitch(
282 switches::kExportUmaLogsToFile);
283 #else
284 // For debug builds, always create |logs_event_observer_|.
285 create_logs_event_observer = true;
286 #endif // NDEBUG
287
288 if (create_logs_event_observer) {
289 logs_event_observer_ = std::make_unique<MetricsServiceObserver>(
290 MetricsServiceObserver::MetricsServiceType::UMA);
291 logs_event_manager_.AddObserver(logs_event_observer_.get());
292 }
293
294 if (base::FeatureList::IsEnabled(
295 features::kMetricsClearLogsOnClonedInstall)) {
296 cloned_install_subscription_ =
297 state_manager->AddOnClonedInstallDetectedCallback(
298 base::BindOnce(&MetricsService::OnClonedInstallDetected,
299 self_ptr_factory_.GetWeakPtr()));
300 }
301
302 RegisterMetricsProvider(
303 std::make_unique<StabilityMetricsProvider>(local_state_));
304
305 RegisterMetricsProvider(state_manager_->GetProvider());
306 }
307
~MetricsService()308 MetricsService::~MetricsService() {
309 DisableRecording();
310
311 if (logs_event_observer_) {
312 logs_event_manager_.RemoveObserver(logs_event_observer_.get());
313 const base::CommandLine* command_line =
314 base::CommandLine::ForCurrentProcess();
315 if (command_line->HasSwitch(switches::kExportUmaLogsToFile)) {
316 // We should typically not write to files on the main thread, but since
317 // this only happens when |kExportUmaLogsToFile| is passed (which
318 // indicates debugging), this should be fine.
319 logs_event_observer_->ExportLogsToFile(
320 command_line->GetSwitchValuePath(switches::kExportUmaLogsToFile));
321 }
322 }
323 }
324
InitializeMetricsRecordingState()325 void MetricsService::InitializeMetricsRecordingState() {
326 DCHECK_EQ(CONSTRUCTED, state_);
327
328 // The FieldTrialsProvider should be registered last. This ensures that
329 // studies whose features are checked when providers add their information to
330 // the log appear in the active field trials.
331 RegisterMetricsProvider(std::make_unique<variations::FieldTrialsProvider>(
332 client_->GetSyntheticTrialRegistry(), base::StringPiece()));
333
334 reporting_service_.Initialize();
335 InitializeMetricsState();
336
337 base::RepeatingClosure upload_callback = base::BindRepeating(
338 &MetricsService::StartScheduledUpload, self_ptr_factory_.GetWeakPtr());
339
340 rotation_scheduler_ = std::make_unique<MetricsRotationScheduler>(
341 upload_callback,
342 // MetricsServiceClient outlives MetricsService, and
343 // MetricsRotationScheduler is tied to the lifetime of |this|.
344 base::BindRepeating(&MetricsServiceClient::GetUploadInterval,
345 base::Unretained(client_)),
346 client_->ShouldStartUpFastForTesting());
347
348 // Init() has to be called after LogCrash() in order for LogCrash() to work.
349 delegating_provider_.Init();
350
351 state_ = INITIALIZED;
352 }
353
Start()354 void MetricsService::Start() {
355 HandleIdleSinceLastTransmission(false);
356 EnableRecording();
357 EnableReporting();
358 }
359
StartRecordingForTests()360 void MetricsService::StartRecordingForTests() {
361 test_mode_active_ = true;
362 EnableRecording();
363 DisableReporting();
364 }
365
StartUpdatingLastLiveTimestamp()366 void MetricsService::StartUpdatingLastLiveTimestamp() {
367 base::SequencedTaskRunner::GetCurrentDefault()->PostDelayedTask(
368 FROM_HERE,
369 base::BindOnce(&MetricsService::UpdateLastLiveTimestampTask,
370 self_ptr_factory_.GetWeakPtr()),
371 GetUpdateLastAliveTimestampDelay());
372 }
373
Stop()374 void MetricsService::Stop() {
375 HandleIdleSinceLastTransmission(false);
376 DisableReporting();
377 DisableRecording();
378 }
379
EnableReporting()380 void MetricsService::EnableReporting() {
381 if (reporting_service_.reporting_active())
382 return;
383 reporting_service_.EnableReporting();
384 StartSchedulerIfNecessary();
385 }
386
DisableReporting()387 void MetricsService::DisableReporting() {
388 reporting_service_.DisableReporting();
389 }
390
GetClientId() const391 std::string MetricsService::GetClientId() const {
392 return state_manager_->client_id();
393 }
394
SetExternalClientId(const std::string & id)395 void MetricsService::SetExternalClientId(const std::string& id) {
396 state_manager_->SetExternalClientId(id);
397 }
398
WasLastShutdownClean() const399 bool MetricsService::WasLastShutdownClean() const {
400 return state_manager_->clean_exit_beacon()->exited_cleanly();
401 }
402
EnableRecording()403 void MetricsService::EnableRecording() {
404 DCHECK_CALLED_ON_VALID_SEQUENCE(sequence_checker_);
405
406 if (recording_state_ == ACTIVE)
407 return;
408 recording_state_ = ACTIVE;
409
410 state_manager_->ForceClientIdCreation();
411 client_->SetMetricsClientId(state_manager_->client_id());
412
413 if (!log_manager_.current_log())
414 OpenNewLog();
415
416 delegating_provider_.OnRecordingEnabled();
417 #if BUILDFLAG(IS_CHROMEOS_ASH)
418 // This must be after OnRecordingEnabled() to ensure that the structured
419 // logging has been enabled.
420 metrics::structured::NeutrinoDevicesLogWithClientId(
421 state_manager_->client_id(),
422 metrics::structured::NeutrinoDevicesLocation::kEnableRecording);
423 #endif // BUILDFLAG(IS_CHROMEOS_ASH)
424
425 // Fill in the system profile in the log and persist it (to prefs, .pma
426 // and crashpad). This includes running the providers so that information
427 // like field trials and hardware info is provided. If Chrome crashes
428 // before this log is completed, the .pma file will have this system
429 // profile.
430 RecordCurrentEnvironment(log_manager_.current_log(), /*complete=*/false);
431
432 base::RemoveActionCallback(action_callback_);
433 action_callback_ = base::BindRepeating(&MetricsService::OnUserAction,
434 base::Unretained(this));
435 base::AddActionCallback(action_callback_);
436
437 enablement_observers_.Notify(/*enabled=*/true);
438 }
439
DisableRecording()440 void MetricsService::DisableRecording() {
441 DCHECK_CALLED_ON_VALID_SEQUENCE(sequence_checker_);
442
443 if (recording_state_ == INACTIVE)
444 return;
445 recording_state_ = INACTIVE;
446
447 base::RemoveActionCallback(action_callback_);
448
449 delegating_provider_.OnRecordingDisabled();
450
451 base::UmaHistogramBoolean("UMA.MetricsService.PendingOngoingLogOnDisable",
452 pending_ongoing_log_);
453 PushPendingLogsToPersistentStorage(
454 MetricsLogsEventManager::CreateReason::kServiceShutdown);
455
456 // Because histograms may still be emitted after the last log was closed, an
457 // independent log may be created in a future session in order to report
458 // those histograms. To ensure that this independent log contains histograms
459 // that we wish to appear in every log, call OnDidCreateMetricsLog().
460 delegating_provider_.OnDidCreateMetricsLog();
461
462 enablement_observers_.Notify(/*enabled=*/false);
463 }
464
recording_active() const465 bool MetricsService::recording_active() const {
466 DCHECK_CALLED_ON_VALID_SEQUENCE(sequence_checker_);
467 return recording_state_ == ACTIVE;
468 }
469
reporting_active() const470 bool MetricsService::reporting_active() const {
471 DCHECK_CALLED_ON_VALID_SEQUENCE(sequence_checker_);
472 return reporting_service_.reporting_active();
473 }
474
has_unsent_logs() const475 bool MetricsService::has_unsent_logs() const {
476 return reporting_service_.metrics_log_store()->has_unsent_logs();
477 }
478
IsMetricsReportingEnabled() const479 bool MetricsService::IsMetricsReportingEnabled() const {
480 return state_manager_->IsMetricsReportingEnabled();
481 }
482
HandleIdleSinceLastTransmission(bool in_idle)483 void MetricsService::HandleIdleSinceLastTransmission(bool in_idle) {
484 // If there wasn't a lot of action, maybe the computer was asleep, in which
485 // case, the log transmissions should have stopped. Here we start them up
486 // again.
487 if (!in_idle && idle_since_last_transmission_)
488 StartSchedulerIfNecessary();
489 idle_since_last_transmission_ = in_idle;
490 }
491
OnApplicationNotIdle()492 void MetricsService::OnApplicationNotIdle() {
493 if (recording_state_ == ACTIVE)
494 HandleIdleSinceLastTransmission(false);
495 }
496
497 #if BUILDFLAG(IS_ANDROID) || BUILDFLAG(IS_IOS)
OnAppEnterBackground(bool keep_recording_in_background)498 void MetricsService::OnAppEnterBackground(bool keep_recording_in_background) {
499 is_in_foreground_ = false;
500 reporting_service_.SetIsInForegound(false);
501 if (!keep_recording_in_background) {
502 rotation_scheduler_->Stop();
503 reporting_service_.Stop();
504 }
505
506 state_manager_->LogHasSessionShutdownCleanly(true);
507 // Schedule a write, which happens on a different thread.
508 local_state_->CommitPendingWrite();
509
510 // Give providers a chance to persist histograms as part of being
511 // backgrounded.
512 delegating_provider_.OnAppEnterBackground();
513
514 // At this point, there's no way of knowing when the process will be killed,
515 // so this has to be treated similar to a shutdown, closing and persisting all
516 // logs. Unlike a shutdown, the state is primed to be ready to continue
517 // logging and uploading if the process does return.
518 if (recording_active() && !IsTooEarlyToCloseLog()) {
519 base::UmaHistogramBoolean(
520 "UMA.MetricsService.PendingOngoingLogOnBackgrounded",
521 pending_ongoing_log_);
522 PushPendingLogsToPersistentStorage(
523 MetricsLogsEventManager::CreateReason::kBackgrounded);
524 // Persisting logs closes the current log, so start recording a new log
525 // immediately to capture any background work that might be done before the
526 // process is killed.
527 OpenNewLog();
528 }
529 }
530
OnAppEnterForeground(bool force_open_new_log)531 void MetricsService::OnAppEnterForeground(bool force_open_new_log) {
532 is_in_foreground_ = true;
533 reporting_service_.SetIsInForegound(true);
534 state_manager_->LogHasSessionShutdownCleanly(false);
535 StartSchedulerIfNecessary();
536
537 if (force_open_new_log && recording_active() && !IsTooEarlyToCloseLog()) {
538 base::UmaHistogramBoolean(
539 "UMA.MetricsService.PendingOngoingLogOnForegrounded",
540 pending_ongoing_log_);
541 // Because state_ >= SENDING_LOGS, PushPendingLogsToPersistentStorage()
542 // will close the log, allowing a new log to be opened.
543 PushPendingLogsToPersistentStorage(
544 MetricsLogsEventManager::CreateReason::kForegrounded);
545 OpenNewLog();
546 }
547 }
548 #endif // BUILDFLAG(IS_ANDROID) || BUILDFLAG(IS_IOS)
549
LogCleanShutdown()550 void MetricsService::LogCleanShutdown() {
551 DCHECK_CALLED_ON_VALID_SEQUENCE(sequence_checker_);
552 state_manager_->LogHasSessionShutdownCleanly(true);
553 }
554
ClearSavedStabilityMetrics()555 void MetricsService::ClearSavedStabilityMetrics() {
556 delegating_provider_.ClearSavedStabilityMetrics();
557 // Stability metrics are stored in Local State prefs, so schedule a Local
558 // State write to flush the updated prefs.
559 local_state_->CommitPendingWrite();
560 }
561
MarkCurrentHistogramsAsReported()562 void MetricsService::MarkCurrentHistogramsAsReported() {
563 DiscardingFlattener flattener;
564 base::HistogramSnapshotManager snapshot_manager(&flattener);
565 base::StatisticsRecorder::PrepareDeltas(
566 /*include_persistent=*/true, /*flags_to_set=*/base::Histogram::kNoFlags,
567 /*required_flags=*/base::Histogram::kUmaTargetedHistogramFlag,
568 &snapshot_manager);
569 }
570
571 #if BUILDFLAG(IS_CHROMEOS_ASH)
SetUserLogStore(std::unique_ptr<UnsentLogStore> user_log_store)572 void MetricsService::SetUserLogStore(
573 std::unique_ptr<UnsentLogStore> user_log_store) {
574 if (log_store()->has_alternate_ongoing_log_store())
575 return;
576
577 if (state_ >= SENDING_LOGS) {
578 // Closes the current log so that a new log can be opened in the user log
579 // store.
580 PushPendingLogsToPersistentStorage(
581 MetricsLogsEventManager::CreateReason::kAlternateOngoingLogStoreSet);
582 log_store()->SetAlternateOngoingLogStore(std::move(user_log_store));
583 OpenNewLog();
584 RecordUserLogStoreState(kSetPostSendLogsState);
585 } else {
586 // Initial log has not yet been created and flushing now would result in
587 // incomplete information in the current log.
588 //
589 // Logs recorded before a user login will be appended to user logs. This
590 // should not happen frequently.
591 //
592 // TODO(crbug/1264627): Look for a way to "pause" pre-login logs and flush
593 // when INIT_TASK is done.
594 log_store()->SetAlternateOngoingLogStore(std::move(user_log_store));
595 RecordUserLogStoreState(kSetPreSendLogsState);
596 }
597 }
598
UnsetUserLogStore()599 void MetricsService::UnsetUserLogStore() {
600 if (!log_store()->has_alternate_ongoing_log_store())
601 return;
602
603 if (state_ >= SENDING_LOGS) {
604 PushPendingLogsToPersistentStorage(
605 MetricsLogsEventManager::CreateReason::kAlternateOngoingLogStoreUnset);
606 log_store()->UnsetAlternateOngoingLogStore();
607 OpenNewLog();
608 RecordUserLogStoreState(kUnsetPostSendLogsState);
609 return;
610 }
611
612 // Fast startup and logout case. We flush all histograms and discard the
613 // current log. This is to prevent histograms captured during the user
614 // session from leaking into local state logs.
615 // TODO(crbug/1381581): Consider not flushing histograms here.
616
617 // Discard histograms.
618 DiscardingFlattener flattener;
619 base::HistogramSnapshotManager histogram_snapshot_manager(&flattener);
620 delegating_provider_.RecordHistogramSnapshots(&histogram_snapshot_manager);
621 base::StatisticsRecorder::PrepareDeltas(
622 /*include_persistent=*/true, /*flags_to_set=*/base::Histogram::kNoFlags,
623 /*required_flags=*/base::Histogram::kUmaTargetedHistogramFlag,
624 &histogram_snapshot_manager);
625
626 // Release the current log and don't store it (i.e., we discard it).
627 log_manager_.ReleaseCurrentLog();
628
629 log_store()->UnsetAlternateOngoingLogStore();
630 RecordUserLogStoreState(kUnsetPreSendLogsState);
631 }
632
HasUserLogStore()633 bool MetricsService::HasUserLogStore() {
634 return log_store()->has_alternate_ongoing_log_store();
635 }
636
InitPerUserMetrics()637 void MetricsService::InitPerUserMetrics() {
638 client_->InitPerUserMetrics();
639 }
640
GetCurrentUserMetricsConsent() const641 absl::optional<bool> MetricsService::GetCurrentUserMetricsConsent() const {
642 return client_->GetCurrentUserMetricsConsent();
643 }
644
GetCurrentUserId() const645 absl::optional<std::string> MetricsService::GetCurrentUserId() const {
646 return client_->GetCurrentUserId();
647 }
648
UpdateCurrentUserMetricsConsent(bool user_metrics_consent)649 void MetricsService::UpdateCurrentUserMetricsConsent(
650 bool user_metrics_consent) {
651 client_->UpdateCurrentUserMetricsConsent(user_metrics_consent);
652 }
653 #endif // BUILDFLAG(IS_CHROMEOS_ASH)
654
655 #if BUILDFLAG(IS_CHROMEOS)
ResetClientId()656 void MetricsService::ResetClientId() {
657 // Pref must be cleared in order for ForceClientIdCreation to generate a new
658 // client ID.
659 local_state_->ClearPref(prefs::kMetricsClientID);
660 local_state_->ClearPref(prefs::kMetricsLogRecordId);
661 state_manager_->ForceClientIdCreation();
662 client_->SetMetricsClientId(state_manager_->client_id());
663 }
664 #endif // BUILDFLAG(IS_CHROMEOS)
665
666 variations::SyntheticTrialRegistry*
GetSyntheticTrialRegistry()667 MetricsService::GetSyntheticTrialRegistry() {
668 return client_->GetSyntheticTrialRegistry();
669 }
670
GetInitializationDelay()671 base::TimeDelta MetricsService::GetInitializationDelay() {
672 return base::Seconds(
673 client_->ShouldStartUpFastForTesting() ? 0 : kInitializationDelaySeconds);
674 }
675
GetUpdateLastAliveTimestampDelay()676 base::TimeDelta MetricsService::GetUpdateLastAliveTimestampDelay() {
677 return base::Seconds(kUpdateAliveTimestampSeconds);
678 }
679
StageCurrentLogForTest()680 bool MetricsService::StageCurrentLogForTest() {
681 CloseCurrentLog(/*async=*/false,
682 MetricsLogsEventManager::CreateReason::kUnknown);
683
684 MetricsLogStore* const log_store = reporting_service_.metrics_log_store();
685 log_store->StageNextLog();
686 if (!log_store->has_staged_log())
687 return false;
688
689 OpenNewLog();
690 return true;
691 }
692
693 //------------------------------------------------------------------------------
694 // private methods
695 //------------------------------------------------------------------------------
696
697 //------------------------------------------------------------------------------
698 // Initialization methods
699
InitializeMetricsState()700 void MetricsService::InitializeMetricsState() {
701 SCOPED_UMA_HISTOGRAM_TIMER_MICROS("UMA.MetricsService.Initialize.Time");
702
703 const int64_t buildtime = MetricsLog::GetBuildTime();
704 const std::string version = client_->GetVersionString();
705
706 bool version_changed = false;
707 EnvironmentRecorder recorder(local_state_);
708 int64_t previous_buildtime = recorder.GetLastBuildtime();
709 std::string previous_version = recorder.GetLastVersion();
710 if (previous_buildtime != buildtime || previous_version != version) {
711 recorder.SetBuildtimeAndVersion(buildtime, version);
712 version_changed = true;
713 }
714
715 session_id_ = local_state_->GetInteger(prefs::kMetricsSessionID);
716
717 StabilityMetricsProvider provider(local_state_);
718 const bool was_last_shutdown_clean = WasLastShutdownClean();
719 if (!was_last_shutdown_clean) {
720 provider.LogCrash(
721 state_manager_->clean_exit_beacon()->browser_last_live_timestamp());
722 #if BUILDFLAG(IS_ANDROID)
723 if (!state_manager_->is_foreground_session()) {
724 // Android can have background sessions in which the app may not come to
725 // the foreground, so signal that Chrome should stop watching for crashes
726 // here. This ensures that the termination of such sessions is not
727 // considered a crash. If and when the app enters the foreground, Chrome
728 // starts watching for crashes via MetricsService::OnAppEnterForeground().
729 //
730 // TODO(crbug/1232027): Such sessions do not yet exist on iOS. When they
731 // do, it may not be possible to know at this point whether a session is a
732 // background session.
733 //
734 // TODO(crbug/1245347): On WebLayer, it is not possible to know whether
735 // it's a background session at this point.
736 //
737 // TODO(crbug/1245676): Ditto for WebView.
738 state_manager_->clean_exit_beacon()->WriteBeaconValue(true);
739 }
740 #endif // BUILDFLAG(IS_ANDROID)
741 }
742
743 // HasPreviousSessionData is called first to ensure it is never bypassed.
744 const bool is_initial_stability_log_required =
745 delegating_provider_.HasPreviousSessionData() || !was_last_shutdown_clean;
746 bool has_initial_stability_log = false;
747 if (is_initial_stability_log_required) {
748 // If the previous session didn't exit cleanly, or if any provider
749 // explicitly requests it, prepare an initial stability log -
750 // provided UMA is enabled.
751 if (state_manager_->IsMetricsReportingEnabled()) {
752 has_initial_stability_log = PrepareInitialStabilityLog(previous_version);
753 }
754 }
755
756 // If the version changed, but no initial stability log was generated, clear
757 // the stability stats from the previous version (so that they don't get
758 // attributed to the current version). This could otherwise happen due to a
759 // number of different edge cases, such as if the last version crashed before
760 // it could save off a system profile or if UMA reporting is disabled (which
761 // normally results in stats being accumulated).
762 if (version_changed && !has_initial_stability_log)
763 ClearSavedStabilityMetrics();
764
765 // If the version changed, the system profile is obsolete and needs to be
766 // cleared. This is to avoid the stability data misattribution that could
767 // occur if the current version crashed before saving its own system profile.
768 // Note however this clearing occurs only after preparing the initial
769 // stability log, an operation that requires the previous version's system
770 // profile. At this point, stability metrics pertaining to the previous
771 // version have been cleared.
772 if (version_changed)
773 recorder.ClearEnvironmentFromPrefs();
774
775 // Update session ID.
776 ++session_id_;
777 local_state_->SetInteger(prefs::kMetricsSessionID, session_id_);
778
779 // Notify stability metrics providers about the launch.
780 provider.LogLaunch();
781
782 // Call GetUptimes() for the first time, thus allowing all later calls
783 // to record incremental uptimes accurately.
784 base::TimeDelta ignored_uptime_parameter;
785 base::TimeDelta startup_uptime;
786 GetUptimes(local_state_, &startup_uptime, &ignored_uptime_parameter);
787 DCHECK_EQ(0, startup_uptime.InMicroseconds());
788 }
789
OnUserAction(const std::string & action,base::TimeTicks action_time)790 void MetricsService::OnUserAction(const std::string& action,
791 base::TimeTicks action_time) {
792 log_manager_.current_log()->RecordUserAction(action, action_time);
793 HandleIdleSinceLastTransmission(false);
794 }
795
FinishedInitTask()796 void MetricsService::FinishedInitTask() {
797 DCHECK_EQ(INIT_TASK_SCHEDULED, state_);
798 state_ = INIT_TASK_DONE;
799 rotation_scheduler_->InitTaskComplete();
800 }
801
GetUptimes(PrefService * pref,base::TimeDelta * incremental_uptime,base::TimeDelta * uptime)802 void MetricsService::GetUptimes(PrefService* pref,
803 base::TimeDelta* incremental_uptime,
804 base::TimeDelta* uptime) {
805 base::TimeTicks now = base::TimeTicks::Now();
806 // If this is the first call, init |first_updated_time_| and
807 // |last_updated_time_|.
808 if (last_updated_time_.is_null()) {
809 first_updated_time_ = now;
810 last_updated_time_ = now;
811 }
812 *incremental_uptime = now - last_updated_time_;
813 *uptime = now - first_updated_time_;
814 last_updated_time_ = now;
815 }
816
817 //------------------------------------------------------------------------------
818 // Recording control methods
819
OpenNewLog(bool call_providers)820 void MetricsService::OpenNewLog(bool call_providers) {
821 DCHECK(!log_manager_.current_log());
822
823 log_manager_.BeginLoggingWithLog(CreateLog(MetricsLog::ONGOING_LOG));
824 if (call_providers) {
825 delegating_provider_.OnDidCreateMetricsLog();
826 }
827
828 DCHECK_NE(CONSTRUCTED, state_);
829 if (state_ == INITIALIZED) {
830 // We only need to schedule that run once.
831 state_ = INIT_TASK_SCHEDULED;
832
833 base::TimeDelta initialization_delay = GetInitializationDelay();
834 base::SequencedTaskRunner::GetCurrentDefault()->PostDelayedTask(
835 FROM_HERE,
836 base::BindOnce(&MetricsService::StartInitTask,
837 self_ptr_factory_.GetWeakPtr()),
838 initialization_delay);
839
840 base::SequencedTaskRunner::GetCurrentDefault()->PostDelayedTask(
841 FROM_HERE,
842 base::BindOnce(&MetricsService::PrepareProviderMetricsTask,
843 self_ptr_factory_.GetWeakPtr()),
844 2 * initialization_delay);
845 }
846 }
847
848 MetricsService::FinalizedLog::FinalizedLog() = default;
849 MetricsService::FinalizedLog::~FinalizedLog() = default;
850 MetricsService::FinalizedLog::FinalizedLog(FinalizedLog&& other) = default;
851
MetricsLogHistogramWriter(MetricsLog * log)852 MetricsService::MetricsLogHistogramWriter::MetricsLogHistogramWriter(
853 MetricsLog* log)
854 : MetricsLogHistogramWriter(log,
855 base::Histogram::kUmaTargetedHistogramFlag) {}
856
MetricsLogHistogramWriter(MetricsLog * log,base::HistogramBase::Flags required_flags)857 MetricsService::MetricsLogHistogramWriter::MetricsLogHistogramWriter(
858 MetricsLog* log,
859 base::HistogramBase::Flags required_flags)
860 : required_flags_(required_flags),
861 flattener_(std::make_unique<IndependentFlattener>(log)),
862 histogram_snapshot_manager_(
863 std::make_unique<base::HistogramSnapshotManager>(flattener_.get())),
864 snapshot_transaction_id_(0) {}
865
866 MetricsService::MetricsLogHistogramWriter::~MetricsLogHistogramWriter() =
867 default;
868
869 void MetricsService::MetricsLogHistogramWriter::
SnapshotStatisticsRecorderDeltas()870 SnapshotStatisticsRecorderDeltas() {
871 SCOPED_UMA_HISTOGRAM_TIMER("UMA.MetricsService.SnapshotDeltasTime");
872 snapshot_transaction_id_ = base::StatisticsRecorder::PrepareDeltas(
873 /*include_persistent=*/true,
874 /*flags_to_set=*/base::Histogram::kNoFlags, required_flags_,
875 histogram_snapshot_manager_.get());
876 }
877
878 void MetricsService::MetricsLogHistogramWriter::
SnapshotStatisticsRecorderUnloggedSamples()879 SnapshotStatisticsRecorderUnloggedSamples() {
880 snapshot_transaction_id_ = base::StatisticsRecorder::SnapshotUnloggedSamples(
881 required_flags_, histogram_snapshot_manager_.get());
882 }
883
IndependentMetricsLoader(std::unique_ptr<MetricsLog> log)884 MetricsService::IndependentMetricsLoader::IndependentMetricsLoader(
885 std::unique_ptr<MetricsLog> log)
886 : log_(std::move(log)),
887 flattener_(new IndependentFlattener(log_.get())),
888 snapshot_manager_(new base::HistogramSnapshotManager(flattener_.get())) {}
889
890 MetricsService::IndependentMetricsLoader::~IndependentMetricsLoader() = default;
891
Run(base::OnceCallback<void (bool)> done_callback,MetricsProvider * metrics_provider)892 void MetricsService::IndependentMetricsLoader::Run(
893 base::OnceCallback<void(bool)> done_callback,
894 MetricsProvider* metrics_provider) {
895 metrics_provider->ProvideIndependentMetrics(
896 std::move(done_callback), log_->uma_proto(), snapshot_manager_.get());
897 }
898
899 std::unique_ptr<MetricsLog>
ReleaseLog()900 MetricsService::IndependentMetricsLoader::ReleaseLog() {
901 return std::move(log_);
902 }
903
StartInitTask()904 void MetricsService::StartInitTask() {
905 delegating_provider_.AsyncInit(base::BindOnce(
906 &MetricsService::FinishedInitTask, self_ptr_factory_.GetWeakPtr()));
907 }
908
CloseCurrentLog(bool async,MetricsLogsEventManager::CreateReason reason,base::OnceClosure log_stored_callback)909 void MetricsService::CloseCurrentLog(
910 bool async,
911 MetricsLogsEventManager::CreateReason reason,
912 base::OnceClosure log_stored_callback) {
913 if (!log_manager_.current_log())
914 return;
915
916 // If a persistent allocator is in use, update its internal histograms (such
917 // as how much memory is being used) before reporting.
918 base::PersistentHistogramAllocator* allocator =
919 base::GlobalHistogramAllocator::Get();
920 if (allocator)
921 allocator->UpdateTrackingHistograms();
922
923 // Put incremental data (histogram deltas, and realtime stats deltas) at the
924 // end of all log transmissions (initial log handles this separately).
925 // RecordIncrementalStabilityElements only exists on the derived
926 // MetricsLog class.
927 std::unique_ptr<MetricsLog> current_log = log_manager_.ReleaseCurrentLog();
928 DCHECK(current_log);
929 RecordCurrentEnvironment(current_log.get(), /*complete=*/true);
930 base::TimeDelta incremental_uptime;
931 base::TimeDelta uptime;
932 GetUptimes(local_state_, &incremental_uptime, &uptime);
933 current_log->RecordCurrentSessionData(incremental_uptime, uptime,
934 &delegating_provider_, local_state_);
935
936 auto log_histogram_writer =
937 std::make_unique<MetricsLogHistogramWriter>(current_log.get());
938
939 // Let metrics providers provide histogram snapshots independently if they
940 // have any. This is done synchronously.
941 delegating_provider_.RecordHistogramSnapshots(
942 log_histogram_writer->histogram_snapshot_manager());
943
944 MetricsLog::LogType log_type = current_log->log_type();
945 std::string signing_key = log_store()->GetSigningKeyForLogType(log_type);
946 if (async) {
947 // To finalize the log asynchronously, we snapshot the unlogged samples of
948 // histograms and fill them into the log, without actually marking the
949 // samples as logged. We only mark them as logged after running the main
950 // thread reply task to store the log. This way, we will not lose the
951 // samples in case Chrome closes while the background task is running. Note
952 // that while this async log is being finalized, it is possible that another
953 // log is finalized and stored synchronously, which could potentially cause
954 // the same samples to be in two different logs, and hence sent twice. To
955 // prevent this, if a synchronous log is stored while the async one is being
956 // finalized, we discard the async log as it would be a subset of the
957 // synchronous one (in terms of histograms). For more details, see
958 // MaybeCleanUpAndStoreFinalizedLog().
959 //
960 // TODO(crbug/1052796): Find a way to save the other data such as user
961 // actions and omnibox events when we discard an async log.
962 MetricsLogHistogramWriter* log_histogram_writer_ptr =
963 log_histogram_writer.get();
964 base::ThreadPool::PostTaskAndReplyWithResult(
965 FROM_HERE,
966 base::BindOnce(&MetricsService::SnapshotUnloggedSamplesAndFinalizeLog,
967 log_histogram_writer_ptr, std::move(current_log),
968 /*truncate_events=*/true, client_->GetVersionString(),
969 std::move(signing_key)),
970 base::BindOnce(&MetricsService::MaybeCleanUpAndStoreFinalizedLog,
971 self_ptr_factory_.GetWeakPtr(),
972 std::move(log_histogram_writer), log_type, reason,
973 std::move(log_stored_callback)));
974 async_ongoing_log_posted_time_ = base::TimeTicks::Now();
975 } else {
976 FinalizedLog finalized_log = SnapshotDeltasAndFinalizeLog(
977 std::move(log_histogram_writer), std::move(current_log),
978 /*truncate_events=*/true, client_->GetVersionString(),
979 std::move(signing_key));
980 StoreFinalizedLog(log_type, reason, std::move(log_stored_callback),
981 std::move(finalized_log));
982 }
983 }
984
StoreFinalizedLog(MetricsLog::LogType log_type,MetricsLogsEventManager::CreateReason reason,base::OnceClosure done_callback,FinalizedLog finalized_log)985 void MetricsService::StoreFinalizedLog(
986 MetricsLog::LogType log_type,
987 MetricsLogsEventManager::CreateReason reason,
988 base::OnceClosure done_callback,
989 FinalizedLog finalized_log) {
990 log_store()->StoreLogInfo(std::move(finalized_log.log_info),
991 finalized_log.uncompressed_log_size, log_type,
992 reason);
993 std::move(done_callback).Run();
994 }
995
MaybeCleanUpAndStoreFinalizedLog(std::unique_ptr<MetricsLogHistogramWriter> log_histogram_writer,MetricsLog::LogType log_type,MetricsLogsEventManager::CreateReason reason,base::OnceClosure done_callback,FinalizedLog finalized_log)996 void MetricsService::MaybeCleanUpAndStoreFinalizedLog(
997 std::unique_ptr<MetricsLogHistogramWriter> log_histogram_writer,
998 MetricsLog::LogType log_type,
999 MetricsLogsEventManager::CreateReason reason,
1000 base::OnceClosure done_callback,
1001 FinalizedLog finalized_log) {
1002 UMA_HISTOGRAM_TIMES("UMA.MetricsService.PeriodicOngoingLog.ReplyTime",
1003 base::TimeTicks::Now() - async_ongoing_log_posted_time_);
1004
1005 // Store the finalized log only if the StatisticRecorder's last transaction ID
1006 // is the same as the one from |log_histogram_writer|. If they are not the
1007 // same, then it indicates that another log was created while creating
1008 // |finalized_log| (that log would be a superset of |finalized_log| in terms
1009 // of histograms, so we discard |finalized_log| by not storing it).
1010 //
1011 // TODO(crbug/1052796): Find a way to save the other data such as user actions
1012 // and omnibox events when we discard |finalized_log|.
1013 //
1014 // Note that the call to StatisticsRecorder::GetLastSnapshotTransactionId()
1015 // here should not have to wait for a lock since there should not be any async
1016 // logs being created (|rotation_scheduler_| is only re-scheduled at the end
1017 // of this method).
1018 bool should_store_log =
1019 (base::StatisticsRecorder::GetLastSnapshotTransactionId() ==
1020 log_histogram_writer->snapshot_transaction_id());
1021 base::UmaHistogramBoolean("UMA.MetricsService.ShouldStoreAsyncLog",
1022 should_store_log);
1023
1024 if (!should_store_log) {
1025 // We still need to run |done_callback| even if we do not store the log.
1026 std::move(done_callback).Run();
1027 return;
1028 }
1029
1030 SCOPED_UMA_HISTOGRAM_TIMER(
1031 "UMA.MetricsService.MaybeCleanUpAndStoreFinalizedLog.Time");
1032
1033 log_histogram_writer->histogram_snapshot_manager()
1034 ->MarkUnloggedSamplesAsLogged();
1035 StoreFinalizedLog(log_type, reason, std::move(done_callback),
1036 std::move(finalized_log));
1037
1038 // Call OnDidCreateMetricsLog() after storing a log instead of directly after
1039 // opening a log. Otherwise, the async log that was created would potentially
1040 // have mistakenly snapshotted the histograms intended for the newly opened
1041 // log.
1042 delegating_provider_.OnDidCreateMetricsLog();
1043 }
1044
PushPendingLogsToPersistentStorage(MetricsLogsEventManager::CreateReason reason)1045 void MetricsService::PushPendingLogsToPersistentStorage(
1046 MetricsLogsEventManager::CreateReason reason) {
1047 if (IsTooEarlyToCloseLog()) {
1048 return;
1049 }
1050
1051 base::UmaHistogramBoolean("UMA.MetricsService.PendingOngoingLog",
1052 pending_ongoing_log_);
1053
1054 // Close and store a log synchronously because this is usually called in
1055 // critical code paths (e.g., shutdown) where we may not have time to run
1056 // background tasks.
1057 CloseCurrentLog(/*async=*/false, reason);
1058 log_store()->TrimAndPersistUnsentLogs(/*overwrite_in_memory_store=*/true);
1059 }
1060
1061 //------------------------------------------------------------------------------
1062 // Transmission of logs methods
1063
StartSchedulerIfNecessary()1064 void MetricsService::StartSchedulerIfNecessary() {
1065 // Never schedule cutting or uploading of logs in test mode.
1066 if (test_mode_active_)
1067 return;
1068
1069 // Even if reporting is disabled, the scheduler is needed to trigger the
1070 // creation of the first ongoing log, which must be done in order for any logs
1071 // to be persisted on shutdown or backgrounding.
1072 if (recording_active() && (reporting_active() || state_ < SENDING_LOGS)) {
1073 rotation_scheduler_->Start();
1074 reporting_service_.Start();
1075 }
1076 }
1077
StartScheduledUpload()1078 void MetricsService::StartScheduledUpload() {
1079 DVLOG(1) << "StartScheduledUpload";
1080 DCHECK(state_ >= INIT_TASK_DONE);
1081
1082 // If we're getting no notifications, then the log won't have much in it, and
1083 // it's possible the computer is about to go to sleep, so don't upload and
1084 // stop the scheduler.
1085 // If recording has been turned off, the scheduler doesn't need to run.
1086 // If reporting is off, proceed if the first ongoing log hasn't been created,
1087 // since that has to happen in order for logs to be cut and stored when
1088 // persisting.
1089 // TODO(stuartmorgan): Call Stop() on the scheduler when reporting and/or
1090 // recording are turned off instead of letting it fire and then aborting.
1091 if (idle_since_last_transmission_ || !recording_active() ||
1092 (!reporting_active() && state_ >= SENDING_LOGS)) {
1093 rotation_scheduler_->Stop();
1094 rotation_scheduler_->RotationFinished();
1095 return;
1096 }
1097
1098 // The first ongoing log should be collected prior to sending any unsent logs.
1099 if (state_ == INIT_TASK_DONE) {
1100 client_->CollectFinalMetricsForLog(
1101 base::BindOnce(&MetricsService::OnFinalLogInfoCollectionDone,
1102 self_ptr_factory_.GetWeakPtr()));
1103 return;
1104 }
1105
1106 // If there are unsent logs, send the next one. If not, start the asynchronous
1107 // process of finalizing the current log for upload.
1108 if (has_unsent_logs()) {
1109 reporting_service_.Start();
1110 rotation_scheduler_->RotationFinished();
1111 } else {
1112 // There are no logs left to send, so start creating a new one.
1113 client_->CollectFinalMetricsForLog(
1114 base::BindOnce(&MetricsService::OnFinalLogInfoCollectionDone,
1115 self_ptr_factory_.GetWeakPtr()));
1116 }
1117 }
1118
OnFinalLogInfoCollectionDone()1119 void MetricsService::OnFinalLogInfoCollectionDone() {
1120 DVLOG(1) << "OnFinalLogInfoCollectionDone";
1121 DCHECK(state_ >= INIT_TASK_DONE);
1122 state_ = SENDING_LOGS;
1123
1124 // Abort if metrics were turned off during the final info gathering.
1125 if (!recording_active()) {
1126 rotation_scheduler_->Stop();
1127 rotation_scheduler_->RotationFinished();
1128 return;
1129 }
1130
1131 SCOPED_UMA_HISTOGRAM_TIMER("UMA.MetricsService.PeriodicOngoingLog.CloseTime");
1132
1133 // There shouldn't be two periodic ongoing logs being finalized in the
1134 // background simultaneously. This is currently enforced because:
1135 // 1. Only periodic ongoing logs are finalized asynchronously (i.e., logs
1136 // created by the MetricsRotationScheduler).
1137 // 2. We only re-schedule the MetricsRotationScheduler after storing a
1138 // periodic ongoing log.
1139 //
1140 // TODO(crbug/1052796): Consider making it possible to have multiple
1141 // simultaneous async logs by having some queueing system (e.g., if we want
1142 // the log created when foregrounding Chrome to be async).
1143 DCHECK(!pending_ongoing_log_);
1144 pending_ongoing_log_ = true;
1145
1146 base::OnceClosure log_stored_callback =
1147 base::BindOnce(&MetricsService::OnPeriodicOngoingLogStored,
1148 self_ptr_factory_.GetWeakPtr());
1149 CloseCurrentLog(/*async=*/true,
1150 MetricsLogsEventManager::CreateReason::kPeriodic,
1151 std::move(log_stored_callback));
1152 OpenNewLog(/*call_providers=*/false);
1153 }
1154
OnPeriodicOngoingLogStored()1155 void MetricsService::OnPeriodicOngoingLogStored() {
1156 pending_ongoing_log_ = false;
1157
1158 // Trim and store unsent logs, including the log that was just closed, so that
1159 // they're not lost in case of a crash before upload time. However, the
1160 // in-memory log store is unchanged. I.e., logs that are trimmed will still be
1161 // available in memory. This is to give the log that was just created a chance
1162 // to be sent in case it is trimmed. After uploading (whether successful or
1163 // not), the log store is trimmed and stored again, and at that time, the
1164 // in-memory log store will be updated.
1165 log_store()->TrimAndPersistUnsentLogs(/*overwrite_in_memory_store=*/false);
1166
1167 // Do not re-schedule if metrics were turned off while finalizing the log.
1168 if (!recording_active()) {
1169 rotation_scheduler_->Stop();
1170 rotation_scheduler_->RotationFinished();
1171 } else {
1172 // Only re-schedule |rotation_scheduler_| *after* the log was stored to
1173 // ensure that only one log is created asynchronously at a time.
1174 reporting_service_.Start();
1175 rotation_scheduler_->RotationFinished();
1176 HandleIdleSinceLastTransmission(true);
1177 }
1178 }
1179
PrepareInitialStabilityLog(const std::string & prefs_previous_version)1180 bool MetricsService::PrepareInitialStabilityLog(
1181 const std::string& prefs_previous_version) {
1182 DCHECK_EQ(CONSTRUCTED, state_);
1183
1184 std::unique_ptr<MetricsLog> initial_stability_log(
1185 CreateLog(MetricsLog::INITIAL_STABILITY_LOG));
1186
1187 // Do not call OnDidCreateMetricsLog here because the stability log describes
1188 // stats from the _previous_ session.
1189
1190 if (!initial_stability_log->LoadSavedEnvironmentFromPrefs(local_state_))
1191 return false;
1192
1193 initial_stability_log->RecordPreviousSessionData(&delegating_provider_,
1194 local_state_);
1195
1196 auto log_histogram_writer = std::make_unique<MetricsLogHistogramWriter>(
1197 initial_stability_log.get(), base::Histogram::kUmaStabilityHistogramFlag);
1198
1199 // Let metrics providers provide histogram snapshots independently if they
1200 // have any. This is done synchronously.
1201 delegating_provider_.RecordInitialHistogramSnapshots(
1202 log_histogram_writer->histogram_snapshot_manager());
1203
1204 MetricsLog::LogType log_type = initial_stability_log->log_type();
1205 std::string signing_key = log_store()->GetSigningKeyForLogType(log_type);
1206
1207 // Synchronously create the initial stability log in order to ensure that the
1208 // stability histograms are filled into this specific log.
1209 FinalizedLog finalized_log = SnapshotDeltasAndFinalizeLog(
1210 std::move(log_histogram_writer), std::move(initial_stability_log),
1211 /*truncate_events=*/false, client_->GetVersionString(),
1212 std::move(signing_key));
1213 StoreFinalizedLog(log_type, MetricsLogsEventManager::CreateReason::kStability,
1214 base::DoNothing(), std::move(finalized_log));
1215
1216 // Store unsent logs, including the stability log that was just saved, so
1217 // that they're not lost in case of a crash before upload time.
1218 log_store()->TrimAndPersistUnsentLogs(/*overwrite_in_memory_store=*/true);
1219
1220 return true;
1221 }
1222
RegisterMetricsProvider(std::unique_ptr<MetricsProvider> provider)1223 void MetricsService::RegisterMetricsProvider(
1224 std::unique_ptr<MetricsProvider> provider) {
1225 DCHECK_EQ(CONSTRUCTED, state_);
1226 delegating_provider_.RegisterMetricsProvider(std::move(provider));
1227 }
1228
CheckForClonedInstall()1229 void MetricsService::CheckForClonedInstall() {
1230 state_manager_->CheckForClonedInstall();
1231 }
1232
ShouldResetClientIdsOnClonedInstall()1233 bool MetricsService::ShouldResetClientIdsOnClonedInstall() {
1234 return state_manager_->ShouldResetClientIdsOnClonedInstall();
1235 }
1236
CreateLog(MetricsLog::LogType log_type)1237 std::unique_ptr<MetricsLog> MetricsService::CreateLog(
1238 MetricsLog::LogType log_type) {
1239 auto new_metrics_log = std::make_unique<MetricsLog>(
1240 state_manager_->client_id(), session_id_, log_type, client_);
1241 new_metrics_log->AssignRecordId(local_state_);
1242
1243 #if BUILDFLAG(IS_CHROMEOS_ASH)
1244 absl::optional<std::string> user_id = GetCurrentUserId();
1245 if (user_id.has_value())
1246 new_metrics_log->SetUserId(user_id.value());
1247 #endif // BUILDFLAG(IS_CHROMEOS_ASH)
1248
1249 return new_metrics_log;
1250 }
1251
AddLogsObserver(MetricsLogsEventManager::Observer * observer)1252 void MetricsService::AddLogsObserver(
1253 MetricsLogsEventManager::Observer* observer) {
1254 logs_event_manager_.AddObserver(observer);
1255 }
1256
RemoveLogsObserver(MetricsLogsEventManager::Observer * observer)1257 void MetricsService::RemoveLogsObserver(
1258 MetricsLogsEventManager::Observer* observer) {
1259 logs_event_manager_.RemoveObserver(observer);
1260 }
1261
AddEnablementObserver(const base::RepeatingCallback<void (bool)> & observer)1262 base::CallbackListSubscription MetricsService::AddEnablementObserver(
1263 const base::RepeatingCallback<void(bool)>& observer) {
1264 return enablement_observers_.Add(observer);
1265 }
1266
SetPersistentSystemProfile(const std::string & serialized_proto,bool complete)1267 void MetricsService::SetPersistentSystemProfile(
1268 const std::string& serialized_proto,
1269 bool complete) {
1270 GlobalPersistentSystemProfile::GetInstance()->SetSystemProfile(
1271 serialized_proto, complete);
1272 }
1273
1274 // static
RecordCurrentEnvironmentHelper(MetricsLog * log,PrefService * local_state,DelegatingProvider * delegating_provider)1275 std::string MetricsService::RecordCurrentEnvironmentHelper(
1276 MetricsLog* log,
1277 PrefService* local_state,
1278 DelegatingProvider* delegating_provider) {
1279 const SystemProfileProto& system_profile =
1280 log->RecordEnvironment(delegating_provider);
1281 EnvironmentRecorder recorder(local_state);
1282 return recorder.SerializeAndRecordEnvironmentToPrefs(system_profile);
1283 }
1284
RecordCurrentEnvironment(MetricsLog * log,bool complete)1285 void MetricsService::RecordCurrentEnvironment(MetricsLog* log, bool complete) {
1286 DCHECK(client_);
1287 std::string serialized_proto =
1288 RecordCurrentEnvironmentHelper(log, local_state_, &delegating_provider_);
1289
1290 SetPersistentSystemProfile(serialized_proto, complete);
1291 client_->OnEnvironmentUpdate(&serialized_proto);
1292 }
1293
PrepareProviderMetricsLogDone(std::unique_ptr<IndependentMetricsLoader> loader,bool success)1294 void MetricsService::PrepareProviderMetricsLogDone(
1295 std::unique_ptr<IndependentMetricsLoader> loader,
1296 bool success) {
1297 DCHECK_CALLED_ON_VALID_SEQUENCE(sequence_checker_);
1298 DCHECK(independent_loader_active_);
1299 DCHECK(loader);
1300
1301 if (success) {
1302 // Finalize and store the log that was created independently by the metrics
1303 // provider.
1304 std::unique_ptr<MetricsLog> log = loader->ReleaseLog();
1305 MetricsLog::LogType log_type = log->log_type();
1306 std::string signing_key = log_store()->GetSigningKeyForLogType(log_type);
1307 FinalizedLog finalized_log =
1308 FinalizeLog(std::move(log), /*truncate_events=*/false,
1309 client_->GetVersionString(), std::move(signing_key));
1310 StoreFinalizedLog(log_type,
1311 MetricsLogsEventManager::CreateReason::kIndependent,
1312 base::DoNothing(), std::move(finalized_log));
1313 }
1314
1315 independent_loader_active_ = false;
1316 }
1317
PrepareProviderMetricsLog()1318 bool MetricsService::PrepareProviderMetricsLog() {
1319 DCHECK_CALLED_ON_VALID_SEQUENCE(sequence_checker_);
1320
1321 // If something is still pending, stop now and indicate that there is
1322 // still work to do.
1323 if (independent_loader_active_)
1324 return true;
1325
1326 // Check each provider in turn for data.
1327 for (auto& provider : delegating_provider_.GetProviders()) {
1328 if (provider->HasIndependentMetrics()) {
1329 // Create a new log. This will have some default values injected in it
1330 // but those will be overwritten when an embedded profile is extracted.
1331 std::unique_ptr<MetricsLog> log = CreateLog(MetricsLog::INDEPENDENT_LOG);
1332
1333 // Note that something is happening. This must be set before the
1334 // operation is requested in case the loader decides to do everything
1335 // immediately rather than as a background task.
1336 independent_loader_active_ = true;
1337
1338 // Give the new log to a loader for management and then run it on the
1339 // provider that has something to give. A copy of the pointer is needed
1340 // because the unique_ptr may get moved before the value can be used
1341 // to call Run().
1342 std::unique_ptr<IndependentMetricsLoader> loader =
1343 std::make_unique<IndependentMetricsLoader>(std::move(log));
1344 IndependentMetricsLoader* loader_ptr = loader.get();
1345 loader_ptr->Run(
1346 base::BindOnce(&MetricsService::PrepareProviderMetricsLogDone,
1347 self_ptr_factory_.GetWeakPtr(), std::move(loader)),
1348 provider.get());
1349
1350 // Something was found so there may still be more work to do.
1351 return true;
1352 }
1353 }
1354
1355 // Nothing was found so indicate there is no more work to do.
1356 return false;
1357 }
1358
PrepareProviderMetricsTask()1359 void MetricsService::PrepareProviderMetricsTask() {
1360 DCHECK_CALLED_ON_VALID_SEQUENCE(sequence_checker_);
1361 bool found = PrepareProviderMetricsLog();
1362 base::TimeDelta next_check = found ? base::Seconds(5) : base::Minutes(15);
1363 base::SequencedTaskRunner::GetCurrentDefault()->PostDelayedTask(
1364 FROM_HERE,
1365 base::BindOnce(&MetricsService::PrepareProviderMetricsTask,
1366 self_ptr_factory_.GetWeakPtr()),
1367 next_check);
1368 }
1369
UpdateLastLiveTimestampTask()1370 void MetricsService::UpdateLastLiveTimestampTask() {
1371 state_manager_->clean_exit_beacon()->UpdateLastLiveTimestamp();
1372
1373 // Schecule the next update.
1374 StartUpdatingLastLiveTimestamp();
1375 }
1376
IsTooEarlyToCloseLog()1377 bool MetricsService::IsTooEarlyToCloseLog() {
1378 // When kMetricsServiceAllowEarlyLogClose is enabled, start closing logs as
1379 // soon as the first log is opened (|state_| is set to INIT_TASK_SCHEDULED
1380 // when the first log is opened, see OpenNewLog()). Otherwise, only start
1381 // closing logs when logs have started being sent.
1382 return base::FeatureList::IsEnabled(
1383 features::kMetricsServiceAllowEarlyLogClose)
1384 ? state_ < INIT_TASK_SCHEDULED
1385 : state_ < SENDING_LOGS;
1386 }
1387
OnClonedInstallDetected()1388 void MetricsService::OnClonedInstallDetected() {
1389 // Purge all logs, as they may come from a previous install. Unfortunately,
1390 // since the cloned install detector works asynchronously, it is possible that
1391 // this is called after logs were already sent. However, practically speaking,
1392 // this should not happen, since logs are only sent late into the session.
1393 reporting_service_.metrics_log_store()->Purge();
1394 }
1395
1396 // static
SnapshotDeltasAndFinalizeLog(std::unique_ptr<MetricsLogHistogramWriter> log_histogram_writer,std::unique_ptr<MetricsLog> log,bool truncate_events,std::string current_app_version,std::string signing_key)1397 MetricsService::FinalizedLog MetricsService::SnapshotDeltasAndFinalizeLog(
1398 std::unique_ptr<MetricsLogHistogramWriter> log_histogram_writer,
1399 std::unique_ptr<MetricsLog> log,
1400 bool truncate_events,
1401 std::string current_app_version,
1402 std::string signing_key) {
1403 log_histogram_writer->SnapshotStatisticsRecorderDeltas();
1404 return FinalizeLog(std::move(log), truncate_events,
1405 std::move(current_app_version), std::move(signing_key));
1406 }
1407
1408 // static
1409 MetricsService::FinalizedLog
SnapshotUnloggedSamplesAndFinalizeLog(MetricsLogHistogramWriter * log_histogram_writer,std::unique_ptr<MetricsLog> log,bool truncate_events,std::string current_app_version,std::string signing_key)1410 MetricsService::SnapshotUnloggedSamplesAndFinalizeLog(
1411 MetricsLogHistogramWriter* log_histogram_writer,
1412 std::unique_ptr<MetricsLog> log,
1413 bool truncate_events,
1414 std::string current_app_version,
1415 std::string signing_key) {
1416 log_histogram_writer->SnapshotStatisticsRecorderUnloggedSamples();
1417 return FinalizeLog(std::move(log), truncate_events,
1418 std::move(current_app_version), std::move(signing_key));
1419 }
1420
1421 // static
FinalizeLog(std::unique_ptr<MetricsLog> log,bool truncate_events,std::string current_app_version,std::string signing_key)1422 MetricsService::FinalizedLog MetricsService::FinalizeLog(
1423 std::unique_ptr<MetricsLog> log,
1424 bool truncate_events,
1425 std::string current_app_version,
1426 std::string signing_key) {
1427 DCHECK(log->uma_proto()->has_record_id());
1428 std::string log_data;
1429 log->FinalizeLog(truncate_events, current_app_version, &log_data);
1430
1431 FinalizedLog finalized_log;
1432 finalized_log.uncompressed_log_size = log_data.size();
1433 finalized_log.log_info = std::make_unique<UnsentLogStore::LogInfo>();
1434 finalized_log.log_info->Init(log_data, signing_key, log->log_metadata());
1435 return finalized_log;
1436 }
1437
1438 } // namespace metrics
1439