• Home
  • Line#
  • Scopes#
  • Navigate#
  • Raw
  • Download
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