blob: c25c8e624e2087253500dbbc59c3fee4553c7915 [file] [log] [blame]
[email protected]2e4cd1a2012-01-12 08:51:031// Copyright (c) 2012 The Chromium Authors. All rights reserved.
license.botbf09a502008-08-24 00:55:552// Use of this source code is governed by a BSD-style license that can be
3// found in the LICENSE file.
initial.commit09911bf2008-07-26 23:55:294
initial.commit09911bf2008-07-26 23:55:295//------------------------------------------------------------------------------
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
11// is 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 XML text, and compressing the results for
17// transmission. Transmission includes submitting a compressed log as data in a
[email protected]281d2882009-01-20 20:32:4218// URL-post, and retransmitting (or retaining at process termination) if the
initial.commit09911bf2008-07-26 23:55:2919// attempted transmission failed. Retention across process terminations is done
[email protected]46f89e142010-07-19 08:00:4220// using the the PrefServices facilities. The retained logs (the ones that never
21// got transmitted) are compressed and base64-encoded before being persisted.
initial.commit09911bf2008-07-26 23:55:2922//
[email protected]281d2882009-01-20 20:32:4223// Logs fall into one of two categories: "initial logs," and "ongoing logs."
24// There is at most one initial log sent for each complete run of the chromium
initial.commit09911bf2008-07-26 23:55:2925// product (from startup, to browser shutdown). An initial log is generally
26// transmitted some short time (1 minute?) after startup, and includes stats
27// such as recent crash info, the number and types of plugins, etc. The
[email protected]281d2882009-01-20 20:32:4228// external server's response to the initial log conceptually tells this MS if
29// it should continue transmitting logs (during this session). The server
30// response can actually be much more detailed, and always includes (at a
31// minimum) how often additional ongoing logs should be sent.
initial.commit09911bf2008-07-26 23:55:2932//
33// After the above initial log, a series of ongoing logs will be transmitted.
34// The first ongoing log actually begins to accumulate information stating when
35// the MS was first constructed. Note that even though the initial log is
36// commonly sent a full minute after startup, the initial log does not include
37// much in the way of user stats. The most common interlog period (delay)
[email protected]0b33f80b2008-12-17 21:34:3638// is 20 minutes. That time period starts when the first user action causes a
initial.commit09911bf2008-07-26 23:55:2939// logging event. This means that if there is no user action, there may be long
[email protected]281d2882009-01-20 20:32:4240// periods without any (ongoing) log transmissions. Ongoing logs typically
initial.commit09911bf2008-07-26 23:55:2941// contain very detailed records of user activities (ex: opened tab, closed
42// tab, fetched URL, maximized window, etc.) In addition, just before an
43// ongoing log is closed out, a call is made to gather memory statistics. Those
44// memory statistics are deposited into a histogram, and the log finalization
45// code is then called. In the finalization, a call to a Histogram server
46// acquires a list of all local histograms that have been flagged for upload
[email protected]281d2882009-01-20 20:32:4247// to the UMA server. The finalization also acquires a the most recent number
48// of page loads, along with any counts of renderer or plugin crashes.
initial.commit09911bf2008-07-26 23:55:2949//
50// When the browser shuts down, there will typically be a fragment of an ongoing
51// log that has not yet been transmitted. At shutdown time, that fragment
[email protected]cac267c2011-09-29 15:18:1052// is closed (including snapshotting histograms), and persisted, for
initial.commit09911bf2008-07-26 23:55:2953// potential transmission during a future run of the product.
54//
55// There are two slightly abnormal shutdown conditions. There is a
56// "disconnected scenario," and a "really fast startup and shutdown" scenario.
57// In the "never connected" situation, the user has (during the running of the
58// process) never established an internet connection. As a result, attempts to
59// transmit the initial log have failed, and a lot(?) of data has accumulated in
60// the ongoing log (which didn't yet get closed, because there was never even a
61// contemplation of sending it). There is also a kindred "lost connection"
62// situation, where a loss of connection prevented an ongoing log from being
63// transmitted, and a (still open) log was stuck accumulating a lot(?) of data,
64// while the earlier log retried its transmission. In both of these
65// disconnected situations, two logs need to be, and are, persistently stored
66// for future transmission.
67//
68// The other unusual shutdown condition, termed "really fast startup and
69// shutdown," involves the deliberate user termination of the process before
70// the initial log is even formed or transmitted. In that situation, no logging
71// is done, but the historical crash statistics remain (unlogged) for inclusion
72// in a future run's initial log. (i.e., we don't lose crash stats).
73//
74// With the above overview, we can now describe the state machine's various
75// stats, based on the State enum specified in the state_ member. Those states
76// are:
77//
78// INITIALIZED, // Constructor was called.
[email protected]85ed9d42010-06-08 22:37:4479// INIT_TASK_SCHEDULED, // Waiting for deferred init tasks to complete.
80// INIT_TASK_DONE, // Waiting for timer to send initial log.
initial.commit09911bf2008-07-26 23:55:2981// INITIAL_LOG_READY, // Initial log generated, and waiting for reply.
initial.commit09911bf2008-07-26 23:55:2982// SENDING_OLD_LOGS, // Sending unsent logs from previous session.
83// SENDING_CURRENT_LOGS, // Sending standard current logs as they accrue.
84//
85// In more detail, we have:
86//
87// INITIALIZED, // Constructor was called.
88// The MS has been constructed, but has taken no actions to compose the
89// initial log.
90//
[email protected]85ed9d42010-06-08 22:37:4491// INIT_TASK_SCHEDULED, // Waiting for deferred init tasks to complete.
initial.commit09911bf2008-07-26 23:55:2992// Typically about 30 seconds after startup, a task is sent to a second thread
[email protected]85ed9d42010-06-08 22:37:4493// (the file thread) to perform deferred (lower priority and slower)
94// initialization steps such as getting the list of plugins. That task will
95// (when complete) make an async callback (via a Task) to indicate the
96// completion.
initial.commit09911bf2008-07-26 23:55:2997//
[email protected]85ed9d42010-06-08 22:37:4498// INIT_TASK_DONE, // Waiting for timer to send initial log.
initial.commit09911bf2008-07-26 23:55:2999// The callback has arrived, and it is now possible for an initial log to be
100// created. This callback typically arrives back less than one second after
[email protected]85ed9d42010-06-08 22:37:44101// the deferred init task is dispatched.
initial.commit09911bf2008-07-26 23:55:29102//
103// INITIAL_LOG_READY, // Initial log generated, and waiting for reply.
104// This state is entered only after an initial log has been composed, and
105// prepared for transmission. It is also the case that any previously unsent
106// logs have been loaded into instance variables for possible transmission.
107//
initial.commit09911bf2008-07-26 23:55:29108// SENDING_OLD_LOGS, // Sending unsent logs from previous session.
[email protected]cac267c2011-09-29 15:18:10109// This state indicates that the initial log for this session has been
110// successfully sent and it is now time to send any logs that were
111// saved from previous sessions. All such logs will be transmitted before
112// exiting this state, and proceeding with ongoing logs from the current session
113// (see next state).
initial.commit09911bf2008-07-26 23:55:29114//
115// SENDING_CURRENT_LOGS, // Sending standard current logs as they accrue.
[email protected]0b33f80b2008-12-17 21:34:36116// Current logs are being accumulated. Typically every 20 minutes a log is
initial.commit09911bf2008-07-26 23:55:29117// closed and finalized for transmission, at the same time as a new log is
118// started.
119//
120// The progression through the above states is simple, and sequential, in the
121// most common use cases. States proceed from INITIAL to SENDING_CURRENT_LOGS,
122// and remain in the latter until shutdown.
123//
124// The one unusual case is when the user asks that we stop logging. When that
[email protected]cac267c2011-09-29 15:18:10125// happens, any staged (transmission in progress) log is persisted, and any log
[email protected]410938e02012-10-24 16:33:59126// that is currently accumulating is also finalized and persisted. We then
[email protected]cac267c2011-09-29 15:18:10127// regress back to the SEND_OLD_LOGS state in case the user enables log
128// recording again during this session. This way anything we have persisted
129// will be sent automatically if/when we progress back to SENDING_CURRENT_LOG
130// state.
initial.commit09911bf2008-07-26 23:55:29131//
[email protected]410938e02012-10-24 16:33:59132// Another similar case is on mobile, when the application is backgrounded and
133// then foregrounded again. Backgrounding created new "old" stored logs, so the
134// state drops back from SENDING_CURRENT_LOGS to SENDING_OLD_LOGS so those logs
135// will be sent.
136//
[email protected]cac267c2011-09-29 15:18:10137// Also note that whenever we successfully send an old log, we mirror the list
138// of logs into the PrefService. This ensures that IF we crash, we won't start
139// up and retransmit our old logs again.
initial.commit09911bf2008-07-26 23:55:29140//
141// Due to race conditions, it is always possible that a log file could be sent
142// twice. For example, if a log file is sent, but not yet acknowledged by
143// the external server, and the user shuts down, then a copy of the log may be
144// saved for re-transmission. These duplicates could be filtered out server
[email protected]281d2882009-01-20 20:32:42145// side, but are not expected to be a significant problem.
initial.commit09911bf2008-07-26 23:55:29146//
147//
148//------------------------------------------------------------------------------
149
[email protected]40bcc302009-03-02 20:50:39150#include "chrome/browser/metrics/metrics_service.h"
151
[email protected]d7c1fa62012-06-15 23:35:30152#include <algorithm>
153
[email protected]7f7f1962011-04-20 15:58:16154#include "base/bind.h"
155#include "base/callback.h"
[email protected]5d91c9e2010-07-28 17:25:28156#include "base/command_line.h"
[email protected]3dc1bc42012-06-19 08:20:53157#include "base/guid.h"
[email protected]46f89e142010-07-19 08:00:42158#include "base/md5.h"
[email protected]835d7c82010-10-14 04:38:38159#include "base/metrics/histogram.h"
[email protected]1026afd2013-03-20 14:28:54160#include "base/metrics/sparse_histogram.h"
[email protected]567d30e2012-07-13 21:48:29161#include "base/metrics/statistics_recorder.h"
[email protected]3853a4c2013-02-11 17:15:57162#include "base/prefs/pref_registry_simple.h"
163#include "base/prefs/pref_service.h"
[email protected]e61003a2012-05-24 17:03:19164#include "base/rand_util.h"
[email protected]3ea1b182013-02-08 22:38:41165#include "base/strings/string_number_conversions.h"
[email protected]ce072a72010-12-31 20:02:16166#include "base/threading/platform_thread.h"
[email protected]b3841c502011-03-09 01:21:31167#include "base/threading/thread.h"
[email protected]3a7b66d2012-04-26 16:34:16168#include "base/threading/thread_restrictions.h"
[email protected]ed0fd002012-04-25 23:10:34169#include "base/tracked_objects.h"
[email protected]440b37b22010-08-30 05:31:40170#include "base/utf_string_conversions.h"
[email protected]679082052010-07-21 21:30:13171#include "base/values.h"
[email protected]19871a92012-06-27 19:50:32172#include "chrome/browser/autocomplete/autocomplete_log.h"
initial.commit09911bf2008-07-26 23:55:29173#include "chrome/browser/browser_process.h"
[email protected]6f371442011-11-09 06:45:46174#include "chrome/browser/extensions/extension_service.h"
175#include "chrome/browser/extensions/process_map.h"
[email protected]b8ddb052012-04-19 02:36:06176#include "chrome/browser/io_thread.h"
[email protected]84c988a2011-04-19 17:56:33177#include "chrome/browser/memory_details.h"
[email protected]679082052010-07-21 21:30:13178#include "chrome/browser/metrics/metrics_log.h"
[email protected]cac267c2011-09-29 15:18:10179#include "chrome/browser/metrics/metrics_log_serializer.h"
[email protected]7f7f1962011-04-20 15:58:16180#include "chrome/browser/metrics/metrics_reporting_scheduler.h"
[email protected]ed0fd002012-04-25 23:10:34181#include "chrome/browser/metrics/tracking_synchronizer.h"
[email protected]adbb3762012-03-09 22:20:08182#include "chrome/browser/net/http_pipelining_compatibility_client.h"
[email protected]d67d1052011-06-09 05:11:41183#include "chrome/browser/net/network_stats.h"
[email protected]f8628c22011-04-05 12:10:18184#include "chrome/browser/prefs/scoped_user_pref_update.h"
[email protected]8ecad5e2010-12-02 21:18:33185#include "chrome/browser/profiles/profile.h"
[email protected]8e5c89a2011-06-07 18:13:33186#include "chrome/browser/search_engines/template_url_service.h"
[email protected]71b73f02011-04-06 15:57:29187#include "chrome/browser/ui/browser_list.h"
[email protected]10b132b02012-07-27 20:46:18188#include "chrome/browser/ui/browser_otr_state.h"
[email protected]157d5472009-11-05 22:31:03189#include "chrome/common/child_process_logging.h"
[email protected]f3b357692013-03-22 05:16:13190#include "chrome/common/chrome_process_type.h"
[email protected]432115822011-07-10 15:52:27191#include "chrome/common/chrome_notification_types.h"
[email protected]d7c1fa62012-06-15 23:35:30192#include "chrome/common/chrome_result_codes.h"
[email protected]92745242009-06-12 16:52:21193#include "chrome/common/chrome_switches.h"
[email protected]20f999b52012-08-24 22:32:59194#include "chrome/common/metrics/entropy_provider.h"
[email protected]2e4cd1a2012-01-12 08:51:03195#include "chrome/common/metrics/metrics_log_manager.h"
[email protected]b4a72d842012-03-22 20:09:09196#include "chrome/common/net/test_server_locations.h"
initial.commit09911bf2008-07-26 23:55:29197#include "chrome/common/pref_names.h"
[email protected]e09ba552009-02-05 03:26:29198#include "chrome/common/render_messages.h"
[email protected]4967f792012-01-20 22:14:40199#include "content/public/browser/child_process_data.h"
[email protected]83ab4a282012-07-12 18:19:45200#include "content/public/browser/histogram_fetcher.h"
[email protected]09d31d52012-03-11 22:30:27201#include "content/public/browser/load_notification_details.h"
[email protected]ad50def52011-10-19 23:17:07202#include "content/public/browser/notification_service.h"
[email protected]3a5180ae2011-12-21 02:39:38203#include "content/public/browser/plugin_service.h"
[email protected]f3b1a082011-11-18 00:34:30204#include "content/public/browser/render_process_host.h"
[email protected]5d490e42012-08-30 05:16:43205#include "content/public/browser/user_metrics.h"
[email protected]459f3502012-09-17 17:08:12206#include "content/public/browser/web_contents.h"
[email protected]fe58acc22012-02-29 01:29:58207#include "net/base/load_flags.h"
[email protected]3dc1bc42012-06-19 08:20:53208#include "net/url_request/url_fetcher.h"
[email protected]91d9f3d2011-08-14 05:24:44209#include "webkit/plugins/webplugininfo.h"
initial.commit09911bf2008-07-26 23:55:29210
[email protected]e06131d2010-02-10 18:40:33211// TODO(port): port browser_distribution.h.
212#if !defined(OS_POSIX)
[email protected]79bf0b72009-04-27 21:30:55213#include "chrome/installer/util/browser_distribution.h"
[email protected]dc6f4962009-02-13 01:25:50214#endif
215
[email protected]5ccaa412009-11-13 22:00:16216#if defined(OS_CHROMEOS)
[email protected]db342d52010-08-09 21:19:37217#include "chrome/browser/chromeos/cros/cros_library.h"
[email protected]5ccaa412009-11-13 22:00:16218#include "chrome/browser/chromeos/external_metrics.h"
[email protected]d43970a72011-07-10 06:24:52219#include "chrome/browser/chromeos/system/statistics_provider.h"
[email protected]5ccaa412009-11-13 22:00:16220#endif
221
[email protected]d7c1fa62012-06-15 23:35:30222#if defined(OS_WIN)
223#include <windows.h> // Needed for STATUS_* codes
[email protected]d7c1fa62012-06-15 23:35:30224#endif
225
[email protected]e1acf6f2008-10-27 20:43:33226using base::Time;
[email protected]631bb742011-11-02 11:29:39227using content::BrowserThread;
[email protected]4967f792012-01-20 22:14:40228using content::ChildProcessData;
[email protected]09d31d52012-03-11 22:30:27229using content::LoadNotificationDetails;
[email protected]3a5180ae2011-12-21 02:39:38230using content::PluginService;
[email protected]e1acf6f2008-10-27 20:43:33231
[email protected]fe58acc22012-02-29 01:29:58232namespace {
[email protected]b2a4812d2012-02-28 05:31:31233
[email protected]fe58acc22012-02-29 01:29:58234// Check to see that we're being called on only one thread.
235bool IsSingleThreaded() {
236 static base::PlatformThreadId thread_id = 0;
237 if (!thread_id)
238 thread_id = base::PlatformThread::CurrentId();
239 return base::PlatformThread::CurrentId() == thread_id;
240}
241
[email protected]7f7f1962011-04-20 15:58:16242// The delay, in seconds, after starting recording before doing expensive
243// initialization work.
[email protected]12180f82012-10-10 21:13:30244#if defined(OS_ANDROID) || defined(OS_IOS)
245// On mobile devices, a significant portion of sessions last less than a minute.
246// Use a shorter timer on these platforms to avoid losing data.
247// TODO(dfalcantara): To avoid delaying startup, tighten up initialization so
248// that it occurs after the user gets their initial page.
249const int kInitializationDelaySeconds = 5;
250#else
[email protected]fe58acc22012-02-29 01:29:58251const int kInitializationDelaySeconds = 30;
[email protected]12180f82012-10-10 21:13:30252#endif
[email protected]252873ef2008-08-04 21:59:45253
[email protected]c9a3ef82009-05-28 22:02:46254// This specifies the amount of time to wait for all renderers to send their
255// data.
[email protected]fe58acc22012-02-29 01:29:58256const int kMaxHistogramGatheringWaitDuration = 60000; // 60 seconds.
[email protected]c9a3ef82009-05-28 22:02:46257
[email protected]54702c92011-04-15 15:06:43258// The maximum number of events in a log uploaded to the UMA server.
[email protected]fe58acc22012-02-29 01:29:58259const int kEventLimit = 2400;
[email protected]68475e602008-08-22 03:21:15260
261// If an upload fails, and the transmission was over this byte count, then we
262// will discard the log, and not try to retransmit it. We also don't persist
263// the log to the prefs for transmission during the next chrome session if this
264// limit is exceeded.
[email protected]fe58acc22012-02-29 01:29:58265const size_t kUploadLogAvoidRetransmitSize = 50000;
initial.commit09911bf2008-07-26 23:55:29266
[email protected]fc4252a72012-01-12 21:58:47267// Interval, in minutes, between state saves.
[email protected]fe58acc22012-02-29 01:29:58268const int kSaveStateIntervalMinutes = 5;
269
[email protected]4266def22012-05-17 01:02:40270enum ResponseStatus {
271 UNKNOWN_FAILURE,
272 SUCCESS,
273 BAD_REQUEST, // Invalid syntax or log too large.
[email protected]9f5c1ce82012-05-23 23:11:28274 NO_RESPONSE,
[email protected]4266def22012-05-17 01:02:40275 NUM_RESPONSE_STATUSES
276};
277
278ResponseStatus ResponseCodeToStatus(int response_code) {
279 switch (response_code) {
280 case 200:
281 return SUCCESS;
282 case 400:
283 return BAD_REQUEST;
[email protected]9f5c1ce82012-05-23 23:11:28284 case net::URLFetcher::RESPONSE_CODE_INVALID:
285 return NO_RESPONSE;
[email protected]4266def22012-05-17 01:02:40286 default:
287 return UNKNOWN_FAILURE;
288 }
289}
290
[email protected]e61003a2012-05-24 17:03:19291// The argument used to generate a non-identifying entropy source. We want no
292// more than 13 bits of entropy, so use this max to return a number between 1
293// and 2^13 = 8192 as the entropy source.
[email protected]20f999b52012-08-24 22:32:59294const uint32 kMaxLowEntropySize = (1 << 13);
[email protected]e61003a2012-05-24 17:03:19295
[email protected]e63a9ef2012-08-30 15:29:42296// Default prefs value for prefs::kMetricsLowEntropySource to indicate that the
297// value has not yet been set.
298const int kLowEntropySourceNotSet = -1;
299
[email protected]e61003a2012-05-24 17:03:19300// Generates a new non-identifying entropy source used to seed persistent
301// activities.
302int GenerateLowEntropySource() {
[email protected]20f999b52012-08-24 22:32:59303 return base::RandInt(0, kMaxLowEntropySize - 1);
[email protected]e61003a2012-05-24 17:03:19304}
305
[email protected]d7c1fa62012-06-15 23:35:30306// Converts an exit code into something that can be inserted into our
307// histograms (which expect non-negative numbers less than MAX_INT).
308int MapCrashExitCodeForHistogram(int exit_code) {
309#if defined(OS_WIN)
310 // Since |abs(STATUS_GUARD_PAGE_VIOLATION) == MAX_INT| it causes problems in
311 // histograms.cc. Solve this by remapping it to a smaller value, which
312 // hopefully doesn't conflict with other codes.
313 if (exit_code == STATUS_GUARD_PAGE_VIOLATION)
314 return 0x1FCF7EC3; // Randomly picked number.
315#endif
316
317 return std::abs(exit_code);
318}
319
[email protected]84c384e2013-03-01 23:20:19320void MarkAppCleanShutdownAndCommit() {
321 PrefService* pref = g_browser_process->local_state();
322 pref->SetBoolean(prefs::kStabilityExitedCleanly, true);
323 // Start writing right away (write happens on a different thread).
324 pref->CommitPendingWrite();
325}
326
[email protected]20f999b52012-08-24 22:32:59327} // namespace
initial.commit09911bf2008-07-26 23:55:29328
[email protected]c0c55e92011-09-10 18:47:30329// static
330MetricsService::ShutdownCleanliness MetricsService::clean_shutdown_status_ =
331 MetricsService::CLEANLY_SHUTDOWN;
332
[email protected]679082052010-07-21 21:30:13333// This is used to quickly log stats from child process related notifications in
334// MetricsService::child_stats_buffer_. The buffer's contents are transferred
335// out when Local State is periodically saved. The information is then
336// reported to the UMA server on next launch.
337struct MetricsService::ChildProcessStats {
338 public:
[email protected]f3b357692013-03-22 05:16:13339 explicit ChildProcessStats(int process_type)
[email protected]679082052010-07-21 21:30:13340 : process_launches(0),
341 process_crashes(0),
342 instances(0),
[email protected]cd937072012-07-02 09:00:29343 loading_errors(0),
[email protected]f3b357692013-03-22 05:16:13344 process_type(process_type) {}
[email protected]679082052010-07-21 21:30:13345
346 // This constructor is only used by the map to return some default value for
347 // an index for which no value has been assigned.
348 ChildProcessStats()
349 : process_launches(0),
[email protected]d88bf0a2011-08-30 23:55:57350 process_crashes(0),
351 instances(0),
[email protected]cd937072012-07-02 09:00:29352 loading_errors(0),
[email protected]bd5d6cf2011-12-01 00:39:12353 process_type(content::PROCESS_TYPE_UNKNOWN) {}
[email protected]679082052010-07-21 21:30:13354
355 // The number of times that the given child process has been launched
356 int process_launches;
357
358 // The number of times that the given child process has crashed
359 int process_crashes;
360
361 // The number of instances of this child process that have been created.
362 // An instance is a DOM object rendered by this child process during a page
363 // load.
364 int instances;
365
[email protected]cd937072012-07-02 09:00:29366 // The number of times there was an error loading an instance of this child
367 // process.
368 int loading_errors;
369
[email protected]f3b357692013-03-22 05:16:13370 int process_type;
[email protected]679082052010-07-21 21:30:13371};
initial.commit09911bf2008-07-26 23:55:29372
[email protected]84c988a2011-04-19 17:56:33373// Handles asynchronous fetching of memory details.
374// Will run the provided task after finished.
375class MetricsMemoryDetails : public MemoryDetails {
376 public:
[email protected]2226c222011-11-22 00:08:40377 explicit MetricsMemoryDetails(const base::Closure& callback)
378 : callback_(callback) {}
[email protected]84c988a2011-04-19 17:56:33379
[email protected]b94584a2013-02-07 03:02:08380 virtual void OnDetailsAvailable() OVERRIDE {
[email protected]2226c222011-11-22 00:08:40381 MessageLoop::current()->PostTask(FROM_HERE, callback_);
[email protected]84c988a2011-04-19 17:56:33382 }
383
384 private:
[email protected]b94584a2013-02-07 03:02:08385 virtual ~MetricsMemoryDetails() {}
[email protected]84c988a2011-04-19 17:56:33386
[email protected]2226c222011-11-22 00:08:40387 base::Closure callback_;
[email protected]84c988a2011-04-19 17:56:33388 DISALLOW_COPY_AND_ASSIGN(MetricsMemoryDetails);
389};
390
initial.commit09911bf2008-07-26 23:55:29391// static
[email protected]b1de2c72013-02-06 02:45:47392void MetricsService::RegisterPrefs(PrefRegistrySimple* registry) {
initial.commit09911bf2008-07-26 23:55:29393 DCHECK(IsSingleThreaded());
[email protected]007b3f82013-04-09 08:46:45394 registry->RegisterStringPref(prefs::kMetricsClientID, std::string());
[email protected]b1de2c72013-02-06 02:45:47395 registry->RegisterIntegerPref(prefs::kMetricsLowEntropySource,
396 kLowEntropySourceNotSet);
397 registry->RegisterInt64Pref(prefs::kMetricsClientIDTimestamp, 0);
398 registry->RegisterInt64Pref(prefs::kStabilityLaunchTimeSec, 0);
399 registry->RegisterInt64Pref(prefs::kStabilityLastTimestampSec, 0);
[email protected]007b3f82013-04-09 08:46:45400 registry->RegisterStringPref(prefs::kStabilityStatsVersion, std::string());
[email protected]b1de2c72013-02-06 02:45:47401 registry->RegisterInt64Pref(prefs::kStabilityStatsBuildTime, 0);
402 registry->RegisterBooleanPref(prefs::kStabilityExitedCleanly, true);
403 registry->RegisterBooleanPref(prefs::kStabilitySessionEndCompleted, true);
404 registry->RegisterIntegerPref(prefs::kMetricsSessionID, -1);
405 registry->RegisterIntegerPref(prefs::kStabilityLaunchCount, 0);
406 registry->RegisterIntegerPref(prefs::kStabilityCrashCount, 0);
407 registry->RegisterIntegerPref(prefs::kStabilityIncompleteSessionEndCount, 0);
408 registry->RegisterIntegerPref(prefs::kStabilityPageLoadCount, 0);
409 registry->RegisterIntegerPref(prefs::kStabilityRendererCrashCount, 0);
410 registry->RegisterIntegerPref(prefs::kStabilityExtensionRendererCrashCount,
411 0);
412 registry->RegisterIntegerPref(prefs::kStabilityRendererHangCount, 0);
413 registry->RegisterIntegerPref(prefs::kStabilityChildProcessCrashCount, 0);
414 registry->RegisterIntegerPref(prefs::kStabilityBreakpadRegistrationFail, 0);
415 registry->RegisterIntegerPref(prefs::kStabilityBreakpadRegistrationSuccess,
416 0);
417 registry->RegisterIntegerPref(prefs::kStabilityDebuggerPresent, 0);
418 registry->RegisterIntegerPref(prefs::kStabilityDebuggerNotPresent, 0);
[email protected]c1834a92011-01-21 18:21:03419#if defined(OS_CHROMEOS)
[email protected]b1de2c72013-02-06 02:45:47420 registry->RegisterIntegerPref(prefs::kStabilityOtherUserCrashCount, 0);
421 registry->RegisterIntegerPref(prefs::kStabilityKernelCrashCount, 0);
422 registry->RegisterIntegerPref(prefs::kStabilitySystemUncleanShutdownCount, 0);
[email protected]c1834a92011-01-21 18:21:03423#endif // OS_CHROMEOS
[email protected]e73c01972008-08-13 00:18:24424
[email protected]b1de2c72013-02-06 02:45:47425 registry->RegisterDictionaryPref(prefs::kProfileMetrics);
426 registry->RegisterIntegerPref(prefs::kNumKeywords, 0);
427 registry->RegisterListPref(prefs::kMetricsInitialLogsXml);
428 registry->RegisterListPref(prefs::kMetricsOngoingLogsXml);
429 registry->RegisterListPref(prefs::kMetricsInitialLogsProto);
430 registry->RegisterListPref(prefs::kMetricsOngoingLogsProto);
[email protected]0bb1a622009-03-04 03:22:32431
[email protected]5c181552013-02-07 09:12:52432 registry->RegisterInt64Pref(prefs::kInstallDate, 0);
[email protected]b1de2c72013-02-06 02:45:47433 registry->RegisterInt64Pref(prefs::kUninstallMetricsPageLoadCount, 0);
434 registry->RegisterInt64Pref(prefs::kUninstallLaunchCount, 0);
[email protected]b1de2c72013-02-06 02:45:47435 registry->RegisterInt64Pref(prefs::kUninstallMetricsUptimeSec, 0);
436 registry->RegisterInt64Pref(prefs::kUninstallLastLaunchTimeSec, 0);
437 registry->RegisterInt64Pref(prefs::kUninstallLastObservedRunTimeSec, 0);
initial.commit09911bf2008-07-26 23:55:29438}
439
[email protected]541f77922009-02-23 21:14:38440// static
441void MetricsService::DiscardOldStabilityStats(PrefService* local_state) {
442 local_state->SetBoolean(prefs::kStabilityExitedCleanly, true);
[email protected]c9abf242009-07-18 06:00:38443 local_state->SetBoolean(prefs::kStabilitySessionEndCompleted, true);
[email protected]541f77922009-02-23 21:14:38444
445 local_state->SetInteger(prefs::kStabilityIncompleteSessionEndCount, 0);
446 local_state->SetInteger(prefs::kStabilityBreakpadRegistrationSuccess, 0);
447 local_state->SetInteger(prefs::kStabilityBreakpadRegistrationFail, 0);
448 local_state->SetInteger(prefs::kStabilityDebuggerPresent, 0);
449 local_state->SetInteger(prefs::kStabilityDebuggerNotPresent, 0);
450
451 local_state->SetInteger(prefs::kStabilityLaunchCount, 0);
452 local_state->SetInteger(prefs::kStabilityCrashCount, 0);
453
454 local_state->SetInteger(prefs::kStabilityPageLoadCount, 0);
455 local_state->SetInteger(prefs::kStabilityRendererCrashCount, 0);
456 local_state->SetInteger(prefs::kStabilityRendererHangCount, 0);
457
[email protected]9165f742010-03-10 22:55:01458 local_state->SetInt64(prefs::kStabilityLaunchTimeSec, 0);
459 local_state->SetInt64(prefs::kStabilityLastTimestampSec, 0);
[email protected]541f77922009-02-23 21:14:38460
461 local_state->ClearPref(prefs::kStabilityPluginStats);
[email protected]ae155cb92009-06-19 06:10:37462
[email protected]fe58acc22012-02-29 01:29:58463 local_state->ClearPref(prefs::kMetricsInitialLogsXml);
464 local_state->ClearPref(prefs::kMetricsOngoingLogsXml);
465 local_state->ClearPref(prefs::kMetricsInitialLogsProto);
466 local_state->ClearPref(prefs::kMetricsOngoingLogsProto);
[email protected]541f77922009-02-23 21:14:38467}
468
initial.commit09911bf2008-07-26 23:55:29469MetricsService::MetricsService()
[email protected]d01b8732008-10-16 02:18:07470 : recording_active_(false),
471 reporting_active_(false),
[email protected]410938e02012-10-24 16:33:59472 test_mode_active_(false),
[email protected]d01b8732008-10-16 02:18:07473 state_(INITIALIZED),
[email protected]e61003a2012-05-24 17:03:19474 low_entropy_source_(0),
[email protected]d01b8732008-10-16 02:18:07475 idle_since_last_transmission_(false),
initial.commit09911bf2008-07-26 23:55:29476 next_window_id_(0),
[email protected]c94d7382012-02-28 08:43:40477 ALLOW_THIS_IN_INITIALIZER_LIST(self_ptr_factory_(this)),
[email protected]40bcc302009-03-02 20:50:39478 ALLOW_THIS_IN_INITIALIZER_LIST(state_saver_factory_(this)),
[email protected]e5354322012-08-09 23:07:37479 waiting_for_asynchronous_reporting_step_(false),
480 entropy_source_returned_(LAST_ENTROPY_NONE) {
initial.commit09911bf2008-07-26 23:55:29481 DCHECK(IsSingleThreaded());
482 InitializeMetricsState();
[email protected]7f7f1962011-04-20 15:58:16483
484 base::Closure callback = base::Bind(&MetricsService::StartScheduledUpload,
[email protected]c94d7382012-02-28 08:43:40485 self_ptr_factory_.GetWeakPtr());
[email protected]7f7f1962011-04-20 15:58:16486 scheduler_.reset(new MetricsReportingScheduler(callback));
[email protected]cac267c2011-09-29 15:18:10487 log_manager_.set_log_serializer(new MetricsLogSerializer());
488 log_manager_.set_max_ongoing_log_store_size(kUploadLogAvoidRetransmitSize);
[email protected]f4eaf7b92013-02-28 22:00:40489
490 BrowserChildProcessObserver::Add(this);
initial.commit09911bf2008-07-26 23:55:29491}
492
493MetricsService::~MetricsService() {
[email protected]410938e02012-10-24 16:33:59494 DisableRecording();
[email protected]f4eaf7b92013-02-28 22:00:40495
496 BrowserChildProcessObserver::Remove(this);
initial.commit09911bf2008-07-26 23:55:29497}
498
[email protected]d01b8732008-10-16 02:18:07499void MetricsService::Start() {
[email protected]b1c8dc02011-04-13 18:32:04500 HandleIdleSinceLastTransmission(false);
[email protected]410938e02012-10-24 16:33:59501 EnableRecording();
502 EnableReporting();
[email protected]d01b8732008-10-16 02:18:07503}
504
[email protected]410938e02012-10-24 16:33:59505void MetricsService::StartRecordingForTests() {
506 test_mode_active_ = true;
507 EnableRecording();
508 DisableReporting();
[email protected]d01b8732008-10-16 02:18:07509}
510
511void MetricsService::Stop() {
[email protected]b1c8dc02011-04-13 18:32:04512 HandleIdleSinceLastTransmission(false);
[email protected]410938e02012-10-24 16:33:59513 DisableReporting();
514 DisableRecording();
515}
516
517void MetricsService::EnableReporting() {
518 if (reporting_active_)
519 return;
520 reporting_active_ = true;
521 StartSchedulerIfNecessary();
522}
523
524void MetricsService::DisableReporting() {
525 reporting_active_ = false;
[email protected]d01b8732008-10-16 02:18:07526}
527
[email protected]edafd4c2011-05-10 17:18:53528std::string MetricsService::GetClientId() {
529 return client_id_;
530}
531
[email protected]20f999b52012-08-24 22:32:59532scoped_ptr<const base::FieldTrial::EntropyProvider>
533 MetricsService::CreateEntropyProvider(bool reporting_will_be_enabled) {
[email protected]29d81ee02012-05-25 05:45:42534 // For metrics reporting-enabled users, we combine the client ID and low
535 // entropy source to get the final entropy source. Otherwise, only use the low
536 // entropy source.
537 // This has two useful properties:
[email protected]e61003a2012-05-24 17:03:19538 // 1) It makes the entropy source less identifiable for parties that do not
539 // know the low entropy source.
540 // 2) It makes the final entropy source resettable.
[email protected]e5354322012-08-09 23:07:37541 if (reporting_will_be_enabled) {
[email protected]5fbffb72012-08-18 01:59:18542 if (entropy_source_returned_ == LAST_ENTROPY_NONE)
543 entropy_source_returned_ = LAST_ENTROPY_HIGH;
544 DCHECK_EQ(LAST_ENTROPY_HIGH, entropy_source_returned_);
[email protected]20f999b52012-08-24 22:32:59545 const std::string high_entropy_source =
546 client_id_ + base::IntToString(GetLowEntropySource());
547 return scoped_ptr<const base::FieldTrial::EntropyProvider>(
548 new metrics::SHA1EntropyProvider(high_entropy_source));
[email protected]e5354322012-08-09 23:07:37549 }
[email protected]20f999b52012-08-24 22:32:59550
[email protected]5fbffb72012-08-18 01:59:18551 if (entropy_source_returned_ == LAST_ENTROPY_NONE)
552 entropy_source_returned_ = LAST_ENTROPY_LOW;
553 DCHECK_EQ(LAST_ENTROPY_LOW, entropy_source_returned_);
[email protected]20f999b52012-08-24 22:32:59554 return scoped_ptr<const base::FieldTrial::EntropyProvider>(
555 new metrics::PermutedEntropyProvider(GetLowEntropySource(),
556 kMaxLowEntropySize));
[email protected]e61003a2012-05-24 17:03:19557}
558
[email protected]5cbeeef72012-02-08 02:05:18559void MetricsService::ForceClientIdCreation() {
560 if (!client_id_.empty())
561 return;
562 PrefService* pref = g_browser_process->local_state();
563 client_id_ = pref->GetString(prefs::kMetricsClientID);
564 if (!client_id_.empty())
565 return;
566
567 client_id_ = GenerateClientID();
568 pref->SetString(prefs::kMetricsClientID, client_id_);
569
570 // Might as well make a note of how long this ID has existed
571 pref->SetString(prefs::kMetricsClientIDTimestamp,
572 base::Int64ToString(Time::Now().ToTimeT()));
573}
574
[email protected]410938e02012-10-24 16:33:59575void MetricsService::EnableRecording() {
initial.commit09911bf2008-07-26 23:55:29576 DCHECK(IsSingleThreaded());
577
[email protected]410938e02012-10-24 16:33:59578 if (recording_active_)
initial.commit09911bf2008-07-26 23:55:29579 return;
[email protected]410938e02012-10-24 16:33:59580 recording_active_ = true;
initial.commit09911bf2008-07-26 23:55:29581
[email protected]410938e02012-10-24 16:33:59582 ForceClientIdCreation();
583 child_process_logging::SetClientId(client_id_);
584 if (!log_manager_.current_log())
585 OpenNewLog();
[email protected]005ef3e2009-05-22 20:55:46586
[email protected]410938e02012-10-24 16:33:59587 SetUpNotifications(&registrar_, this);
[email protected]dd98f392013-02-04 13:03:22588 content::RemoveActionCallback(action_callback_);
589 action_callback_ = base::Bind(&MetricsService::OnUserAction,
590 base::Unretained(this));
591 content::AddActionCallback(action_callback_);
[email protected]410938e02012-10-24 16:33:59592}
593
594void MetricsService::DisableRecording() {
595 DCHECK(IsSingleThreaded());
596
597 if (!recording_active_)
598 return;
599 recording_active_ = false;
600
[email protected]dd98f392013-02-04 13:03:22601 content::RemoveActionCallback(action_callback_);
[email protected]410938e02012-10-24 16:33:59602 registrar_.RemoveAll();
603 PushPendingLogsToPersistentStorage();
604 DCHECK(!log_manager_.has_staged_log());
initial.commit09911bf2008-07-26 23:55:29605}
606
[email protected]d01b8732008-10-16 02:18:07607bool MetricsService::recording_active() const {
initial.commit09911bf2008-07-26 23:55:29608 DCHECK(IsSingleThreaded());
[email protected]d01b8732008-10-16 02:18:07609 return recording_active_;
initial.commit09911bf2008-07-26 23:55:29610}
611
[email protected]d01b8732008-10-16 02:18:07612bool MetricsService::reporting_active() const {
613 DCHECK(IsSingleThreaded());
614 return reporting_active_;
initial.commit09911bf2008-07-26 23:55:29615}
616
[email protected]87ef9ea2011-02-26 03:15:15617// static
[email protected]6c2381d2011-10-19 02:52:53618void MetricsService::SetUpNotifications(
619 content::NotificationRegistrar* registrar,
620 content::NotificationObserver* observer) {
621 registrar->Add(observer, chrome::NOTIFICATION_BROWSER_OPENED,
[email protected]ad50def52011-10-19 23:17:07622 content::NotificationService::AllBrowserContextsAndSources());
[email protected]6c2381d2011-10-19 02:52:53623 registrar->Add(observer, chrome::NOTIFICATION_BROWSER_CLOSED,
[email protected]ad50def52011-10-19 23:17:07624 content::NotificationService::AllSources());
[email protected]884033e2012-04-16 19:38:42625 registrar->Add(observer, chrome::NOTIFICATION_TAB_PARENTED,
[email protected]ad50def52011-10-19 23:17:07626 content::NotificationService::AllSources());
[email protected]884033e2012-04-16 19:38:42627 registrar->Add(observer, chrome::NOTIFICATION_TAB_CLOSING,
[email protected]ad50def52011-10-19 23:17:07628 content::NotificationService::AllSources());
[email protected]6c2381d2011-10-19 02:52:53629 registrar->Add(observer, content::NOTIFICATION_LOAD_START,
[email protected]ad50def52011-10-19 23:17:07630 content::NotificationService::AllSources());
[email protected]6c2381d2011-10-19 02:52:53631 registrar->Add(observer, content::NOTIFICATION_LOAD_STOP,
[email protected]ad50def52011-10-19 23:17:07632 content::NotificationService::AllSources());
[email protected]6c2381d2011-10-19 02:52:53633 registrar->Add(observer, content::NOTIFICATION_RENDERER_PROCESS_CLOSED,
[email protected]ad50def52011-10-19 23:17:07634 content::NotificationService::AllSources());
[email protected]6c2381d2011-10-19 02:52:53635 registrar->Add(observer, content::NOTIFICATION_RENDERER_PROCESS_HANG,
[email protected]ad50def52011-10-19 23:17:07636 content::NotificationService::AllSources());
[email protected]6c2381d2011-10-19 02:52:53637 registrar->Add(observer, chrome::NOTIFICATION_TEMPLATE_URL_SERVICE_LOADED,
[email protected]ad50def52011-10-19 23:17:07638 content::NotificationService::AllSources());
[email protected]6c2381d2011-10-19 02:52:53639 registrar->Add(observer, chrome::NOTIFICATION_OMNIBOX_OPENED_URL,
[email protected]ad50def52011-10-19 23:17:07640 content::NotificationService::AllSources());
[email protected]87ef9ea2011-02-26 03:15:15641}
642
[email protected]f4eaf7b92013-02-28 22:00:40643void MetricsService::BrowserChildProcessHostConnected(
644 const content::ChildProcessData& data) {
645 GetChildProcessStats(data).process_launches++;
646}
647
648void MetricsService::BrowserChildProcessCrashed(
649 const content::ChildProcessData& data) {
650 GetChildProcessStats(data).process_crashes++;
651 // Exclude plugin crashes from the count below because we report them via
652 // a separate UMA metric.
[email protected]f3b357692013-03-22 05:16:13653 if (!IsPluginProcess(data.process_type))
[email protected]f4eaf7b92013-02-28 22:00:40654 IncrementPrefValue(prefs::kStabilityChildProcessCrashCount);
655}
656
657void MetricsService::BrowserChildProcessInstanceCreated(
658 const content::ChildProcessData& data) {
659 GetChildProcessStats(data).instances++;
660}
661
[email protected]432115822011-07-10 15:52:27662void MetricsService::Observe(int type,
[email protected]6c2381d2011-10-19 02:52:53663 const content::NotificationSource& source,
664 const content::NotificationDetails& details) {
[email protected]cac267c2011-09-29 15:18:10665 DCHECK(log_manager_.current_log());
initial.commit09911bf2008-07-26 23:55:29666 DCHECK(IsSingleThreaded());
667
[email protected]dd98f392013-02-04 13:03:22668 if (!CanLogNotification())
initial.commit09911bf2008-07-26 23:55:29669 return;
670
[email protected]432115822011-07-10 15:52:27671 switch (type) {
[email protected]432115822011-07-10 15:52:27672 case chrome::NOTIFICATION_BROWSER_OPENED:
[email protected]459f3502012-09-17 17:08:12673 case chrome::NOTIFICATION_BROWSER_CLOSED: {
674 Browser* browser = content::Source<Browser>(source).ptr();
675 LogWindowOrTabChange(type, reinterpret_cast<uintptr_t>(browser));
initial.commit09911bf2008-07-26 23:55:29676 break;
[email protected]459f3502012-09-17 17:08:12677 }
initial.commit09911bf2008-07-26 23:55:29678
[email protected]459f3502012-09-17 17:08:12679 case chrome::NOTIFICATION_TAB_PARENTED: {
680 content::WebContents* web_contents =
681 content::Source<content::WebContents>(source).ptr();
682 LogWindowOrTabChange(type, reinterpret_cast<uintptr_t>(web_contents));
initial.commit09911bf2008-07-26 23:55:29683 break;
[email protected]459f3502012-09-17 17:08:12684 }
685
686 case chrome::NOTIFICATION_TAB_CLOSING: {
687 content::NavigationController* controller =
688 content::Source<content::NavigationController>(source).ptr();
689 content::WebContents* web_contents = controller->GetWebContents();
690 LogWindowOrTabChange(type, reinterpret_cast<uintptr_t>(web_contents));
691 break;
692 }
initial.commit09911bf2008-07-26 23:55:29693
[email protected]432115822011-07-10 15:52:27694 case content::NOTIFICATION_LOAD_STOP:
initial.commit09911bf2008-07-26 23:55:29695 LogLoadComplete(type, source, details);
696 break;
697
[email protected]432115822011-07-10 15:52:27698 case content::NOTIFICATION_LOAD_START:
initial.commit09911bf2008-07-26 23:55:29699 LogLoadStarted();
700 break;
701
[email protected]432115822011-07-10 15:52:27702 case content::NOTIFICATION_RENDERER_PROCESS_CLOSED: {
[email protected]f3b1a082011-11-18 00:34:30703 content::RenderProcessHost::RendererClosedDetails* process_details =
704 content::Details<
705 content::RenderProcessHost::RendererClosedDetails>(
706 details).ptr();
707 content::RenderProcessHost* host =
708 content::Source<content::RenderProcessHost>(source).ptr();
[email protected]c3721482012-03-23 16:21:48709 LogRendererCrash(
[email protected]f1675202012-07-09 15:18:00710 host, process_details->status, process_details->exit_code);
[email protected]1f085622009-12-04 05:33:45711 }
initial.commit09911bf2008-07-26 23:55:29712 break;
713
[email protected]432115822011-07-10 15:52:27714 case content::NOTIFICATION_RENDERER_PROCESS_HANG:
initial.commit09911bf2008-07-26 23:55:29715 LogRendererHang();
716 break;
717
[email protected]432115822011-07-10 15:52:27718 case chrome::NOTIFICATION_TEMPLATE_URL_SERVICE_LOADED:
[email protected]604d8a062012-03-16 21:37:46719 LogKeywordCount(content::Source<TemplateURLService>(
720 source)->GetTemplateURLs().size());
initial.commit09911bf2008-07-26 23:55:29721 break;
722
[email protected]432115822011-07-10 15:52:27723 case chrome::NOTIFICATION_OMNIBOX_OPENED_URL: {
[email protected]279703f2012-01-20 22:23:26724 MetricsLog* current_log =
725 static_cast<MetricsLog*>(log_manager_.current_log());
[email protected]1226abb2010-06-10 18:01:28726 DCHECK(current_log);
727 current_log->RecordOmniboxOpenedURL(
[email protected]6c2381d2011-10-19 02:52:53728 *content::Details<AutocompleteLog>(details).ptr());
initial.commit09911bf2008-07-26 23:55:29729 break;
[email protected]1226abb2010-06-10 18:01:28730 }
initial.commit09911bf2008-07-26 23:55:29731
initial.commit09911bf2008-07-26 23:55:29732 default:
[email protected]a063c102010-07-22 22:20:19733 NOTREACHED();
initial.commit09911bf2008-07-26 23:55:29734 break;
735 }
[email protected]d01b8732008-10-16 02:18:07736
737 HandleIdleSinceLastTransmission(false);
[email protected]d01b8732008-10-16 02:18:07738}
739
740void MetricsService::HandleIdleSinceLastTransmission(bool in_idle) {
741 // If there wasn't a lot of action, maybe the computer was asleep, in which
742 // case, the log transmissions should have stopped. Here we start them up
743 // again.
[email protected]cac78842008-11-27 01:02:20744 if (!in_idle && idle_since_last_transmission_)
[email protected]7f7f1962011-04-20 15:58:16745 StartSchedulerIfNecessary();
[email protected]cac78842008-11-27 01:02:20746 idle_since_last_transmission_ = in_idle;
initial.commit09911bf2008-07-26 23:55:29747}
748
initial.commit09911bf2008-07-26 23:55:29749void MetricsService::RecordStartOfSessionEnd() {
[email protected]466f3c12011-03-23 21:20:38750 LogCleanShutdown();
initial.commit09911bf2008-07-26 23:55:29751 RecordBooleanPrefValue(prefs::kStabilitySessionEndCompleted, false);
752}
753
754void MetricsService::RecordCompletedSessionEnd() {
[email protected]466f3c12011-03-23 21:20:38755 LogCleanShutdown();
initial.commit09911bf2008-07-26 23:55:29756 RecordBooleanPrefValue(prefs::kStabilitySessionEndCompleted, true);
757}
758
[email protected]410938e02012-10-24 16:33:59759#if defined(OS_ANDROID) || defined(OS_IOS)
[email protected]117fbdf22012-06-26 18:36:39760void MetricsService::OnAppEnterBackground() {
761 scheduler_->Stop();
762
[email protected]84c384e2013-03-01 23:20:19763 MarkAppCleanShutdownAndCommit();
[email protected]117fbdf22012-06-26 18:36:39764
765 // At this point, there's no way of knowing when the process will be
766 // killed, so this has to be treated similar to a shutdown, closing and
767 // persisting all logs. Unlinke a shutdown, the state is primed to be ready
768 // to continue logging and uploading if the process does return.
769 if (recording_active() && state_ >= INITIAL_LOG_READY) {
770 PushPendingLogsToPersistentStorage();
[email protected]410938e02012-10-24 16:33:59771 // Persisting logs closes the current log, so start recording a new log
772 // immediately to capture any background work that might be done before the
773 // process is killed.
774 OpenNewLog();
[email protected]117fbdf22012-06-26 18:36:39775 }
[email protected]117fbdf22012-06-26 18:36:39776}
777
778void MetricsService::OnAppEnterForeground() {
779 PrefService* pref = g_browser_process->local_state();
780 pref->SetBoolean(prefs::kStabilityExitedCleanly, false);
781
782 StartSchedulerIfNecessary();
783}
[email protected]84c384e2013-03-01 23:20:19784#else
785void MetricsService::LogNeedForCleanShutdown() {
786 PrefService* pref = g_browser_process->local_state();
787 pref->SetBoolean(prefs::kStabilityExitedCleanly, false);
788 // Redundant setting to be sure we call for a clean shutdown.
789 clean_shutdown_status_ = NEED_TO_SHUTDOWN;
790}
791#endif // defined(OS_ANDROID) || defined(OS_IOS)
[email protected]117fbdf22012-06-26 18:36:39792
[email protected]7f7f1962011-04-20 15:58:16793void MetricsService::RecordBreakpadRegistration(bool success) {
[email protected]68475e602008-08-22 03:21:15794 if (!success)
[email protected]e73c01972008-08-13 00:18:24795 IncrementPrefValue(prefs::kStabilityBreakpadRegistrationFail);
796 else
797 IncrementPrefValue(prefs::kStabilityBreakpadRegistrationSuccess);
798}
799
800void MetricsService::RecordBreakpadHasDebugger(bool has_debugger) {
801 if (!has_debugger)
802 IncrementPrefValue(prefs::kStabilityDebuggerNotPresent);
803 else
[email protected]68475e602008-08-22 03:21:15804 IncrementPrefValue(prefs::kStabilityDebuggerPresent);
[email protected]e73c01972008-08-13 00:18:24805}
806
initial.commit09911bf2008-07-26 23:55:29807//------------------------------------------------------------------------------
808// private methods
809//------------------------------------------------------------------------------
810
811
812//------------------------------------------------------------------------------
813// Initialization methods
814
815void MetricsService::InitializeMetricsState() {
[email protected]79bf0b72009-04-27 21:30:55816#if defined(OS_POSIX)
[email protected]fe58acc22012-02-29 01:29:58817 server_url_xml_ = ASCIIToUTF16(kServerUrlXml);
818 server_url_proto_ = ASCIIToUTF16(kServerUrlProto);
[email protected]b4a72d842012-03-22 20:09:09819 network_stats_server_ = chrome_common_net::kEchoTestServerLocation;
820 http_pipelining_test_server_ = chrome_common_net::kPipelineTestServerBaseUrl;
[email protected]79bf0b72009-04-27 21:30:55821#else
822 BrowserDistribution* dist = BrowserDistribution::GetDistribution();
[email protected]fe58acc22012-02-29 01:29:58823 server_url_xml_ = dist->GetStatsServerURL();
824 server_url_proto_ = ASCIIToUTF16(kServerUrlProto);
[email protected]d67d1052011-06-09 05:11:41825 network_stats_server_ = dist->GetNetworkStatsServer();
[email protected]adbb3762012-03-09 22:20:08826 http_pipelining_test_server_ = dist->GetHttpPipeliningTestServer();
[email protected]79bf0b72009-04-27 21:30:55827#endif
828
initial.commit09911bf2008-07-26 23:55:29829 PrefService* pref = g_browser_process->local_state();
830 DCHECK(pref);
831
[email protected]225c50842010-01-19 21:19:13832 if ((pref->GetInt64(prefs::kStabilityStatsBuildTime)
833 != MetricsLog::GetBuildTime()) ||
[email protected]ddd231e2010-06-29 20:35:19834 (pref->GetString(prefs::kStabilityStatsVersion)
[email protected]225c50842010-01-19 21:19:13835 != MetricsLog::GetVersionString())) {
[email protected]541f77922009-02-23 21:14:38836 // This is a new version, so we don't want to confuse the stats about the
837 // old version with info that we upload.
838 DiscardOldStabilityStats(pref);
839 pref->SetString(prefs::kStabilityStatsVersion,
[email protected]ddd231e2010-06-29 20:35:19840 MetricsLog::GetVersionString());
[email protected]225c50842010-01-19 21:19:13841 pref->SetInt64(prefs::kStabilityStatsBuildTime,
842 MetricsLog::GetBuildTime());
[email protected]541f77922009-02-23 21:14:38843 }
844
initial.commit09911bf2008-07-26 23:55:29845 // Update session ID
846 session_id_ = pref->GetInteger(prefs::kMetricsSessionID);
847 ++session_id_;
848 pref->SetInteger(prefs::kMetricsSessionID, session_id_);
849
initial.commit09911bf2008-07-26 23:55:29850 // Stability bookkeeping
[email protected]e73c01972008-08-13 00:18:24851 IncrementPrefValue(prefs::kStabilityLaunchCount);
initial.commit09911bf2008-07-26 23:55:29852
[email protected]e73c01972008-08-13 00:18:24853 if (!pref->GetBoolean(prefs::kStabilityExitedCleanly)) {
854 IncrementPrefValue(prefs::kStabilityCrashCount);
[email protected]c0c55e92011-09-10 18:47:30855 // Reset flag, and wait until we call LogNeedForCleanShutdown() before
856 // monitoring.
857 pref->SetBoolean(prefs::kStabilityExitedCleanly, true);
initial.commit09911bf2008-07-26 23:55:29858 }
[email protected]e73c01972008-08-13 00:18:24859
[email protected]e73c01972008-08-13 00:18:24860 if (!pref->GetBoolean(prefs::kStabilitySessionEndCompleted)) {
861 IncrementPrefValue(prefs::kStabilityIncompleteSessionEndCount);
[email protected]c9abf242009-07-18 06:00:38862 // This is marked false when we get a WM_ENDSESSION.
863 pref->SetBoolean(prefs::kStabilitySessionEndCompleted, true);
initial.commit09911bf2008-07-26 23:55:29864 }
initial.commit09911bf2008-07-26 23:55:29865
[email protected]9165f742010-03-10 22:55:01866 // Initialize uptime counters.
867 int64 startup_uptime = MetricsLog::GetIncrementalUptime(pref);
[email protected]ae393ec702010-06-27 16:23:14868 DCHECK_EQ(0, startup_uptime);
[email protected]9165f742010-03-10 22:55:01869 // For backwards compatibility, leave this intact in case Omaha is checking
870 // them. prefs::kStabilityLastTimestampSec may also be useless now.
871 // TODO(jar): Delete these if they have no uses.
[email protected]0bb1a622009-03-04 03:22:32872 pref->SetInt64(prefs::kStabilityLaunchTimeSec, Time::Now().ToTimeT());
873
874 // Bookkeeping for the uninstall metrics.
875 IncrementLongPrefsValue(prefs::kUninstallLaunchCount);
initial.commit09911bf2008-07-26 23:55:29876
877 // Save profile metrics.
878 PrefService* prefs = g_browser_process->local_state();
879 if (prefs) {
880 // Remove the current dictionary and store it for use when sending data to
881 // server. By removing the value we prune potentially dead profiles
882 // (and keys). All valid values are added back once services startup.
883 const DictionaryValue* profile_dictionary =
884 prefs->GetDictionary(prefs::kProfileMetrics);
885 if (profile_dictionary) {
886 // Do a deep copy of profile_dictionary since ClearPref will delete it.
887 profile_dictionary_.reset(static_cast<DictionaryValue*>(
888 profile_dictionary->DeepCopy()));
889 prefs->ClearPref(prefs::kProfileMetrics);
890 }
891 }
892
[email protected]92745242009-06-12 16:52:21893 // Get stats on use of command line.
894 const CommandLine* command_line(CommandLine::ForCurrentProcess());
895 size_t common_commands = 0;
896 if (command_line->HasSwitch(switches::kUserDataDir)) {
897 ++common_commands;
898 UMA_HISTOGRAM_COUNTS_100("Chrome.CommandLineDatDirCount", 1);
899 }
900
901 if (command_line->HasSwitch(switches::kApp)) {
902 ++common_commands;
903 UMA_HISTOGRAM_COUNTS_100("Chrome.CommandLineAppModeCount", 1);
904 }
905
[email protected]62b4e522011-07-13 21:46:32906 size_t switch_count = command_line->GetSwitches().size();
907 UMA_HISTOGRAM_COUNTS_100("Chrome.CommandLineFlagCount", switch_count);
[email protected]92745242009-06-12 16:52:21908 UMA_HISTOGRAM_COUNTS_100("Chrome.CommandLineUncommonFlagCount",
[email protected]62b4e522011-07-13 21:46:32909 switch_count - common_commands);
[email protected]92745242009-06-12 16:52:21910
initial.commit09911bf2008-07-26 23:55:29911 // Kick off the process of saving the state (so the uptime numbers keep
912 // getting updated) every n minutes.
913 ScheduleNextStateSave();
914}
915
[email protected]c94d7382012-02-28 08:43:40916// static
[email protected]d33e7cc2011-09-23 01:43:56917void MetricsService::InitTaskGetHardwareClass(
[email protected]c94d7382012-02-28 08:43:40918 base::WeakPtr<MetricsService> self,
[email protected]d33e7cc2011-09-23 01:43:56919 base::MessageLoopProxy* target_loop) {
[email protected]d33e7cc2011-09-23 01:43:56920 DCHECK(BrowserThread::CurrentlyOn(BrowserThread::FILE));
921
922 std::string hardware_class;
923#if defined(OS_CHROMEOS)
924 chromeos::system::StatisticsProvider::GetInstance()->GetMachineStatistic(
925 "hardware_class", &hardware_class);
926#endif // OS_CHROMEOS
927
928 target_loop->PostTask(FROM_HERE,
929 base::Bind(&MetricsService::OnInitTaskGotHardwareClass,
[email protected]c94d7382012-02-28 08:43:40930 self, hardware_class));
[email protected]d33e7cc2011-09-23 01:43:56931}
932
933void MetricsService::OnInitTaskGotHardwareClass(
934 const std::string& hardware_class) {
[email protected]ed0fd002012-04-25 23:10:34935 DCHECK_EQ(INIT_TASK_SCHEDULED, state_);
[email protected]85ed9d42010-06-08 22:37:44936 hardware_class_ = hardware_class;
[email protected]d33e7cc2011-09-23 01:43:56937
[email protected]ebd71962012-12-20 02:56:55938#if defined(ENABLE_PLUGINS)
[email protected]d33e7cc2011-09-23 01:43:56939 // Start the next part of the init task: loading plugin information.
940 PluginService::GetInstance()->GetPlugins(
941 base::Bind(&MetricsService::OnInitTaskGotPluginInfo,
[email protected]c94d7382012-02-28 08:43:40942 self_ptr_factory_.GetWeakPtr()));
[email protected]ebd71962012-12-20 02:56:55943#else
944 std::vector<webkit::WebPluginInfo> plugin_list_empty;
945 OnInitTaskGotPluginInfo(plugin_list_empty);
946#endif // defined(ENABLE_PLUGINS)
[email protected]d33e7cc2011-09-23 01:43:56947}
948
949void MetricsService::OnInitTaskGotPluginInfo(
950 const std::vector<webkit::WebPluginInfo>& plugins) {
[email protected]ed0fd002012-04-25 23:10:34951 DCHECK_EQ(INIT_TASK_SCHEDULED, state_);
[email protected]35fa6a22009-08-15 00:04:01952 plugins_ = plugins;
[email protected]d33e7cc2011-09-23 01:43:56953
[email protected]197c0772012-05-14 23:50:51954 // Schedules a task on a blocking pool thread to gather Google Update
955 // statistics (requires Registry reads).
956 BrowserThread::PostBlockingPoolTask(
957 FROM_HERE,
958 base::Bind(&MetricsService::InitTaskGetGoogleUpdateData,
959 self_ptr_factory_.GetWeakPtr(),
960 MessageLoop::current()->message_loop_proxy()));
961}
962
963// static
964void MetricsService::InitTaskGetGoogleUpdateData(
965 base::WeakPtr<MetricsService> self,
966 base::MessageLoopProxy* target_loop) {
967 GoogleUpdateMetrics google_update_metrics;
968
969#if defined(OS_WIN) && defined(GOOGLE_CHROME_BUILD)
970 const bool system_install = GoogleUpdateSettings::IsSystemInstall();
971
972 google_update_metrics.is_system_install = system_install;
973 google_update_metrics.last_started_au =
974 GoogleUpdateSettings::GetGoogleUpdateLastStartedAU(system_install);
975 google_update_metrics.last_checked =
976 GoogleUpdateSettings::GetGoogleUpdateLastChecked(system_install);
977 GoogleUpdateSettings::GetUpdateDetailForGoogleUpdate(
978 system_install,
979 &google_update_metrics.google_update_data);
980 GoogleUpdateSettings::GetUpdateDetail(
981 system_install,
982 &google_update_metrics.product_data);
983#endif // defined(OS_WIN) && defined(GOOGLE_CHROME_BUILD)
984
985 target_loop->PostTask(FROM_HERE,
986 base::Bind(&MetricsService::OnInitTaskGotGoogleUpdateData,
987 self, google_update_metrics));
988}
989
990void MetricsService::OnInitTaskGotGoogleUpdateData(
991 const GoogleUpdateMetrics& google_update_metrics) {
992 DCHECK_EQ(INIT_TASK_SCHEDULED, state_);
993
994 google_update_metrics_ = google_update_metrics;
995
[email protected]ed0fd002012-04-25 23:10:34996 // Start the next part of the init task: fetching performance data. This will
997 // call into |FinishedReceivingProfilerData()| when the task completes.
998 chrome_browser_metrics::TrackingSynchronizer::FetchProfilerDataAsynchronously(
999 self_ptr_factory_.GetWeakPtr());
1000}
1001
[email protected]dd98f392013-02-04 13:03:221002void MetricsService::OnUserAction(const std::string& action) {
1003 if (!CanLogNotification())
1004 return;
1005
1006 log_manager_.current_log()->RecordUserAction(action.c_str());
1007 HandleIdleSinceLastTransmission(false);
1008}
1009
[email protected]ed0fd002012-04-25 23:10:341010void MetricsService::ReceivedProfilerData(
1011 const tracked_objects::ProcessDataSnapshot& process_data,
[email protected]f3b357692013-03-22 05:16:131012 int process_type) {
[email protected]ed0fd002012-04-25 23:10:341013 DCHECK_EQ(INIT_TASK_SCHEDULED, state_);
1014
1015 // Upon the first callback, create the initial log so that we can immediately
1016 // save the profiler data.
1017 if (!initial_log_.get())
1018 initial_log_.reset(new MetricsLog(client_id_, session_id_));
1019
1020 initial_log_->RecordProfilerData(process_data, process_type);
1021}
1022
1023void MetricsService::FinishedReceivingProfilerData() {
1024 DCHECK_EQ(INIT_TASK_SCHEDULED, state_);
[email protected]3a7b66d2012-04-26 16:34:161025 state_ = INIT_TASK_DONE;
initial.commit09911bf2008-07-26 23:55:291026}
1027
[email protected]e61003a2012-05-24 17:03:191028int MetricsService::GetLowEntropySource() {
1029 // Note that the default value for the low entropy source and the default pref
1030 // value are both zero, which is used to identify if the value has been set
1031 // or not. Valid values start at 1.
1032 if (low_entropy_source_)
1033 return low_entropy_source_;
1034
1035 PrefService* pref = g_browser_process->local_state();
1036 const CommandLine* command_line(CommandLine::ForCurrentProcess());
1037 // Only try to load the value from prefs if the user did not request a reset.
1038 // Otherwise, skip to generating a new value.
[email protected]44237682012-10-30 13:59:371039 bool reset_variations =
1040 command_line->HasSwitch(switches::kResetVariationState);
1041 // TODO(stevet): This histogram is temporary. Remove this after default group
1042 // investigations are complete.
1043 UMA_HISTOGRAM_BOOLEAN("UMA.UsedResetVariationsFlag", reset_variations);
1044 if (!reset_variations) {
[email protected]e63a9ef2012-08-30 15:29:421045 const int value = pref->GetInteger(prefs::kMetricsLowEntropySource);
1046 if (value != kLowEntropySourceNotSet) {
1047 // Ensure the prefs value is in the range [0, kMaxLowEntropySize). Old
1048 // versions of the code would generate values in the range of [1, 8192],
1049 // so the below line ensures 8192 gets mapped to 0 and also guards against
1050 // the case of corrupted values.
1051 low_entropy_source_ = value % kMaxLowEntropySize;
[email protected]0c906e92012-10-18 15:24:131052 UMA_HISTOGRAM_BOOLEAN("UMA.GeneratedLowEntropySource", false);
[email protected]e61003a2012-05-24 17:03:191053 return low_entropy_source_;
[email protected]e63a9ef2012-08-30 15:29:421054 }
[email protected]e61003a2012-05-24 17:03:191055 }
1056
[email protected]0c906e92012-10-18 15:24:131057 UMA_HISTOGRAM_BOOLEAN("UMA.GeneratedLowEntropySource", true);
[email protected]e61003a2012-05-24 17:03:191058 low_entropy_source_ = GenerateLowEntropySource();
1059 pref->SetInteger(prefs::kMetricsLowEntropySource, low_entropy_source_);
1060
1061 return low_entropy_source_;
1062}
1063
1064// static
initial.commit09911bf2008-07-26 23:55:291065std::string MetricsService::GenerateClientID() {
[email protected]7e49ad32012-06-14 14:22:071066 return base::GenerateGUID();
initial.commit09911bf2008-07-26 23:55:291067}
1068
initial.commit09911bf2008-07-26 23:55:291069//------------------------------------------------------------------------------
1070// State save methods
1071
1072void MetricsService::ScheduleNextStateSave() {
[email protected]8454aeb2011-11-19 23:38:201073 state_saver_factory_.InvalidateWeakPtrs();
initial.commit09911bf2008-07-26 23:55:291074
1075 MessageLoop::current()->PostDelayedTask(FROM_HERE,
[email protected]8454aeb2011-11-19 23:38:201076 base::Bind(&MetricsService::SaveLocalState,
1077 state_saver_factory_.GetWeakPtr()),
[email protected]fc4252a72012-01-12 21:58:471078 base::TimeDelta::FromMinutes(kSaveStateIntervalMinutes));
initial.commit09911bf2008-07-26 23:55:291079}
1080
1081void MetricsService::SaveLocalState() {
1082 PrefService* pref = g_browser_process->local_state();
1083 if (!pref) {
[email protected]a063c102010-07-22 22:20:191084 NOTREACHED();
initial.commit09911bf2008-07-26 23:55:291085 return;
1086 }
1087
1088 RecordCurrentState(pref);
initial.commit09911bf2008-07-26 23:55:291089
[email protected]fc4252a72012-01-12 21:58:471090 // TODO(jar):110021 Does this run down the batteries????
initial.commit09911bf2008-07-26 23:55:291091 ScheduleNextStateSave();
1092}
1093
1094
1095//------------------------------------------------------------------------------
1096// Recording control methods
1097
[email protected]410938e02012-10-24 16:33:591098void MetricsService::OpenNewLog() {
1099 DCHECK(!log_manager_.current_log());
initial.commit09911bf2008-07-26 23:55:291100
[email protected]29948262012-03-01 12:15:081101 log_manager_.BeginLoggingWithLog(new MetricsLog(client_id_, session_id_),
1102 MetricsLogManager::ONGOING_LOG);
initial.commit09911bf2008-07-26 23:55:291103 if (state_ == INITIALIZED) {
1104 // We only need to schedule that run once.
[email protected]85ed9d42010-06-08 22:37:441105 state_ = INIT_TASK_SCHEDULED;
initial.commit09911bf2008-07-26 23:55:291106
[email protected]85ed9d42010-06-08 22:37:441107 // Schedules a task on the file thread for execution of slower
1108 // initialization steps (such as plugin list generation) necessary
1109 // for sending the initial log. This avoids blocking the main UI
1110 // thread.
[email protected]ed10dd12011-12-07 12:03:421111 BrowserThread::PostDelayedTask(
1112 BrowserThread::FILE,
1113 FROM_HERE,
[email protected]d33e7cc2011-09-23 01:43:561114 base::Bind(&MetricsService::InitTaskGetHardwareClass,
[email protected]c94d7382012-02-28 08:43:401115 self_ptr_factory_.GetWeakPtr(),
[email protected]d33e7cc2011-09-23 01:43:561116 MessageLoop::current()->message_loop_proxy()),
[email protected]7e560102012-03-08 20:58:421117 base::TimeDelta::FromSeconds(kInitializationDelaySeconds));
initial.commit09911bf2008-07-26 23:55:291118 }
1119}
1120
[email protected]410938e02012-10-24 16:33:591121void MetricsService::CloseCurrentLog() {
[email protected]cac267c2011-09-29 15:18:101122 if (!log_manager_.current_log())
initial.commit09911bf2008-07-26 23:55:291123 return;
1124
[email protected]68475e602008-08-22 03:21:151125 // TODO(jar): Integrate bounds on log recording more consistently, so that we
1126 // can stop recording logs that are too big much sooner.
[email protected]cac267c2011-09-29 15:18:101127 if (log_manager_.current_log()->num_events() > kEventLimit) {
[email protected]553dba62009-02-24 19:08:231128 UMA_HISTOGRAM_COUNTS("UMA.Discarded Log Events",
[email protected]cac267c2011-09-29 15:18:101129 log_manager_.current_log()->num_events());
1130 log_manager_.DiscardCurrentLog();
[email protected]410938e02012-10-24 16:33:591131 OpenNewLog(); // Start trivial log to hold our histograms.
[email protected]68475e602008-08-22 03:21:151132 }
1133
[email protected]cac267c2011-09-29 15:18:101134 // Adds to ongoing logs.
1135 log_manager_.current_log()->set_hardware_class(hardware_class_);
[email protected]accdfa62011-09-20 01:56:521136
[email protected]0b33f80b2008-12-17 21:34:361137 // Put incremental data (histogram deltas, and realtime stats deltas) at the
[email protected]147bbc0b2009-01-06 19:37:401138 // end of all log transmissions (initial log handles this separately).
[email protected]024b5cd2011-05-27 03:29:381139 // RecordIncrementalStabilityElements only exists on the derived
1140 // MetricsLog class.
[email protected]279703f2012-01-20 22:23:261141 MetricsLog* current_log =
1142 static_cast<MetricsLog*>(log_manager_.current_log());
[email protected]024b5cd2011-05-27 03:29:381143 DCHECK(current_log);
[email protected]197c0772012-05-14 23:50:511144 current_log->RecordEnvironmentProto(plugins_, google_update_metrics_);
[email protected]fe58acc22012-02-29 01:29:581145 current_log->RecordIncrementalStabilityElements(plugins_);
[email protected]024b5cd2011-05-27 03:29:381146 RecordCurrentHistograms();
initial.commit09911bf2008-07-26 23:55:291147
[email protected]29948262012-03-01 12:15:081148 log_manager_.FinishCurrentLog();
initial.commit09911bf2008-07-26 23:55:291149}
1150
[email protected]cac267c2011-09-29 15:18:101151void MetricsService::PushPendingLogsToPersistentStorage() {
initial.commit09911bf2008-07-26 23:55:291152 if (state_ < INITIAL_LOG_READY)
[email protected]28ab7f92009-01-06 21:39:041153 return; // We didn't and still don't have time to get plugin list etc.
initial.commit09911bf2008-07-26 23:55:291154
[email protected]cac267c2011-09-29 15:18:101155 if (log_manager_.has_staged_log()) {
[email protected]7d41ae6d2012-06-26 08:53:031156 // We may race here, and send second copy of the log later.
[email protected]dc61fe92012-06-12 00:13:501157 MetricsLogManager::StoreType store_type;
1158 if (current_fetch_xml_.get() || current_fetch_proto_.get())
1159 store_type = MetricsLogManager::PROVISIONAL_STORE;
1160 else
1161 store_type = MetricsLogManager::NORMAL_STORE;
[email protected]e7508d82012-05-03 15:59:531162 log_manager_.StoreStagedLogAsUnsent(store_type);
initial.commit09911bf2008-07-26 23:55:291163 }
[email protected]cac267c2011-09-29 15:18:101164 DCHECK(!log_manager_.has_staged_log());
[email protected]410938e02012-10-24 16:33:591165 CloseCurrentLog();
initial.commit09911bf2008-07-26 23:55:291166 StoreUnsentLogs();
[email protected]7d41ae6d2012-06-26 08:53:031167
1168 // If there was a staged and/or current log, then there is now at least one
1169 // log waiting to be uploaded.
1170 if (log_manager_.has_unsent_logs())
1171 state_ = SENDING_OLD_LOGS;
initial.commit09911bf2008-07-26 23:55:291172}
1173
1174//------------------------------------------------------------------------------
1175// Transmission of logs methods
1176
[email protected]7f7f1962011-04-20 15:58:161177void MetricsService::StartSchedulerIfNecessary() {
[email protected]410938e02012-10-24 16:33:591178 // Never schedule cutting or uploading of logs in test mode.
1179 if (test_mode_active_)
1180 return;
1181
1182 // Even if reporting is disabled, the scheduler is needed to trigger the
1183 // creation of the initial log, which must be done in order for any logs to be
1184 // persisted on shutdown or backgrounding.
1185 if (recording_active() && (reporting_active() || state_ < INITIAL_LOG_READY))
[email protected]7f7f1962011-04-20 15:58:161186 scheduler_->Start();
initial.commit09911bf2008-07-26 23:55:291187}
1188
[email protected]7f7f1962011-04-20 15:58:161189void MetricsService::StartScheduledUpload() {
[email protected]cd1ac712012-06-26 08:26:471190 // If we're getting no notifications, then the log won't have much in it, and
1191 // it's possible the computer is about to go to sleep, so don't upload and
1192 // stop the scheduler.
[email protected]410938e02012-10-24 16:33:591193 // If recording has been turned off, the scheduler doesn't need to run.
1194 // If reporting is off, proceed if the initial log hasn't been created, since
1195 // that has to happen in order for logs to be cut and stored when persisting.
[email protected]cd1ac712012-06-26 08:26:471196 // TODO(stuartmorgan): Call Stop() on the schedule when reporting and/or
1197 // recording are turned off instead of letting it fire and then aborting.
1198 if (idle_since_last_transmission_ ||
[email protected]410938e02012-10-24 16:33:591199 !recording_active() ||
1200 (!reporting_active() && state_ >= INITIAL_LOG_READY)) {
[email protected]7f7f1962011-04-20 15:58:161201 scheduler_->Stop();
1202 scheduler_->UploadCancelled();
1203 return;
1204 }
1205
[email protected]c15faf372012-07-11 06:01:341206 // If the callback was to upload an old log, but there no longer is one,
1207 // just report success back to the scheduler to begin the ongoing log
1208 // callbacks.
1209 // TODO(stuartmorgan): Consider removing the distinction between
1210 // SENDING_OLD_LOGS and SENDING_CURRENT_LOGS to simplify the state machine
1211 // now that the log upload flow is the same for both modes.
1212 if (state_ == SENDING_OLD_LOGS && !log_manager_.has_unsent_logs()) {
1213 state_ = SENDING_CURRENT_LOGS;
1214 scheduler_->UploadFinished(true /* healthy */, false /* no unsent logs */);
1215 return;
1216 }
[email protected]cd1ac712012-06-26 08:26:471217 // If there are unsent logs, send the next one. If not, start the asynchronous
1218 // process of finalizing the current log for upload.
1219 if (state_ == SENDING_OLD_LOGS) {
1220 DCHECK(log_manager_.has_unsent_logs());
1221 log_manager_.StageNextLogForUpload();
1222 SendStagedLog();
1223 } else {
1224 StartFinalLogInfoCollection();
1225 }
[email protected]29948262012-03-01 12:15:081226}
1227
1228void MetricsService::StartFinalLogInfoCollection() {
1229 // Begin the multi-step process of collecting memory usage histograms:
1230 // First spawn a task to collect the memory details; when that task is
1231 // finished, it will call OnMemoryDetailCollectionDone. That will in turn
1232 // call HistogramSynchronization to collect histograms from all renderers and
1233 // then call OnHistogramSynchronizationDone to continue processing.
[email protected]d119f222012-06-08 02:33:271234 DCHECK(!waiting_for_asynchronous_reporting_step_);
1235 waiting_for_asynchronous_reporting_step_ = true;
[email protected]7f7f1962011-04-20 15:58:161236
[email protected]2226c222011-11-22 00:08:401237 base::Closure callback =
1238 base::Bind(&MetricsService::OnMemoryDetailCollectionDone,
[email protected]c94d7382012-02-28 08:43:401239 self_ptr_factory_.GetWeakPtr());
[email protected]84c988a2011-04-19 17:56:331240
[email protected]2226c222011-11-22 00:08:401241 scoped_refptr<MetricsMemoryDetails> details(
1242 new MetricsMemoryDetails(callback));
[email protected]4306df72012-04-20 18:58:571243 details->StartFetch(MemoryDetails::UPDATE_USER_METRICS);
[email protected]84c988a2011-04-19 17:56:331244
1245 // Collect WebCore cache information to put into a histogram.
[email protected]f3b1a082011-11-18 00:34:301246 for (content::RenderProcessHost::iterator i(
1247 content::RenderProcessHost::AllHostsIterator());
[email protected]84c988a2011-04-19 17:56:331248 !i.IsAtEnd(); i.Advance())
[email protected]2ccf45c2011-08-19 23:35:501249 i.GetCurrentValue()->Send(new ChromeViewMsg_GetCacheResourceStats());
[email protected]84c988a2011-04-19 17:56:331250}
1251
1252void MetricsService::OnMemoryDetailCollectionDone() {
[email protected]c9a3ef82009-05-28 22:02:461253 DCHECK(IsSingleThreaded());
[email protected]7f7f1962011-04-20 15:58:161254 // This function should only be called as the callback from an ansynchronous
1255 // step.
[email protected]d119f222012-06-08 02:33:271256 DCHECK(waiting_for_asynchronous_reporting_step_);
[email protected]c9a3ef82009-05-28 22:02:461257
[email protected]c9a3ef82009-05-28 22:02:461258 // Create a callback_task for OnHistogramSynchronizationDone.
[email protected]2226c222011-11-22 00:08:401259 base::Closure callback = base::Bind(
1260 &MetricsService::OnHistogramSynchronizationDone,
[email protected]c94d7382012-02-28 08:43:401261 self_ptr_factory_.GetWeakPtr());
[email protected]c9a3ef82009-05-28 22:02:461262
[email protected]908de522011-10-20 00:55:001263 base::StatisticsRecorder::CollectHistogramStats("Browser");
1264
[email protected]c9a3ef82009-05-28 22:02:461265 // Set up the callback to task to call after we receive histograms from all
[email protected]83ab4a282012-07-12 18:19:451266 // child processes. Wait time specifies how long to wait before absolutely
[email protected]c9a3ef82009-05-28 22:02:461267 // calling us back on the task.
[email protected]83ab4a282012-07-12 18:19:451268 content::FetchHistogramsAsynchronously(
[email protected]2226c222011-11-22 00:08:401269 MessageLoop::current(), callback,
[email protected]7e560102012-03-08 20:58:421270 base::TimeDelta::FromMilliseconds(kMaxHistogramGatheringWaitDuration));
[email protected]c9a3ef82009-05-28 22:02:461271}
1272
1273void MetricsService::OnHistogramSynchronizationDone() {
initial.commit09911bf2008-07-26 23:55:291274 DCHECK(IsSingleThreaded());
[email protected]29948262012-03-01 12:15:081275 // This function should only be called as the callback from an ansynchronous
1276 // step.
[email protected]d119f222012-06-08 02:33:271277 DCHECK(waiting_for_asynchronous_reporting_step_);
initial.commit09911bf2008-07-26 23:55:291278
[email protected]d119f222012-06-08 02:33:271279 waiting_for_asynchronous_reporting_step_ = false;
[email protected]29948262012-03-01 12:15:081280 OnFinalLogInfoCollectionDone();
1281}
1282
1283void MetricsService::OnFinalLogInfoCollectionDone() {
[email protected]7f7f1962011-04-20 15:58:161284 // If somehow there is a fetch in progress, we return and hope things work
1285 // out. The scheduler isn't informed since if this happens, the scheduler
1286 // will get a response from the upload.
[email protected]fe58acc22012-02-29 01:29:581287 DCHECK(!current_fetch_xml_.get());
1288 DCHECK(!current_fetch_proto_.get());
1289 if (current_fetch_xml_.get() || current_fetch_proto_.get())
[email protected]7f7f1962011-04-20 15:58:161290 return;
1291
[email protected]cd1ac712012-06-26 08:26:471292 // Abort if metrics were turned off during the final info gathering.
[email protected]410938e02012-10-24 16:33:591293 if (!recording_active()) {
[email protected]7f7f1962011-04-20 15:58:161294 scheduler_->Stop();
1295 scheduler_->UploadCancelled();
[email protected]d01b8732008-10-16 02:18:071296 return;
1297 }
1298
[email protected]cd1ac712012-06-26 08:26:471299 StageNewLog();
[email protected]410938e02012-10-24 16:33:591300
1301 // If logs shouldn't be uploaded, stop here. It's important that this check
1302 // be after StageNewLog(), otherwise the previous logs will never be loaded,
1303 // and thus the open log won't be persisted.
1304 // TODO(stuartmorgan): This is unnecessarily complicated; restructure loading
1305 // of previous logs to not require running part of the upload logic.
1306 // http://crbug.com/157337
1307 if (!reporting_active()) {
1308 scheduler_->Stop();
1309 scheduler_->UploadCancelled();
1310 return;
1311 }
1312
[email protected]29948262012-03-01 12:15:081313 SendStagedLog();
1314}
1315
[email protected]cd1ac712012-06-26 08:26:471316void MetricsService::StageNewLog() {
[email protected]29948262012-03-01 12:15:081317 if (log_manager_.has_staged_log())
1318 return;
1319
1320 switch (state_) {
1321 case INITIALIZED:
1322 case INIT_TASK_SCHEDULED: // We should be further along by now.
[email protected]dc61fe92012-06-12 00:13:501323 NOTREACHED();
[email protected]29948262012-03-01 12:15:081324 return;
1325
1326 case INIT_TASK_DONE:
[email protected]29948262012-03-01 12:15:081327 PrepareInitialLog();
[email protected]ed0fd002012-04-25 23:10:341328 DCHECK_EQ(INIT_TASK_DONE, state_);
[email protected]29948262012-03-01 12:15:081329 log_manager_.LoadPersistedUnsentLogs();
1330 state_ = INITIAL_LOG_READY;
1331 break;
1332
1333 case SENDING_OLD_LOGS:
[email protected]cd1ac712012-06-26 08:26:471334 NOTREACHED(); // Shouldn't be staging a new log during old log sending.
1335 return;
[email protected]29948262012-03-01 12:15:081336
1337 case SENDING_CURRENT_LOGS:
[email protected]410938e02012-10-24 16:33:591338 CloseCurrentLog();
1339 OpenNewLog();
[email protected]29948262012-03-01 12:15:081340 log_manager_.StageNextLogForUpload();
1341 break;
1342
1343 default:
1344 NOTREACHED();
1345 return;
1346 }
1347
1348 DCHECK(log_manager_.has_staged_log());
1349}
1350
1351void MetricsService::PrepareInitialLog() {
[email protected]ed0fd002012-04-25 23:10:341352 DCHECK_EQ(INIT_TASK_DONE, state_);
[email protected]29948262012-03-01 12:15:081353
[email protected]ed0fd002012-04-25 23:10:341354 DCHECK(initial_log_.get());
1355 initial_log_->set_hardware_class(hardware_class_);
[email protected]197c0772012-05-14 23:50:511356 initial_log_->RecordEnvironment(plugins_, google_update_metrics_,
1357 profile_dictionary_.get());
[email protected]29948262012-03-01 12:15:081358
1359 // Histograms only get written to the current log, so make the new log current
1360 // before writing them.
1361 log_manager_.PauseCurrentLog();
[email protected]ed0fd002012-04-25 23:10:341362 log_manager_.BeginLoggingWithLog(initial_log_.release(),
1363 MetricsLogManager::INITIAL_LOG);
[email protected]29948262012-03-01 12:15:081364 RecordCurrentHistograms();
1365 log_manager_.FinishCurrentLog();
1366 log_manager_.ResumePausedLog();
1367
1368 DCHECK(!log_manager_.has_staged_log());
1369 log_manager_.StageNextLogForUpload();
1370}
1371
1372void MetricsService::StoreUnsentLogs() {
1373 if (state_ < INITIAL_LOG_READY)
1374 return; // We never Recalled the prior unsent logs.
1375
1376 log_manager_.PersistUnsentLogs();
1377}
1378
1379void MetricsService::SendStagedLog() {
1380 DCHECK(log_manager_.has_staged_log());
1381
[email protected]cac267c2011-09-29 15:18:101382 PrepareFetchWithStagedLog();
[email protected]d01b8732008-10-16 02:18:071383
[email protected]d6bebb92012-06-13 23:14:551384 bool upload_created = current_fetch_xml_.get() || current_fetch_proto_.get();
1385 UMA_HISTOGRAM_BOOLEAN("UMA.UploadCreation", upload_created);
1386 if (!upload_created) {
[email protected]d01b8732008-10-16 02:18:071387 // Compression failed, and log discarded :-/.
[email protected]dc61fe92012-06-12 00:13:501388 // Skip this upload and hope things work out next time.
[email protected]cac267c2011-09-29 15:18:101389 log_manager_.DiscardStagedLog();
[email protected]7f7f1962011-04-20 15:58:161390 scheduler_->UploadCancelled();
[email protected]d01b8732008-10-16 02:18:071391 return;
1392 }
1393
[email protected]d119f222012-06-08 02:33:271394 DCHECK(!waiting_for_asynchronous_reporting_step_);
[email protected]d119f222012-06-08 02:33:271395 waiting_for_asynchronous_reporting_step_ = true;
[email protected]dc61fe92012-06-12 00:13:501396
1397 if (current_fetch_xml_.get())
1398 current_fetch_xml_->Start();
[email protected]fe58acc22012-02-29 01:29:581399 if (current_fetch_proto_.get())
1400 current_fetch_proto_->Start();
[email protected]d01b8732008-10-16 02:18:071401
1402 HandleIdleSinceLastTransmission(true);
1403}
1404
[email protected]cac267c2011-09-29 15:18:101405void MetricsService::PrepareFetchWithStagedLog() {
[email protected]dc61fe92012-06-12 00:13:501406 DCHECK(log_manager_.has_staged_log());
[email protected]cac78842008-11-27 01:02:201407
[email protected]fe58acc22012-02-29 01:29:581408 // Prepare the XML version.
1409 DCHECK(!current_fetch_xml_.get());
[email protected]dc61fe92012-06-12 00:13:501410 if (log_manager_.has_staged_log_xml()) {
[email protected]3dc1bc42012-06-19 08:20:531411 current_fetch_xml_.reset(net::URLFetcher::Create(
[email protected]dc61fe92012-06-12 00:13:501412 GURL(server_url_xml_), net::URLFetcher::POST, this));
1413 current_fetch_xml_->SetRequestContext(
1414 g_browser_process->system_request_context());
1415 current_fetch_xml_->SetUploadData(kMimeTypeXml,
1416 log_manager_.staged_log_text().xml);
1417 // We already drop cookies server-side, but we might as well strip them out
1418 // client-side as well.
1419 current_fetch_xml_->SetLoadFlags(net::LOAD_DO_NOT_SAVE_COOKIES |
1420 net::LOAD_DO_NOT_SEND_COOKIES);
1421 }
[email protected]fe58acc22012-02-29 01:29:581422
1423 // Prepare the protobuf version.
1424 DCHECK(!current_fetch_proto_.get());
1425 if (log_manager_.has_staged_log_proto()) {
[email protected]3dc1bc42012-06-19 08:20:531426 current_fetch_proto_.reset(net::URLFetcher::Create(
[email protected]d3ec669b2012-05-23 07:12:141427 GURL(server_url_proto_), net::URLFetcher::POST, this));
[email protected]fe58acc22012-02-29 01:29:581428 current_fetch_proto_->SetRequestContext(
1429 g_browser_process->system_request_context());
[email protected]448ca4d2012-05-09 19:53:121430 current_fetch_proto_->SetUploadData(kMimeTypeProto,
[email protected]fe58acc22012-02-29 01:29:581431 log_manager_.staged_log_text().proto);
1432 // We already drop cookies server-side, but we might as well strip them out
1433 // client-side as well.
1434 current_fetch_proto_->SetLoadFlags(net::LOAD_DO_NOT_SAVE_COOKIES |
1435 net::LOAD_DO_NOT_SEND_COOKIES);
[email protected]fe58acc22012-02-29 01:29:581436 }
initial.commit09911bf2008-07-26 23:55:291437}
1438
[email protected]fe58acc22012-02-29 01:29:581439// We need to wait for two responses: the response to the XML upload, and the
[email protected]dc61fe92012-06-12 00:13:501440// response to the protobuf upload. In the case that exactly one of the uploads
1441// fails and needs to be retried, we "zap" the other pipeline's staged log to
1442// avoid incorrectly re-uploading it as well.
[email protected]10c2d692012-05-11 05:32:231443void MetricsService::OnURLFetchComplete(const net::URLFetcher* source) {
[email protected]d119f222012-06-08 02:33:271444 DCHECK(waiting_for_asynchronous_reporting_step_);
[email protected]fe58acc22012-02-29 01:29:581445
1446 // We're not allowed to re-use the existing |URLFetcher|s, so free them here.
[email protected]4266def22012-05-17 01:02:401447 // Note however that |source| is aliased to one of these, so we should be
1448 // careful not to delete it too early.
[email protected]15fb2aa2012-05-22 22:52:591449 scoped_ptr<net::URLFetcher> s;
[email protected]dc61fe92012-06-12 00:13:501450 bool is_xml;
[email protected]fe58acc22012-02-29 01:29:581451 if (source == current_fetch_xml_.get()) {
1452 s.reset(current_fetch_xml_.release());
[email protected]dc61fe92012-06-12 00:13:501453 is_xml = true;
[email protected]fe58acc22012-02-29 01:29:581454 } else if (source == current_fetch_proto_.get()) {
1455 s.reset(current_fetch_proto_.release());
[email protected]dc61fe92012-06-12 00:13:501456 is_xml = false;
[email protected]fe58acc22012-02-29 01:29:581457 } else {
1458 NOTREACHED();
1459 return;
1460 }
1461
[email protected]dc61fe92012-06-12 00:13:501462 int response_code = source->GetResponseCode();
[email protected]fe58acc22012-02-29 01:29:581463
[email protected]dc61fe92012-06-12 00:13:501464 // Log a histogram to track response success vs. failure rates.
1465 if (is_xml) {
1466 UMA_HISTOGRAM_ENUMERATION("UMA.UploadResponseStatus.XML",
1467 ResponseCodeToStatus(response_code),
1468 NUM_RESPONSE_STATUSES);
1469 } else {
1470 UMA_HISTOGRAM_ENUMERATION("UMA.UploadResponseStatus.Protobuf",
1471 ResponseCodeToStatus(response_code),
1472 NUM_RESPONSE_STATUSES);
1473 }
[email protected]fe58acc22012-02-29 01:29:581474
[email protected]e7508d82012-05-03 15:59:531475 // If the upload was provisionally stored, drop it now that the upload is
1476 // known to have gone through.
1477 log_manager_.DiscardLastProvisionalStore();
initial.commit09911bf2008-07-26 23:55:291478
[email protected]dc61fe92012-06-12 00:13:501479 bool upload_succeeded = response_code == 200;
[email protected]7f7f1962011-04-20 15:58:161480
[email protected]0eb34fee2009-01-21 08:04:381481 // Provide boolean for error recovery (allow us to ignore response_code).
[email protected]dc6f4962009-02-13 01:25:501482 bool discard_log = false;
[email protected]dc61fe92012-06-12 00:13:501483 const size_t log_size = is_xml ?
1484 log_manager_.staged_log_text().xml.length() :
1485 log_manager_.staged_log_text().proto.length();
1486 if (!upload_succeeded && log_size > kUploadLogAvoidRetransmitSize) {
1487 UMA_HISTOGRAM_COUNTS("UMA.Large Rejected Log was Discarded",
1488 static_cast<int>(log_size));
[email protected]0eb34fee2009-01-21 08:04:381489 discard_log = true;
[email protected]dc61fe92012-06-12 00:13:501490 } else if (response_code == 400) {
[email protected]0eb34fee2009-01-21 08:04:381491 // Bad syntax. Retransmission won't work.
[email protected]0eb34fee2009-01-21 08:04:381492 discard_log = true;
[email protected]68475e602008-08-22 03:21:151493 }
1494
[email protected]bf02f922012-06-13 23:25:311495 if (upload_succeeded || discard_log) {
[email protected]dc61fe92012-06-12 00:13:501496 if (is_xml)
1497 log_manager_.DiscardStagedLogXml();
1498 else
1499 log_manager_.DiscardStagedLogProto();
1500 }
1501
1502 // If we're still waiting for one of the responses, keep waiting...
1503 if (current_fetch_xml_.get() || current_fetch_proto_.get())
1504 return;
1505
1506 waiting_for_asynchronous_reporting_step_ = false;
1507
1508 if (!log_manager_.has_staged_log()) {
initial.commit09911bf2008-07-26 23:55:291509 switch (state_) {
1510 case INITIAL_LOG_READY:
[email protected]cd1ac712012-06-26 08:26:471511 state_ = log_manager_.has_unsent_logs() ? SENDING_OLD_LOGS
1512 : SENDING_CURRENT_LOGS;
initial.commit09911bf2008-07-26 23:55:291513 break;
1514
initial.commit09911bf2008-07-26 23:55:291515 case SENDING_OLD_LOGS:
[email protected]d53e2232011-06-30 15:54:571516 // Store the updated list to disk now that the removed log is uploaded.
initial.commit09911bf2008-07-26 23:55:291517 StoreUnsentLogs();
[email protected]cd1ac712012-06-26 08:26:471518 if (!log_manager_.has_unsent_logs())
1519 state_ = SENDING_CURRENT_LOGS;
initial.commit09911bf2008-07-26 23:55:291520 break;
1521
1522 case SENDING_CURRENT_LOGS:
1523 break;
1524
1525 default:
[email protected]a063c102010-07-22 22:20:191526 NOTREACHED();
initial.commit09911bf2008-07-26 23:55:291527 break;
1528 }
[email protected]d01b8732008-10-16 02:18:071529
[email protected]cac267c2011-09-29 15:18:101530 if (log_manager_.has_unsent_logs())
[email protected]ed0fd002012-04-25 23:10:341531 DCHECK_LT(state_, SENDING_CURRENT_LOGS);
initial.commit09911bf2008-07-26 23:55:291532 }
[email protected]252873ef2008-08-04 21:59:451533
[email protected]7f7f1962011-04-20 15:58:161534 // Error 400 indicates a problem with the log, not with the server, so
1535 // don't consider that a sign that the server is in trouble.
[email protected]dc61fe92012-06-12 00:13:501536 bool server_is_healthy = upload_succeeded || response_code == 400;
[email protected]7f7f1962011-04-20 15:58:161537
[email protected]dc61fe92012-06-12 00:13:501538 // Note that we are essentially randomly choosing to report either the XML or
1539 // the protobuf server's health status, but this is ok: In the case that the
1540 // two statuses are not the same, one of the uploads succeeded but the other
1541 // did not. In this case, we'll re-try only the upload that failed. This first
1542 // re-try might ignore the server's unhealthiness; but the response to the
1543 // re-tried upload will correctly propagate the server's health status for any
1544 // subsequent re-tries. Hence, we'll at most delay slowing the upload rate by
1545 // one re-try, which is fine.
1546 scheduler_->UploadFinished(server_is_healthy, log_manager_.has_unsent_logs());
[email protected]d67d1052011-06-09 05:11:411547
1548 // Collect network stats if UMA upload succeeded.
[email protected]b8ddb052012-04-19 02:36:061549 IOThread* io_thread = g_browser_process->io_thread();
1550 if (server_is_healthy && io_thread) {
1551 chrome_browser_net::CollectNetworkStats(network_stats_server_, io_thread);
[email protected]adbb3762012-03-09 22:20:081552 chrome_browser_net::CollectPipeliningCapabilityStatsOnUIThread(
[email protected]b8ddb052012-04-19 02:36:061553 http_pipelining_test_server_, io_thread);
[email protected]adbb3762012-03-09 22:20:081554 }
initial.commit09911bf2008-07-26 23:55:291555}
1556
[email protected]459f3502012-09-17 17:08:121557void MetricsService::LogWindowOrTabChange(int type, uintptr_t window_or_tab) {
[email protected]534e54b2008-08-13 15:40:091558 int controller_id = -1;
initial.commit09911bf2008-07-26 23:55:291559 MetricsLog::WindowEventType window_type;
1560
1561 // Note: since we stop all logging when a single OTR session is active, it is
1562 // possible that we start getting notifications about a window that we don't
1563 // know about.
[email protected]534e54b2008-08-13 15:40:091564 if (window_map_.find(window_or_tab) == window_map_.end()) {
1565 controller_id = next_window_id_++;
1566 window_map_[window_or_tab] = controller_id;
initial.commit09911bf2008-07-26 23:55:291567 } else {
[email protected]534e54b2008-08-13 15:40:091568 controller_id = window_map_[window_or_tab];
initial.commit09911bf2008-07-26 23:55:291569 }
[email protected]92745242009-06-12 16:52:211570 DCHECK_NE(controller_id, -1);
initial.commit09911bf2008-07-26 23:55:291571
[email protected]432115822011-07-10 15:52:271572 switch (type) {
[email protected]884033e2012-04-16 19:38:421573 case chrome::NOTIFICATION_TAB_PARENTED:
[email protected]432115822011-07-10 15:52:271574 case chrome::NOTIFICATION_BROWSER_OPENED:
initial.commit09911bf2008-07-26 23:55:291575 window_type = MetricsLog::WINDOW_CREATE;
1576 break;
1577
[email protected]884033e2012-04-16 19:38:421578 case chrome::NOTIFICATION_TAB_CLOSING:
[email protected]432115822011-07-10 15:52:271579 case chrome::NOTIFICATION_BROWSER_CLOSED:
[email protected]534e54b2008-08-13 15:40:091580 window_map_.erase(window_map_.find(window_or_tab));
initial.commit09911bf2008-07-26 23:55:291581 window_type = MetricsLog::WINDOW_DESTROY;
1582 break;
1583
1584 default:
[email protected]a063c102010-07-22 22:20:191585 NOTREACHED();
[email protected]68d74f02009-02-13 01:36:501586 return;
initial.commit09911bf2008-07-26 23:55:291587 }
1588
[email protected]534e54b2008-08-13 15:40:091589 // TODO(brettw) we should have some kind of ID for the parent.
[email protected]cac267c2011-09-29 15:18:101590 log_manager_.current_log()->RecordWindowEvent(window_type, controller_id, 0);
initial.commit09911bf2008-07-26 23:55:291591}
1592
[email protected]6c2381d2011-10-19 02:52:531593void MetricsService::LogLoadComplete(
1594 int type,
1595 const content::NotificationSource& source,
1596 const content::NotificationDetails& details) {
[email protected]ad50def52011-10-19 23:17:071597 if (details == content::NotificationService::NoDetails())
initial.commit09911bf2008-07-26 23:55:291598 return;
1599
[email protected]68475e602008-08-22 03:21:151600 // TODO(jar): There is a bug causing this to be called too many times, and
1601 // the log overflows. For now, we won't record these events.
[email protected]553dba62009-02-24 19:08:231602 UMA_HISTOGRAM_COUNTS("UMA.LogLoadComplete called", 1);
[email protected]68475e602008-08-22 03:21:151603 return;
1604
[email protected]6c2381d2011-10-19 02:52:531605 const content::Details<LoadNotificationDetails> load_details(details);
[email protected]534e54b2008-08-13 15:40:091606 int controller_id = window_map_[details.map_key()];
[email protected]cac267c2011-09-29 15:18:101607 log_manager_.current_log()->RecordLoadEvent(controller_id,
[email protected]09d31d52012-03-11 22:30:271608 load_details->url,
1609 load_details->origin,
1610 load_details->session_index,
1611 load_details->load_time);
initial.commit09911bf2008-07-26 23:55:291612}
1613
[email protected]57ecc4b2010-08-11 03:02:511614void MetricsService::IncrementPrefValue(const char* path) {
[email protected]e73c01972008-08-13 00:18:241615 PrefService* pref = g_browser_process->local_state();
1616 DCHECK(pref);
1617 int value = pref->GetInteger(path);
1618 pref->SetInteger(path, value + 1);
1619}
1620
[email protected]57ecc4b2010-08-11 03:02:511621void MetricsService::IncrementLongPrefsValue(const char* path) {
[email protected]0bb1a622009-03-04 03:22:321622 PrefService* pref = g_browser_process->local_state();
1623 DCHECK(pref);
1624 int64 value = pref->GetInt64(path);
[email protected]b42c5e42010-06-03 20:43:251625 pref->SetInt64(path, value + 1);
[email protected]0bb1a622009-03-04 03:22:321626}
1627
initial.commit09911bf2008-07-26 23:55:291628void MetricsService::LogLoadStarted() {
[email protected]5d490e42012-08-30 05:16:431629 content::RecordAction(content::UserMetricsAction("PageLoad"));
[email protected]dd8d12a2011-09-02 02:10:151630 HISTOGRAM_ENUMERATION("Chrome.UmaPageloadCounter", 1, 2);
[email protected]e73c01972008-08-13 00:18:241631 IncrementPrefValue(prefs::kStabilityPageLoadCount);
[email protected]0bb1a622009-03-04 03:22:321632 IncrementLongPrefsValue(prefs::kUninstallMetricsPageLoadCount);
[email protected]0b33f80b2008-12-17 21:34:361633 // We need to save the prefs, as page load count is a critical stat, and it
1634 // might be lost due to a crash :-(.
initial.commit09911bf2008-07-26 23:55:291635}
1636
[email protected]c3721482012-03-23 16:21:481637void MetricsService::LogRendererCrash(content::RenderProcessHost* host,
1638 base::TerminationStatus status,
[email protected]f1675202012-07-09 15:18:001639 int exit_code) {
[email protected]f3b1a082011-11-18 00:34:301640 Profile* profile = Profile::FromBrowserContext(host->GetBrowserContext());
[email protected]6f371442011-11-09 06:45:461641 ExtensionService* service = profile->GetExtensionService();
1642 bool was_extension_process =
[email protected]f3b1a082011-11-18 00:34:301643 service && service->process_map()->Contains(host->GetID());
[email protected]c3721482012-03-23 16:21:481644 if (status == base::TERMINATION_STATUS_PROCESS_CRASHED ||
1645 status == base::TERMINATION_STATUS_ABNORMAL_TERMINATION) {
[email protected]d7c1fa62012-06-15 23:35:301646 if (was_extension_process) {
[email protected]718eab62011-10-05 21:16:521647 IncrementPrefValue(prefs::kStabilityExtensionRendererCrashCount);
[email protected]d7c1fa62012-06-15 23:35:301648
[email protected]1026afd2013-03-20 14:28:541649 UMA_HISTOGRAM_SPARSE_SLOWLY("CrashExitCodes.Extension",
1650 MapCrashExitCodeForHistogram(exit_code));
[email protected]d7c1fa62012-06-15 23:35:301651 } else {
[email protected]718eab62011-10-05 21:16:521652 IncrementPrefValue(prefs::kStabilityRendererCrashCount);
initial.commit09911bf2008-07-26 23:55:291653
[email protected]1026afd2013-03-20 14:28:541654 UMA_HISTOGRAM_SPARSE_SLOWLY("CrashExitCodes.Renderer",
1655 MapCrashExitCodeForHistogram(exit_code));
[email protected]d7c1fa62012-06-15 23:35:301656 }
1657
[email protected]718eab62011-10-05 21:16:521658 UMA_HISTOGRAM_PERCENTAGE("BrowserRenderProcessHost.ChildCrashes",
1659 was_extension_process ? 2 : 1);
[email protected]c3721482012-03-23 16:21:481660 } else if (status == base::TERMINATION_STATUS_PROCESS_WAS_KILLED) {
[email protected]718eab62011-10-05 21:16:521661 UMA_HISTOGRAM_PERCENTAGE("BrowserRenderProcessHost.ChildKills",
1662 was_extension_process ? 2 : 1);
[email protected]f1675202012-07-09 15:18:001663 } else if (status == base::TERMINATION_STATUS_STILL_RUNNING) {
1664 UMA_HISTOGRAM_PERCENTAGE("BrowserRenderProcessHost.DisconnectedAlive",
[email protected]718eab62011-10-05 21:16:521665 was_extension_process ? 2 : 1);
1666 }
1667 }
[email protected]1f085622009-12-04 05:33:451668
initial.commit09911bf2008-07-26 23:55:291669void MetricsService::LogRendererHang() {
[email protected]e73c01972008-08-13 00:18:241670 IncrementPrefValue(prefs::kStabilityRendererHangCount);
initial.commit09911bf2008-07-26 23:55:291671}
1672
[email protected]c0c55e92011-09-10 18:47:301673bool MetricsService::UmaMetricsProperlyShutdown() {
1674 CHECK(clean_shutdown_status_ == CLEANLY_SHUTDOWN ||
1675 clean_shutdown_status_ == NEED_TO_SHUTDOWN);
1676 return clean_shutdown_status_ == CLEANLY_SHUTDOWN;
1677}
1678
[email protected]466f3c12011-03-23 21:20:381679void MetricsService::LogCleanShutdown() {
[email protected]acd55b32011-09-05 17:35:311680 // Redundant hack to write pref ASAP.
[email protected]84c384e2013-03-01 23:20:191681 MarkAppCleanShutdownAndCommit();
1682
[email protected]c0c55e92011-09-10 18:47:301683 // Redundant setting to assure that we always reset this value at shutdown
1684 // (and that we don't use some alternate path, and not call LogCleanShutdown).
1685 clean_shutdown_status_ = CLEANLY_SHUTDOWN;
[email protected]acd55b32011-09-05 17:35:311686
[email protected]466f3c12011-03-23 21:20:381687 RecordBooleanPrefValue(prefs::kStabilityExitedCleanly, true);
1688}
1689
[email protected]c1834a92011-01-21 18:21:031690#if defined(OS_CHROMEOS)
1691void MetricsService::LogChromeOSCrash(const std::string &crash_type) {
1692 if (crash_type == "user")
1693 IncrementPrefValue(prefs::kStabilityOtherUserCrashCount);
1694 else if (crash_type == "kernel")
1695 IncrementPrefValue(prefs::kStabilityKernelCrashCount);
1696 else if (crash_type == "uncleanshutdown")
1697 IncrementPrefValue(prefs::kStabilitySystemUncleanShutdownCount);
1698 else
1699 NOTREACHED() << "Unexpected Chrome OS crash type " << crash_type;
1700 // Wake up metrics logs sending if necessary now that new
1701 // log data is available.
1702 HandleIdleSinceLastTransmission(false);
1703}
1704#endif // OS_CHROMEOS
1705
[email protected]650b2d52013-02-10 03:41:451706void MetricsService::LogPluginLoadingError(const base::FilePath& plugin_path) {
[email protected]cd937072012-07-02 09:00:291707 webkit::WebPluginInfo plugin;
1708 bool success =
1709 content::PluginService::GetInstance()->GetPluginInfoByPath(plugin_path,
1710 &plugin);
1711 DCHECK(success);
1712 ChildProcessStats& stats = child_process_stats_buffer_[plugin.name];
1713 // Initialize the type if this entry is new.
1714 if (stats.process_type == content::PROCESS_TYPE_UNKNOWN) {
1715 // The plug-in process might not actually of type PLUGIN (which means
1716 // NPAPI), but we only care that it is *a* plug-in process.
1717 stats.process_type = content::PROCESS_TYPE_PLUGIN;
1718 } else {
1719 DCHECK(IsPluginProcess(stats.process_type));
1720 }
1721 stats.loading_errors++;
1722}
1723
[email protected]f4eaf7b92013-02-28 22:00:401724MetricsService::ChildProcessStats& MetricsService::GetChildProcessStats(
1725 const content::ChildProcessData& data) {
1726 const string16& child_name = data.name;
[email protected]f3b357692013-03-22 05:16:131727 if (!ContainsKey(child_process_stats_buffer_, child_name)) {
1728 child_process_stats_buffer_[child_name] =
1729 ChildProcessStats(data.process_type);
1730 }
[email protected]f4eaf7b92013-02-28 22:00:401731 return child_process_stats_buffer_[child_name];
initial.commit09911bf2008-07-26 23:55:291732}
1733
[email protected]604d8a062012-03-16 21:37:461734void MetricsService::LogKeywordCount(size_t keyword_count) {
initial.commit09911bf2008-07-26 23:55:291735 PrefService* pref = g_browser_process->local_state();
1736 DCHECK(pref);
[email protected]604d8a062012-03-16 21:37:461737 pref->SetInteger(prefs::kNumKeywords, static_cast<int>(keyword_count));
initial.commit09911bf2008-07-26 23:55:291738 ScheduleNextStateSave();
1739}
1740
1741void MetricsService::RecordPluginChanges(PrefService* pref) {
[email protected]f8628c22011-04-05 12:10:181742 ListPrefUpdate update(pref, prefs::kStabilityPluginStats);
1743 ListValue* plugins = update.Get();
initial.commit09911bf2008-07-26 23:55:291744 DCHECK(plugins);
1745
1746 for (ListValue::iterator value_iter = plugins->begin();
1747 value_iter != plugins->end(); ++value_iter) {
1748 if (!(*value_iter)->IsType(Value::TYPE_DICTIONARY)) {
[email protected]a063c102010-07-22 22:20:191749 NOTREACHED();
initial.commit09911bf2008-07-26 23:55:291750 continue;
1751 }
1752
1753 DictionaryValue* plugin_dict = static_cast<DictionaryValue*>(*value_iter);
[email protected]57ecc4b2010-08-11 03:02:511754 std::string plugin_name;
[email protected]8e50b602009-03-03 22:59:431755 plugin_dict->GetString(prefs::kStabilityPluginName, &plugin_name);
[email protected]6470ee8f2009-03-03 20:46:401756 if (plugin_name.empty()) {
[email protected]a063c102010-07-22 22:20:191757 NOTREACHED();
initial.commit09911bf2008-07-26 23:55:291758 continue;
1759 }
1760
[email protected]57ecc4b2010-08-11 03:02:511761 // TODO(viettrungluu): remove conversions
[email protected]68b9e72b2011-08-05 23:08:221762 string16 name16 = UTF8ToUTF16(plugin_name);
1763 if (child_process_stats_buffer_.find(name16) ==
1764 child_process_stats_buffer_.end()) {
initial.commit09911bf2008-07-26 23:55:291765 continue;
[email protected]68b9e72b2011-08-05 23:08:221766 }
initial.commit09911bf2008-07-26 23:55:291767
[email protected]68b9e72b2011-08-05 23:08:221768 ChildProcessStats stats = child_process_stats_buffer_[name16];
initial.commit09911bf2008-07-26 23:55:291769 if (stats.process_launches) {
1770 int launches = 0;
[email protected]8e50b602009-03-03 22:59:431771 plugin_dict->GetInteger(prefs::kStabilityPluginLaunches, &launches);
initial.commit09911bf2008-07-26 23:55:291772 launches += stats.process_launches;
[email protected]8e50b602009-03-03 22:59:431773 plugin_dict->SetInteger(prefs::kStabilityPluginLaunches, launches);
initial.commit09911bf2008-07-26 23:55:291774 }
1775 if (stats.process_crashes) {
1776 int crashes = 0;
[email protected]8e50b602009-03-03 22:59:431777 plugin_dict->GetInteger(prefs::kStabilityPluginCrashes, &crashes);
initial.commit09911bf2008-07-26 23:55:291778 crashes += stats.process_crashes;
[email protected]8e50b602009-03-03 22:59:431779 plugin_dict->SetInteger(prefs::kStabilityPluginCrashes, crashes);
initial.commit09911bf2008-07-26 23:55:291780 }
1781 if (stats.instances) {
1782 int instances = 0;
[email protected]8e50b602009-03-03 22:59:431783 plugin_dict->GetInteger(prefs::kStabilityPluginInstances, &instances);
initial.commit09911bf2008-07-26 23:55:291784 instances += stats.instances;
[email protected]8e50b602009-03-03 22:59:431785 plugin_dict->SetInteger(prefs::kStabilityPluginInstances, instances);
initial.commit09911bf2008-07-26 23:55:291786 }
[email protected]cd937072012-07-02 09:00:291787 if (stats.loading_errors) {
1788 int loading_errors = 0;
1789 plugin_dict->GetInteger(prefs::kStabilityPluginLoadingErrors,
1790 &loading_errors);
1791 loading_errors += stats.loading_errors;
1792 plugin_dict->SetInteger(prefs::kStabilityPluginLoadingErrors,
1793 loading_errors);
1794 }
initial.commit09911bf2008-07-26 23:55:291795
[email protected]68b9e72b2011-08-05 23:08:221796 child_process_stats_buffer_.erase(name16);
initial.commit09911bf2008-07-26 23:55:291797 }
1798
1799 // Now go through and add dictionaries for plugins that didn't already have
1800 // reports in Local State.
[email protected]68b9e72b2011-08-05 23:08:221801 for (std::map<string16, ChildProcessStats>::iterator cache_iter =
[email protected]a27a9382009-02-11 23:55:101802 child_process_stats_buffer_.begin();
1803 cache_iter != child_process_stats_buffer_.end(); ++cache_iter) {
[email protected]a27a9382009-02-11 23:55:101804 ChildProcessStats stats = cache_iter->second;
[email protected]0d84c5d2009-10-09 01:10:421805
1806 // Insert only plugins information into the plugins list.
[email protected]8d5f1dae2011-11-11 14:30:411807 if (!IsPluginProcess(stats.process_type))
[email protected]0d84c5d2009-10-09 01:10:421808 continue;
1809
[email protected]57ecc4b2010-08-11 03:02:511810 // TODO(viettrungluu): remove conversion
[email protected]68b9e72b2011-08-05 23:08:221811 std::string plugin_name = UTF16ToUTF8(cache_iter->first);
[email protected]0d84c5d2009-10-09 01:10:421812
initial.commit09911bf2008-07-26 23:55:291813 DictionaryValue* plugin_dict = new DictionaryValue;
1814
[email protected]8e50b602009-03-03 22:59:431815 plugin_dict->SetString(prefs::kStabilityPluginName, plugin_name);
1816 plugin_dict->SetInteger(prefs::kStabilityPluginLaunches,
initial.commit09911bf2008-07-26 23:55:291817 stats.process_launches);
[email protected]8e50b602009-03-03 22:59:431818 plugin_dict->SetInteger(prefs::kStabilityPluginCrashes,
initial.commit09911bf2008-07-26 23:55:291819 stats.process_crashes);
[email protected]8e50b602009-03-03 22:59:431820 plugin_dict->SetInteger(prefs::kStabilityPluginInstances,
initial.commit09911bf2008-07-26 23:55:291821 stats.instances);
[email protected]cd937072012-07-02 09:00:291822 plugin_dict->SetInteger(prefs::kStabilityPluginLoadingErrors,
1823 stats.loading_errors);
initial.commit09911bf2008-07-26 23:55:291824 plugins->Append(plugin_dict);
1825 }
[email protected]a27a9382009-02-11 23:55:101826 child_process_stats_buffer_.clear();
initial.commit09911bf2008-07-26 23:55:291827}
1828
[email protected]dd98f392013-02-04 13:03:221829bool MetricsService::CanLogNotification() {
[email protected]2c910b72011-03-08 21:16:321830 // We simply don't log anything to UMA if there is a single incognito
initial.commit09911bf2008-07-26 23:55:291831 // session visible. The problem is that we always notify using the orginal
1832 // profile in order to simplify notification processing.
[email protected]e764e582012-08-01 03:01:291833 return !chrome::IsOffTheRecordSessionActive();
initial.commit09911bf2008-07-26 23:55:291834}
1835
[email protected]57ecc4b2010-08-11 03:02:511836void MetricsService::RecordBooleanPrefValue(const char* path, bool value) {
initial.commit09911bf2008-07-26 23:55:291837 DCHECK(IsSingleThreaded());
1838
1839 PrefService* pref = g_browser_process->local_state();
1840 DCHECK(pref);
1841
1842 pref->SetBoolean(path, value);
1843 RecordCurrentState(pref);
1844}
1845
1846void MetricsService::RecordCurrentState(PrefService* pref) {
[email protected]0bb1a622009-03-04 03:22:321847 pref->SetInt64(prefs::kStabilityLastTimestampSec, Time::Now().ToTimeT());
initial.commit09911bf2008-07-26 23:55:291848
1849 RecordPluginChanges(pref);
1850}
1851
[email protected]8d5f1dae2011-11-11 14:30:411852// static
[email protected]f3b357692013-03-22 05:16:131853bool MetricsService::IsPluginProcess(int process_type) {
1854 return (process_type == content::PROCESS_TYPE_PLUGIN ||
1855 process_type == content::PROCESS_TYPE_PPAPI_PLUGIN ||
1856 process_type == content::PROCESS_TYPE_PPAPI_BROKER);
[email protected]8d5f1dae2011-11-11 14:30:411857}
1858
[email protected]5ccaa412009-11-13 22:00:161859#if defined(OS_CHROMEOS)
[email protected]29cf16772010-04-21 15:13:471860void MetricsService::StartExternalMetrics() {
[email protected]5ccaa412009-11-13 22:00:161861 external_metrics_ = new chromeos::ExternalMetrics;
[email protected]29cf16772010-04-21 15:13:471862 external_metrics_->Start();
[email protected]5ccaa412009-11-13 22:00:161863}
1864#endif
[email protected]3819f2ee2011-08-21 09:44:381865
1866// static
1867bool MetricsServiceHelper::IsMetricsReportingEnabled() {
1868 bool result = false;
1869 const PrefService* local_state = g_browser_process->local_state();
1870 if (local_state) {
1871 const PrefService::Preference* uma_pref =
1872 local_state->FindPreference(prefs::kMetricsReportingEnabled);
1873 if (uma_pref) {
1874 bool success = uma_pref->GetValue()->GetAsBoolean(&result);
1875 DCHECK(success);
1876 }
1877 }
1878 return result;
1879}