| // Copyright 2014 The Chromium Authors |
| // Use of this source code is governed by a BSD-style license that can be |
| // found in the LICENSE file. |
| |
| //------------------------------------------------------------------------------ |
| // Description of a MetricsService instance's life cycle. |
| // |
| // OVERVIEW |
| // |
| // A MetricsService instance is typically created at application startup. It is |
| // the central controller for the acquisition of log data, and the automatic |
| // transmission of that log data to an external server. Its major job is to |
| // manage logs, grouping them for transmission, and transmitting them. As part |
| // of its grouping, MS finalizes logs by including some just-in-time gathered |
| // memory statistics, snapshotting the current stats of numerous histograms, |
| // closing the logs, translating to protocol buffer format, and compressing the |
| // results for transmission. Transmission includes submitting a compressed log |
| // as data in a URL-post, and retransmitting (or retaining at process |
| // termination) if the attempted transmission failed. Retention across process |
| // terminations is done using the PrefServices facilities. The retained logs |
| // (the ones that never got transmitted) are compressed and base64-encoded |
| // before being persisted. |
| // |
| // Logs fall into one of two categories: "initial logs," and "ongoing logs." |
| // There is at most one initial log sent for each complete run of Chrome (from |
| // startup, to browser shutdown). An initial log is generally transmitted some |
| // short time (1 minute?) after startup, and includes stats such as recent crash |
| // info, the number and types of plugins, etc. The external server's response |
| // to the initial log conceptually tells this MS if it should continue |
| // transmitting logs (during this session). The server response can actually be |
| // much more detailed, and always includes (at a minimum) how often additional |
| // ongoing logs should be sent. |
| // |
| // After the above initial log, a series of ongoing logs will be transmitted. |
| // The first ongoing log actually begins to accumulate information stating when |
| // the MS was first constructed. Note that even though the initial log is |
| // commonly sent a full minute after startup, the initial log does not include |
| // much in the way of user stats. The most common interlog period (delay) |
| // is 30 minutes. That time period starts when the first user action causes a |
| // logging event. This means that if there is no user action, there may be long |
| // periods without any (ongoing) log transmissions. Ongoing logs typically |
| // contain very detailed records of user activities (ex: opened tab, closed |
| // tab, fetched URL, maximized window, etc.) In addition, just before an |
| // ongoing log is closed out, a call is made to gather memory statistics. Those |
| // memory statistics are deposited into a histogram, and the log finalization |
| // code is then called. In the finalization, a call to a Histogram server |
| // acquires a list of all local histograms that have been flagged for upload |
| // to the UMA server. The finalization also acquires the most recent number |
| // of page loads, along with any counts of renderer or plugin crashes. |
| // |
| // When the browser shuts down, there will typically be a fragment of an ongoing |
| // log that has not yet been transmitted. At shutdown time, that fragment is |
| // closed (including snapshotting histograms), and persisted, for potential |
| // transmission during a future run of the product. |
| // |
| // There are two slightly abnormal shutdown conditions. There is a |
| // "disconnected scenario," and a "really fast startup and shutdown" scenario. |
| // In the "never connected" situation, the user has (during the running of the |
| // process) never established an internet connection. As a result, attempts to |
| // transmit the initial log have failed, and a lot(?) of data has accumulated in |
| // the ongoing log (which didn't yet get closed, because there was never even a |
| // contemplation of sending it). There is also a kindred "lost connection" |
| // situation, where a loss of connection prevented an ongoing log from being |
| // transmitted, and a (still open) log was stuck accumulating a lot(?) of data, |
| // while the earlier log retried its transmission. In both of these |
| // disconnected situations, two logs need to be, and are, persistently stored |
| // for future transmission. |
| // |
| // The other unusual shutdown condition, termed "really fast startup and |
| // shutdown," involves the deliberate user termination of the process before |
| // the initial log is even formed or transmitted. In that situation, no logging |
| // is done, but the historical crash statistics remain (unlogged) for inclusion |
| // in a future run's initial log. (i.e., we don't lose crash stats). |
| // |
| // With the above overview, we can now describe the state machine's various |
| // states, based on the State enum specified in the state_ member. Those states |
| // are: |
| // |
| // CONSTRUCTED, // Constructor was called. |
| // INITIALIZED, // InitializeMetricsRecordingState() was called. |
| // INIT_TASK_SCHEDULED, // Waiting for deferred init tasks to finish. |
| // INIT_TASK_DONE, // Waiting for timer to send the first ongoing log. |
| // SENDING_LOGS, // Sending logs and creating new ones when we run out. |
| // |
| // In more detail, we have: |
| // |
| // INIT_TASK_SCHEDULED, // Waiting for deferred init tasks to finish. |
| // Typically about 30 seconds after startup, a task is sent to a background |
| // thread to perform deferred (lower priority and slower) initialization steps |
| // such as getting the list of plugins. That task will (when complete) make an |
| // async callback (via a Task) to indicate the completion. |
| // |
| // INIT_TASK_DONE, // Waiting for timer to send first ongoing log. |
| // The callback has arrived, and it is now possible for an ongoing log to be |
| // created. This callback typically arrives back less than one second after |
| // the deferred init task is dispatched. |
| // |
| // SENDING_LOGS, // Sending logs and creating new ones when we run out. |
| // Logs from previous sessions have been loaded, and an optional initial |
| // stability log has been created. We will send all of these logs, and when |
| // they run out, we will start cutting new logs to send. We will also cut a new |
| // log if we expect a shutdown. |
| // |
| // The progression through the above states is simple, and sequential. |
| // States proceed from INITIALIZED to SENDING_LOGS, and remain in the latter |
| // until shutdown. |
| // |
| // Also note that whenever we successfully send a log, we mirror the list |
| // of logs into the PrefService. This ensures that IF we crash, we won't start |
| // up and retransmit our old logs again. |
| // |
| // Due to race conditions, it is always possible that a log file could be sent |
| // twice. For example, if a log file is sent, but not yet acknowledged by |
| // the external server, and the user shuts down, then a copy of the log may be |
| // saved for re-transmission. These duplicates could be filtered out server |
| // side, but are not expected to be a significant problem. |
| // |
| // |
| //------------------------------------------------------------------------------ |
| |
| #include "components/metrics/metrics_service.h" |
| |
| #include <stddef.h> |
| |
| #include <algorithm> |
| #include <memory> |
| #include <utility> |
| |
| #include "base/callback_list.h" |
| #include "base/functional/bind.h" |
| #include "base/functional/callback.h" |
| #include "base/location.h" |
| #include "base/metrics/histogram_base.h" |
| #include "base/metrics/histogram_flattener.h" |
| #include "base/metrics/histogram_functions.h" |
| #include "base/metrics/histogram_macros.h" |
| #include "base/metrics/histogram_macros_local.h" |
| #include "base/metrics/histogram_samples.h" |
| #include "base/metrics/persistent_histogram_allocator.h" |
| #include "base/metrics/statistics_recorder.h" |
| #include "base/process/process_handle.h" |
| #include "base/rand_util.h" |
| #include "base/strings/string_piece.h" |
| #include "base/task/sequenced_task_runner.h" |
| #include "base/task/single_thread_task_runner.h" |
| #include "base/task/task_traits.h" |
| #include "base/task/thread_pool.h" |
| #include "base/time/time.h" |
| #include "build/build_config.h" |
| #include "build/chromeos_buildflags.h" |
| #include "components/metrics/clean_exit_beacon.h" |
| #include "components/metrics/environment_recorder.h" |
| #include "components/metrics/field_trials_provider.h" |
| #include "components/metrics/metrics_features.h" |
| #include "components/metrics/metrics_log.h" |
| #include "components/metrics/metrics_log_uploader.h" |
| #include "components/metrics/metrics_logs_event_manager.h" |
| #include "components/metrics/metrics_pref_names.h" |
| #include "components/metrics/metrics_rotation_scheduler.h" |
| #include "components/metrics/metrics_service_client.h" |
| #include "components/metrics/metrics_service_observer.h" |
| #include "components/metrics/metrics_state_manager.h" |
| #include "components/metrics/metrics_switches.h" |
| #include "components/metrics/persistent_system_profile.h" |
| #include "components/metrics/stability_metrics_provider.h" |
| #include "components/metrics/url_constants.h" |
| #include "components/prefs/pref_registry_simple.h" |
| #include "components/prefs/pref_service.h" |
| #include "components/variations/entropy_provider.h" |
| |
| #if !BUILDFLAG(IS_ANDROID) |
| #include "components/keep_alive_registry/keep_alive_registry.h" |
| #include "components/keep_alive_registry/keep_alive_types.h" |
| #include "components/keep_alive_registry/scoped_keep_alive.h" |
| #endif // !BUILDFLAG(IS_ANDROID) |
| |
| namespace metrics { |
| namespace { |
| |
| // Used to write histogram data to a log. Does not take ownership of the log. |
| class IndependentFlattener : public base::HistogramFlattener { |
| public: |
| explicit IndependentFlattener(MetricsLog* log) : log_(log) {} |
| |
| IndependentFlattener(const IndependentFlattener&) = delete; |
| IndependentFlattener& operator=(const IndependentFlattener&) = delete; |
| |
| ~IndependentFlattener() override = default; |
| |
| // base::HistogramFlattener: |
| void RecordDelta(const base::HistogramBase& histogram, |
| const base::HistogramSamples& snapshot) override { |
| CHECK(histogram.HasFlags(base::HistogramBase::kUmaTargetedHistogramFlag)); |
| log_->RecordHistogramDelta(histogram.histogram_name(), snapshot); |
| } |
| |
| private: |
| const raw_ptr<MetricsLog, AcrossTasksDanglingUntriaged> log_; |
| }; |
| |
| // Used to mark histogram samples as reported so that they are not included in |
| // the next log. A histogram's snapshot samples are simply discarded/ignored |
| // when attempting to record them through this |HistogramFlattener|. |
| class DiscardingFlattener : public base::HistogramFlattener { |
| public: |
| DiscardingFlattener() = default; |
| |
| DiscardingFlattener(const DiscardingFlattener&) = delete; |
| DiscardingFlattener& operator=(const DiscardingFlattener&) = delete; |
| |
| ~DiscardingFlattener() override = default; |
| |
| void RecordDelta(const base::HistogramBase& histogram, |
| const base::HistogramSamples& snapshot) override { |
| // No-op. We discard the samples. |
| } |
| }; |
| |
| #if BUILDFLAG(IS_ANDROID) || BUILDFLAG(IS_IOS) |
| // Emits a histogram upon instantiation, and on destruction. Used to measure how |
| // often the browser is ungracefully killed between two different points. In |
| // particular, currently, this is used on mobile to measure how often the |
| // browser is killed while finalizing a log, right after backgrounding. This |
| // scenario is prone to data loss because a histogram may have been snapshotted |
| // and put into a log, but the browser was killed before it could be fully |
| // finalized and stored. |
| // |
| // TODO(crbug/1293026): Consider improving this. In particular, the "Started" |
| // bucket is emitted before finalizing the log, and the "Finished" bucket is |
| // emitted after. Hence, the latter will be reported in a different log, which |
| // may cause a "lag" and/or bias (e.g. if the latter log is more prone to loss). |
| // A better way to do this is to allocate an object on the persistent memory |
| // upon instantiation, and flip a bit in it upon destruction. A future session |
| // that will consume this persistent memory should take care of emitting the |
| // histogram samples. |
| class ScopedTerminationChecker { |
| public: |
| // These values are persisted to logs. Entries should not be renumbered and |
| // numeric values should never be reused. |
| enum class Status { |
| kStarted = 0, |
| kFinished = 1, |
| kMaxValue = kFinished, |
| }; |
| |
| explicit ScopedTerminationChecker(base::StringPiece histogram_name) { |
| // Do nothing if the persistent histogram system is not being used. |
| // Otherwise, the "Finished" bucket may be more prone to loss, which may |
| // incorrectly make it seem like the browser was killed in between the |
| // scoped code. |
| if (!base::GlobalHistogramAllocator::Get()) { |
| return; |
| } |
| |
| active_ = true; |
| histogram_name_ = histogram_name; |
| base::UmaHistogramEnumeration(histogram_name_, Status::kStarted); |
| } |
| |
| ScopedTerminationChecker(const ScopedTerminationChecker& other) = delete; |
| ScopedTerminationChecker& operator=(const ScopedTerminationChecker& other) = |
| delete; |
| |
| ~ScopedTerminationChecker() { |
| if (!active_) { |
| return; |
| } |
| base::UmaHistogramEnumeration(histogram_name_, Status::kFinished); |
| } |
| |
| private: |
| // Name of the histogram to emit to upon instantiation/destruction. |
| std::string histogram_name_; |
| |
| // Whether or not this will emit histograms. In particular, if this browser |
| // session does not make use of persistent memory, this will be false, and |
| // this object will do nothing. |
| bool active_ = false; |
| }; |
| #endif // BUILDFLAG(IS_ANDROID) || BUILDFLAG(IS_IOS) |
| |
| // The delay, in seconds, after starting recording before doing expensive |
| // initialization work. |
| #if BUILDFLAG(IS_ANDROID) || BUILDFLAG(IS_IOS) |
| // On mobile devices, a significant portion of sessions last less than a minute. |
| // Use a shorter timer on these platforms to avoid losing data. |
| // TODO(dfalcantara): To avoid delaying startup, tighten up initialization so |
| // that it occurs after the user gets their initial page. |
| const int kInitializationDelaySeconds = 5; |
| #else |
| const int kInitializationDelaySeconds = 30; |
| #endif |
| |
| // The browser last live timestamp is updated every 15 minutes. |
| const int kUpdateAliveTimestampSeconds = 15 * 60; |
| |
| #if BUILDFLAG(IS_CHROMEOS_ASH) |
| enum UserLogStoreState { |
| kSetPostSendLogsState = 0, |
| kSetPreSendLogsState = 1, |
| kUnsetPostSendLogsState = 2, |
| kUnsetPreSendLogsState = 3, |
| kMaxValue = kUnsetPreSendLogsState, |
| }; |
| |
| void RecordUserLogStoreState(UserLogStoreState state) { |
| base::UmaHistogramEnumeration("UMA.CrosPerUser.UserLogStoreState", state); |
| } |
| #endif // BUILDFLAG(IS_CHROMEOS_ASH) |
| |
| } // namespace |
| |
| // static |
| void MetricsService::RegisterPrefs(PrefRegistrySimple* registry) { |
| CleanExitBeacon::RegisterPrefs(registry); |
| MetricsStateManager::RegisterPrefs(registry); |
| MetricsLog::RegisterPrefs(registry); |
| StabilityMetricsProvider::RegisterPrefs(registry); |
| MetricsReportingService::RegisterPrefs(registry); |
| |
| registry->RegisterIntegerPref(prefs::kMetricsSessionID, -1); |
| } |
| |
| MetricsService::MetricsService(MetricsStateManager* state_manager, |
| MetricsServiceClient* client, |
| PrefService* local_state) |
| : reporting_service_(client, local_state, &logs_event_manager_), |
| state_manager_(state_manager), |
| client_(client), |
| local_state_(local_state), |
| recording_state_(UNSET), |
| test_mode_active_(false), |
| state_(CONSTRUCTED), |
| idle_since_last_transmission_(false), |
| session_id_(-1) { |
| DCHECK_CALLED_ON_VALID_SEQUENCE(sequence_checker_); |
| DCHECK(state_manager_); |
| DCHECK(client_); |
| DCHECK(local_state_); |
| |
| // Emit a local histogram, which should not be reported to servers. This is |
| // monitored from the serverside. |
| LOCAL_HISTOGRAM_BOOLEAN("UMA.LocalHistogram", true); |
| |
| bool create_logs_event_observer; |
| #ifdef NDEBUG |
| // For non-debug builds, we only create |logs_event_observer_| if the |
| // |kExportUmaLogsToFile| command line flag is passed. This is mostly for |
| // performance reasons: 1) we don't want to have to notify an observer in |
| // non-debug circumstances (there may be heavy work like copying large |
| // strings), and 2) we don't want logs to be lingering in memory. |
| create_logs_event_observer = |
| base::CommandLine::ForCurrentProcess()->HasSwitch( |
| switches::kExportUmaLogsToFile); |
| #else |
| // For debug builds, always create |logs_event_observer_|. |
| create_logs_event_observer = true; |
| #endif // NDEBUG |
| |
| if (create_logs_event_observer) { |
| logs_event_observer_ = std::make_unique<MetricsServiceObserver>( |
| MetricsServiceObserver::MetricsServiceType::UMA); |
| logs_event_manager_.AddObserver(logs_event_observer_.get()); |
| } |
| |
| cloned_install_subscription_ = |
| state_manager->AddOnClonedInstallDetectedCallback( |
| base::BindOnce(&MetricsService::OnClonedInstallDetected, |
| self_ptr_factory_.GetWeakPtr())); |
| |
| RegisterMetricsProvider( |
| std::make_unique<StabilityMetricsProvider>(local_state_)); |
| |
| RegisterMetricsProvider(state_manager_->GetProvider()); |
| } |
| |
| MetricsService::~MetricsService() { |
| DisableRecording(); |
| |
| if (logs_event_observer_) { |
| logs_event_manager_.RemoveObserver(logs_event_observer_.get()); |
| const base::CommandLine* command_line = |
| base::CommandLine::ForCurrentProcess(); |
| if (command_line->HasSwitch(switches::kExportUmaLogsToFile)) { |
| // We should typically not write to files on the main thread, but since |
| // this only happens when |kExportUmaLogsToFile| is passed (which |
| // indicates debugging), this should be fine. |
| logs_event_observer_->ExportLogsToFile( |
| command_line->GetSwitchValuePath(switches::kExportUmaLogsToFile)); |
| } |
| } |
| |
| // Emit a local histogram, which should not be reported to servers. This is |
| // monitored from the serverside. Because this is emitted after closing the |
| // last log before shutdown, this sample should be retrieved by the persistent |
| // histograms system in a follow up session. This is to ensure independent |
| // logs do not include local histograms, a previously buggy behaviour. |
| LOCAL_HISTOGRAM_BOOLEAN("UMA.LocalHistogram", true); |
| } |
| |
| void MetricsService::InitializeMetricsRecordingState() { |
| DCHECK_EQ(CONSTRUCTED, state_); |
| |
| // The FieldTrialsProvider should be registered last. This ensures that |
| // studies whose features are checked when providers add their information to |
| // the log appear in the active field trials. |
| RegisterMetricsProvider(std::make_unique<variations::FieldTrialsProvider>( |
| client_->GetSyntheticTrialRegistry(), base::StringPiece())); |
| |
| reporting_service_.Initialize(); |
| InitializeMetricsState(); |
| |
| base::RepeatingClosure upload_callback = base::BindRepeating( |
| &MetricsService::StartScheduledUpload, self_ptr_factory_.GetWeakPtr()); |
| |
| rotation_scheduler_ = std::make_unique<MetricsRotationScheduler>( |
| upload_callback, |
| // MetricsServiceClient outlives MetricsService, and |
| // MetricsRotationScheduler is tied to the lifetime of |this|. |
| base::BindRepeating(&MetricsServiceClient::GetUploadInterval, |
| base::Unretained(client_)), |
| client_->ShouldStartUpFastForTesting()); |
| |
| // Init() has to be called after LogCrash() in order for LogCrash() to work. |
| delegating_provider_.Init(); |
| |
| state_ = INITIALIZED; |
| } |
| |
| void MetricsService::Start() { |
| HandleIdleSinceLastTransmission(false); |
| EnableRecording(); |
| EnableReporting(); |
| } |
| |
| void MetricsService::StartRecordingForTests() { |
| test_mode_active_ = true; |
| EnableRecording(); |
| DisableReporting(); |
| } |
| |
| void MetricsService::StartUpdatingLastLiveTimestamp() { |
| base::SequencedTaskRunner::GetCurrentDefault()->PostDelayedTask( |
| FROM_HERE, |
| base::BindOnce(&MetricsService::UpdateLastLiveTimestampTask, |
| self_ptr_factory_.GetWeakPtr()), |
| GetUpdateLastAliveTimestampDelay()); |
| } |
| |
| void MetricsService::Stop() { |
| HandleIdleSinceLastTransmission(false); |
| DisableReporting(); |
| DisableRecording(); |
| } |
| |
| void MetricsService::EnableReporting() { |
| if (reporting_service_.reporting_active()) |
| return; |
| reporting_service_.EnableReporting(); |
| StartSchedulerIfNecessary(); |
| } |
| |
| void MetricsService::DisableReporting() { |
| reporting_service_.DisableReporting(); |
| } |
| |
| std::string MetricsService::GetClientId() const { |
| return state_manager_->client_id(); |
| } |
| |
| int MetricsService::GetLowEntropySource() { |
| return state_manager_->GetLowEntropySource(); |
| } |
| |
| int MetricsService::GetOldLowEntropySource() { |
| return state_manager_->GetOldLowEntropySource(); |
| } |
| |
| int MetricsService::GetPseudoLowEntropySource() { |
| return state_manager_->GetPseudoLowEntropySource(); |
| } |
| |
| std::string_view MetricsService::GetLimitedEntropyRandomizationSource() { |
| return state_manager_->GetLimitedEntropyRandomizationSource(); |
| } |
| |
| void MetricsService::SetExternalClientId(const std::string& id) { |
| state_manager_->SetExternalClientId(id); |
| } |
| |
| bool MetricsService::WasLastShutdownClean() const { |
| return state_manager_->clean_exit_beacon()->exited_cleanly(); |
| } |
| |
| void MetricsService::EnableRecording() { |
| DCHECK_CALLED_ON_VALID_SEQUENCE(sequence_checker_); |
| |
| if (recording_state_ == ACTIVE) |
| return; |
| recording_state_ = ACTIVE; |
| |
| state_manager_->ForceClientIdCreation(); |
| client_->SetMetricsClientId(state_manager_->client_id()); |
| |
| if (!current_log_) { |
| OpenNewLog(); |
| } |
| |
| delegating_provider_.OnRecordingEnabled(); |
| |
| // Fill in the system profile in the log and persist it (to prefs, .pma |
| // and crashpad). This includes running the providers so that information |
| // like field trials and hardware info is provided. If Chrome crashes |
| // before this log is completed, the .pma file will have this system |
| // profile. |
| RecordCurrentEnvironment(current_log_.get(), /*complete=*/false); |
| |
| base::RemoveActionCallback(action_callback_); |
| action_callback_ = base::BindRepeating(&MetricsService::OnUserAction, |
| base::Unretained(this)); |
| base::AddActionCallback(action_callback_); |
| |
| enablement_observers_.Notify(/*enabled=*/true); |
| } |
| |
| void MetricsService::DisableRecording() { |
| DCHECK_CALLED_ON_VALID_SEQUENCE(sequence_checker_); |
| |
| if (recording_state_ == INACTIVE) |
| return; |
| recording_state_ = INACTIVE; |
| |
| base::RemoveActionCallback(action_callback_); |
| |
| delegating_provider_.OnRecordingDisabled(); |
| |
| base::UmaHistogramBoolean("UMA.MetricsService.PendingOngoingLogOnDisable", |
| pending_ongoing_log_); |
| PushPendingLogsToPersistentStorage( |
| MetricsLogsEventManager::CreateReason::kServiceShutdown); |
| |
| // Because histograms may still be emitted after the last log was closed, an |
| // independent log may be created in a future session in order to report |
| // those histograms. To ensure that this independent log contains histograms |
| // that we wish to appear in every log, call OnDidCreateMetricsLog(). |
| delegating_provider_.OnDidCreateMetricsLog(); |
| |
| enablement_observers_.Notify(/*enabled=*/false); |
| } |
| |
| bool MetricsService::recording_active() const { |
| DCHECK_CALLED_ON_VALID_SEQUENCE(sequence_checker_); |
| return recording_state_ == ACTIVE; |
| } |
| |
| bool MetricsService::reporting_active() const { |
| DCHECK_CALLED_ON_VALID_SEQUENCE(sequence_checker_); |
| return reporting_service_.reporting_active(); |
| } |
| |
| bool MetricsService::has_unsent_logs() const { |
| return reporting_service_.metrics_log_store()->has_unsent_logs(); |
| } |
| |
| bool MetricsService::IsMetricsReportingEnabled() const { |
| return state_manager_->IsMetricsReportingEnabled(); |
| } |
| |
| void MetricsService::HandleIdleSinceLastTransmission(bool in_idle) { |
| // If there wasn't a lot of action, maybe the computer was asleep, in which |
| // case, the log transmissions should have stopped. Here we start them up |
| // again. |
| if (!in_idle && idle_since_last_transmission_) |
| StartSchedulerIfNecessary(); |
| idle_since_last_transmission_ = in_idle; |
| } |
| |
| void MetricsService::OnApplicationNotIdle() { |
| if (recording_state_ == ACTIVE) |
| HandleIdleSinceLastTransmission(false); |
| } |
| |
| #if BUILDFLAG(IS_ANDROID) || BUILDFLAG(IS_IOS) |
| void MetricsService::OnAppEnterBackground(bool keep_recording_in_background) { |
| is_in_foreground_ = false; |
| reporting_service_.SetIsInForegound(false); |
| if (!keep_recording_in_background) { |
| rotation_scheduler_->Stop(); |
| reporting_service_.Stop(); |
| } |
| |
| state_manager_->LogHasSessionShutdownCleanly(true); |
| // Schedule a write, which happens on a different thread. |
| local_state_->CommitPendingWrite(); |
| |
| // Give providers a chance to persist histograms as part of being |
| // backgrounded. |
| delegating_provider_.OnAppEnterBackground(); |
| |
| // At this point, there's no way of knowing when the process will be killed, |
| // so this has to be treated similar to a shutdown, closing and persisting all |
| // logs. Unlike a shutdown, the state is primed to be ready to continue |
| // logging and uploading if the process does return. |
| if (recording_active() && !IsTooEarlyToCloseLog()) { |
| base::UmaHistogramBoolean( |
| "UMA.MetricsService.PendingOngoingLogOnBackgrounded", |
| pending_ongoing_log_); |
| #if BUILDFLAG(IS_ANDROID) |
| client_->MergeSubprocessHistograms(); |
| #endif // BUILDFLAG(IS_ANDROID) |
| { |
| ScopedTerminationChecker scoped_termination_checker( |
| "UMA.MetricsService.OnBackgroundedScopedTerminationChecker"); |
| PushPendingLogsToPersistentStorage( |
| MetricsLogsEventManager::CreateReason::kBackgrounded); |
| } |
| // Persisting logs closes the current log, so start recording a new log |
| // immediately to capture any background work that might be done before the |
| // process is killed. |
| OpenNewLog(); |
| } |
| } |
| |
| void MetricsService::OnAppEnterForeground(bool force_open_new_log) { |
| is_in_foreground_ = true; |
| reporting_service_.SetIsInForegound(true); |
| state_manager_->LogHasSessionShutdownCleanly(false); |
| StartSchedulerIfNecessary(); |
| |
| if (force_open_new_log && recording_active() && !IsTooEarlyToCloseLog()) { |
| base::UmaHistogramBoolean( |
| "UMA.MetricsService.PendingOngoingLogOnForegrounded", |
| pending_ongoing_log_); |
| #if BUILDFLAG(IS_ANDROID) |
| client_->MergeSubprocessHistograms(); |
| #endif // BUILDFLAG(IS_ANDROID) |
| // Because state_ >= SENDING_LOGS, PushPendingLogsToPersistentStorage() |
| // will close the log, allowing a new log to be opened. |
| PushPendingLogsToPersistentStorage( |
| MetricsLogsEventManager::CreateReason::kForegrounded); |
| OpenNewLog(); |
| } |
| } |
| #endif // BUILDFLAG(IS_ANDROID) || BUILDFLAG(IS_IOS) |
| |
| void MetricsService::OnPageLoadStarted() { |
| delegating_provider_.OnPageLoadStarted(); |
| } |
| |
| void MetricsService::LogCleanShutdown() { |
| DCHECK_CALLED_ON_VALID_SEQUENCE(sequence_checker_); |
| state_manager_->LogHasSessionShutdownCleanly(true); |
| } |
| |
| void MetricsService::ClearSavedStabilityMetrics() { |
| delegating_provider_.ClearSavedStabilityMetrics(); |
| // Stability metrics are stored in Local State prefs, so schedule a Local |
| // State write to flush the updated prefs. |
| local_state_->CommitPendingWrite(); |
| } |
| |
| void MetricsService::MarkCurrentHistogramsAsReported() { |
| DiscardingFlattener flattener; |
| base::HistogramSnapshotManager snapshot_manager(&flattener); |
| base::StatisticsRecorder::PrepareDeltas( |
| /*include_persistent=*/true, /*flags_to_set=*/base::Histogram::kNoFlags, |
| /*required_flags=*/base::Histogram::kUmaTargetedHistogramFlag, |
| &snapshot_manager); |
| } |
| |
| #if BUILDFLAG(IS_CHROMEOS_ASH) |
| void MetricsService::SetUserLogStore( |
| std::unique_ptr<UnsentLogStore> user_log_store) { |
| if (log_store()->has_alternate_ongoing_log_store()) |
| return; |
| |
| if (state_ >= SENDING_LOGS) { |
| // Closes the current log so that a new log can be opened in the user log |
| // store. |
| PushPendingLogsToPersistentStorage( |
| MetricsLogsEventManager::CreateReason::kAlternateOngoingLogStoreSet); |
| log_store()->SetAlternateOngoingLogStore(std::move(user_log_store)); |
| OpenNewLog(); |
| RecordUserLogStoreState(kSetPostSendLogsState); |
| } else { |
| // Initial log has not yet been created and flushing now would result in |
| // incomplete information in the current log. |
| // |
| // Logs recorded before a user login will be appended to user logs. This |
| // should not happen frequently. |
| // |
| // TODO(crbug.com/40203458): Look for a way to "pause" pre-login logs and |
| // flush when INIT_TASK is done. |
| log_store()->SetAlternateOngoingLogStore(std::move(user_log_store)); |
| RecordUserLogStoreState(kSetPreSendLogsState); |
| } |
| } |
| |
| void MetricsService::UnsetUserLogStore() { |
| if (!log_store()->has_alternate_ongoing_log_store()) |
| return; |
| |
| if (state_ >= SENDING_LOGS) { |
| PushPendingLogsToPersistentStorage( |
| MetricsLogsEventManager::CreateReason::kAlternateOngoingLogStoreUnset); |
| log_store()->UnsetAlternateOngoingLogStore(); |
| OpenNewLog(); |
| RecordUserLogStoreState(kUnsetPostSendLogsState); |
| return; |
| } |
| |
| // Fast startup and logout case. We flush all histograms and discard the |
| // current log. This is to prevent histograms captured during the user |
| // session from leaking into local state logs. |
| // TODO(crbug.com/40245274): Consider not flushing histograms here. |
| |
| // Discard histograms. |
| DiscardingFlattener flattener; |
| base::HistogramSnapshotManager histogram_snapshot_manager(&flattener); |
| delegating_provider_.RecordHistogramSnapshots(&histogram_snapshot_manager); |
| base::StatisticsRecorder::PrepareDeltas( |
| /*include_persistent=*/true, /*flags_to_set=*/base::Histogram::kNoFlags, |
| /*required_flags=*/base::Histogram::kUmaTargetedHistogramFlag, |
| &histogram_snapshot_manager); |
| |
| // Discard the current log and don't store it. |
| CHECK(current_log_); |
| current_log_.reset(); |
| |
| log_store()->UnsetAlternateOngoingLogStore(); |
| RecordUserLogStoreState(kUnsetPreSendLogsState); |
| } |
| |
| bool MetricsService::HasUserLogStore() { |
| return log_store()->has_alternate_ongoing_log_store(); |
| } |
| |
| void MetricsService::InitPerUserMetrics() { |
| client_->InitPerUserMetrics(); |
| } |
| |
| std::optional<bool> MetricsService::GetCurrentUserMetricsConsent() const { |
| return client_->GetCurrentUserMetricsConsent(); |
| } |
| |
| std::optional<std::string> MetricsService::GetCurrentUserId() const { |
| return client_->GetCurrentUserId(); |
| } |
| |
| void MetricsService::UpdateCurrentUserMetricsConsent( |
| bool user_metrics_consent) { |
| client_->UpdateCurrentUserMetricsConsent(user_metrics_consent); |
| } |
| #endif // BUILDFLAG(IS_CHROMEOS_ASH) |
| |
| #if BUILDFLAG(IS_CHROMEOS) |
| void MetricsService::ResetClientId() { |
| // Pref must be cleared in order for ForceClientIdCreation to generate a new |
| // client ID. |
| local_state_->ClearPref(prefs::kMetricsClientID); |
| local_state_->ClearPref(prefs::kMetricsLogFinalizedRecordId); |
| local_state_->ClearPref(prefs::kMetricsLogRecordId); |
| state_manager_->ForceClientIdCreation(); |
| client_->SetMetricsClientId(state_manager_->client_id()); |
| } |
| #endif // BUILDFLAG(IS_CHROMEOS) |
| |
| variations::SyntheticTrialRegistry* |
| MetricsService::GetSyntheticTrialRegistry() { |
| return client_->GetSyntheticTrialRegistry(); |
| } |
| |
| base::TimeDelta MetricsService::GetInitializationDelay() { |
| return base::Seconds( |
| client_->ShouldStartUpFastForTesting() ? 0 : kInitializationDelaySeconds); |
| } |
| |
| base::TimeDelta MetricsService::GetUpdateLastAliveTimestampDelay() { |
| return base::Seconds(kUpdateAliveTimestampSeconds); |
| } |
| |
| bool MetricsService::StageCurrentLogForTest() { |
| CloseCurrentLog(/*async=*/false, |
| MetricsLogsEventManager::CreateReason::kUnknown); |
| |
| MetricsLogStore* const log_store = reporting_service_.metrics_log_store(); |
| log_store->StageNextLog(); |
| if (!log_store->has_staged_log()) |
| return false; |
| |
| OpenNewLog(); |
| return true; |
| } |
| |
| //------------------------------------------------------------------------------ |
| // private methods |
| //------------------------------------------------------------------------------ |
| |
| //------------------------------------------------------------------------------ |
| // Initialization methods |
| |
| void MetricsService::InitializeMetricsState() { |
| SCOPED_UMA_HISTOGRAM_TIMER_MICROS("UMA.MetricsService.Initialize.Time"); |
| |
| const int64_t buildtime = MetricsLog::GetBuildTime(); |
| const std::string version = client_->GetVersionString(); |
| |
| bool version_changed = false; |
| EnvironmentRecorder recorder(local_state_); |
| int64_t previous_buildtime = recorder.GetLastBuildtime(); |
| std::string previous_version = recorder.GetLastVersion(); |
| if (previous_buildtime != buildtime || previous_version != version) { |
| recorder.SetBuildtimeAndVersion(buildtime, version); |
| version_changed = true; |
| } |
| |
| session_id_ = local_state_->GetInteger(prefs::kMetricsSessionID); |
| |
| StabilityMetricsProvider provider(local_state_); |
| const bool was_last_shutdown_clean = WasLastShutdownClean(); |
| if (!was_last_shutdown_clean) { |
| provider.LogCrash( |
| state_manager_->clean_exit_beacon()->browser_last_live_timestamp()); |
| #if BUILDFLAG(IS_ANDROID) |
| if (!state_manager_->is_foreground_session()) { |
| // Android can have background sessions in which the app may not come to |
| // the foreground, so signal that Chrome should stop watching for crashes |
| // here. This ensures that the termination of such sessions is not |
| // considered a crash. If and when the app enters the foreground, Chrome |
| // starts watching for crashes via MetricsService::OnAppEnterForeground(). |
| // |
| // TODO(crbug/1232027): Such sessions do not yet exist on iOS. When they |
| // do, it may not be possible to know at this point whether a session is a |
| // background session. |
| // |
| // TODO(crbug.com/40788576): On WebLayer, it is not possible to know |
| // whether it's a background session at this point. |
| // |
| // TODO(crbug.com/40196247): Ditto for WebView. |
| state_manager_->clean_exit_beacon()->WriteBeaconValue(true); |
| } |
| #endif // BUILDFLAG(IS_ANDROID) |
| } |
| |
| // HasPreviousSessionData is called first to ensure it is never bypassed. |
| const bool is_initial_stability_log_required = |
| delegating_provider_.HasPreviousSessionData() || !was_last_shutdown_clean; |
| bool has_initial_stability_log = false; |
| if (is_initial_stability_log_required) { |
| // If the previous session didn't exit cleanly, or if any provider |
| // explicitly requests it, prepare an initial stability log - |
| // provided UMA is enabled. |
| if (state_manager_->IsMetricsReportingEnabled()) { |
| has_initial_stability_log = PrepareInitialStabilityLog(previous_version); |
| } |
| } |
| |
| // If the version changed, but no initial stability log was generated, clear |
| // the stability stats from the previous version (so that they don't get |
| // attributed to the current version). This could otherwise happen due to a |
| // number of different edge cases, such as if the last version crashed before |
| // it could save off a system profile or if UMA reporting is disabled (which |
| // normally results in stats being accumulated). |
| if (version_changed && !has_initial_stability_log) |
| ClearSavedStabilityMetrics(); |
| |
| // If the version changed, the system profile is obsolete and needs to be |
| // cleared. This is to avoid the stability data misattribution that could |
| // occur if the current version crashed before saving its own system profile. |
| // Note however this clearing occurs only after preparing the initial |
| // stability log, an operation that requires the previous version's system |
| // profile. At this point, stability metrics pertaining to the previous |
| // version have been cleared. |
| if (version_changed) |
| recorder.ClearEnvironmentFromPrefs(); |
| |
| // Update session ID. |
| ++session_id_; |
| local_state_->SetInteger(prefs::kMetricsSessionID, session_id_); |
| |
| // Notify stability metrics providers about the launch. |
| provider.LogLaunch(); |
| |
| // Call GetUptimes() for the first time, thus allowing all later calls |
| // to record incremental uptimes accurately. |
| base::TimeDelta ignored_uptime_parameter; |
| base::TimeDelta startup_uptime; |
| GetUptimes(local_state_, &startup_uptime, &ignored_uptime_parameter); |
| DCHECK_EQ(0, startup_uptime.InMicroseconds()); |
| } |
| |
| void MetricsService::OnUserAction(const std::string& action, |
| base::TimeTicks action_time) { |
| current_log_->RecordUserAction(action, action_time); |
| HandleIdleSinceLastTransmission(false); |
| } |
| |
| void MetricsService::FinishedInitTask() { |
| DCHECK_EQ(INIT_TASK_SCHEDULED, state_); |
| state_ = INIT_TASK_DONE; |
| rotation_scheduler_->InitTaskComplete(); |
| } |
| |
| void MetricsService::GetUptimes(PrefService* pref, |
| base::TimeDelta* incremental_uptime, |
| base::TimeDelta* uptime) { |
| base::TimeTicks now = base::TimeTicks::Now(); |
| // If this is the first call, init |first_updated_time_| and |
| // |last_updated_time_|. |
| if (last_updated_time_.is_null()) { |
| first_updated_time_ = now; |
| last_updated_time_ = now; |
| } |
| *incremental_uptime = now - last_updated_time_; |
| *uptime = now - first_updated_time_; |
| last_updated_time_ = now; |
| } |
| |
| //------------------------------------------------------------------------------ |
| // Recording control methods |
| |
| void MetricsService::OpenNewLog(bool call_providers) { |
| CHECK(!current_log_); |
| |
| current_log_ = CreateLog(MetricsLog::ONGOING_LOG); |
| if (call_providers) { |
| delegating_provider_.OnDidCreateMetricsLog(); |
| } |
| |
| DCHECK_NE(CONSTRUCTED, state_); |
| if (state_ == INITIALIZED) { |
| // We only need to schedule that run once. |
| state_ = INIT_TASK_SCHEDULED; |
| |
| base::TimeDelta initialization_delay = GetInitializationDelay(); |
| base::SequencedTaskRunner::GetCurrentDefault()->PostDelayedTask( |
| FROM_HERE, |
| base::BindOnce(&MetricsService::StartInitTask, |
| self_ptr_factory_.GetWeakPtr()), |
| initialization_delay); |
| |
| base::SequencedTaskRunner::GetCurrentDefault()->PostDelayedTask( |
| FROM_HERE, |
| base::BindOnce(&MetricsService::PrepareProviderMetricsTask, |
| self_ptr_factory_.GetWeakPtr()), |
| 2 * initialization_delay); |
| } |
| } |
| |
| MetricsService::FinalizedLog::FinalizedLog() = default; |
| MetricsService::FinalizedLog::~FinalizedLog() = default; |
| MetricsService::FinalizedLog::FinalizedLog(FinalizedLog&& other) = default; |
| MetricsService::FinalizedLog& MetricsService::FinalizedLog::operator=( |
| FinalizedLog&& other) = default; |
| |
| MetricsService::MetricsLogHistogramWriter::MetricsLogHistogramWriter( |
| MetricsLog* log) |
| : MetricsLogHistogramWriter(log, |
| base::Histogram::kUmaTargetedHistogramFlag) {} |
| |
| MetricsService::MetricsLogHistogramWriter::MetricsLogHistogramWriter( |
| MetricsLog* log, |
| base::HistogramBase::Flags required_flags) |
| : required_flags_(required_flags), |
| flattener_(std::make_unique<IndependentFlattener>(log)), |
| histogram_snapshot_manager_( |
| std::make_unique<base::HistogramSnapshotManager>(flattener_.get())), |
| snapshot_transaction_id_(0) {} |
| |
| MetricsService::MetricsLogHistogramWriter::~MetricsLogHistogramWriter() = |
| default; |
| |
| void MetricsService::MetricsLogHistogramWriter:: |
| SnapshotStatisticsRecorderDeltas() { |
| SCOPED_UMA_HISTOGRAM_TIMER("UMA.MetricsService.SnapshotDeltasTime"); |
| snapshot_transaction_id_ = base::StatisticsRecorder::PrepareDeltas( |
| /*include_persistent=*/true, |
| /*flags_to_set=*/base::Histogram::kNoFlags, required_flags_, |
| histogram_snapshot_manager_.get()); |
| } |
| |
| void MetricsService::MetricsLogHistogramWriter:: |
| SnapshotStatisticsRecorderUnloggedSamples() { |
| snapshot_transaction_id_ = base::StatisticsRecorder::SnapshotUnloggedSamples( |
| required_flags_, histogram_snapshot_manager_.get()); |
| } |
| |
| MetricsService::IndependentMetricsLoader::IndependentMetricsLoader( |
| std::unique_ptr<MetricsLog> log, |
| std::string app_version, |
| std::string signing_key) |
| : log_(std::move(log)), |
| flattener_(new IndependentFlattener(log_.get())), |
| snapshot_manager_(new base::HistogramSnapshotManager(flattener_.get())), |
| app_version_(std::move(app_version)), |
| signing_key_(std::move(signing_key)) { |
| CHECK(log_); |
| CHECK_EQ(log_->log_type(), MetricsLog::INDEPENDENT_LOG); |
| } |
| |
| MetricsService::IndependentMetricsLoader::~IndependentMetricsLoader() = default; |
| |
| void MetricsService::IndependentMetricsLoader::Run( |
| base::OnceCallback<void(bool)> done_callback, |
| MetricsProvider* metrics_provider) { |
| CHECK(!run_called_); |
| run_called_ = true; |
| |
| metrics_provider->ProvideIndependentMetrics( |
| // Unretained is safe because this callback is either called before |
| // |done_callback|, or in |done_callback|. Either case is fine because |
| // |done_callback| owns |this|. |
| base::BindOnce(&MetricsService::IndependentMetricsLoader::FinalizeLog, |
| base::Unretained(this)), |
| std::move(done_callback), log_->uma_proto(), snapshot_manager_.get()); |
| } |
| |
| void MetricsService::IndependentMetricsLoader::FinalizeLog() { |
| CHECK(run_called_); |
| CHECK(!finalize_log_called_); |
| finalize_log_called_ = true; |
| |
| // Release |snapshot_manager_| and then |flattener_| to prevent dangling |
| // pointers, since |log_| will be released in MetricsService::FinalizeLog(). |
| snapshot_manager_.reset(); |
| flattener_.reset(); |
| |
| // Note that the close_time param must not be set for independent logs. |
| finalized_log_ = MetricsService::FinalizeLog( |
| std::move(log_), /*truncate_events=*/false, /*close_time=*/std::nullopt, |
| app_version_, signing_key_); |
| } |
| |
| bool MetricsService::IndependentMetricsLoader::HasFinalizedLog() { |
| return finalize_log_called_ && !release_finalized_log_called_; |
| } |
| |
| MetricsService::FinalizedLog |
| MetricsService::IndependentMetricsLoader::ReleaseFinalizedLog() { |
| CHECK(HasFinalizedLog()); |
| |
| release_finalized_log_called_ = true; |
| return std::move(finalized_log_); |
| } |
| |
| void MetricsService::StartInitTask() { |
| delegating_provider_.AsyncInit(base::BindOnce( |
| &MetricsService::FinishedInitTask, self_ptr_factory_.GetWeakPtr())); |
| } |
| |
| void MetricsService::CloseCurrentLog( |
| bool async, |
| MetricsLogsEventManager::CreateReason reason, |
| base::OnceClosure log_stored_callback) { |
| if (!current_log_) { |
| return; |
| } |
| |
| // If a persistent allocator is in use, update its internal histograms (such |
| // as how much memory is being used) before reporting. |
| base::PersistentHistogramAllocator* allocator = |
| base::GlobalHistogramAllocator::Get(); |
| if (allocator) |
| allocator->UpdateTrackingHistograms(); |
| |
| // Put incremental data (histogram deltas, and realtime stats deltas) at the |
| // end of all log transmissions (initial log handles this separately). |
| // RecordIncrementalStabilityElements only exists on the derived |
| // MetricsLog class. |
| std::unique_ptr<MetricsLog> current_log(std::move(current_log_)); |
| RecordCurrentEnvironment(current_log.get(), /*complete=*/true); |
| base::TimeDelta incremental_uptime; |
| base::TimeDelta uptime; |
| GetUptimes(local_state_, &incremental_uptime, &uptime); |
| current_log->RecordCurrentSessionData(incremental_uptime, uptime, |
| &delegating_provider_, local_state_); |
| current_log->AssignFinalizedRecordId(local_state_); |
| |
| auto log_histogram_writer = |
| std::make_unique<MetricsLogHistogramWriter>(current_log.get()); |
| |
| // Let metrics providers provide histogram snapshots independently if they |
| // have any. This is done synchronously. |
| delegating_provider_.RecordHistogramSnapshots( |
| log_histogram_writer->histogram_snapshot_manager()); |
| |
| MetricsLog::LogType log_type = current_log->log_type(); |
| CHECK_EQ(log_type, MetricsLog::ONGOING_LOG); |
| ChromeUserMetricsExtension::RealLocalTime close_time = |
| current_log->GetCurrentClockTime(/*record_time_zone=*/true); |
| std::string signing_key = log_store()->GetSigningKeyForLogType(log_type); |
| std::string current_app_version = client_->GetVersionString(); |
| |
| #if !BUILDFLAG(IS_ANDROID) |
| if (base::FeatureList::IsEnabled( |
| features::kMetricsServiceDeltaSnapshotInBg)) { |
| // If this is an async periodic log, and the browser is about to be shut |
| // down (determined by KeepAliveRegistry::IsShuttingDown(), indicating that |
| // there is nothing else to keep the browser alive), then do the work |
| // synchronously instead. Otherwise, creating a ScopedKeepAlive below while |
| // the KeepAliveRegistry has already started shutting down will trigger a |
| // CHECK. Alternatively, the ScopedKeepAlive below could be omitted when the |
| // KeepAliveRegistry is shutting down, but since the browser is shutting |
| // down soon, then it is likely that the asynchronous task to close the |
| // current the log will be cut short, causing data loss. |
| if (async && KeepAliveRegistry::GetInstance()->IsShuttingDown()) { |
| async = false; |
| } |
| } |
| #endif |
| |
| if (async) { |
| if (base::FeatureList::IsEnabled( |
| features::kMetricsServiceDeltaSnapshotInBg)) { |
| // In this mode, we perform the full "delta snapshot" (snapshotting |
| // unlogged samples and marking them as logged) in the background, in |
| // contrast to snapshotting unlogged samples in the background and marking |
| // them as logged when back on the main thread, as is done in the else |
| // branch. |
| |
| auto background_task = base::BindOnce( |
| &MetricsService::SnapshotDeltasAndFinalizeLog, |
| std::move(log_histogram_writer), std::move(current_log), |
| /*truncate_events=*/true, std::move(close_time), |
| std::move(current_app_version), std::move(signing_key)); |
| auto reply_task = base::BindOnce(&MetricsService::StoreFinalizedLog, |
| self_ptr_factory_.GetWeakPtr(), log_type, |
| reason, std::move(log_stored_callback)); |
| |
| #if !BUILDFLAG(IS_ANDROID) |
| // Prevent the browser from shutting down while creating the log in the |
| // background. This is done by creating a ScopedKeepAlive that is only |
| // destroyed after the log has been stored. Not used on Android because it |
| // has no shutdown code path. |
| reply_task = std::move(reply_task) |
| .Then(base::BindOnce( |
| [](std::unique_ptr<ScopedKeepAlive>) { |
| // This function does nothing but keep the |
| // ScopedKeepAlive param alive until we have |
| // finished storing the log. |
| }, |
| std::make_unique<ScopedKeepAlive>( |
| KeepAliveOrigin::UMA_LOG, |
| KeepAliveRestartOption::DISABLED))); |
| #endif // !BUILDFLAG(IS_ANDROID) |
| |
| base::ThreadPool::PostTaskAndReplyWithResult( |
| FROM_HERE, |
| {base::TaskPriority::USER_BLOCKING, |
| base::TaskShutdownBehavior::BLOCK_SHUTDOWN}, |
| std::move(background_task), std::move(reply_task)); |
| } else { |
| // To finalize the log asynchronously, we snapshot the unlogged samples of |
| // histograms and fill them into the log, without actually marking the |
| // samples as logged. We only mark them as logged after running the main |
| // thread reply task to store the log. This way, we will not lose the |
| // samples in case Chrome closes while the background task is running. |
| // Note that while this async log is being finalized, it is possible that |
| // another log is finalized and stored synchronously, which could |
| // potentially cause the same samples to be in two different logs, and |
| // hence sent twice. To prevent this, if a synchronous log is stored while |
| // the async one is being finalized, we discard the async log as it would |
| // be a subset of the synchronous one (in terms of histograms). For more |
| // details, see MaybeCleanUpAndStoreFinalizedLog(). |
| // |
| // TODO(crbug/1052796): Find a way to save the other data such as user |
| // actions and omnibox events when we discard an async log. |
| MetricsLogHistogramWriter* log_histogram_writer_ptr = |
| log_histogram_writer.get(); |
| base::ThreadPool::PostTaskAndReplyWithResult( |
| FROM_HERE, |
| // CONTINUE_ON_SHUTDOWN because the work done is only useful once the |
| // reply task is run (and there are no side effects). So, no need to |
| // block shutdown since the reply task won't be run anyway. |
| // NOTE: If attempting to change the USER_BLOCKING priority, do a |
| // study on the impact first since it might affect the number of logs |
| // being uploaded (which might have secondary effects, e.g. on metrics |
| // that rely on number of logs uploaded). |
| {base::TaskPriority::USER_BLOCKING, |
| base::TaskShutdownBehavior::CONTINUE_ON_SHUTDOWN}, |
| base::BindOnce(&MetricsService::SnapshotUnloggedSamplesAndFinalizeLog, |
| log_histogram_writer_ptr, std::move(current_log), |
| /*truncate_events=*/true, std::move(close_time), |
| std::move(current_app_version), |
| std::move(signing_key)), |
| base::BindOnce(&MetricsService::MaybeCleanUpAndStoreFinalizedLog, |
| self_ptr_factory_.GetWeakPtr(), |
| std::move(log_histogram_writer), log_type, reason, |
| std::move(log_stored_callback))); |
| async_ongoing_log_posted_time_ = base::TimeTicks::Now(); |
| } |
| } else { |
| FinalizedLog finalized_log = SnapshotDeltasAndFinalizeLog( |
| std::move(log_histogram_writer), std::move(current_log), |
| /*truncate_events=*/true, std::move(close_time), |
| std::move(current_app_version), std::move(signing_key)); |
| StoreFinalizedLog(log_type, reason, std::move(log_stored_callback), |
| std::move(finalized_log)); |
| } |
| } |
| |
| void MetricsService::StoreFinalizedLog( |
| MetricsLog::LogType log_type, |
| MetricsLogsEventManager::CreateReason reason, |
| base::OnceClosure done_callback, |
| FinalizedLog finalized_log) { |
| log_store()->StoreLogInfo(std::move(finalized_log.log_info), |
| finalized_log.uncompressed_log_size, log_type, |
| reason); |
| std::move(done_callback).Run(); |
| } |
| |
| void MetricsService::MaybeCleanUpAndStoreFinalizedLog( |
| std::unique_ptr<MetricsLogHistogramWriter> log_histogram_writer, |
| MetricsLog::LogType log_type, |
| MetricsLogsEventManager::CreateReason reason, |
| base::OnceClosure done_callback, |
| FinalizedLog finalized_log) { |
| UMA_HISTOGRAM_TIMES("UMA.MetricsService.PeriodicOngoingLog.ReplyTime", |
| base::TimeTicks::Now() - async_ongoing_log_posted_time_); |
| |
| // Store the finalized log only if the StatisticRecorder's last transaction ID |
| // is the same as the one from |log_histogram_writer|. If they are not the |
| // same, then it indicates that another log was created while creating |
| // |finalized_log| (that log would be a superset of |finalized_log| in terms |
| // of histograms, so we discard |finalized_log| by not storing it). |
| // |
| // TODO(crbug/1052796): Find a way to save the other data such as user actions |
| // and omnibox events when we discard |finalized_log|. |
| // |
| // Note that the call to StatisticsRecorder::GetLastSnapshotTransactionId() |
| // here should not have to wait for a lock since there should not be any async |
| // logs being created (|rotation_scheduler_| is only re-scheduled at the end |
| // of this method). |
| bool should_store_log = |
| (base::StatisticsRecorder::GetLastSnapshotTransactionId() == |
| log_histogram_writer->snapshot_transaction_id()); |
| base::UmaHistogramBoolean("UMA.MetricsService.ShouldStoreAsyncLog", |
| should_store_log); |
| |
| if (!should_store_log) { |
| // We still need to run |done_callback| even if we do not store the log. |
| std::move(done_callback).Run(); |
| return; |
| } |
| |
| SCOPED_UMA_HISTOGRAM_TIMER( |
| "UMA.MetricsService.MaybeCleanUpAndStoreFinalizedLog.Time"); |
| |
| log_histogram_writer->histogram_snapshot_manager() |
| ->MarkUnloggedSamplesAsLogged(); |
| StoreFinalizedLog(log_type, reason, std::move(done_callback), |
| std::move(finalized_log)); |
| } |
| |
| void MetricsService::PushPendingLogsToPersistentStorage( |
| MetricsLogsEventManager::CreateReason reason) { |
| if (IsTooEarlyToCloseLog()) { |
| return; |
| } |
| |
| base::UmaHistogramBoolean("UMA.MetricsService.PendingOngoingLog", |
| pending_ongoing_log_); |
| |
| // Close and store a log synchronously because this is usually called in |
| // critical code paths (e.g., shutdown) where we may not have time to run |
| // background tasks. |
| CloseCurrentLog(/*async=*/false, reason); |
| log_store()->TrimAndPersistUnsentLogs(/*overwrite_in_memory_store=*/true); |
| } |
| |
| //------------------------------------------------------------------------------ |
| // Transmission of logs methods |
| |
| void MetricsService::StartSchedulerIfNecessary() { |
| // Never schedule cutting or uploading of logs in test mode. |
| if (test_mode_active_) |
| return; |
| |
| // Even if reporting is disabled, the scheduler is needed to trigger the |
| // creation of the first ongoing log, which must be done in order for any logs |
| // to be persisted on shutdown or backgrounding. |
| if (recording_active() && (reporting_active() || state_ < SENDING_LOGS)) { |
| rotation_scheduler_->Start(); |
| reporting_service_.Start(); |
| } |
| } |
| |
| void MetricsService::StartScheduledUpload() { |
| DVLOG(1) << "StartScheduledUpload"; |
| DCHECK(state_ >= INIT_TASK_DONE); |
| |
| // If we're getting no notifications, then the log won't have much in it, and |
| // it's possible the computer is about to go to sleep, so don't upload and |
| // stop the scheduler. |
| // If recording has been turned off, the scheduler doesn't need to run. |
| // If reporting is off, proceed if the first ongoing log hasn't been created, |
| // since that has to happen in order for logs to be cut and stored when |
| // persisting. |
| // TODO(stuartmorgan): Call Stop() on the scheduler when reporting and/or |
| // recording are turned off instead of letting it fire and then aborting. |
| if (idle_since_last_transmission_ || !recording_active() || |
| (!reporting_active() && state_ >= SENDING_LOGS)) { |
| rotation_scheduler_->Stop(); |
| rotation_scheduler_->RotationFinished(); |
| return; |
| } |
| |
| // The first ongoing log should be collected prior to sending any unsent logs. |
| if (state_ == INIT_TASK_DONE) { |
| client_->CollectFinalMetricsForLog( |
| base::BindOnce(&MetricsService::OnFinalLogInfoCollectionDone, |
| self_ptr_factory_.GetWeakPtr())); |
| return; |
| } |
| |
| // If there are unsent logs, send the next one. If not, start the asynchronous |
| // process of finalizing the current log for upload. |
| if (has_unsent_logs()) { |
| reporting_service_.Start(); |
| rotation_scheduler_->RotationFinished(); |
| } else { |
| // There are no logs left to send, so start creating a new one. |
| client_->CollectFinalMetricsForLog( |
| base::BindOnce(&MetricsService::OnFinalLogInfoCollectionDone, |
| self_ptr_factory_.GetWeakPtr())); |
| } |
| } |
| |
| void MetricsService::OnFinalLogInfoCollectionDone() { |
| DVLOG(1) << "OnFinalLogInfoCollectionDone"; |
| DCHECK(state_ >= INIT_TASK_DONE); |
| state_ = SENDING_LOGS; |
| |
| // Abort if metrics were turned off during the final info gathering. |
| if (!recording_active()) { |
| rotation_scheduler_->Stop(); |
| rotation_scheduler_->RotationFinished(); |
| return; |
| } |
| |
| SCOPED_UMA_HISTOGRAM_TIMER("UMA.MetricsService.PeriodicOngoingLog.CloseTime"); |
| |
| // There shouldn't be two periodic ongoing logs being finalized in the |
| // background simultaneously. This is currently enforced because: |
| // 1. Only periodic ongoing logs are finalized asynchronously (i.e., logs |
| // created by the MetricsRotationScheduler). |
| // 2. We only re-schedule the MetricsRotationScheduler after storing a |
| // periodic ongoing log. |
| // |
| // TODO(crbug/1052796): Consider making it possible to have multiple |
| // simultaneous async logs by having some queueing system (e.g., if we want |
| // the log created when foregrounding Chrome to be async). |
| DCHECK(!pending_ongoing_log_); |
| pending_ongoing_log_ = true; |
| |
| base::OnceClosure log_stored_callback = |
| base::BindOnce(&MetricsService::OnAsyncPeriodicOngoingLogStored, |
| self_ptr_factory_.GetWeakPtr()); |
| CloseCurrentLog(/*async=*/true, |
| MetricsLogsEventManager::CreateReason::kPeriodic, |
| std::move(log_stored_callback)); |
| OpenNewLog(/*call_providers=*/false); |
| } |
| |
| void MetricsService::OnAsyncPeriodicOngoingLogStored() { |
| pending_ongoing_log_ = false; |
| |
| // Call OnDidCreateMetricsLog() after storing a log instead of directly after |
| // opening a log. Otherwise, the async log that was created would potentially |
| // have mistakenly snapshotted the histograms intended for the newly opened |
| // log. |
| delegating_provider_.OnDidCreateMetricsLog(); |
| |
| // Trim and store unsent logs, including the log that was just closed, so that |
| // they're not lost in case of a crash before upload time. However, the |
| // in-memory log store is unchanged. I.e., logs that are trimmed will still be |
| // available in memory. This is to give the log that was just created a chance |
| // to be sent in case it is trimmed. After uploading (whether successful or |
| // not), the log store is trimmed and stored again, and at that time, the |
| // in-memory log store will be updated. |
| log_store()->TrimAndPersistUnsentLogs(/*overwrite_in_memory_store=*/false); |
| |
| // Do not re-schedule if metrics were turned off while finalizing the log. |
| if (!recording_active()) { |
| rotation_scheduler_->Stop(); |
| rotation_scheduler_->RotationFinished(); |
| } else { |
| // Only re-schedule |rotation_scheduler_| *after* the log was stored to |
| // ensure that only one log is created asynchronously at a time. |
| reporting_service_.Start(); |
| rotation_scheduler_->RotationFinished(); |
| HandleIdleSinceLastTransmission(true); |
| } |
| } |
| |
| bool MetricsService::PrepareInitialStabilityLog( |
| const std::string& prefs_previous_version) { |
| DCHECK_EQ(CONSTRUCTED, state_); |
| |
| constexpr MetricsLog::LogType log_type = MetricsLog::INITIAL_STABILITY_LOG; |
| std::unique_ptr<MetricsLog> initial_stability_log = CreateLog(log_type); |
| |
| // Do not call OnDidCreateMetricsLog here because the stability log describes |
| // stats from the _previous_ session. |
| |
| if (!initial_stability_log->LoadSavedEnvironmentFromPrefs(local_state_)) |
| return false; |
| |
| initial_stability_log->RecordPreviousSessionData(&delegating_provider_, |
| local_state_); |
| initial_stability_log->AssignFinalizedRecordId(local_state_); |
| |
| auto log_histogram_writer = std::make_unique<MetricsLogHistogramWriter>( |
| initial_stability_log.get(), base::Histogram::kUmaStabilityHistogramFlag); |
| |
| // Add a beacon to this record to indicate that it's part of the initial |
| // stability log. |
| UMA_STABILITY_HISTOGRAM_BOOLEAN("UMA.InitialStabilityRecordBeacon", true); |
| |
| // Let metrics providers provide histogram snapshots independently if they |
| // have any. This is done synchronously. |
| delegating_provider_.RecordInitialHistogramSnapshots( |
| log_histogram_writer->histogram_snapshot_manager()); |
| |
| std::string signing_key = log_store()->GetSigningKeyForLogType(log_type); |
| |
| // Synchronously create the initial stability log in order to ensure that the |
| // stability histograms are filled into this specific log. Note that the |
| // close_time param must not be set for initial stability logs. |
| FinalizedLog finalized_log = SnapshotDeltasAndFinalizeLog( |
| std::move(log_histogram_writer), std::move(initial_stability_log), |
| /*truncate_events=*/false, /*close_time=*/std::nullopt, |
| client_->GetVersionString(), std::move(signing_key)); |
| StoreFinalizedLog(log_type, MetricsLogsEventManager::CreateReason::kStability, |
| base::DoNothing(), std::move(finalized_log)); |
| |
| // Store unsent logs, including the stability log that was just saved, so |
| // that they're not lost in case of a crash before upload time. |
| log_store()->TrimAndPersistUnsentLogs(/*overwrite_in_memory_store=*/true); |
| |
| return true; |
| } |
| |
| void MetricsService::RegisterMetricsProvider( |
| std::unique_ptr<MetricsProvider> provider) { |
| DCHECK_EQ(CONSTRUCTED, state_); |
| delegating_provider_.RegisterMetricsProvider(std::move(provider)); |
| } |
| |
| void MetricsService::CheckForClonedInstall() { |
| state_manager_->CheckForClonedInstall(); |
| } |
| |
| bool MetricsService::ShouldResetClientIdsOnClonedInstall() { |
| return state_manager_->ShouldResetClientIdsOnClonedInstall(); |
| } |
| |
| std::unique_ptr<MetricsLog> MetricsService::CreateLog( |
| MetricsLog::LogType log_type) { |
| auto new_metrics_log = std::make_unique<MetricsLog>( |
| state_manager_->client_id(), session_id_, log_type, client_); |
| new_metrics_log->AssignRecordId(local_state_); |
| |
| #if BUILDFLAG(IS_CHROMEOS_ASH) |
| std::optional<std::string> user_id = GetCurrentUserId(); |
| if (user_id.has_value()) |
| new_metrics_log->SetUserId(user_id.value()); |
| #endif // BUILDFLAG(IS_CHROMEOS_ASH) |
| |
| return new_metrics_log; |
| } |
| |
| void MetricsService::AddLogsObserver( |
| MetricsLogsEventManager::Observer* observer) { |
| logs_event_manager_.AddObserver(observer); |
| } |
| |
| void MetricsService::RemoveLogsObserver( |
| MetricsLogsEventManager::Observer* observer) { |
| logs_event_manager_.RemoveObserver(observer); |
| } |
| |
| base::CallbackListSubscription MetricsService::AddEnablementObserver( |
| const base::RepeatingCallback<void(bool)>& observer) { |
| return enablement_observers_.Add(observer); |
| } |
| |
| void MetricsService::SetPersistentSystemProfile( |
| const std::string& serialized_proto, |
| bool complete) { |
| GlobalPersistentSystemProfile::GetInstance()->SetSystemProfile( |
| serialized_proto, complete); |
| } |
| |
| // static |
| std::string MetricsService::RecordCurrentEnvironmentHelper( |
| MetricsLog* log, |
| PrefService* local_state, |
| DelegatingProvider* delegating_provider) { |
| const SystemProfileProto& system_profile = |
| log->RecordEnvironment(delegating_provider); |
| EnvironmentRecorder recorder(local_state); |
| return recorder.SerializeAndRecordEnvironmentToPrefs(system_profile); |
| } |
| |
| void MetricsService::RecordCurrentEnvironment(MetricsLog* log, bool complete) { |
| DCHECK(client_); |
| std::string serialized_proto = |
| RecordCurrentEnvironmentHelper(log, local_state_, &delegating_provider_); |
| |
| SetPersistentSystemProfile(serialized_proto, complete); |
| client_->OnEnvironmentUpdate(&serialized_proto); |
| |
| // The call to SetPersistentSystemProfile() above will have written the |
| // current system profile to persistent memory. Because it may span over |
| // multiple pages, it is possible that the system profile may become corrupted |
| // if only certain pages were flushed to disk. For example, say we overwrite |
| // the persistent memory's system profile with a newer one, and that it spans |
| // over two pages. Then, the OS flushes the second page, but not the first |
| // page. If the device is shut down unexpectedly, e.g. due to a power outage, |
| // then the first page will contain the beginning of the old system profile, |
| // while the second page will contain the ending of the new system profile, |
| // resulting in an unparsable system profile and rendering the whole file |
| // useless. So, manually schedule a flush every time we overwrite the system |
| // profile with a new one to ensure we don't ever get a corrupted one. |
| if (base::FeatureList::IsEnabled( |
| features::kFlushPersistentSystemProfileOnWrite)) { |
| base::ThreadPool::PostTask( |
| FROM_HERE, {base::TaskPriority::BEST_EFFORT, base::MayBlock()}, |
| base::BindOnce([]() { |
| if (auto* allocator = base::GlobalHistogramAllocator::Get()) { |
| // Ideally, we'd just call Flush() with the |sync| parameter set to |
| // false on the main thread, but Windows does not support async |
| // flushing, so do this synchronously on a background thread |
| // instead. |
| allocator->memory_allocator()->Flush(/*sync=*/true); |
| } |
| })); |
| } |
| } |
| |
| void MetricsService::PrepareProviderMetricsLogDone( |
| std::unique_ptr<IndependentMetricsLoader> loader, |
| bool success) { |
| DCHECK_CALLED_ON_VALID_SEQUENCE(sequence_checker_); |
| DCHECK(independent_loader_active_); |
| DCHECK(loader); |
| |
| if (success) { |
| // If not already done, finalize the log that was created independently by |
| // the metrics provider. |
| if (!loader->HasFinalizedLog()) { |
| loader->FinalizeLog(); |
| } |
| |
| StoreFinalizedLog(MetricsLog::INDEPENDENT_LOG, |
| MetricsLogsEventManager::CreateReason::kIndependent, |
| /*done_callback=*/base::DoNothing(), |
| loader->ReleaseFinalizedLog()); |
| } |
| |
| independent_loader_active_ = false; |
| } |
| |
| bool MetricsService::PrepareProviderMetricsLog() { |
| DCHECK_CALLED_ON_VALID_SEQUENCE(sequence_checker_); |
| |
| // If something is still pending, stop now and indicate that there is |
| // still work to do. |
| if (independent_loader_active_) |
| return true; |
| |
| // Check each provider in turn for data. |
| for (auto& provider : delegating_provider_.GetProviders()) { |
| if (provider->HasIndependentMetrics()) { |
| // Create a new log. This will have some default values injected in it |
| // but those will be overwritten when an embedded profile is extracted. |
| constexpr MetricsLog::LogType log_type = MetricsLog::INDEPENDENT_LOG; |
| std::unique_ptr<MetricsLog> log = CreateLog(log_type); |
| log->AssignFinalizedRecordId(local_state_); |
| |
| // Note that something is happening. This must be set before the |
| // operation is requested in case the loader decides to do everything |
| // immediately rather than as a background task. |
| independent_loader_active_ = true; |
| |
| // Give the new log to a loader for management and then run it on the |
| // provider that has something to give. A copy of the pointer is needed |
| // because the unique_ptr may get moved before the value can be used |
| // to call Run(). |
| std::unique_ptr<IndependentMetricsLoader> loader = |
| std::make_unique<IndependentMetricsLoader>( |
| std::move(log), client_->GetVersionString(), |
| log_store()->GetSigningKeyForLogType(log_type)); |
| IndependentMetricsLoader* loader_ptr = loader.get(); |
| loader_ptr->Run( |
| base::BindOnce(&MetricsService::PrepareProviderMetricsLogDone, |
| self_ptr_factory_.GetWeakPtr(), std::move(loader)), |
| provider.get()); |
| |
| // Something was found so there may still be more work to do. |
| return true; |
| } |
| } |
| |
| // Nothing was found so indicate there is no more work to do. |
| return false; |
| } |
| |
| void MetricsService::PrepareProviderMetricsTask() { |
| DCHECK_CALLED_ON_VALID_SEQUENCE(sequence_checker_); |
| bool found = PrepareProviderMetricsLog(); |
| base::TimeDelta next_check = found ? base::Seconds(5) : base::Minutes(15); |
| base::SequencedTaskRunner::GetCurrentDefault()->PostDelayedTask( |
| FROM_HERE, |
| base::BindOnce(&MetricsService::PrepareProviderMetricsTask, |
| self_ptr_factory_.GetWeakPtr()), |
| next_check); |
| } |
| |
| void MetricsService::UpdateLastLiveTimestampTask() { |
| state_manager_->clean_exit_beacon()->UpdateLastLiveTimestamp(); |
| |
| // Schecule the next update. |
| StartUpdatingLastLiveTimestamp(); |
| } |
| |
| bool MetricsService::IsTooEarlyToCloseLog() { |
| // When kMetricsServiceAllowEarlyLogClose is enabled, start closing logs as |
| // soon as the first log is opened (|state_| is set to INIT_TASK_SCHEDULED |
| // when the first log is opened, see OpenNewLog()). Otherwise, only start |
| // closing logs when logs have started being sent. |
| return base::FeatureList::IsEnabled( |
| features::kMetricsServiceAllowEarlyLogClose) |
| ? state_ < INIT_TASK_SCHEDULED |
| : state_ < SENDING_LOGS; |
| } |
| |
| void MetricsService::OnClonedInstallDetected() { |
| // Purge all logs, as they may come from a previous install. Unfortunately, |
| // since the cloned install detector works asynchronously, it is possible that |
| // this is called after logs were already sent. However, practically speaking, |
| // this should not happen, since logs are only sent late into the session. |
| reporting_service_.metrics_log_store()->Purge(); |
| } |
| |
| // static |
| MetricsService::FinalizedLog MetricsService::SnapshotDeltasAndFinalizeLog( |
| std::unique_ptr<MetricsLogHistogramWriter> log_histogram_writer, |
| std::unique_ptr<MetricsLog> log, |
| bool truncate_events, |
| std::optional<ChromeUserMetricsExtension::RealLocalTime> close_time, |
| std::string&& current_app_version, |
| std::string&& signing_key) { |
| log_histogram_writer->SnapshotStatisticsRecorderDeltas(); |
| return FinalizeLog(std::move(log), truncate_events, std::move(close_time), |
| current_app_version, signing_key); |
| } |
| |
| // static |
| MetricsService::FinalizedLog |
| MetricsService::SnapshotUnloggedSamplesAndFinalizeLog( |
| MetricsLogHistogramWriter* log_histogram_writer, |
| std::unique_ptr<MetricsLog> log, |
| bool truncate_events, |
| std::optional<ChromeUserMetricsExtension::RealLocalTime> close_time, |
| std::string&& current_app_version, |
| std::string&& signing_key) { |
| log_histogram_writer->SnapshotStatisticsRecorderUnloggedSamples(); |
| return FinalizeLog(std::move(log), truncate_events, std::move(close_time), |
| current_app_version, signing_key); |
| } |
| |
| // static |
| MetricsService::FinalizedLog MetricsService::FinalizeLog( |
| std::unique_ptr<MetricsLog> log, |
| bool truncate_events, |
| std::optional<ChromeUserMetricsExtension::RealLocalTime> close_time, |
| const std::string& current_app_version, |
| const std::string& signing_key) { |
| DCHECK(log->uma_proto()->has_record_id()); |
| std::string log_data; |
| log->FinalizeLog(truncate_events, current_app_version, std::move(close_time), |
| &log_data); |
| |
| FinalizedLog finalized_log; |
| finalized_log.uncompressed_log_size = log_data.size(); |
| finalized_log.log_info = std::make_unique<UnsentLogStore::LogInfo>(); |
| finalized_log.log_info->Init(log_data, signing_key, log->log_metadata()); |
| return finalized_log; |
| } |
| |
| } // namespace metrics |