Chromium Code Reviews
chromiumcodereview-hr@appspot.gserviceaccount.com (chromiumcodereview-hr) | Please choose your nickname with Settings | Help | Chromium Project | Gerrit Changes | Sign out
(109)

Side by Side Diff: components/variations/synthetic_trial_registry.cc

Issue 2975273003: Extract SyntheticTrialRegistry from MetricsService (Closed)
Patch Set: asdf Created 3 years, 5 months ago
Use n/p to move between diff chunks; N/P to move between comments. Draft comments are only viewable by you.
Jump to:
View unified diff | Download patch
OLDNEW
1 // Copyright 2014 The Chromium Authors. All rights reserved. 1 // Copyright 2017 The Chromium Authors. All rights reserved.
2 // Use of this source code is governed by a BSD-style license that can be 2 // Use of this source code is governed by a BSD-style license that can be
3 // found in the LICENSE file. 3 // found in the LICENSE file.
4 4
5 //------------------------------------------------------------------------------ 5 #include "components/variations/synthetic_trial_registry.h"
6 // Description of the life cycle of a instance of MetricsService.
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 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 // INITIALIZED, // Constructor was called.
80 // INIT_TASK_SCHEDULED, // Waiting for deferred init tasks to finish.
81 // INIT_TASK_DONE, // Waiting for timer to send initial log.
82 // SENDING_LOGS, // Sending logs and creating new ones when we run out.
83 //
84 // In more detail, we have:
85 //
86 // INITIALIZED, // Constructor was called.
87 // The MS has been constructed, but has taken no actions to compose the
88 // initial log.
89 //
90 // INIT_TASK_SCHEDULED, // Waiting for deferred init tasks to finish.
91 // Typically about 30 seconds after startup, a task is sent to a second thread
92 // (the file thread) to perform deferred (lower priority and slower)
93 // initialization steps such as getting the list of plugins. That task will
94 // (when complete) make an async callback (via a Task) to indicate the
95 // completion.
96 //
97 // INIT_TASK_DONE, // Waiting for timer to send initial log.
98 // The callback has arrived, and it is now possible for an initial log to be
99 // created. This callback typically arrives back less than one second after
100 // the deferred init task is dispatched.
101 //
102 // SENDING_LOGS, // Sending logs an creating new ones when we run out.
103 // Logs from previous sessions have been loaded, and initial logs have been
104 // created (an optional stability log and the first metrics log). We will
105 // send all of these logs, and when run out, we will start cutting new logs
106 // to send. We will also cut a new log if we expect a shutdown.
107 //
108 // The progression through the above states is simple, and sequential.
109 // States proceed from INITIAL to SENDING_LOGS, and remain in the latter until
110 // shutdown.
111 //
112 // Also note that whenever we successfully send a log, we mirror the list
113 // of logs into the PrefService. This ensures that IF we crash, we won't start
114 // up and retransmit our old logs again.
115 //
116 // Due to race conditions, it is always possible that a log file could be sent
117 // twice. For example, if a log file is sent, but not yet acknowledged by
118 // the external server, and the user shuts down, then a copy of the log may be
119 // saved for re-transmission. These duplicates could be filtered out server
120 // side, but are not expected to be a significant problem.
121 //
122 //
123 //------------------------------------------------------------------------------
124 6
125 #include "components/metrics/metrics_service.h" 7 namespace variations {
126 8
127 #include <stddef.h> 9 SyntheticTrialRegistry::SyntheticTrialRegistry() = default;
10 SyntheticTrialRegistry::~SyntheticTrialRegistry() = default;
128 11
129 #include <algorithm> 12 void SyntheticTrialRegistry::AddSyntheticTrialObserver(
130 #include <utility> 13 SyntheticTrialObserver* observer) {
131
132 #include "base/bind.h"
133 #include "base/callback.h"
134 #include "base/location.h"
135 #include "base/memory/ptr_util.h"
136 #include "base/metrics/histogram_base.h"
137 #include "base/metrics/histogram_macros.h"
138 #include "base/metrics/histogram_samples.h"
139 #include "base/metrics/persistent_histogram_allocator.h"
140 #include "base/metrics/sparse_histogram.h"
141 #include "base/metrics/statistics_recorder.h"
142 #include "base/single_thread_task_runner.h"
143 #include "base/threading/thread_task_runner_handle.h"
144 #include "base/time/time.h"
145 #include "base/tracked_objects.h"
146 #include "build/build_config.h"
147 #include "components/metrics/environment_recorder.h"
148 #include "components/metrics/metrics_log.h"
149 #include "components/metrics/metrics_log_manager.h"
150 #include "components/metrics/metrics_log_uploader.h"
151 #include "components/metrics/metrics_pref_names.h"
152 #include "components/metrics/metrics_rotation_scheduler.h"
153 #include "components/metrics/metrics_service_client.h"
154 #include "components/metrics/metrics_state_manager.h"
155 #include "components/metrics/stability_metrics_provider.h"
156 #include "components/metrics/url_constants.h"
157 #include "components/prefs/pref_registry_simple.h"
158 #include "components/prefs/pref_service.h"
159 #include "components/variations/entropy_provider.h"
160
161 namespace metrics {
162
163 namespace {
164
165 // The delay, in seconds, after starting recording before doing expensive
166 // initialization work.
167 #if defined(OS_ANDROID) || defined(OS_IOS)
168 // On mobile devices, a significant portion of sessions last less than a minute.
169 // Use a shorter timer on these platforms to avoid losing data.
170 // TODO(dfalcantara): To avoid delaying startup, tighten up initialization so
171 // that it occurs after the user gets their initial page.
172 const int kInitializationDelaySeconds = 5;
173 #else
174 const int kInitializationDelaySeconds = 30;
175 #endif
176
177 #if defined(OS_ANDROID) || defined(OS_IOS)
178 void MarkAppCleanShutdownAndCommit(CleanExitBeacon* clean_exit_beacon,
179 PrefService* local_state) {
180 clean_exit_beacon->WriteBeaconValue(true);
181 ExecutionPhaseManager(local_state).OnAppEnterBackground();
182 // Start writing right away (write happens on a different thread).
183 local_state->CommitPendingWrite();
184 }
185 #endif // defined(OS_ANDROID) || defined(OS_IOS)
186
187 } // namespace
188
189 // static
190 MetricsService::ShutdownCleanliness MetricsService::clean_shutdown_status_ =
191 MetricsService::CLEANLY_SHUTDOWN;
192
193 // static
194 void MetricsService::RegisterPrefs(PrefRegistrySimple* registry) {
195 CleanExitBeacon::RegisterPrefs(registry);
196 MetricsStateManager::RegisterPrefs(registry);
197 MetricsLog::RegisterPrefs(registry);
198 StabilityMetricsProvider::RegisterPrefs(registry);
199 ExecutionPhaseManager::RegisterPrefs(registry);
200 MetricsReportingService::RegisterPrefs(registry);
201
202 registry->RegisterInt64Pref(prefs::kInstallDate, 0);
203
204 registry->RegisterIntegerPref(prefs::kMetricsSessionID, -1);
205
206 registry->RegisterInt64Pref(prefs::kUninstallLaunchCount, 0);
207 registry->RegisterInt64Pref(prefs::kUninstallMetricsUptimeSec, 0);
208 }
209
210 MetricsService::MetricsService(MetricsStateManager* state_manager,
211 MetricsServiceClient* client,
212 PrefService* local_state)
213 : reporting_service_(client, local_state),
214 histogram_snapshot_manager_(this),
215 state_manager_(state_manager),
216 client_(client),
217 local_state_(local_state),
218 recording_state_(UNSET),
219 test_mode_active_(false),
220 state_(INITIALIZED),
221 idle_since_last_transmission_(false),
222 session_id_(-1),
223 self_ptr_factory_(this) {
224 DCHECK(thread_checker_.CalledOnValidThread());
225 DCHECK(state_manager_);
226 DCHECK(client_);
227 DCHECK(local_state_);
228
229 // Set the install date if this is our first run.
230 int64_t install_date = local_state_->GetInt64(prefs::kInstallDate);
231 if (install_date == 0)
232 local_state_->SetInt64(prefs::kInstallDate, base::Time::Now().ToTimeT());
233
234 RegisterMetricsProvider(std::unique_ptr<metrics::MetricsProvider>(
235 new StabilityMetricsProvider(local_state_)));
236 }
237
238 MetricsService::~MetricsService() {
239 DisableRecording();
240 }
241
242 void MetricsService::InitializeMetricsRecordingState() {
243 reporting_service_.Initialize();
244 InitializeMetricsState();
245
246 base::Closure upload_callback =
247 base::Bind(&MetricsService::StartScheduledUpload,
248 self_ptr_factory_.GetWeakPtr());
249
250 rotation_scheduler_.reset(new MetricsRotationScheduler(
251 upload_callback,
252 // MetricsServiceClient outlives MetricsService, and
253 // MetricsRotationScheduler is tied to the lifetime of |this|.
254 base::Bind(&MetricsServiceClient::GetStandardUploadInterval,
255 base::Unretained(client_))));
256
257 for (auto& provider : metrics_providers_)
258 provider->Init();
259 }
260
261 void MetricsService::Start() {
262 HandleIdleSinceLastTransmission(false);
263 EnableRecording();
264 EnableReporting();
265 }
266
267 void MetricsService::StartRecordingForTests() {
268 test_mode_active_ = true;
269 EnableRecording();
270 DisableReporting();
271 }
272
273 void MetricsService::Stop() {
274 HandleIdleSinceLastTransmission(false);
275 DisableReporting();
276 DisableRecording();
277 }
278
279 void MetricsService::EnableReporting() {
280 if (reporting_service_.reporting_active())
281 return;
282 reporting_service_.EnableReporting();
283 StartSchedulerIfNecessary();
284 }
285
286 void MetricsService::DisableReporting() {
287 reporting_service_.DisableReporting();
288 }
289
290 std::string MetricsService::GetClientId() {
291 return state_manager_->client_id();
292 }
293
294 int64_t MetricsService::GetInstallDate() {
295 return local_state_->GetInt64(prefs::kInstallDate);
296 }
297
298 int64_t MetricsService::GetMetricsReportingEnabledDate() {
299 return local_state_->GetInt64(prefs::kMetricsReportingEnabledTimestamp);
300 }
301
302 bool MetricsService::WasLastShutdownClean() const {
303 return state_manager_->clean_exit_beacon()->exited_cleanly();
304 }
305
306 void MetricsService::EnableRecording() {
307 DCHECK(thread_checker_.CalledOnValidThread());
308
309 if (recording_state_ == ACTIVE)
310 return;
311 recording_state_ = ACTIVE;
312
313 state_manager_->ForceClientIdCreation();
314 client_->SetMetricsClientId(state_manager_->client_id());
315 if (!log_manager_.current_log())
316 OpenNewLog();
317
318 for (auto& provider : metrics_providers_)
319 provider->OnRecordingEnabled();
320
321 base::RemoveActionCallback(action_callback_);
322 action_callback_ = base::Bind(&MetricsService::OnUserAction,
323 base::Unretained(this));
324 base::AddActionCallback(action_callback_);
325 }
326
327 void MetricsService::DisableRecording() {
328 DCHECK(thread_checker_.CalledOnValidThread());
329
330 if (recording_state_ == INACTIVE)
331 return;
332 recording_state_ = INACTIVE;
333
334 base::RemoveActionCallback(action_callback_);
335
336 for (auto& provider : metrics_providers_)
337 provider->OnRecordingDisabled();
338
339 PushPendingLogsToPersistentStorage();
340 }
341
342 bool MetricsService::recording_active() const {
343 DCHECK(thread_checker_.CalledOnValidThread());
344 return recording_state_ == ACTIVE;
345 }
346
347 bool MetricsService::reporting_active() const {
348 DCHECK(thread_checker_.CalledOnValidThread());
349 return reporting_service_.reporting_active();
350 }
351
352 bool MetricsService::has_unsent_logs() const {
353 return reporting_service_.metrics_log_store()->has_unsent_logs();
354 }
355
356 void MetricsService::RecordDelta(const base::HistogramBase& histogram,
357 const base::HistogramSamples& snapshot) {
358 log_manager_.current_log()->RecordHistogramDelta(histogram.histogram_name(),
359 snapshot);
360 }
361
362 void MetricsService::InconsistencyDetected(
363 base::HistogramBase::Inconsistency problem) {
364 UMA_HISTOGRAM_ENUMERATION("Histogram.InconsistenciesBrowser",
365 problem, base::HistogramBase::NEVER_EXCEEDED_VALUE);
366 }
367
368 void MetricsService::UniqueInconsistencyDetected(
369 base::HistogramBase::Inconsistency problem) {
370 UMA_HISTOGRAM_ENUMERATION("Histogram.InconsistenciesBrowserUnique",
371 problem, base::HistogramBase::NEVER_EXCEEDED_VALUE);
372 }
373
374 void MetricsService::InconsistencyDetectedInLoggedCount(int amount) {
375 UMA_HISTOGRAM_COUNTS("Histogram.InconsistentSnapshotBrowser",
376 std::abs(amount));
377 }
378
379 void MetricsService::HandleIdleSinceLastTransmission(bool in_idle) {
380 // If there wasn't a lot of action, maybe the computer was asleep, in which
381 // case, the log transmissions should have stopped. Here we start them up
382 // again.
383 if (!in_idle && idle_since_last_transmission_)
384 StartSchedulerIfNecessary();
385 idle_since_last_transmission_ = in_idle;
386 }
387
388 void MetricsService::OnApplicationNotIdle() {
389 if (recording_state_ == ACTIVE)
390 HandleIdleSinceLastTransmission(false);
391 }
392
393 void MetricsService::RecordStartOfSessionEnd() {
394 LogCleanShutdown(false);
395 }
396
397 void MetricsService::RecordCompletedSessionEnd() {
398 LogCleanShutdown(true);
399 }
400
401 #if defined(OS_ANDROID) || defined(OS_IOS)
402 void MetricsService::OnAppEnterBackground() {
403 rotation_scheduler_->Stop();
404 reporting_service_.Stop();
405
406 MarkAppCleanShutdownAndCommit(state_manager_->clean_exit_beacon(),
407 local_state_);
408
409 // Give providers a chance to persist histograms as part of being
410 // backgrounded.
411 for (auto& provider : metrics_providers_)
412 provider->OnAppEnterBackground();
413
414 // At this point, there's no way of knowing when the process will be
415 // killed, so this has to be treated similar to a shutdown, closing and
416 // persisting all logs. Unlinke a shutdown, the state is primed to be ready
417 // to continue logging and uploading if the process does return.
418 if (recording_active() && state_ >= SENDING_LOGS) {
419 PushPendingLogsToPersistentStorage();
420 // Persisting logs closes the current log, so start recording a new log
421 // immediately to capture any background work that might be done before the
422 // process is killed.
423 OpenNewLog();
424 }
425 }
426
427 void MetricsService::OnAppEnterForeground() {
428 state_manager_->clean_exit_beacon()->WriteBeaconValue(false);
429 ExecutionPhaseManager(local_state_).OnAppEnterForeground();
430 StartSchedulerIfNecessary();
431 }
432 #else
433 void MetricsService::LogNeedForCleanShutdown() {
434 state_manager_->clean_exit_beacon()->WriteBeaconValue(false);
435 // Redundant setting to be sure we call for a clean shutdown.
436 clean_shutdown_status_ = NEED_TO_SHUTDOWN;
437 }
438 #endif // defined(OS_ANDROID) || defined(OS_IOS)
439
440 // static
441 void MetricsService::SetExecutionPhase(ExecutionPhase execution_phase,
442 PrefService* local_state) {
443 ExecutionPhaseManager(local_state).SetExecutionPhase(execution_phase);
444 }
445
446 void MetricsService::RecordBreakpadRegistration(bool success) {
447 StabilityMetricsProvider(local_state_).RecordBreakpadRegistration(success);
448 }
449
450 void MetricsService::RecordBreakpadHasDebugger(bool has_debugger) {
451 StabilityMetricsProvider(local_state_)
452 .RecordBreakpadHasDebugger(has_debugger);
453 }
454
455 void MetricsService::ClearSavedStabilityMetrics() {
456 for (auto& provider : metrics_providers_)
457 provider->ClearSavedStabilityMetrics();
458 }
459
460 void MetricsService::PushExternalLog(const std::string& log) {
461 log_store()->StoreLog(log, MetricsLog::ONGOING_LOG);
462 }
463
464 void MetricsService::UpdateMetricsUsagePrefs(const std::string& service_name,
465 int message_size,
466 bool is_cellular) {
467 DCHECK(thread_checker_.CalledOnValidThread());
468 reporting_service_.UpdateMetricsUsagePrefs(service_name, message_size,
469 is_cellular);
470 }
471
472 //------------------------------------------------------------------------------
473 // private methods
474 //------------------------------------------------------------------------------
475
476
477 //------------------------------------------------------------------------------
478 // Initialization methods
479
480 void MetricsService::InitializeMetricsState() {
481 const int64_t buildtime = MetricsLog::GetBuildTime();
482 const std::string version = client_->GetVersionString();
483
484 bool version_changed = false;
485 EnvironmentRecorder recorder(local_state_);
486 int64_t previous_buildtime = recorder.GetLastBuildtime();
487 std::string previous_version = recorder.GetLastVersion();
488 if (previous_buildtime != buildtime || previous_version != version) {
489 recorder.SetBuildtimeAndVersion(buildtime, version);
490 version_changed = true;
491 }
492
493 session_id_ = local_state_->GetInteger(prefs::kMetricsSessionID);
494
495 StabilityMetricsProvider provider(local_state_);
496 if (!state_manager_->clean_exit_beacon()->exited_cleanly()) {
497 provider.LogCrash();
498 // Reset flag, and wait until we call LogNeedForCleanShutdown() before
499 // monitoring.
500 state_manager_->clean_exit_beacon()->WriteBeaconValue(true);
501 ExecutionPhaseManager manager(local_state_);
502 UMA_HISTOGRAM_SPARSE_SLOWLY("Chrome.Browser.CrashedExecutionPhase",
503 static_cast<int>(manager.GetExecutionPhase()));
504 manager.SetExecutionPhase(ExecutionPhase::UNINITIALIZED_PHASE);
505 }
506
507 // ProvidersHaveInitialStabilityMetrics is called first to ensure it is never
508 // bypassed.
509 const bool is_initial_stability_log_required =
510 ProvidersHaveInitialStabilityMetrics() ||
511 !state_manager_->clean_exit_beacon()->exited_cleanly();
512 bool has_initial_stability_log = false;
513 if (is_initial_stability_log_required) {
514 // If the previous session didn't exit cleanly, or if any provider
515 // explicitly requests it, prepare an initial stability log -
516 // provided UMA is enabled.
517 if (state_manager_->IsMetricsReportingEnabled()) {
518 has_initial_stability_log = PrepareInitialStabilityLog(previous_version);
519 if (!has_initial_stability_log)
520 provider.LogStabilityLogDeferred();
521 }
522 }
523
524 // If the version changed, but no initial stability log was generated, clear
525 // the stability stats from the previous version (so that they don't get
526 // attributed to the current version). This could otherwise happen due to a
527 // number of different edge cases, such as if the last version crashed before
528 // it could save off a system profile or if UMA reporting is disabled (which
529 // normally results in stats being accumulated).
530 if (version_changed && !has_initial_stability_log) {
531 ClearSavedStabilityMetrics();
532 provider.LogStabilityDataDiscarded();
533 }
534
535 // If the version changed, the system profile is obsolete and needs to be
536 // cleared. This is to avoid the stability data misattribution that could
537 // occur if the current version crashed before saving its own system profile.
538 // Note however this clearing occurs only after preparing the initial
539 // stability log, an operation that requires the previous version's system
540 // profile. At this point, stability metrics pertaining to the previous
541 // version have been cleared.
542 if (version_changed)
543 recorder.ClearEnvironmentFromPrefs();
544
545 // Update session ID.
546 ++session_id_;
547 local_state_->SetInteger(prefs::kMetricsSessionID, session_id_);
548
549 // Notify stability metrics providers about the launch.
550 provider.LogLaunch();
551 SetExecutionPhase(ExecutionPhase::START_METRICS_RECORDING, local_state_);
552 provider.CheckLastSessionEndCompleted();
553
554 // Call GetUptimes() for the first time, thus allowing all later calls
555 // to record incremental uptimes accurately.
556 base::TimeDelta ignored_uptime_parameter;
557 base::TimeDelta startup_uptime;
558 GetUptimes(local_state_, &startup_uptime, &ignored_uptime_parameter);
559 DCHECK_EQ(0, startup_uptime.InMicroseconds());
560
561 // Bookkeeping for the uninstall metrics.
562 IncrementLongPrefsValue(prefs::kUninstallLaunchCount);
563 }
564
565 void MetricsService::OnUserAction(const std::string& action) {
566 log_manager_.current_log()->RecordUserAction(action);
567 HandleIdleSinceLastTransmission(false);
568 }
569
570 void MetricsService::FinishedInitTask() {
571 DCHECK_EQ(INIT_TASK_SCHEDULED, state_);
572 state_ = INIT_TASK_DONE;
573
574 // Create the initial log.
575 if (!initial_metrics_log_.get()) {
576 initial_metrics_log_ = CreateLog(MetricsLog::ONGOING_LOG);
577 NotifyOnDidCreateMetricsLog();
578 }
579
580 rotation_scheduler_->InitTaskComplete();
581 }
582
583 void MetricsService::GetUptimes(PrefService* pref,
584 base::TimeDelta* incremental_uptime,
585 base::TimeDelta* uptime) {
586 base::TimeTicks now = base::TimeTicks::Now();
587 // If this is the first call, init |first_updated_time_| and
588 // |last_updated_time_|.
589 if (last_updated_time_.is_null()) {
590 first_updated_time_ = now;
591 last_updated_time_ = now;
592 }
593 *incremental_uptime = now - last_updated_time_;
594 *uptime = now - first_updated_time_;
595 last_updated_time_ = now;
596
597 const int64_t incremental_time_secs = incremental_uptime->InSeconds();
598 if (incremental_time_secs > 0) {
599 int64_t metrics_uptime = pref->GetInt64(prefs::kUninstallMetricsUptimeSec);
600 metrics_uptime += incremental_time_secs;
601 pref->SetInt64(prefs::kUninstallMetricsUptimeSec, metrics_uptime);
602 }
603 }
604
605 void MetricsService::NotifyOnDidCreateMetricsLog() {
606 DCHECK(thread_checker_.CalledOnValidThread());
607 for (auto& provider : metrics_providers_)
608 provider->OnDidCreateMetricsLog();
609 }
610
611
612 //------------------------------------------------------------------------------
613 // Recording control methods
614
615 void MetricsService::OpenNewLog() {
616 DCHECK(!log_manager_.current_log());
617
618 log_manager_.BeginLoggingWithLog(CreateLog(MetricsLog::ONGOING_LOG));
619 NotifyOnDidCreateMetricsLog();
620 if (state_ == INITIALIZED) {
621 // We only need to schedule that run once.
622 state_ = INIT_TASK_SCHEDULED;
623
624 base::ThreadTaskRunnerHandle::Get()->PostDelayedTask(
625 FROM_HERE, base::Bind(&MetricsService::StartInitTask,
626 self_ptr_factory_.GetWeakPtr()),
627 base::TimeDelta::FromSeconds(kInitializationDelaySeconds));
628
629 base::ThreadTaskRunnerHandle::Get()->PostDelayedTask(
630 FROM_HERE,
631 base::Bind(&MetricsService::PrepareProviderMetricsTask,
632 self_ptr_factory_.GetWeakPtr()),
633 base::TimeDelta::FromSeconds(2 * kInitializationDelaySeconds));
634 }
635 }
636
637 void MetricsService::StartInitTask() {
638 client_->InitializeSystemProfileMetrics(
639 base::Bind(&MetricsService::FinishedInitTask,
640 self_ptr_factory_.GetWeakPtr()));
641 }
642
643 void MetricsService::CloseCurrentLog() {
644 if (!log_manager_.current_log())
645 return;
646
647 // If a persistent allocator is in use, update its internal histograms (such
648 // as how much memory is being used) before reporting.
649 base::PersistentHistogramAllocator* allocator =
650 base::GlobalHistogramAllocator::Get();
651 if (allocator)
652 allocator->UpdateTrackingHistograms();
653
654 // Put incremental data (histogram deltas, and realtime stats deltas) at the
655 // end of all log transmissions (initial log handles this separately).
656 // RecordIncrementalStabilityElements only exists on the derived
657 // MetricsLog class.
658 MetricsLog* current_log = log_manager_.current_log();
659 DCHECK(current_log);
660 RecordCurrentEnvironment(current_log);
661 base::TimeDelta incremental_uptime;
662 base::TimeDelta uptime;
663 GetUptimes(local_state_, &incremental_uptime, &uptime);
664 current_log->RecordStabilityMetrics(metrics_providers_, incremental_uptime,
665 uptime);
666
667 current_log->RecordGeneralMetrics(metrics_providers_);
668 RecordCurrentHistograms();
669 current_log->TruncateEvents();
670 DVLOG(1) << "Generated an ongoing log.";
671 log_manager_.FinishCurrentLog(log_store());
672 }
673
674 void MetricsService::PushPendingLogsToPersistentStorage() {
675 if (state_ < SENDING_LOGS)
676 return; // We didn't and still don't have time to get plugin list etc.
677
678 CloseCurrentLog();
679 log_store()->PersistUnsentLogs();
680 }
681
682 //------------------------------------------------------------------------------
683 // Transmission of logs methods
684
685 void MetricsService::StartSchedulerIfNecessary() {
686 // Never schedule cutting or uploading of logs in test mode.
687 if (test_mode_active_)
688 return;
689
690 // Even if reporting is disabled, the scheduler is needed to trigger the
691 // creation of the initial log, which must be done in order for any logs to be
692 // persisted on shutdown or backgrounding.
693 if (recording_active() &&
694 (reporting_active() || state_ < SENDING_LOGS)) {
695 rotation_scheduler_->Start();
696 reporting_service_.Start();
697 }
698 }
699
700 void MetricsService::StartScheduledUpload() {
701 DVLOG(1) << "StartScheduledUpload";
702 DCHECK(state_ >= INIT_TASK_DONE);
703 // If we're getting no notifications, then the log won't have much in it, and
704 // it's possible the computer is about to go to sleep, so don't upload and
705 // stop the scheduler.
706 // If recording has been turned off, the scheduler doesn't need to run.
707 // If reporting is off, proceed if the initial log hasn't been created, since
708 // that has to happen in order for logs to be cut and stored when persisting.
709 // TODO(stuartmorgan): Call Stop() on the scheduler when reporting and/or
710 // recording are turned off instead of letting it fire and then aborting.
711 if (idle_since_last_transmission_ ||
712 !recording_active() ||
713 (!reporting_active() && state_ >= SENDING_LOGS)) {
714 rotation_scheduler_->Stop();
715 rotation_scheduler_->RotationFinished();
716 return;
717 }
718
719 // If there are unsent logs, send the next one. If not, start the asynchronous
720 // process of finalizing the current log for upload.
721 if (state_ == SENDING_LOGS && has_unsent_logs()) {
722 reporting_service_.Start();
723 rotation_scheduler_->RotationFinished();
724 } else {
725 // There are no logs left to send, so start creating a new one.
726 client_->CollectFinalMetricsForLog(
727 base::Bind(&MetricsService::OnFinalLogInfoCollectionDone,
728 self_ptr_factory_.GetWeakPtr()));
729 }
730 }
731
732 void MetricsService::OnFinalLogInfoCollectionDone() {
733 DVLOG(1) << "OnFinalLogInfoCollectionDone";
734 // Abort if metrics were turned off during the final info gathering.
735 if (!recording_active()) {
736 rotation_scheduler_->Stop();
737 rotation_scheduler_->RotationFinished();
738 return;
739 }
740
741 if (state_ == INIT_TASK_DONE) {
742 PrepareInitialMetricsLog();
743 } else {
744 DCHECK_EQ(SENDING_LOGS, state_);
745 CloseCurrentLog();
746 OpenNewLog();
747 }
748 reporting_service_.Start();
749 rotation_scheduler_->RotationFinished();
750 HandleIdleSinceLastTransmission(true);
751 }
752
753 bool MetricsService::ProvidersHaveInitialStabilityMetrics() {
754 // Check whether any metrics provider has initial stability metrics.
755 // All providers are queried (rather than stopping after the first "true"
756 // response) in case they do any kind of setup work in preparation for
757 // the later call to RecordInitialHistogramSnapshots().
758 bool has_stability_metrics = false;
759 for (auto& provider : metrics_providers_)
760 has_stability_metrics |= provider->HasInitialStabilityMetrics();
761
762 return has_stability_metrics;
763 }
764
765 bool MetricsService::PrepareInitialStabilityLog(
766 const std::string& prefs_previous_version) {
767 DCHECK_EQ(INITIALIZED, state_);
768
769 std::unique_ptr<MetricsLog> initial_stability_log(
770 CreateLog(MetricsLog::INITIAL_STABILITY_LOG));
771
772 // Do not call NotifyOnDidCreateMetricsLog here because the stability
773 // log describes stats from the _previous_ session.
774 std::string system_profile_app_version;
775 if (!initial_stability_log->LoadSavedEnvironmentFromPrefs(
776 &system_profile_app_version)) {
777 return false;
778 }
779 if (system_profile_app_version != prefs_previous_version)
780 StabilityMetricsProvider(local_state_).LogStabilityVersionMismatch();
781
782 log_manager_.PauseCurrentLog();
783 log_manager_.BeginLoggingWithLog(std::move(initial_stability_log));
784
785 // Note: Some stability providers may record stability stats via histograms,
786 // so this call has to be after BeginLoggingWithLog().
787 log_manager_.current_log()->RecordStabilityMetrics(
788 metrics_providers_, base::TimeDelta(), base::TimeDelta());
789 RecordCurrentStabilityHistograms();
790
791 // Note: RecordGeneralMetrics() intentionally not called since this log is for
792 // stability stats from a previous session only.
793
794 DVLOG(1) << "Generated an stability log.";
795 log_manager_.FinishCurrentLog(log_store());
796 log_manager_.ResumePausedLog();
797
798 // Store unsent logs, including the stability log that was just saved, so
799 // that they're not lost in case of a crash before upload time.
800 log_store()->PersistUnsentLogs();
801
802 return true;
803 }
804
805 void MetricsService::PrepareInitialMetricsLog() {
806 DCHECK_EQ(INIT_TASK_DONE, state_);
807
808 RecordCurrentEnvironment(initial_metrics_log_.get());
809 base::TimeDelta incremental_uptime;
810 base::TimeDelta uptime;
811 GetUptimes(local_state_, &incremental_uptime, &uptime);
812
813 // Histograms only get written to the current log, so make the new log current
814 // before writing them.
815 log_manager_.PauseCurrentLog();
816 log_manager_.BeginLoggingWithLog(std::move(initial_metrics_log_));
817
818 // Note: Some stability providers may record stability stats via histograms,
819 // so this call has to be after BeginLoggingWithLog().
820 MetricsLog* current_log = log_manager_.current_log();
821 current_log->RecordStabilityMetrics(metrics_providers_, base::TimeDelta(),
822 base::TimeDelta());
823 current_log->RecordGeneralMetrics(metrics_providers_);
824 RecordCurrentHistograms();
825
826 DVLOG(1) << "Generated an initial log.";
827 log_manager_.FinishCurrentLog(log_store());
828 log_manager_.ResumePausedLog();
829
830 // Store unsent logs, including the initial log that was just saved, so
831 // that they're not lost in case of a crash before upload time.
832 log_store()->PersistUnsentLogs();
833
834 state_ = SENDING_LOGS;
835 }
836
837 void MetricsService::IncrementLongPrefsValue(const char* path) {
838 int64_t value = local_state_->GetInt64(path);
839 local_state_->SetInt64(path, value + 1);
840 }
841
842 bool MetricsService::UmaMetricsProperlyShutdown() {
843 CHECK(clean_shutdown_status_ == CLEANLY_SHUTDOWN ||
844 clean_shutdown_status_ == NEED_TO_SHUTDOWN);
845 return clean_shutdown_status_ == CLEANLY_SHUTDOWN;
846 }
847
848 void MetricsService::AddSyntheticTrialObserver(
849 variations::SyntheticTrialObserver* observer) {
850 synthetic_trial_observer_list_.AddObserver(observer); 14 synthetic_trial_observer_list_.AddObserver(observer);
851 if (!synthetic_trial_groups_.empty()) 15 if (!synthetic_trial_groups_.empty())
852 observer->OnSyntheticTrialsChanged(synthetic_trial_groups_); 16 observer->OnSyntheticTrialsChanged(synthetic_trial_groups_);
853 } 17 }
854 18
855 void MetricsService::RemoveSyntheticTrialObserver( 19 void SyntheticTrialRegistry::RemoveSyntheticTrialObserver(
856 variations::SyntheticTrialObserver* observer) { 20 SyntheticTrialObserver* observer) {
857 synthetic_trial_observer_list_.RemoveObserver(observer); 21 synthetic_trial_observer_list_.RemoveObserver(observer);
858 } 22 }
859 23
860 void MetricsService::RegisterSyntheticFieldTrial( 24 void SyntheticTrialRegistry::RegisterSyntheticFieldTrial(
861 const variations::SyntheticTrialGroup& trial) { 25 const SyntheticTrialGroup& trial) {
862 for (size_t i = 0; i < synthetic_trial_groups_.size(); ++i) { 26 for (size_t i = 0; i < synthetic_trial_groups_.size(); ++i) {
863 if (synthetic_trial_groups_[i].id.name == trial.id.name) { 27 if (synthetic_trial_groups_[i].id.name == trial.id.name) {
864 if (synthetic_trial_groups_[i].id.group != trial.id.group) { 28 if (synthetic_trial_groups_[i].id.group != trial.id.group) {
865 synthetic_trial_groups_[i].id.group = trial.id.group; 29 synthetic_trial_groups_[i].id.group = trial.id.group;
866 synthetic_trial_groups_[i].start_time = base::TimeTicks::Now(); 30 synthetic_trial_groups_[i].start_time = base::TimeTicks::Now();
867 NotifySyntheticTrialObservers(); 31 NotifySyntheticTrialObservers();
868 } 32 }
869 return; 33 return;
870 } 34 }
871 } 35 }
872 36
873 variations::SyntheticTrialGroup trial_group = trial; 37 SyntheticTrialGroup trial_group = trial;
874 trial_group.start_time = base::TimeTicks::Now(); 38 trial_group.start_time = base::TimeTicks::Now();
875 synthetic_trial_groups_.push_back(trial_group); 39 synthetic_trial_groups_.push_back(trial_group);
876 NotifySyntheticTrialObservers(); 40 NotifySyntheticTrialObservers();
877 } 41 }
878 42
879 void MetricsService::RegisterSyntheticMultiGroupFieldTrial( 43 void SyntheticTrialRegistry::RegisterSyntheticMultiGroupFieldTrial(
880 uint32_t trial_name_hash, 44 uint32_t trial_name_hash,
881 const std::vector<uint32_t>& group_name_hashes) { 45 const std::vector<uint32_t>& group_name_hashes) {
882 auto has_same_trial_name = 46 auto has_same_trial_name = [trial_name_hash](const SyntheticTrialGroup& x) {
883 [trial_name_hash](const variations::SyntheticTrialGroup& x) { 47 return x.id.name == trial_name_hash;
884 return x.id.name == trial_name_hash; 48 };
885 };
886 synthetic_trial_groups_.erase( 49 synthetic_trial_groups_.erase(
887 std::remove_if(synthetic_trial_groups_.begin(), 50 std::remove_if(synthetic_trial_groups_.begin(),
888 synthetic_trial_groups_.end(), has_same_trial_name), 51 synthetic_trial_groups_.end(), has_same_trial_name),
889 synthetic_trial_groups_.end()); 52 synthetic_trial_groups_.end());
890 53
891 if (group_name_hashes.empty()) 54 if (group_name_hashes.empty())
892 return; 55 return;
893 56
894 variations::SyntheticTrialGroup trial_group(trial_name_hash, 57 SyntheticTrialGroup trial_group(trial_name_hash, group_name_hashes[0]);
895 group_name_hashes[0]);
896 trial_group.start_time = base::TimeTicks::Now(); 58 trial_group.start_time = base::TimeTicks::Now();
897 for (uint32_t group_name_hash : group_name_hashes) { 59 for (uint32_t group_name_hash : group_name_hashes) {
898 // Note: Adding the trial group will copy it, so this re-uses the same 60 // Note: Adding the trial group will copy it, so this re-uses the same
899 // |trial_group| struct for convenience (e.g. so start_time's all match). 61 // |trial_group| struct for convenience (e.g. so start_time's all match).
900 trial_group.id.group = group_name_hash; 62 trial_group.id.group = group_name_hash;
901 synthetic_trial_groups_.push_back(trial_group); 63 synthetic_trial_groups_.push_back(trial_group);
902 } 64 }
903 NotifySyntheticTrialObservers(); 65 NotifySyntheticTrialObservers();
904 } 66 }
905 67
906 void MetricsService::GetCurrentSyntheticFieldTrialsForTesting( 68 void SyntheticTrialRegistry::GetCurrentSyntheticFieldTrialsForTesting(
907 std::vector<variations::ActiveGroupId>* synthetic_trials) { 69 std::vector<ActiveGroupId>* synthetic_trials) {
908 GetSyntheticFieldTrialsOlderThan(base::TimeTicks::Now(), synthetic_trials); 70 GetSyntheticFieldTrialsOlderThan(base::TimeTicks::Now(), synthetic_trials);
909 } 71 }
910 72
911 void MetricsService::RegisterMetricsProvider( 73 void SyntheticTrialRegistry::NotifySyntheticTrialObservers() {
912 std::unique_ptr<MetricsProvider> provider) { 74 for (SyntheticTrialObserver& observer : synthetic_trial_observer_list_) {
913 DCHECK_EQ(INITIALIZED, state_);
914 metrics_providers_.push_back(std::move(provider));
915 }
916
917 void MetricsService::CheckForClonedInstall() {
918 state_manager_->CheckForClonedInstall();
919 }
920
921 void MetricsService::NotifySyntheticTrialObservers() {
922 for (variations::SyntheticTrialObserver& observer :
923 synthetic_trial_observer_list_) {
924 observer.OnSyntheticTrialsChanged(synthetic_trial_groups_); 75 observer.OnSyntheticTrialsChanged(synthetic_trial_groups_);
925 } 76 }
926 } 77 }
927 78
928 void MetricsService::GetSyntheticFieldTrialsOlderThan( 79 void SyntheticTrialRegistry::GetSyntheticFieldTrialsOlderThan(
929 base::TimeTicks time, 80 base::TimeTicks time,
930 std::vector<variations::ActiveGroupId>* synthetic_trials) { 81 std::vector<ActiveGroupId>* synthetic_trials) {
931 DCHECK(synthetic_trials); 82 DCHECK(synthetic_trials);
932 synthetic_trials->clear(); 83 synthetic_trials->clear();
933 for (size_t i = 0; i < synthetic_trial_groups_.size(); ++i) { 84 for (size_t i = 0; i < synthetic_trial_groups_.size(); ++i) {
934 if (synthetic_trial_groups_[i].start_time <= time) 85 if (synthetic_trial_groups_[i].start_time <= time)
935 synthetic_trials->push_back(synthetic_trial_groups_[i].id); 86 synthetic_trials->push_back(synthetic_trial_groups_[i].id);
936 } 87 }
937 } 88 }
938 89
939 std::unique_ptr<MetricsLog> MetricsService::CreateLog( 90 } // namespace variations
940 MetricsLog::LogType log_type) {
941 return base::MakeUnique<MetricsLog>(state_manager_->client_id(), session_id_,
942 log_type, client_, local_state_);
943 }
944
945 void MetricsService::RecordCurrentEnvironment(MetricsLog* log) {
946 DCHECK(client_);
947 std::vector<variations::ActiveGroupId> synthetic_trials;
948 GetSyntheticFieldTrialsOlderThan(log->creation_time(), &synthetic_trials);
949 std::string serialized_environment = log->RecordEnvironment(
950 metrics_providers_, synthetic_trials, GetInstallDate(),
951 GetMetricsReportingEnabledDate());
952 client_->OnEnvironmentUpdate(&serialized_environment);
953 }
954
955 void MetricsService::RecordCurrentHistograms() {
956 DCHECK(log_manager_.current_log());
957 SCOPED_UMA_HISTOGRAM_TIMER("UMA.MetricsService.RecordCurrentHistograms.Time");
958
959 // "true" to the begin() call indicates that StatisticsRecorder should include
960 // histograms held in persistent storage.
961 histogram_snapshot_manager_.PrepareDeltas(
962 base::StatisticsRecorder::begin(true), base::StatisticsRecorder::end(),
963 base::Histogram::kNoFlags, base::Histogram::kUmaTargetedHistogramFlag);
964 for (auto& provider : metrics_providers_)
965 provider->RecordHistogramSnapshots(&histogram_snapshot_manager_);
966 }
967
968 void MetricsService::RecordCurrentStabilityHistograms() {
969 DCHECK(log_manager_.current_log());
970 // "true" indicates that StatisticsRecorder should include histograms in
971 // persistent storage.
972 histogram_snapshot_manager_.PrepareDeltas(
973 base::StatisticsRecorder::begin(true), base::StatisticsRecorder::end(),
974 base::Histogram::kNoFlags, base::Histogram::kUmaStabilityHistogramFlag);
975 for (auto& provider : metrics_providers_)
976 provider->RecordInitialHistogramSnapshots(&histogram_snapshot_manager_);
977 }
978
979 bool MetricsService::PrepareProviderMetricsLog() {
980 DCHECK(thread_checker_.CalledOnValidThread());
981
982 // Create a new log. This will have some defaut values injected in it but
983 // those will be overwritten when an embedded profile is extracted.
984 std::unique_ptr<MetricsLog> log = CreateLog(MetricsLog::INDEPENDENT_LOG);
985
986 for (auto& provider : metrics_providers_) {
987 if (log->LoadIndependentMetrics(provider.get())) {
988 log_manager_.PauseCurrentLog();
989 log_manager_.BeginLoggingWithLog(std::move(log));
990 log_manager_.FinishCurrentLog(log_store());
991 log_manager_.ResumePausedLog();
992 return true;
993 }
994 }
995 return false;
996 }
997
998 void MetricsService::PrepareProviderMetricsTask() {
999 DCHECK(thread_checker_.CalledOnValidThread());
1000 bool found = PrepareProviderMetricsLog();
1001 base::TimeDelta next_check = found ? base::TimeDelta::FromSeconds(5)
1002 : base::TimeDelta::FromMinutes(15);
1003 base::ThreadTaskRunnerHandle::Get()->PostDelayedTask(
1004 FROM_HERE,
1005 base::Bind(&MetricsService::PrepareProviderMetricsTask,
1006 self_ptr_factory_.GetWeakPtr()),
1007 next_check);
1008 }
1009
1010 void MetricsService::LogCleanShutdown(bool end_completed) {
1011 DCHECK(thread_checker_.CalledOnValidThread());
1012 // Redundant setting to assure that we always reset this value at shutdown
1013 // (and that we don't use some alternate path, and not call LogCleanShutdown).
1014 clean_shutdown_status_ = CLEANLY_SHUTDOWN;
1015 client_->OnLogCleanShutdown();
1016 state_manager_->clean_exit_beacon()->WriteBeaconValue(true);
1017 SetExecutionPhase(ExecutionPhase::SHUTDOWN_COMPLETE, local_state_);
1018 StabilityMetricsProvider(local_state_).MarkSessionEndCompleted(end_completed);
1019 }
1020
1021 } // namespace metrics
OLDNEW
« no previous file with comments | « components/variations/synthetic_trial_registry.h ('k') | components/variations/synthetic_trial_registry_unittest.cc » ('j') | no next file with comments »

Powered by Google App Engine
This is Rietveld 408576698