blob: 56bf7e57feddf4c3aeb60e2517184deddc6a8408 [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
126// log that is currently accumulating is also finalized and persisted. We then
127// 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]cac267c2011-09-29 15:18:10132// Also note that whenever we successfully send an old log, we mirror the list
133// of logs into the PrefService. This ensures that IF we crash, we won't start
134// up and retransmit our old logs again.
initial.commit09911bf2008-07-26 23:55:29135//
136// Due to race conditions, it is always possible that a log file could be sent
137// twice. For example, if a log file is sent, but not yet acknowledged by
138// the external server, and the user shuts down, then a copy of the log may be
139// saved for re-transmission. These duplicates could be filtered out server
[email protected]281d2882009-01-20 20:32:42140// side, but are not expected to be a significant problem.
initial.commit09911bf2008-07-26 23:55:29141//
142//
143//------------------------------------------------------------------------------
144
[email protected]40bcc302009-03-02 20:50:39145#include "chrome/browser/metrics/metrics_service.h"
146
[email protected]7f7f1962011-04-20 15:58:16147#include "base/bind.h"
148#include "base/callback.h"
[email protected]5d91c9e2010-07-28 17:25:28149#include "base/command_line.h"
[email protected]46f89e142010-07-19 08:00:42150#include "base/md5.h"
[email protected]835d7c82010-10-14 04:38:38151#include "base/metrics/histogram.h"
[email protected]e61003a2012-05-24 17:03:19152#include "base/rand_util.h"
[email protected]528c56d2010-07-30 19:28:44153#include "base/string_number_conversions.h"
[email protected]ce072a72010-12-31 20:02:16154#include "base/threading/platform_thread.h"
[email protected]b3841c502011-03-09 01:21:31155#include "base/threading/thread.h"
[email protected]3a7b66d2012-04-26 16:34:16156#include "base/threading/thread_restrictions.h"
[email protected]ed0fd002012-04-25 23:10:34157#include "base/tracked_objects.h"
[email protected]440b37b22010-08-30 05:31:40158#include "base/utf_string_conversions.h"
[email protected]679082052010-07-21 21:30:13159#include "base/values.h"
[email protected]d8e41ed2008-09-11 15:22:32160#include "chrome/browser/bookmarks/bookmark_model.h"
initial.commit09911bf2008-07-26 23:55:29161#include "chrome/browser/browser_process.h"
[email protected]6f371442011-11-09 06:45:46162#include "chrome/browser/extensions/extension_service.h"
163#include "chrome/browser/extensions/process_map.h"
[email protected]b8ddb052012-04-19 02:36:06164#include "chrome/browser/io_thread.h"
[email protected]84c988a2011-04-19 17:56:33165#include "chrome/browser/memory_details.h"
[email protected]7c927b62010-02-24 09:54:13166#include "chrome/browser/metrics/histogram_synchronizer.h"
[email protected]679082052010-07-21 21:30:13167#include "chrome/browser/metrics/metrics_log.h"
[email protected]cac267c2011-09-29 15:18:10168#include "chrome/browser/metrics/metrics_log_serializer.h"
[email protected]7f7f1962011-04-20 15:58:16169#include "chrome/browser/metrics/metrics_reporting_scheduler.h"
[email protected]ed0fd002012-04-25 23:10:34170#include "chrome/browser/metrics/tracking_synchronizer.h"
[email protected]adbb3762012-03-09 22:20:08171#include "chrome/browser/net/http_pipelining_compatibility_client.h"
[email protected]d67d1052011-06-09 05:11:41172#include "chrome/browser/net/network_stats.h"
[email protected]37858e52010-08-26 00:22:02173#include "chrome/browser/prefs/pref_service.h"
[email protected]f8628c22011-04-05 12:10:18174#include "chrome/browser/prefs/scoped_user_pref_update.h"
[email protected]8ecad5e2010-12-02 21:18:33175#include "chrome/browser/profiles/profile.h"
[email protected]8e5c89a2011-06-07 18:13:33176#include "chrome/browser/search_engines/template_url_service.h"
[email protected]71b73f02011-04-06 15:57:29177#include "chrome/browser/ui/browser_list.h"
[email protected]157d5472009-11-05 22:31:03178#include "chrome/common/child_process_logging.h"
[email protected]432115822011-07-10 15:52:27179#include "chrome/common/chrome_notification_types.h"
[email protected]92745242009-06-12 16:52:21180#include "chrome/common/chrome_switches.h"
[email protected]3eb0d8f72010-12-15 23:38:25181#include "chrome/common/guid.h"
[email protected]2e4cd1a2012-01-12 08:51:03182#include "chrome/common/metrics/metrics_log_manager.h"
[email protected]b4a72d842012-03-22 20:09:09183#include "chrome/common/net/test_server_locations.h"
initial.commit09911bf2008-07-26 23:55:29184#include "chrome/common/pref_names.h"
[email protected]e09ba552009-02-05 03:26:29185#include "chrome/common/render_messages.h"
[email protected]4967f792012-01-20 22:14:40186#include "content/public/browser/child_process_data.h"
[email protected]09d31d52012-03-11 22:30:27187#include "content/public/browser/load_notification_details.h"
[email protected]ad50def52011-10-19 23:17:07188#include "content/public/browser/notification_service.h"
[email protected]3a5180ae2011-12-21 02:39:38189#include "content/public/browser/plugin_service.h"
[email protected]f3b1a082011-11-18 00:34:30190#include "content/public/browser/render_process_host.h"
[email protected]36aea2702011-10-26 01:12:22191#include "content/public/common/url_fetcher.h"
[email protected]fe58acc22012-02-29 01:29:58192#include "net/base/load_flags.h"
[email protected]91d9f3d2011-08-14 05:24:44193#include "webkit/plugins/webplugininfo.h"
initial.commit09911bf2008-07-26 23:55:29194
[email protected]e06131d2010-02-10 18:40:33195// TODO(port): port browser_distribution.h.
196#if !defined(OS_POSIX)
[email protected]79bf0b72009-04-27 21:30:55197#include "chrome/installer/util/browser_distribution.h"
[email protected]dc6f4962009-02-13 01:25:50198#endif
199
[email protected]5ccaa412009-11-13 22:00:16200#if defined(OS_CHROMEOS)
[email protected]db342d52010-08-09 21:19:37201#include "chrome/browser/chromeos/cros/cros_library.h"
[email protected]5ccaa412009-11-13 22:00:16202#include "chrome/browser/chromeos/external_metrics.h"
[email protected]d43970a72011-07-10 06:24:52203#include "chrome/browser/chromeos/system/statistics_provider.h"
[email protected]5ccaa412009-11-13 22:00:16204#endif
205
[email protected]e1acf6f2008-10-27 20:43:33206using base::Time;
[email protected]631bb742011-11-02 11:29:39207using content::BrowserThread;
[email protected]4967f792012-01-20 22:14:40208using content::ChildProcessData;
[email protected]09d31d52012-03-11 22:30:27209using content::LoadNotificationDetails;
[email protected]3a5180ae2011-12-21 02:39:38210using content::PluginService;
[email protected]e1acf6f2008-10-27 20:43:33211
[email protected]fe58acc22012-02-29 01:29:58212namespace {
[email protected]b2a4812d2012-02-28 05:31:31213
[email protected]fe58acc22012-02-29 01:29:58214// Check to see that we're being called on only one thread.
215bool IsSingleThreaded() {
216 static base::PlatformThreadId thread_id = 0;
217 if (!thread_id)
218 thread_id = base::PlatformThread::CurrentId();
219 return base::PlatformThread::CurrentId() == thread_id;
220}
221
[email protected]7f7f1962011-04-20 15:58:16222// The delay, in seconds, after starting recording before doing expensive
223// initialization work.
[email protected]fe58acc22012-02-29 01:29:58224const int kInitializationDelaySeconds = 30;
[email protected]252873ef2008-08-04 21:59:45225
[email protected]c9a3ef82009-05-28 22:02:46226// This specifies the amount of time to wait for all renderers to send their
227// data.
[email protected]fe58acc22012-02-29 01:29:58228const int kMaxHistogramGatheringWaitDuration = 60000; // 60 seconds.
[email protected]c9a3ef82009-05-28 22:02:46229
[email protected]54702c92011-04-15 15:06:43230// The maximum number of events in a log uploaded to the UMA server.
[email protected]fe58acc22012-02-29 01:29:58231const int kEventLimit = 2400;
[email protected]68475e602008-08-22 03:21:15232
233// If an upload fails, and the transmission was over this byte count, then we
234// will discard the log, and not try to retransmit it. We also don't persist
235// the log to the prefs for transmission during the next chrome session if this
236// limit is exceeded.
[email protected]fe58acc22012-02-29 01:29:58237const size_t kUploadLogAvoidRetransmitSize = 50000;
initial.commit09911bf2008-07-26 23:55:29238
[email protected]fc4252a72012-01-12 21:58:47239// Interval, in minutes, between state saves.
[email protected]fe58acc22012-02-29 01:29:58240const int kSaveStateIntervalMinutes = 5;
241
[email protected]6b44e9b52012-03-27 07:46:19242// Used to indicate that the response code is currently not set at all --
243// RESPONSE_CODE_INVALID can sometimes be returned in response to a request if,
244// e.g., the server is down.
[email protected]d3ec669b2012-05-23 07:12:14245const int kNoResponseCode = net::URLFetcher::RESPONSE_CODE_INVALID - 1;
[email protected]6b44e9b52012-03-27 07:46:19246
[email protected]4266def22012-05-17 01:02:40247enum ResponseStatus {
248 UNKNOWN_FAILURE,
249 SUCCESS,
250 BAD_REQUEST, // Invalid syntax or log too large.
[email protected]9f5c1ce82012-05-23 23:11:28251 NO_RESPONSE,
[email protected]4266def22012-05-17 01:02:40252 NUM_RESPONSE_STATUSES
253};
254
255ResponseStatus ResponseCodeToStatus(int response_code) {
256 switch (response_code) {
257 case 200:
258 return SUCCESS;
259 case 400:
260 return BAD_REQUEST;
[email protected]9f5c1ce82012-05-23 23:11:28261 case net::URLFetcher::RESPONSE_CODE_INVALID:
262 return NO_RESPONSE;
[email protected]4266def22012-05-17 01:02:40263 default:
264 return UNKNOWN_FAILURE;
265 }
266}
267
[email protected]e61003a2012-05-24 17:03:19268// The argument used to generate a non-identifying entropy source. We want no
269// more than 13 bits of entropy, so use this max to return a number between 1
270// and 2^13 = 8192 as the entropy source.
271const uint32 kMaxEntropySize = (1 << 13);
272
273// Generates a new non-identifying entropy source used to seed persistent
274// activities.
275int GenerateLowEntropySource() {
276 return base::RandInt(1, kMaxEntropySize);
277}
278
[email protected]fe58acc22012-02-29 01:29:58279}
initial.commit09911bf2008-07-26 23:55:29280
[email protected]c0c55e92011-09-10 18:47:30281// static
282MetricsService::ShutdownCleanliness MetricsService::clean_shutdown_status_ =
283 MetricsService::CLEANLY_SHUTDOWN;
284
[email protected]679082052010-07-21 21:30:13285// This is used to quickly log stats from child process related notifications in
286// MetricsService::child_stats_buffer_. The buffer's contents are transferred
287// out when Local State is periodically saved. The information is then
288// reported to the UMA server on next launch.
289struct MetricsService::ChildProcessStats {
290 public:
[email protected]bd5d6cf2011-12-01 00:39:12291 explicit ChildProcessStats(content::ProcessType type)
[email protected]679082052010-07-21 21:30:13292 : process_launches(0),
293 process_crashes(0),
294 instances(0),
295 process_type(type) {}
296
297 // This constructor is only used by the map to return some default value for
298 // an index for which no value has been assigned.
299 ChildProcessStats()
300 : process_launches(0),
[email protected]d88bf0a2011-08-30 23:55:57301 process_crashes(0),
302 instances(0),
[email protected]bd5d6cf2011-12-01 00:39:12303 process_type(content::PROCESS_TYPE_UNKNOWN) {}
[email protected]679082052010-07-21 21:30:13304
305 // The number of times that the given child process has been launched
306 int process_launches;
307
308 // The number of times that the given child process has crashed
309 int process_crashes;
310
311 // The number of instances of this child process that have been created.
312 // An instance is a DOM object rendered by this child process during a page
313 // load.
314 int instances;
315
[email protected]bd5d6cf2011-12-01 00:39:12316 content::ProcessType process_type;
[email protected]679082052010-07-21 21:30:13317};
initial.commit09911bf2008-07-26 23:55:29318
[email protected]84c988a2011-04-19 17:56:33319// Handles asynchronous fetching of memory details.
320// Will run the provided task after finished.
321class MetricsMemoryDetails : public MemoryDetails {
322 public:
[email protected]2226c222011-11-22 00:08:40323 explicit MetricsMemoryDetails(const base::Closure& callback)
324 : callback_(callback) {}
[email protected]84c988a2011-04-19 17:56:33325
326 virtual void OnDetailsAvailable() {
[email protected]2226c222011-11-22 00:08:40327 MessageLoop::current()->PostTask(FROM_HERE, callback_);
[email protected]84c988a2011-04-19 17:56:33328 }
329
330 private:
331 ~MetricsMemoryDetails() {}
332
[email protected]2226c222011-11-22 00:08:40333 base::Closure callback_;
[email protected]84c988a2011-04-19 17:56:33334 DISALLOW_COPY_AND_ASSIGN(MetricsMemoryDetails);
335};
336
initial.commit09911bf2008-07-26 23:55:29337// static
338void MetricsService::RegisterPrefs(PrefService* local_state) {
339 DCHECK(IsSingleThreaded());
[email protected]20ce516d2010-06-18 02:20:04340 local_state->RegisterStringPref(prefs::kMetricsClientID, "");
[email protected]e61003a2012-05-24 17:03:19341 local_state->RegisterIntegerPref(prefs::kMetricsLowEntropySource, 0);
[email protected]0bb1a622009-03-04 03:22:32342 local_state->RegisterInt64Pref(prefs::kMetricsClientIDTimestamp, 0);
343 local_state->RegisterInt64Pref(prefs::kStabilityLaunchTimeSec, 0);
344 local_state->RegisterInt64Pref(prefs::kStabilityLastTimestampSec, 0);
[email protected]20ce516d2010-06-18 02:20:04345 local_state->RegisterStringPref(prefs::kStabilityStatsVersion, "");
[email protected]225c50842010-01-19 21:19:13346 local_state->RegisterInt64Pref(prefs::kStabilityStatsBuildTime, 0);
initial.commit09911bf2008-07-26 23:55:29347 local_state->RegisterBooleanPref(prefs::kStabilityExitedCleanly, true);
348 local_state->RegisterBooleanPref(prefs::kStabilitySessionEndCompleted, true);
349 local_state->RegisterIntegerPref(prefs::kMetricsSessionID, -1);
350 local_state->RegisterIntegerPref(prefs::kStabilityLaunchCount, 0);
351 local_state->RegisterIntegerPref(prefs::kStabilityCrashCount, 0);
352 local_state->RegisterIntegerPref(prefs::kStabilityIncompleteSessionEndCount,
353 0);
354 local_state->RegisterIntegerPref(prefs::kStabilityPageLoadCount, 0);
initial.commit09911bf2008-07-26 23:55:29355 local_state->RegisterIntegerPref(prefs::kStabilityRendererCrashCount, 0);
[email protected]1f085622009-12-04 05:33:45356 local_state->RegisterIntegerPref(prefs::kStabilityExtensionRendererCrashCount,
357 0);
initial.commit09911bf2008-07-26 23:55:29358 local_state->RegisterIntegerPref(prefs::kStabilityRendererHangCount, 0);
[email protected]1f085622009-12-04 05:33:45359 local_state->RegisterIntegerPref(prefs::kStabilityChildProcessCrashCount, 0);
[email protected]e73c01972008-08-13 00:18:24360 local_state->RegisterIntegerPref(prefs::kStabilityBreakpadRegistrationFail,
361 0);
362 local_state->RegisterIntegerPref(prefs::kStabilityBreakpadRegistrationSuccess,
363 0);
364 local_state->RegisterIntegerPref(prefs::kStabilityDebuggerPresent, 0);
365 local_state->RegisterIntegerPref(prefs::kStabilityDebuggerNotPresent, 0);
[email protected]c1834a92011-01-21 18:21:03366#if defined(OS_CHROMEOS)
367 local_state->RegisterIntegerPref(prefs::kStabilityOtherUserCrashCount, 0);
368 local_state->RegisterIntegerPref(prefs::kStabilityKernelCrashCount, 0);
369 local_state->RegisterIntegerPref(prefs::kStabilitySystemUncleanShutdownCount,
370 0);
371#endif // OS_CHROMEOS
[email protected]e73c01972008-08-13 00:18:24372
initial.commit09911bf2008-07-26 23:55:29373 local_state->RegisterDictionaryPref(prefs::kProfileMetrics);
374 local_state->RegisterIntegerPref(prefs::kNumBookmarksOnBookmarkBar, 0);
375 local_state->RegisterIntegerPref(prefs::kNumFoldersOnBookmarkBar, 0);
376 local_state->RegisterIntegerPref(prefs::kNumBookmarksInOtherBookmarkFolder,
377 0);
378 local_state->RegisterIntegerPref(prefs::kNumFoldersInOtherBookmarkFolder, 0);
379 local_state->RegisterIntegerPref(prefs::kNumKeywords, 0);
[email protected]fe58acc22012-02-29 01:29:58380 local_state->RegisterListPref(prefs::kMetricsInitialLogsXml);
381 local_state->RegisterListPref(prefs::kMetricsOngoingLogsXml);
382 local_state->RegisterListPref(prefs::kMetricsInitialLogsProto);
383 local_state->RegisterListPref(prefs::kMetricsOngoingLogsProto);
[email protected]0bb1a622009-03-04 03:22:32384
385 local_state->RegisterInt64Pref(prefs::kUninstallMetricsPageLoadCount, 0);
386 local_state->RegisterInt64Pref(prefs::kUninstallLaunchCount, 0);
[email protected]6b5f21d2009-04-13 17:01:35387 local_state->RegisterInt64Pref(prefs::kUninstallMetricsInstallDate, 0);
[email protected]0bb1a622009-03-04 03:22:32388 local_state->RegisterInt64Pref(prefs::kUninstallMetricsUptimeSec, 0);
389 local_state->RegisterInt64Pref(prefs::kUninstallLastLaunchTimeSec, 0);
390 local_state->RegisterInt64Pref(prefs::kUninstallLastObservedRunTimeSec, 0);
initial.commit09911bf2008-07-26 23:55:29391}
392
[email protected]541f77922009-02-23 21:14:38393// static
394void MetricsService::DiscardOldStabilityStats(PrefService* local_state) {
395 local_state->SetBoolean(prefs::kStabilityExitedCleanly, true);
[email protected]c9abf242009-07-18 06:00:38396 local_state->SetBoolean(prefs::kStabilitySessionEndCompleted, true);
[email protected]541f77922009-02-23 21:14:38397
398 local_state->SetInteger(prefs::kStabilityIncompleteSessionEndCount, 0);
399 local_state->SetInteger(prefs::kStabilityBreakpadRegistrationSuccess, 0);
400 local_state->SetInteger(prefs::kStabilityBreakpadRegistrationFail, 0);
401 local_state->SetInteger(prefs::kStabilityDebuggerPresent, 0);
402 local_state->SetInteger(prefs::kStabilityDebuggerNotPresent, 0);
403
404 local_state->SetInteger(prefs::kStabilityLaunchCount, 0);
405 local_state->SetInteger(prefs::kStabilityCrashCount, 0);
406
407 local_state->SetInteger(prefs::kStabilityPageLoadCount, 0);
408 local_state->SetInteger(prefs::kStabilityRendererCrashCount, 0);
409 local_state->SetInteger(prefs::kStabilityRendererHangCount, 0);
410
[email protected]9165f742010-03-10 22:55:01411 local_state->SetInt64(prefs::kStabilityLaunchTimeSec, 0);
412 local_state->SetInt64(prefs::kStabilityLastTimestampSec, 0);
[email protected]541f77922009-02-23 21:14:38413
414 local_state->ClearPref(prefs::kStabilityPluginStats);
[email protected]ae155cb92009-06-19 06:10:37415
[email protected]fe58acc22012-02-29 01:29:58416 local_state->ClearPref(prefs::kMetricsInitialLogsXml);
417 local_state->ClearPref(prefs::kMetricsOngoingLogsXml);
418 local_state->ClearPref(prefs::kMetricsInitialLogsProto);
419 local_state->ClearPref(prefs::kMetricsOngoingLogsProto);
[email protected]541f77922009-02-23 21:14:38420}
421
initial.commit09911bf2008-07-26 23:55:29422MetricsService::MetricsService()
[email protected]d01b8732008-10-16 02:18:07423 : recording_active_(false),
424 reporting_active_(false),
[email protected]d01b8732008-10-16 02:18:07425 state_(INITIALIZED),
[email protected]e61003a2012-05-24 17:03:19426 low_entropy_source_(0),
[email protected]d01b8732008-10-16 02:18:07427 idle_since_last_transmission_(false),
initial.commit09911bf2008-07-26 23:55:29428 next_window_id_(0),
[email protected]c94d7382012-02-28 08:43:40429 ALLOW_THIS_IN_INITIALIZER_LIST(self_ptr_factory_(this)),
[email protected]40bcc302009-03-02 20:50:39430 ALLOW_THIS_IN_INITIALIZER_LIST(state_saver_factory_(this)),
[email protected]7f7f1962011-04-20 15:58:16431 waiting_for_asynchronus_reporting_step_(false) {
initial.commit09911bf2008-07-26 23:55:29432 DCHECK(IsSingleThreaded());
433 InitializeMetricsState();
[email protected]7f7f1962011-04-20 15:58:16434
435 base::Closure callback = base::Bind(&MetricsService::StartScheduledUpload,
[email protected]c94d7382012-02-28 08:43:40436 self_ptr_factory_.GetWeakPtr());
[email protected]7f7f1962011-04-20 15:58:16437 scheduler_.reset(new MetricsReportingScheduler(callback));
[email protected]cac267c2011-09-29 15:18:10438 log_manager_.set_log_serializer(new MetricsLogSerializer());
439 log_manager_.set_max_ongoing_log_store_size(kUploadLogAvoidRetransmitSize);
initial.commit09911bf2008-07-26 23:55:29440}
441
442MetricsService::~MetricsService() {
443 SetRecording(false);
444}
445
[email protected]d01b8732008-10-16 02:18:07446void MetricsService::Start() {
[email protected]b1c8dc02011-04-13 18:32:04447 HandleIdleSinceLastTransmission(false);
[email protected]d01b8732008-10-16 02:18:07448 SetRecording(true);
449 SetReporting(true);
450}
451
452void MetricsService::StartRecordingOnly() {
453 SetRecording(true);
454 SetReporting(false);
455}
456
457void MetricsService::Stop() {
[email protected]b1c8dc02011-04-13 18:32:04458 HandleIdleSinceLastTransmission(false);
[email protected]d01b8732008-10-16 02:18:07459 SetReporting(false);
460 SetRecording(false);
461}
462
[email protected]edafd4c2011-05-10 17:18:53463std::string MetricsService::GetClientId() {
464 return client_id_;
465}
466
[email protected]e61003a2012-05-24 17:03:19467std::string MetricsService::GetEntropySource() {
468 // Note that client_id_ is empty if metrics reporting is not enabled. For
469 // metrics reporting-enabled users, we combine the client ID and low entropy
470 // source to get the final entropy source. This has two useful properties:
471 // 1) It makes the entropy source less identifiable for parties that do not
472 // know the low entropy source.
473 // 2) It makes the final entropy source resettable.
474 CHECK(reporting_active() || client_id_.empty());
475 return client_id_ + base::IntToString(GetLowEntropySource());
476}
477
[email protected]5cbeeef72012-02-08 02:05:18478void MetricsService::ForceClientIdCreation() {
479 if (!client_id_.empty())
480 return;
481 PrefService* pref = g_browser_process->local_state();
482 client_id_ = pref->GetString(prefs::kMetricsClientID);
483 if (!client_id_.empty())
484 return;
485
486 client_id_ = GenerateClientID();
487 pref->SetString(prefs::kMetricsClientID, client_id_);
488
489 // Might as well make a note of how long this ID has existed
490 pref->SetString(prefs::kMetricsClientIDTimestamp,
491 base::Int64ToString(Time::Now().ToTimeT()));
492}
493
initial.commit09911bf2008-07-26 23:55:29494void MetricsService::SetRecording(bool enabled) {
495 DCHECK(IsSingleThreaded());
496
[email protected]d01b8732008-10-16 02:18:07497 if (enabled == recording_active_)
initial.commit09911bf2008-07-26 23:55:29498 return;
499
500 if (enabled) {
[email protected]5cbeeef72012-02-08 02:05:18501 ForceClientIdCreation();
[email protected]157d5472009-11-05 22:31:03502 child_process_logging::SetClientId(client_id_);
initial.commit09911bf2008-07-26 23:55:29503 StartRecording();
[email protected]005ef3e2009-05-22 20:55:46504
[email protected]3ffd3ae2011-03-17 22:17:52505 SetUpNotifications(&registrar_, this);
initial.commit09911bf2008-07-26 23:55:29506 } else {
[email protected]005ef3e2009-05-22 20:55:46507 registrar_.RemoveAll();
[email protected]cac267c2011-09-29 15:18:10508 PushPendingLogsToPersistentStorage();
509 DCHECK(!log_manager_.has_staged_log());
510 if (state_ > INITIAL_LOG_READY && log_manager_.has_unsent_logs())
511 state_ = SENDING_OLD_LOGS;
initial.commit09911bf2008-07-26 23:55:29512 }
[email protected]d01b8732008-10-16 02:18:07513 recording_active_ = enabled;
initial.commit09911bf2008-07-26 23:55:29514}
515
[email protected]d01b8732008-10-16 02:18:07516bool MetricsService::recording_active() const {
initial.commit09911bf2008-07-26 23:55:29517 DCHECK(IsSingleThreaded());
[email protected]d01b8732008-10-16 02:18:07518 return recording_active_;
initial.commit09911bf2008-07-26 23:55:29519}
520
[email protected]d01b8732008-10-16 02:18:07521void MetricsService::SetReporting(bool enable) {
522 if (reporting_active_ != enable) {
523 reporting_active_ = enable;
524 if (reporting_active_)
[email protected]7f7f1962011-04-20 15:58:16525 StartSchedulerIfNecessary();
initial.commit09911bf2008-07-26 23:55:29526 }
[email protected]d01b8732008-10-16 02:18:07527}
528
529bool MetricsService::reporting_active() const {
530 DCHECK(IsSingleThreaded());
531 return reporting_active_;
initial.commit09911bf2008-07-26 23:55:29532}
533
[email protected]87ef9ea2011-02-26 03:15:15534// static
[email protected]6c2381d2011-10-19 02:52:53535void MetricsService::SetUpNotifications(
536 content::NotificationRegistrar* registrar,
537 content::NotificationObserver* observer) {
538 registrar->Add(observer, chrome::NOTIFICATION_BROWSER_OPENED,
[email protected]ad50def52011-10-19 23:17:07539 content::NotificationService::AllBrowserContextsAndSources());
[email protected]6c2381d2011-10-19 02:52:53540 registrar->Add(observer, chrome::NOTIFICATION_BROWSER_CLOSED,
[email protected]ad50def52011-10-19 23:17:07541 content::NotificationService::AllSources());
[email protected]6c2381d2011-10-19 02:52:53542 registrar->Add(observer, content::NOTIFICATION_USER_ACTION,
[email protected]ad50def52011-10-19 23:17:07543 content::NotificationService::AllSources());
[email protected]884033e2012-04-16 19:38:42544 registrar->Add(observer, chrome::NOTIFICATION_TAB_PARENTED,
[email protected]ad50def52011-10-19 23:17:07545 content::NotificationService::AllSources());
[email protected]884033e2012-04-16 19:38:42546 registrar->Add(observer, chrome::NOTIFICATION_TAB_CLOSING,
[email protected]ad50def52011-10-19 23:17:07547 content::NotificationService::AllSources());
[email protected]6c2381d2011-10-19 02:52:53548 registrar->Add(observer, content::NOTIFICATION_LOAD_START,
[email protected]ad50def52011-10-19 23:17:07549 content::NotificationService::AllSources());
[email protected]6c2381d2011-10-19 02:52:53550 registrar->Add(observer, content::NOTIFICATION_LOAD_STOP,
[email protected]ad50def52011-10-19 23:17:07551 content::NotificationService::AllSources());
[email protected]6c2381d2011-10-19 02:52:53552 registrar->Add(observer, content::NOTIFICATION_RENDERER_PROCESS_CLOSED,
[email protected]ad50def52011-10-19 23:17:07553 content::NotificationService::AllSources());
[email protected]6c2381d2011-10-19 02:52:53554 registrar->Add(observer, content::NOTIFICATION_RENDERER_PROCESS_HANG,
[email protected]ad50def52011-10-19 23:17:07555 content::NotificationService::AllSources());
[email protected]6c2381d2011-10-19 02:52:53556 registrar->Add(observer, content::NOTIFICATION_CHILD_PROCESS_HOST_CONNECTED,
[email protected]ad50def52011-10-19 23:17:07557 content::NotificationService::AllSources());
[email protected]6c2381d2011-10-19 02:52:53558 registrar->Add(observer, content::NOTIFICATION_CHILD_INSTANCE_CREATED,
[email protected]ad50def52011-10-19 23:17:07559 content::NotificationService::AllSources());
[email protected]6c2381d2011-10-19 02:52:53560 registrar->Add(observer, content::NOTIFICATION_CHILD_PROCESS_CRASHED,
[email protected]ad50def52011-10-19 23:17:07561 content::NotificationService::AllSources());
[email protected]6c2381d2011-10-19 02:52:53562 registrar->Add(observer, chrome::NOTIFICATION_TEMPLATE_URL_SERVICE_LOADED,
[email protected]ad50def52011-10-19 23:17:07563 content::NotificationService::AllSources());
[email protected]6c2381d2011-10-19 02:52:53564 registrar->Add(observer, chrome::NOTIFICATION_OMNIBOX_OPENED_URL,
[email protected]ad50def52011-10-19 23:17:07565 content::NotificationService::AllSources());
[email protected]6c2381d2011-10-19 02:52:53566 registrar->Add(observer, chrome::NOTIFICATION_BOOKMARK_MODEL_LOADED,
[email protected]ad50def52011-10-19 23:17:07567 content::NotificationService::AllBrowserContextsAndSources());
[email protected]87ef9ea2011-02-26 03:15:15568}
569
[email protected]432115822011-07-10 15:52:27570void MetricsService::Observe(int type,
[email protected]6c2381d2011-10-19 02:52:53571 const content::NotificationSource& source,
572 const content::NotificationDetails& details) {
[email protected]cac267c2011-09-29 15:18:10573 DCHECK(log_manager_.current_log());
initial.commit09911bf2008-07-26 23:55:29574 DCHECK(IsSingleThreaded());
575
576 if (!CanLogNotification(type, source, details))
577 return;
578
[email protected]432115822011-07-10 15:52:27579 switch (type) {
580 case content::NOTIFICATION_USER_ACTION:
[email protected]cac267c2011-09-29 15:18:10581 log_manager_.current_log()->RecordUserAction(
[email protected]6c2381d2011-10-19 02:52:53582 *content::Details<const char*>(details).ptr());
initial.commit09911bf2008-07-26 23:55:29583 break;
584
[email protected]432115822011-07-10 15:52:27585 case chrome::NOTIFICATION_BROWSER_OPENED:
586 case chrome::NOTIFICATION_BROWSER_CLOSED:
initial.commit09911bf2008-07-26 23:55:29587 LogWindowChange(type, source, details);
588 break;
589
[email protected]884033e2012-04-16 19:38:42590 case chrome::NOTIFICATION_TAB_PARENTED:
591 case chrome::NOTIFICATION_TAB_CLOSING:
initial.commit09911bf2008-07-26 23:55:29592 LogWindowChange(type, source, details);
593 break;
594
[email protected]432115822011-07-10 15:52:27595 case content::NOTIFICATION_LOAD_STOP:
initial.commit09911bf2008-07-26 23:55:29596 LogLoadComplete(type, source, details);
597 break;
598
[email protected]432115822011-07-10 15:52:27599 case content::NOTIFICATION_LOAD_START:
initial.commit09911bf2008-07-26 23:55:29600 LogLoadStarted();
601 break;
602
[email protected]432115822011-07-10 15:52:27603 case content::NOTIFICATION_RENDERER_PROCESS_CLOSED: {
[email protected]f3b1a082011-11-18 00:34:30604 content::RenderProcessHost::RendererClosedDetails* process_details =
605 content::Details<
606 content::RenderProcessHost::RendererClosedDetails>(
607 details).ptr();
608 content::RenderProcessHost* host =
609 content::Source<content::RenderProcessHost>(source).ptr();
[email protected]c3721482012-03-23 16:21:48610 LogRendererCrash(
611 host, process_details->status, process_details->was_alive);
[email protected]1f085622009-12-04 05:33:45612 }
initial.commit09911bf2008-07-26 23:55:29613 break;
614
[email protected]432115822011-07-10 15:52:27615 case content::NOTIFICATION_RENDERER_PROCESS_HANG:
initial.commit09911bf2008-07-26 23:55:29616 LogRendererHang();
617 break;
618
[email protected]432115822011-07-10 15:52:27619 case content::NOTIFICATION_CHILD_PROCESS_HOST_CONNECTED:
620 case content::NOTIFICATION_CHILD_PROCESS_CRASHED:
621 case content::NOTIFICATION_CHILD_INSTANCE_CREATED:
[email protected]a27a9382009-02-11 23:55:10622 LogChildProcessChange(type, source, details);
initial.commit09911bf2008-07-26 23:55:29623 break;
624
[email protected]432115822011-07-10 15:52:27625 case chrome::NOTIFICATION_TEMPLATE_URL_SERVICE_LOADED:
[email protected]604d8a062012-03-16 21:37:46626 LogKeywordCount(content::Source<TemplateURLService>(
627 source)->GetTemplateURLs().size());
initial.commit09911bf2008-07-26 23:55:29628 break;
629
[email protected]432115822011-07-10 15:52:27630 case chrome::NOTIFICATION_OMNIBOX_OPENED_URL: {
[email protected]279703f2012-01-20 22:23:26631 MetricsLog* current_log =
632 static_cast<MetricsLog*>(log_manager_.current_log());
[email protected]1226abb2010-06-10 18:01:28633 DCHECK(current_log);
634 current_log->RecordOmniboxOpenedURL(
[email protected]6c2381d2011-10-19 02:52:53635 *content::Details<AutocompleteLog>(details).ptr());
initial.commit09911bf2008-07-26 23:55:29636 break;
[email protected]1226abb2010-06-10 18:01:28637 }
initial.commit09911bf2008-07-26 23:55:29638
[email protected]432115822011-07-10 15:52:27639 case chrome::NOTIFICATION_BOOKMARK_MODEL_LOADED: {
[email protected]6c2381d2011-10-19 02:52:53640 Profile* p = content::Source<Profile>(source).ptr();
[email protected]b61236c62009-04-09 22:43:55641 if (p)
642 LogBookmarks(p->GetBookmarkModel());
initial.commit09911bf2008-07-26 23:55:29643 break;
[email protected]b61236c62009-04-09 22:43:55644 }
initial.commit09911bf2008-07-26 23:55:29645 default:
[email protected]a063c102010-07-22 22:20:19646 NOTREACHED();
initial.commit09911bf2008-07-26 23:55:29647 break;
648 }
[email protected]d01b8732008-10-16 02:18:07649
650 HandleIdleSinceLastTransmission(false);
651
[email protected]cac267c2011-09-29 15:18:10652 if (log_manager_.current_log())
653 DVLOG(1) << "METRICS: NUMBER OF EVENTS = "
654 << log_manager_.current_log()->num_events();
[email protected]d01b8732008-10-16 02:18:07655}
656
657void MetricsService::HandleIdleSinceLastTransmission(bool in_idle) {
658 // If there wasn't a lot of action, maybe the computer was asleep, in which
659 // case, the log transmissions should have stopped. Here we start them up
660 // again.
[email protected]cac78842008-11-27 01:02:20661 if (!in_idle && idle_since_last_transmission_)
[email protected]7f7f1962011-04-20 15:58:16662 StartSchedulerIfNecessary();
[email protected]cac78842008-11-27 01:02:20663 idle_since_last_transmission_ = in_idle;
initial.commit09911bf2008-07-26 23:55:29664}
665
initial.commit09911bf2008-07-26 23:55:29666void MetricsService::RecordStartOfSessionEnd() {
[email protected]466f3c12011-03-23 21:20:38667 LogCleanShutdown();
initial.commit09911bf2008-07-26 23:55:29668 RecordBooleanPrefValue(prefs::kStabilitySessionEndCompleted, false);
669}
670
671void MetricsService::RecordCompletedSessionEnd() {
[email protected]466f3c12011-03-23 21:20:38672 LogCleanShutdown();
initial.commit09911bf2008-07-26 23:55:29673 RecordBooleanPrefValue(prefs::kStabilitySessionEndCompleted, true);
674}
675
[email protected]7f7f1962011-04-20 15:58:16676void MetricsService::RecordBreakpadRegistration(bool success) {
[email protected]68475e602008-08-22 03:21:15677 if (!success)
[email protected]e73c01972008-08-13 00:18:24678 IncrementPrefValue(prefs::kStabilityBreakpadRegistrationFail);
679 else
680 IncrementPrefValue(prefs::kStabilityBreakpadRegistrationSuccess);
681}
682
683void MetricsService::RecordBreakpadHasDebugger(bool has_debugger) {
684 if (!has_debugger)
685 IncrementPrefValue(prefs::kStabilityDebuggerNotPresent);
686 else
[email protected]68475e602008-08-22 03:21:15687 IncrementPrefValue(prefs::kStabilityDebuggerPresent);
[email protected]e73c01972008-08-13 00:18:24688}
689
initial.commit09911bf2008-07-26 23:55:29690//------------------------------------------------------------------------------
691// private methods
692//------------------------------------------------------------------------------
693
694
695//------------------------------------------------------------------------------
696// Initialization methods
697
698void MetricsService::InitializeMetricsState() {
[email protected]79bf0b72009-04-27 21:30:55699#if defined(OS_POSIX)
[email protected]fe58acc22012-02-29 01:29:58700 server_url_xml_ = ASCIIToUTF16(kServerUrlXml);
701 server_url_proto_ = ASCIIToUTF16(kServerUrlProto);
[email protected]b4a72d842012-03-22 20:09:09702 network_stats_server_ = chrome_common_net::kEchoTestServerLocation;
703 http_pipelining_test_server_ = chrome_common_net::kPipelineTestServerBaseUrl;
[email protected]79bf0b72009-04-27 21:30:55704#else
705 BrowserDistribution* dist = BrowserDistribution::GetDistribution();
[email protected]fe58acc22012-02-29 01:29:58706 server_url_xml_ = dist->GetStatsServerURL();
707 server_url_proto_ = ASCIIToUTF16(kServerUrlProto);
[email protected]d67d1052011-06-09 05:11:41708 network_stats_server_ = dist->GetNetworkStatsServer();
[email protected]adbb3762012-03-09 22:20:08709 http_pipelining_test_server_ = dist->GetHttpPipeliningTestServer();
[email protected]79bf0b72009-04-27 21:30:55710#endif
711
initial.commit09911bf2008-07-26 23:55:29712 PrefService* pref = g_browser_process->local_state();
713 DCHECK(pref);
714
[email protected]225c50842010-01-19 21:19:13715 if ((pref->GetInt64(prefs::kStabilityStatsBuildTime)
716 != MetricsLog::GetBuildTime()) ||
[email protected]ddd231e2010-06-29 20:35:19717 (pref->GetString(prefs::kStabilityStatsVersion)
[email protected]225c50842010-01-19 21:19:13718 != MetricsLog::GetVersionString())) {
[email protected]541f77922009-02-23 21:14:38719 // This is a new version, so we don't want to confuse the stats about the
720 // old version with info that we upload.
721 DiscardOldStabilityStats(pref);
722 pref->SetString(prefs::kStabilityStatsVersion,
[email protected]ddd231e2010-06-29 20:35:19723 MetricsLog::GetVersionString());
[email protected]225c50842010-01-19 21:19:13724 pref->SetInt64(prefs::kStabilityStatsBuildTime,
725 MetricsLog::GetBuildTime());
[email protected]541f77922009-02-23 21:14:38726 }
727
initial.commit09911bf2008-07-26 23:55:29728 // Update session ID
729 session_id_ = pref->GetInteger(prefs::kMetricsSessionID);
730 ++session_id_;
731 pref->SetInteger(prefs::kMetricsSessionID, session_id_);
732
initial.commit09911bf2008-07-26 23:55:29733 // Stability bookkeeping
[email protected]e73c01972008-08-13 00:18:24734 IncrementPrefValue(prefs::kStabilityLaunchCount);
initial.commit09911bf2008-07-26 23:55:29735
[email protected]e73c01972008-08-13 00:18:24736 if (!pref->GetBoolean(prefs::kStabilityExitedCleanly)) {
737 IncrementPrefValue(prefs::kStabilityCrashCount);
[email protected]c0c55e92011-09-10 18:47:30738 // Reset flag, and wait until we call LogNeedForCleanShutdown() before
739 // monitoring.
740 pref->SetBoolean(prefs::kStabilityExitedCleanly, true);
initial.commit09911bf2008-07-26 23:55:29741 }
[email protected]e73c01972008-08-13 00:18:24742
[email protected]e73c01972008-08-13 00:18:24743 if (!pref->GetBoolean(prefs::kStabilitySessionEndCompleted)) {
744 IncrementPrefValue(prefs::kStabilityIncompleteSessionEndCount);
[email protected]c9abf242009-07-18 06:00:38745 // This is marked false when we get a WM_ENDSESSION.
746 pref->SetBoolean(prefs::kStabilitySessionEndCompleted, true);
initial.commit09911bf2008-07-26 23:55:29747 }
initial.commit09911bf2008-07-26 23:55:29748
[email protected]9165f742010-03-10 22:55:01749 // Initialize uptime counters.
750 int64 startup_uptime = MetricsLog::GetIncrementalUptime(pref);
[email protected]ae393ec702010-06-27 16:23:14751 DCHECK_EQ(0, startup_uptime);
[email protected]9165f742010-03-10 22:55:01752 // For backwards compatibility, leave this intact in case Omaha is checking
753 // them. prefs::kStabilityLastTimestampSec may also be useless now.
754 // TODO(jar): Delete these if they have no uses.
[email protected]0bb1a622009-03-04 03:22:32755 pref->SetInt64(prefs::kStabilityLaunchTimeSec, Time::Now().ToTimeT());
756
757 // Bookkeeping for the uninstall metrics.
758 IncrementLongPrefsValue(prefs::kUninstallLaunchCount);
initial.commit09911bf2008-07-26 23:55:29759
760 // Save profile metrics.
761 PrefService* prefs = g_browser_process->local_state();
762 if (prefs) {
763 // Remove the current dictionary and store it for use when sending data to
764 // server. By removing the value we prune potentially dead profiles
765 // (and keys). All valid values are added back once services startup.
766 const DictionaryValue* profile_dictionary =
767 prefs->GetDictionary(prefs::kProfileMetrics);
768 if (profile_dictionary) {
769 // Do a deep copy of profile_dictionary since ClearPref will delete it.
770 profile_dictionary_.reset(static_cast<DictionaryValue*>(
771 profile_dictionary->DeepCopy()));
772 prefs->ClearPref(prefs::kProfileMetrics);
773 }
774 }
775
[email protected]92745242009-06-12 16:52:21776 // Get stats on use of command line.
777 const CommandLine* command_line(CommandLine::ForCurrentProcess());
778 size_t common_commands = 0;
779 if (command_line->HasSwitch(switches::kUserDataDir)) {
780 ++common_commands;
781 UMA_HISTOGRAM_COUNTS_100("Chrome.CommandLineDatDirCount", 1);
782 }
783
784 if (command_line->HasSwitch(switches::kApp)) {
785 ++common_commands;
786 UMA_HISTOGRAM_COUNTS_100("Chrome.CommandLineAppModeCount", 1);
787 }
788
[email protected]62b4e522011-07-13 21:46:32789 size_t switch_count = command_line->GetSwitches().size();
790 UMA_HISTOGRAM_COUNTS_100("Chrome.CommandLineFlagCount", switch_count);
[email protected]92745242009-06-12 16:52:21791 UMA_HISTOGRAM_COUNTS_100("Chrome.CommandLineUncommonFlagCount",
[email protected]62b4e522011-07-13 21:46:32792 switch_count - common_commands);
[email protected]92745242009-06-12 16:52:21793
initial.commit09911bf2008-07-26 23:55:29794 // Kick off the process of saving the state (so the uptime numbers keep
795 // getting updated) every n minutes.
796 ScheduleNextStateSave();
797}
798
[email protected]c94d7382012-02-28 08:43:40799// static
[email protected]d33e7cc2011-09-23 01:43:56800void MetricsService::InitTaskGetHardwareClass(
[email protected]c94d7382012-02-28 08:43:40801 base::WeakPtr<MetricsService> self,
[email protected]d33e7cc2011-09-23 01:43:56802 base::MessageLoopProxy* target_loop) {
[email protected]d33e7cc2011-09-23 01:43:56803 DCHECK(BrowserThread::CurrentlyOn(BrowserThread::FILE));
804
805 std::string hardware_class;
806#if defined(OS_CHROMEOS)
807 chromeos::system::StatisticsProvider::GetInstance()->GetMachineStatistic(
808 "hardware_class", &hardware_class);
809#endif // OS_CHROMEOS
810
811 target_loop->PostTask(FROM_HERE,
812 base::Bind(&MetricsService::OnInitTaskGotHardwareClass,
[email protected]c94d7382012-02-28 08:43:40813 self, hardware_class));
[email protected]d33e7cc2011-09-23 01:43:56814}
815
816void MetricsService::OnInitTaskGotHardwareClass(
817 const std::string& hardware_class) {
[email protected]ed0fd002012-04-25 23:10:34818 DCHECK_EQ(INIT_TASK_SCHEDULED, state_);
[email protected]85ed9d42010-06-08 22:37:44819 hardware_class_ = hardware_class;
[email protected]d33e7cc2011-09-23 01:43:56820
821 // Start the next part of the init task: loading plugin information.
822 PluginService::GetInstance()->GetPlugins(
823 base::Bind(&MetricsService::OnInitTaskGotPluginInfo,
[email protected]c94d7382012-02-28 08:43:40824 self_ptr_factory_.GetWeakPtr()));
[email protected]d33e7cc2011-09-23 01:43:56825}
826
827void MetricsService::OnInitTaskGotPluginInfo(
828 const std::vector<webkit::WebPluginInfo>& plugins) {
[email protected]ed0fd002012-04-25 23:10:34829 DCHECK_EQ(INIT_TASK_SCHEDULED, state_);
[email protected]35fa6a22009-08-15 00:04:01830 plugins_ = plugins;
[email protected]d33e7cc2011-09-23 01:43:56831
[email protected]197c0772012-05-14 23:50:51832 // Schedules a task on a blocking pool thread to gather Google Update
833 // statistics (requires Registry reads).
834 BrowserThread::PostBlockingPoolTask(
835 FROM_HERE,
836 base::Bind(&MetricsService::InitTaskGetGoogleUpdateData,
837 self_ptr_factory_.GetWeakPtr(),
838 MessageLoop::current()->message_loop_proxy()));
839}
840
841// static
842void MetricsService::InitTaskGetGoogleUpdateData(
843 base::WeakPtr<MetricsService> self,
844 base::MessageLoopProxy* target_loop) {
845 GoogleUpdateMetrics google_update_metrics;
846
847#if defined(OS_WIN) && defined(GOOGLE_CHROME_BUILD)
848 const bool system_install = GoogleUpdateSettings::IsSystemInstall();
849
850 google_update_metrics.is_system_install = system_install;
851 google_update_metrics.last_started_au =
852 GoogleUpdateSettings::GetGoogleUpdateLastStartedAU(system_install);
853 google_update_metrics.last_checked =
854 GoogleUpdateSettings::GetGoogleUpdateLastChecked(system_install);
855 GoogleUpdateSettings::GetUpdateDetailForGoogleUpdate(
856 system_install,
857 &google_update_metrics.google_update_data);
858 GoogleUpdateSettings::GetUpdateDetail(
859 system_install,
860 &google_update_metrics.product_data);
861#endif // defined(OS_WIN) && defined(GOOGLE_CHROME_BUILD)
862
863 target_loop->PostTask(FROM_HERE,
864 base::Bind(&MetricsService::OnInitTaskGotGoogleUpdateData,
865 self, google_update_metrics));
866}
867
868void MetricsService::OnInitTaskGotGoogleUpdateData(
869 const GoogleUpdateMetrics& google_update_metrics) {
870 DCHECK_EQ(INIT_TASK_SCHEDULED, state_);
871
872 google_update_metrics_ = google_update_metrics;
873
[email protected]ed0fd002012-04-25 23:10:34874 // Start the next part of the init task: fetching performance data. This will
875 // call into |FinishedReceivingProfilerData()| when the task completes.
876 chrome_browser_metrics::TrackingSynchronizer::FetchProfilerDataAsynchronously(
877 self_ptr_factory_.GetWeakPtr());
878}
879
880void MetricsService::ReceivedProfilerData(
881 const tracked_objects::ProcessDataSnapshot& process_data,
882 content::ProcessType process_type) {
883 DCHECK_EQ(INIT_TASK_SCHEDULED, state_);
884
885 // Upon the first callback, create the initial log so that we can immediately
886 // save the profiler data.
887 if (!initial_log_.get())
888 initial_log_.reset(new MetricsLog(client_id_, session_id_));
889
890 initial_log_->RecordProfilerData(process_data, process_type);
891}
892
893void MetricsService::FinishedReceivingProfilerData() {
894 DCHECK_EQ(INIT_TASK_SCHEDULED, state_);
[email protected]3a7b66d2012-04-26 16:34:16895 state_ = INIT_TASK_DONE;
initial.commit09911bf2008-07-26 23:55:29896}
897
[email protected]e61003a2012-05-24 17:03:19898int MetricsService::GetLowEntropySource() {
899 // Note that the default value for the low entropy source and the default pref
900 // value are both zero, which is used to identify if the value has been set
901 // or not. Valid values start at 1.
902 if (low_entropy_source_)
903 return low_entropy_source_;
904
905 PrefService* pref = g_browser_process->local_state();
906 const CommandLine* command_line(CommandLine::ForCurrentProcess());
907 // Only try to load the value from prefs if the user did not request a reset.
908 // Otherwise, skip to generating a new value.
909 if (!command_line->HasSwitch(switches::kResetVariationState)) {
910 low_entropy_source_ = pref->GetInteger(prefs::kMetricsLowEntropySource);
911 if (low_entropy_source_)
912 return low_entropy_source_;
913 }
914
915 low_entropy_source_ = GenerateLowEntropySource();
916 pref->SetInteger(prefs::kMetricsLowEntropySource, low_entropy_source_);
917
918 return low_entropy_source_;
919}
920
921// static
initial.commit09911bf2008-07-26 23:55:29922std::string MetricsService::GenerateClientID() {
[email protected]3469e7e2010-10-14 20:34:59923 return guid::GenerateGUID();
initial.commit09911bf2008-07-26 23:55:29924}
925
initial.commit09911bf2008-07-26 23:55:29926//------------------------------------------------------------------------------
927// State save methods
928
929void MetricsService::ScheduleNextStateSave() {
[email protected]8454aeb2011-11-19 23:38:20930 state_saver_factory_.InvalidateWeakPtrs();
initial.commit09911bf2008-07-26 23:55:29931
932 MessageLoop::current()->PostDelayedTask(FROM_HERE,
[email protected]8454aeb2011-11-19 23:38:20933 base::Bind(&MetricsService::SaveLocalState,
934 state_saver_factory_.GetWeakPtr()),
[email protected]fc4252a72012-01-12 21:58:47935 base::TimeDelta::FromMinutes(kSaveStateIntervalMinutes));
initial.commit09911bf2008-07-26 23:55:29936}
937
938void MetricsService::SaveLocalState() {
939 PrefService* pref = g_browser_process->local_state();
940 if (!pref) {
[email protected]a063c102010-07-22 22:20:19941 NOTREACHED();
initial.commit09911bf2008-07-26 23:55:29942 return;
943 }
944
945 RecordCurrentState(pref);
initial.commit09911bf2008-07-26 23:55:29946
[email protected]fc4252a72012-01-12 21:58:47947 // TODO(jar):110021 Does this run down the batteries????
initial.commit09911bf2008-07-26 23:55:29948 ScheduleNextStateSave();
949}
950
951
952//------------------------------------------------------------------------------
953// Recording control methods
954
955void MetricsService::StartRecording() {
[email protected]cac267c2011-09-29 15:18:10956 if (log_manager_.current_log())
initial.commit09911bf2008-07-26 23:55:29957 return;
958
[email protected]29948262012-03-01 12:15:08959 log_manager_.BeginLoggingWithLog(new MetricsLog(client_id_, session_id_),
960 MetricsLogManager::ONGOING_LOG);
initial.commit09911bf2008-07-26 23:55:29961 if (state_ == INITIALIZED) {
962 // We only need to schedule that run once.
[email protected]85ed9d42010-06-08 22:37:44963 state_ = INIT_TASK_SCHEDULED;
initial.commit09911bf2008-07-26 23:55:29964
[email protected]85ed9d42010-06-08 22:37:44965 // Schedules a task on the file thread for execution of slower
966 // initialization steps (such as plugin list generation) necessary
967 // for sending the initial log. This avoids blocking the main UI
968 // thread.
[email protected]ed10dd12011-12-07 12:03:42969 BrowserThread::PostDelayedTask(
970 BrowserThread::FILE,
971 FROM_HERE,
[email protected]d33e7cc2011-09-23 01:43:56972 base::Bind(&MetricsService::InitTaskGetHardwareClass,
[email protected]c94d7382012-02-28 08:43:40973 self_ptr_factory_.GetWeakPtr(),
[email protected]d33e7cc2011-09-23 01:43:56974 MessageLoop::current()->message_loop_proxy()),
[email protected]7e560102012-03-08 20:58:42975 base::TimeDelta::FromSeconds(kInitializationDelaySeconds));
initial.commit09911bf2008-07-26 23:55:29976 }
977}
978
[email protected]024b5cd2011-05-27 03:29:38979void MetricsService::StopRecording() {
[email protected]cac267c2011-09-29 15:18:10980 if (!log_manager_.current_log())
initial.commit09911bf2008-07-26 23:55:29981 return;
982
[email protected]68475e602008-08-22 03:21:15983 // TODO(jar): Integrate bounds on log recording more consistently, so that we
984 // can stop recording logs that are too big much sooner.
[email protected]cac267c2011-09-29 15:18:10985 if (log_manager_.current_log()->num_events() > kEventLimit) {
[email protected]553dba62009-02-24 19:08:23986 UMA_HISTOGRAM_COUNTS("UMA.Discarded Log Events",
[email protected]cac267c2011-09-29 15:18:10987 log_manager_.current_log()->num_events());
988 log_manager_.DiscardCurrentLog();
[email protected]68475e602008-08-22 03:21:15989 StartRecording(); // Start trivial log to hold our histograms.
990 }
991
[email protected]cac267c2011-09-29 15:18:10992 // Adds to ongoing logs.
993 log_manager_.current_log()->set_hardware_class(hardware_class_);
[email protected]accdfa62011-09-20 01:56:52994
[email protected]0b33f80b2008-12-17 21:34:36995 // Put incremental data (histogram deltas, and realtime stats deltas) at the
[email protected]147bbc0b2009-01-06 19:37:40996 // end of all log transmissions (initial log handles this separately).
[email protected]024b5cd2011-05-27 03:29:38997 // RecordIncrementalStabilityElements only exists on the derived
998 // MetricsLog class.
[email protected]279703f2012-01-20 22:23:26999 MetricsLog* current_log =
1000 static_cast<MetricsLog*>(log_manager_.current_log());
[email protected]024b5cd2011-05-27 03:29:381001 DCHECK(current_log);
[email protected]197c0772012-05-14 23:50:511002 current_log->RecordEnvironmentProto(plugins_, google_update_metrics_);
[email protected]fe58acc22012-02-29 01:29:581003 current_log->RecordIncrementalStabilityElements(plugins_);
[email protected]024b5cd2011-05-27 03:29:381004 RecordCurrentHistograms();
initial.commit09911bf2008-07-26 23:55:291005
[email protected]29948262012-03-01 12:15:081006 log_manager_.FinishCurrentLog();
initial.commit09911bf2008-07-26 23:55:291007}
1008
[email protected]cac267c2011-09-29 15:18:101009void MetricsService::PushPendingLogsToPersistentStorage() {
initial.commit09911bf2008-07-26 23:55:291010 if (state_ < INITIAL_LOG_READY)
[email protected]28ab7f92009-01-06 21:39:041011 return; // We didn't and still don't have time to get plugin list etc.
initial.commit09911bf2008-07-26 23:55:291012
[email protected]cac267c2011-09-29 15:18:101013 if (log_manager_.has_staged_log()) {
[email protected]29948262012-03-01 12:15:081014 // We may race here, and send second copy of initial log later.
1015 if (state_ == INITIAL_LOG_READY)
[email protected]cac267c2011-09-29 15:18:101016 state_ = SENDING_OLD_LOGS;
[email protected]e7508d82012-05-03 15:59:531017 MetricsLogManager::StoreType store_type = current_fetch_xml_.get() ?
1018 MetricsLogManager::PROVISIONAL_STORE : MetricsLogManager::NORMAL_STORE;
1019 log_manager_.StoreStagedLogAsUnsent(store_type);
initial.commit09911bf2008-07-26 23:55:291020 }
[email protected]cac267c2011-09-29 15:18:101021 DCHECK(!log_manager_.has_staged_log());
[email protected]024b5cd2011-05-27 03:29:381022 StopRecording();
initial.commit09911bf2008-07-26 23:55:291023 StoreUnsentLogs();
1024}
1025
1026//------------------------------------------------------------------------------
1027// Transmission of logs methods
1028
[email protected]7f7f1962011-04-20 15:58:161029void MetricsService::StartSchedulerIfNecessary() {
1030 if (reporting_active() && recording_active())
1031 scheduler_->Start();
initial.commit09911bf2008-07-26 23:55:291032}
1033
[email protected]7f7f1962011-04-20 15:58:161034void MetricsService::StartScheduledUpload() {
1035 // If reporting has been turned off, the scheduler doesn't need to run.
1036 if (!reporting_active() || !recording_active()) {
1037 scheduler_->Stop();
1038 scheduler_->UploadCancelled();
1039 return;
1040 }
1041
[email protected]29948262012-03-01 12:15:081042 StartFinalLogInfoCollection();
1043}
1044
1045void MetricsService::StartFinalLogInfoCollection() {
1046 // Begin the multi-step process of collecting memory usage histograms:
1047 // First spawn a task to collect the memory details; when that task is
1048 // finished, it will call OnMemoryDetailCollectionDone. That will in turn
1049 // call HistogramSynchronization to collect histograms from all renderers and
1050 // then call OnHistogramSynchronizationDone to continue processing.
[email protected]7f7f1962011-04-20 15:58:161051 DCHECK(!waiting_for_asynchronus_reporting_step_);
1052 waiting_for_asynchronus_reporting_step_ = true;
1053
[email protected]2226c222011-11-22 00:08:401054 base::Closure callback =
1055 base::Bind(&MetricsService::OnMemoryDetailCollectionDone,
[email protected]c94d7382012-02-28 08:43:401056 self_ptr_factory_.GetWeakPtr());
[email protected]84c988a2011-04-19 17:56:331057
[email protected]2226c222011-11-22 00:08:401058 scoped_refptr<MetricsMemoryDetails> details(
1059 new MetricsMemoryDetails(callback));
[email protected]4306df72012-04-20 18:58:571060 details->StartFetch(MemoryDetails::UPDATE_USER_METRICS);
[email protected]84c988a2011-04-19 17:56:331061
1062 // Collect WebCore cache information to put into a histogram.
[email protected]f3b1a082011-11-18 00:34:301063 for (content::RenderProcessHost::iterator i(
1064 content::RenderProcessHost::AllHostsIterator());
[email protected]84c988a2011-04-19 17:56:331065 !i.IsAtEnd(); i.Advance())
[email protected]2ccf45c2011-08-19 23:35:501066 i.GetCurrentValue()->Send(new ChromeViewMsg_GetCacheResourceStats());
[email protected]84c988a2011-04-19 17:56:331067}
1068
1069void MetricsService::OnMemoryDetailCollectionDone() {
[email protected]c9a3ef82009-05-28 22:02:461070 DCHECK(IsSingleThreaded());
[email protected]7f7f1962011-04-20 15:58:161071 // This function should only be called as the callback from an ansynchronous
1072 // step.
1073 DCHECK(waiting_for_asynchronus_reporting_step_);
[email protected]c9a3ef82009-05-28 22:02:461074
[email protected]c9a3ef82009-05-28 22:02:461075 // Create a callback_task for OnHistogramSynchronizationDone.
[email protected]2226c222011-11-22 00:08:401076 base::Closure callback = base::Bind(
1077 &MetricsService::OnHistogramSynchronizationDone,
[email protected]c94d7382012-02-28 08:43:401078 self_ptr_factory_.GetWeakPtr());
[email protected]c9a3ef82009-05-28 22:02:461079
[email protected]908de522011-10-20 00:55:001080 base::StatisticsRecorder::CollectHistogramStats("Browser");
1081
[email protected]c9a3ef82009-05-28 22:02:461082 // Set up the callback to task to call after we receive histograms from all
1083 // renderer processes. Wait time specifies how long to wait before absolutely
1084 // calling us back on the task.
1085 HistogramSynchronizer::FetchRendererHistogramsAsynchronously(
[email protected]2226c222011-11-22 00:08:401086 MessageLoop::current(), callback,
[email protected]7e560102012-03-08 20:58:421087 base::TimeDelta::FromMilliseconds(kMaxHistogramGatheringWaitDuration));
[email protected]c9a3ef82009-05-28 22:02:461088}
1089
1090void MetricsService::OnHistogramSynchronizationDone() {
initial.commit09911bf2008-07-26 23:55:291091 DCHECK(IsSingleThreaded());
[email protected]29948262012-03-01 12:15:081092 // This function should only be called as the callback from an ansynchronous
1093 // step.
1094 DCHECK(waiting_for_asynchronus_reporting_step_);
initial.commit09911bf2008-07-26 23:55:291095
[email protected]29948262012-03-01 12:15:081096 waiting_for_asynchronus_reporting_step_ = false;
1097 OnFinalLogInfoCollectionDone();
1098}
1099
1100void MetricsService::OnFinalLogInfoCollectionDone() {
[email protected]7f7f1962011-04-20 15:58:161101 // If somehow there is a fetch in progress, we return and hope things work
1102 // out. The scheduler isn't informed since if this happens, the scheduler
1103 // will get a response from the upload.
[email protected]fe58acc22012-02-29 01:29:581104 DCHECK(!current_fetch_xml_.get());
1105 DCHECK(!current_fetch_proto_.get());
1106 if (current_fetch_xml_.get() || current_fetch_proto_.get())
[email protected]7f7f1962011-04-20 15:58:161107 return;
1108
[email protected]d01b8732008-10-16 02:18:071109 // If we're getting no notifications, then the log won't have much in it, and
1110 // it's possible the computer is about to go to sleep, so don't upload and
[email protected]7f7f1962011-04-20 15:58:161111 // stop the scheduler.
1112 // Similarly, if logs should no longer be uploaded, stop here.
1113 if (idle_since_last_transmission_ ||
1114 !recording_active() || !reporting_active()) {
1115 scheduler_->Stop();
1116 scheduler_->UploadCancelled();
[email protected]d01b8732008-10-16 02:18:071117 return;
1118 }
1119
[email protected]cac267c2011-09-29 15:18:101120 MakeStagedLog();
initial.commit09911bf2008-07-26 23:55:291121
[email protected]cac267c2011-09-29 15:18:101122 // MakeStagedLog should have prepared log text; if it didn't, skip this
1123 // upload and hope things work out next time.
1124 if (log_manager_.staged_log_text().empty()) {
[email protected]7f7f1962011-04-20 15:58:161125 scheduler_->UploadCancelled();
[email protected]d01b8732008-10-16 02:18:071126 return;
1127 }
initial.commit09911bf2008-07-26 23:55:291128
[email protected]29948262012-03-01 12:15:081129 SendStagedLog();
1130}
1131
1132void MetricsService::MakeStagedLog() {
1133 if (log_manager_.has_staged_log())
1134 return;
1135
1136 switch (state_) {
1137 case INITIALIZED:
1138 case INIT_TASK_SCHEDULED: // We should be further along by now.
1139 DCHECK(false);
1140 return;
1141
1142 case INIT_TASK_DONE:
1143 // We need to wait for the initial log to be ready before sending
1144 // anything, because the server will tell us whether it wants to hear
1145 // from us.
1146 PrepareInitialLog();
[email protected]ed0fd002012-04-25 23:10:341147 DCHECK_EQ(INIT_TASK_DONE, state_);
[email protected]29948262012-03-01 12:15:081148 log_manager_.LoadPersistedUnsentLogs();
1149 state_ = INITIAL_LOG_READY;
1150 break;
1151
1152 case SENDING_OLD_LOGS:
1153 if (log_manager_.has_unsent_logs()) {
1154 log_manager_.StageNextLogForUpload();
1155 break;
1156 }
1157 state_ = SENDING_CURRENT_LOGS;
1158 // Fall through.
1159
1160 case SENDING_CURRENT_LOGS:
1161 StopRecording();
1162 StartRecording();
1163 log_manager_.StageNextLogForUpload();
1164 break;
1165
1166 default:
1167 NOTREACHED();
1168 return;
1169 }
1170
1171 DCHECK(log_manager_.has_staged_log());
1172}
1173
1174void MetricsService::PrepareInitialLog() {
[email protected]ed0fd002012-04-25 23:10:341175 DCHECK_EQ(INIT_TASK_DONE, state_);
[email protected]29948262012-03-01 12:15:081176
[email protected]ed0fd002012-04-25 23:10:341177 DCHECK(initial_log_.get());
1178 initial_log_->set_hardware_class(hardware_class_);
[email protected]197c0772012-05-14 23:50:511179 initial_log_->RecordEnvironment(plugins_, google_update_metrics_,
1180 profile_dictionary_.get());
[email protected]29948262012-03-01 12:15:081181
1182 // Histograms only get written to the current log, so make the new log current
1183 // before writing them.
1184 log_manager_.PauseCurrentLog();
[email protected]ed0fd002012-04-25 23:10:341185 log_manager_.BeginLoggingWithLog(initial_log_.release(),
1186 MetricsLogManager::INITIAL_LOG);
[email protected]29948262012-03-01 12:15:081187 RecordCurrentHistograms();
1188 log_manager_.FinishCurrentLog();
1189 log_manager_.ResumePausedLog();
1190
1191 DCHECK(!log_manager_.has_staged_log());
1192 log_manager_.StageNextLogForUpload();
1193}
1194
1195void MetricsService::StoreUnsentLogs() {
1196 if (state_ < INITIAL_LOG_READY)
1197 return; // We never Recalled the prior unsent logs.
1198
1199 log_manager_.PersistUnsentLogs();
1200}
1201
1202void MetricsService::SendStagedLog() {
1203 DCHECK(log_manager_.has_staged_log());
1204
[email protected]cac267c2011-09-29 15:18:101205 PrepareFetchWithStagedLog();
[email protected]d01b8732008-10-16 02:18:071206
[email protected]fe58acc22012-02-29 01:29:581207 if (!current_fetch_xml_.get()) {
1208 DCHECK(!current_fetch_proto_.get());
[email protected]d01b8732008-10-16 02:18:071209 // Compression failed, and log discarded :-/.
[email protected]cac267c2011-09-29 15:18:101210 log_manager_.DiscardStagedLog();
[email protected]7f7f1962011-04-20 15:58:161211 scheduler_->UploadCancelled();
[email protected]d01b8732008-10-16 02:18:071212 // TODO(jar): If compression failed, we should have created a tiny log and
1213 // compressed that, so that we can signal that we're losing logs.
1214 return;
1215 }
[email protected]fe58acc22012-02-29 01:29:581216 // Currently, the staged log for the protobuf version of the data is discarded
1217 // after we create the URL request, so that there is no chance for
1218 // re-transmission in case the corresponding XML request fails. We will
1219 // handle protobuf failures more carefully once that becomes the main
1220 // pipeline, i.e. once we switch away from the XML pipeline.
1221 DCHECK(current_fetch_proto_.get() || !log_manager_.has_staged_log_proto());
[email protected]d01b8732008-10-16 02:18:071222
[email protected]7f7f1962011-04-20 15:58:161223 DCHECK(!waiting_for_asynchronus_reporting_step_);
[email protected]d01b8732008-10-16 02:18:071224
[email protected]7f7f1962011-04-20 15:58:161225 waiting_for_asynchronus_reporting_step_ = true;
[email protected]fe58acc22012-02-29 01:29:581226 current_fetch_xml_->Start();
1227 if (current_fetch_proto_.get())
1228 current_fetch_proto_->Start();
[email protected]d01b8732008-10-16 02:18:071229
1230 HandleIdleSinceLastTransmission(true);
1231}
1232
[email protected]cac267c2011-09-29 15:18:101233void MetricsService::PrepareFetchWithStagedLog() {
1234 DCHECK(!log_manager_.staged_log_text().empty());
[email protected]cac78842008-11-27 01:02:201235
[email protected]fe58acc22012-02-29 01:29:581236 // Prepare the XML version.
1237 DCHECK(!current_fetch_xml_.get());
1238 current_fetch_xml_.reset(content::URLFetcher::Create(
[email protected]d3ec669b2012-05-23 07:12:141239 GURL(server_url_xml_), net::URLFetcher::POST, this));
[email protected]fe58acc22012-02-29 01:29:581240 current_fetch_xml_->SetRequestContext(
[email protected]8ef3d8052011-07-22 09:03:001241 g_browser_process->system_request_context());
[email protected]448ca4d2012-05-09 19:53:121242 current_fetch_xml_->SetUploadData(kMimeTypeXml,
[email protected]fe58acc22012-02-29 01:29:581243 log_manager_.staged_log_text().xml);
1244 // We already drop cookies server-side, but we might as well strip them out
1245 // client-side as well.
1246 current_fetch_xml_->SetLoadFlags(net::LOAD_DO_NOT_SAVE_COOKIES |
1247 net::LOAD_DO_NOT_SEND_COOKIES);
1248
1249 // Prepare the protobuf version.
1250 DCHECK(!current_fetch_proto_.get());
1251 if (log_manager_.has_staged_log_proto()) {
1252 current_fetch_proto_.reset(content::URLFetcher::Create(
[email protected]d3ec669b2012-05-23 07:12:141253 GURL(server_url_proto_), net::URLFetcher::POST, this));
[email protected]fe58acc22012-02-29 01:29:581254 current_fetch_proto_->SetRequestContext(
1255 g_browser_process->system_request_context());
[email protected]448ca4d2012-05-09 19:53:121256 current_fetch_proto_->SetUploadData(kMimeTypeProto,
[email protected]fe58acc22012-02-29 01:29:581257 log_manager_.staged_log_text().proto);
1258 // We already drop cookies server-side, but we might as well strip them out
1259 // client-side as well.
1260 current_fetch_proto_->SetLoadFlags(net::LOAD_DO_NOT_SAVE_COOKIES |
1261 net::LOAD_DO_NOT_SEND_COOKIES);
1262
1263 // Discard the protobuf version of the staged log, so that we will avoid
1264 // re-uploading it even if we need to re-upload the XML version.
1265 // TODO(isherman): Handle protobuf upload failures more gracefully once we
1266 // transition away from the XML-based pipeline.
1267 log_manager_.DiscardStagedLogProto();
1268 }
initial.commit09911bf2008-07-26 23:55:291269}
1270
[email protected]f90bf0d92011-01-13 02:12:441271static const char* StatusToString(const net::URLRequestStatus& status) {
initial.commit09911bf2008-07-26 23:55:291272 switch (status.status()) {
[email protected]f90bf0d92011-01-13 02:12:441273 case net::URLRequestStatus::SUCCESS:
initial.commit09911bf2008-07-26 23:55:291274 return "SUCCESS";
1275
[email protected]f90bf0d92011-01-13 02:12:441276 case net::URLRequestStatus::IO_PENDING:
initial.commit09911bf2008-07-26 23:55:291277 return "IO_PENDING";
1278
[email protected]f90bf0d92011-01-13 02:12:441279 case net::URLRequestStatus::HANDLED_EXTERNALLY:
initial.commit09911bf2008-07-26 23:55:291280 return "HANDLED_EXTERNALLY";
1281
[email protected]f90bf0d92011-01-13 02:12:441282 case net::URLRequestStatus::CANCELED:
initial.commit09911bf2008-07-26 23:55:291283 return "CANCELED";
1284
[email protected]f90bf0d92011-01-13 02:12:441285 case net::URLRequestStatus::FAILED:
initial.commit09911bf2008-07-26 23:55:291286 return "FAILED";
1287
1288 default:
[email protected]a063c102010-07-22 22:20:191289 NOTREACHED();
initial.commit09911bf2008-07-26 23:55:291290 return "Unknown";
1291 }
1292}
1293
[email protected]fe58acc22012-02-29 01:29:581294// We need to wait for two responses: the response to the XML upload, and the
1295// response to the protobuf upload. For now, only the XML upload's response
1296// affects decisions like whether to retry the upload, whether to abandon the
1297// upload because it is too large, etc. However, we still need to wait for the
1298// protobuf upload, as we cannot reset |current_fetch_proto_| until we have
1299// confirmation that the network request was sent; and the easiest way to do
1300// that is to wait for the response. In case the XML upload's response arrives
1301// first, we cache that response until the protobuf upload's response also
1302// arrives.
1303//
1304// Note that if the XML upload succeeds but the protobuf upload fails, we will
1305// not retry the protobuf upload. If the XML upload fails while the protobuf
1306// upload succeeds, we will still avoid re-uploading the protobuf data because
1307// we "zap" the data after the first upload attempt. This means that we might
1308// lose protobuf uploads when XML ones succeed; but we will never duplicate any
1309// protobuf uploads. Protobuf failures should be rare enough to where this
1310// should be ok while we have the two pipelines running in parallel.
[email protected]10c2d692012-05-11 05:32:231311void MetricsService::OnURLFetchComplete(const net::URLFetcher* source) {
[email protected]7f7f1962011-04-20 15:58:161312 DCHECK(waiting_for_asynchronus_reporting_step_);
[email protected]fe58acc22012-02-29 01:29:581313
1314 // We're not allowed to re-use the existing |URLFetcher|s, so free them here.
[email protected]4266def22012-05-17 01:02:401315 // Note however that |source| is aliased to one of these, so we should be
1316 // careful not to delete it too early.
[email protected]15fb2aa2012-05-22 22:52:591317 scoped_ptr<net::URLFetcher> s;
[email protected]fe58acc22012-02-29 01:29:581318 if (source == current_fetch_xml_.get()) {
1319 s.reset(current_fetch_xml_.release());
1320
1321 // Cache the XML responses, in case we still need to wait for the protobuf
1322 // response.
1323 response_code_ = source->GetResponseCode();
1324 response_status_ = StatusToString(source->GetStatus());
1325 source->GetResponseAsString(&response_data_);
[email protected]4266def22012-05-17 01:02:401326
1327 // Log a histogram to track response success vs. failure rates.
1328 UMA_HISTOGRAM_ENUMERATION("UMA.UploadResponseStatus.XML",
1329 ResponseCodeToStatus(response_code_),
1330 NUM_RESPONSE_STATUSES);
[email protected]fe58acc22012-02-29 01:29:581331 } else if (source == current_fetch_proto_.get()) {
1332 s.reset(current_fetch_proto_.release());
[email protected]4266def22012-05-17 01:02:401333
1334 // Log a histogram to track response success vs. failure rates.
1335 UMA_HISTOGRAM_ENUMERATION("UMA.UploadResponseStatus.Protobuf",
1336 ResponseCodeToStatus(source->GetResponseCode()),
1337 NUM_RESPONSE_STATUSES);
[email protected]fe58acc22012-02-29 01:29:581338 } else {
1339 NOTREACHED();
1340 return;
1341 }
1342
1343 // If we're still waiting for one of the responses, keep waiting...
1344 if (current_fetch_xml_.get() || current_fetch_proto_.get())
1345 return;
1346
1347 // We should only be able to reach here once we've received responses to both
1348 // the XML and the protobuf requests. We should always have the response code
1349 // available.
[email protected]6b44e9b52012-03-27 07:46:191350 DCHECK_NE(response_code_, kNoResponseCode);
[email protected]7f7f1962011-04-20 15:58:161351 waiting_for_asynchronus_reporting_step_ = false;
[email protected]fe58acc22012-02-29 01:29:581352
[email protected]e7508d82012-05-03 15:59:531353 // If the upload was provisionally stored, drop it now that the upload is
1354 // known to have gone through.
1355 log_manager_.DiscardLastProvisionalStore();
initial.commit09911bf2008-07-26 23:55:291356
1357 // Confirm send so that we can move on.
[email protected]4266def22012-05-17 01:02:401358 VLOG(1) << "Metrics response code: " << response_code_
[email protected]fe58acc22012-02-29 01:29:581359 << " status=" << response_status_;
[email protected]252873ef2008-08-04 21:59:451360
[email protected]fe58acc22012-02-29 01:29:581361 bool upload_succeeded = response_code_ == 200;
[email protected]7f7f1962011-04-20 15:58:161362
[email protected]0eb34fee2009-01-21 08:04:381363 // Provide boolean for error recovery (allow us to ignore response_code).
[email protected]dc6f4962009-02-13 01:25:501364 bool discard_log = false;
[email protected]0eb34fee2009-01-21 08:04:381365
[email protected]7f7f1962011-04-20 15:58:161366 if (!upload_succeeded &&
[email protected]fe58acc22012-02-29 01:29:581367 log_manager_.staged_log_text().xml.length() >
1368 kUploadLogAvoidRetransmitSize) {
[email protected]cac267c2011-09-29 15:18:101369 UMA_HISTOGRAM_COUNTS(
1370 "UMA.Large Rejected Log was Discarded",
[email protected]fe58acc22012-02-29 01:29:581371 static_cast<int>(log_manager_.staged_log_text().xml.length()));
[email protected]0eb34fee2009-01-21 08:04:381372 discard_log = true;
[email protected]fe58acc22012-02-29 01:29:581373 } else if (response_code_ == 400) {
[email protected]0eb34fee2009-01-21 08:04:381374 // Bad syntax. Retransmission won't work.
[email protected]0eb34fee2009-01-21 08:04:381375 discard_log = true;
[email protected]68475e602008-08-22 03:21:151376 }
1377
[email protected]7f7f1962011-04-20 15:58:161378 if (!upload_succeeded && !discard_log) {
[email protected]4266def22012-05-17 01:02:401379 VLOG(1) << "Metrics: transmission attempt returned a failure code: "
[email protected]fe58acc22012-02-29 01:29:581380 << response_code_ << ". Verify network connectivity";
[email protected]7f7f1962011-04-20 15:58:161381 LogBadResponseCode();
[email protected]0eb34fee2009-01-21 08:04:381382 } else { // Successful receipt (or we are discarding log).
[email protected]4266def22012-05-17 01:02:401383 VLOG(1) << "Metrics response data: " << response_data_;
initial.commit09911bf2008-07-26 23:55:291384 switch (state_) {
1385 case INITIAL_LOG_READY:
[email protected]cac267c2011-09-29 15:18:101386 state_ = SENDING_OLD_LOGS;
initial.commit09911bf2008-07-26 23:55:291387 break;
1388
initial.commit09911bf2008-07-26 23:55:291389 case SENDING_OLD_LOGS:
[email protected]d53e2232011-06-30 15:54:571390 // Store the updated list to disk now that the removed log is uploaded.
initial.commit09911bf2008-07-26 23:55:291391 StoreUnsentLogs();
1392 break;
1393
1394 case SENDING_CURRENT_LOGS:
1395 break;
1396
1397 default:
[email protected]a063c102010-07-22 22:20:191398 NOTREACHED();
initial.commit09911bf2008-07-26 23:55:291399 break;
1400 }
[email protected]d01b8732008-10-16 02:18:071401
[email protected]cac267c2011-09-29 15:18:101402 log_manager_.DiscardStagedLog();
[email protected]252873ef2008-08-04 21:59:451403
[email protected]cac267c2011-09-29 15:18:101404 if (log_manager_.has_unsent_logs())
[email protected]ed0fd002012-04-25 23:10:341405 DCHECK_LT(state_, SENDING_CURRENT_LOGS);
initial.commit09911bf2008-07-26 23:55:291406 }
[email protected]252873ef2008-08-04 21:59:451407
[email protected]7f7f1962011-04-20 15:58:161408 // Error 400 indicates a problem with the log, not with the server, so
1409 // don't consider that a sign that the server is in trouble.
[email protected]fe58acc22012-02-29 01:29:581410 bool server_is_healthy = upload_succeeded || response_code_ == 400;
[email protected]7f7f1962011-04-20 15:58:161411
[email protected]cac267c2011-09-29 15:18:101412 scheduler_->UploadFinished(server_is_healthy,
1413 log_manager_.has_unsent_logs());
[email protected]d67d1052011-06-09 05:11:411414
1415 // Collect network stats if UMA upload succeeded.
[email protected]b8ddb052012-04-19 02:36:061416 IOThread* io_thread = g_browser_process->io_thread();
1417 if (server_is_healthy && io_thread) {
1418 chrome_browser_net::CollectNetworkStats(network_stats_server_, io_thread);
[email protected]adbb3762012-03-09 22:20:081419 chrome_browser_net::CollectPipeliningCapabilityStatsOnUIThread(
[email protected]b8ddb052012-04-19 02:36:061420 http_pipelining_test_server_, io_thread);
[email protected]adbb3762012-03-09 22:20:081421 }
[email protected]fe58acc22012-02-29 01:29:581422
1423 // Reset the cached response data.
[email protected]6b44e9b52012-03-27 07:46:191424 response_code_ = kNoResponseCode;
[email protected]fe58acc22012-02-29 01:29:581425 response_data_ = std::string();
1426 response_status_ = std::string();
initial.commit09911bf2008-07-26 23:55:291427}
1428
[email protected]7f7f1962011-04-20 15:58:161429void MetricsService::LogBadResponseCode() {
[email protected]666205032010-10-21 20:56:581430 VLOG(1) << "Verify your metrics logs are formatted correctly. Verify server "
[email protected]fe58acc22012-02-29 01:29:581431 "is active at " << server_url_xml_;
[email protected]cac267c2011-09-29 15:18:101432 if (!log_manager_.has_staged_log()) {
[email protected]666205032010-10-21 20:56:581433 VLOG(1) << "METRICS: Recorder shutdown during log transmission.";
[email protected]252873ef2008-08-04 21:59:451434 } else {
[email protected]7f7f1962011-04-20 15:58:161435 VLOG(1) << "METRICS: transmission retry being scheduled for "
[email protected]fe58acc22012-02-29 01:29:581436 << log_manager_.staged_log_text().xml;
initial.commit09911bf2008-07-26 23:55:291437 }
initial.commit09911bf2008-07-26 23:55:291438}
1439
[email protected]6c2381d2011-10-19 02:52:531440void MetricsService::LogWindowChange(
1441 int type,
1442 const content::NotificationSource& source,
1443 const content::NotificationDetails& details) {
[email protected]534e54b2008-08-13 15:40:091444 int controller_id = -1;
1445 uintptr_t window_or_tab = source.map_key();
initial.commit09911bf2008-07-26 23:55:291446 MetricsLog::WindowEventType window_type;
1447
1448 // Note: since we stop all logging when a single OTR session is active, it is
1449 // possible that we start getting notifications about a window that we don't
1450 // know about.
[email protected]534e54b2008-08-13 15:40:091451 if (window_map_.find(window_or_tab) == window_map_.end()) {
1452 controller_id = next_window_id_++;
1453 window_map_[window_or_tab] = controller_id;
initial.commit09911bf2008-07-26 23:55:291454 } else {
[email protected]534e54b2008-08-13 15:40:091455 controller_id = window_map_[window_or_tab];
initial.commit09911bf2008-07-26 23:55:291456 }
[email protected]92745242009-06-12 16:52:211457 DCHECK_NE(controller_id, -1);
initial.commit09911bf2008-07-26 23:55:291458
[email protected]432115822011-07-10 15:52:271459 switch (type) {
[email protected]884033e2012-04-16 19:38:421460 case chrome::NOTIFICATION_TAB_PARENTED:
[email protected]432115822011-07-10 15:52:271461 case chrome::NOTIFICATION_BROWSER_OPENED:
initial.commit09911bf2008-07-26 23:55:291462 window_type = MetricsLog::WINDOW_CREATE;
1463 break;
1464
[email protected]884033e2012-04-16 19:38:421465 case chrome::NOTIFICATION_TAB_CLOSING:
[email protected]432115822011-07-10 15:52:271466 case chrome::NOTIFICATION_BROWSER_CLOSED:
[email protected]534e54b2008-08-13 15:40:091467 window_map_.erase(window_map_.find(window_or_tab));
initial.commit09911bf2008-07-26 23:55:291468 window_type = MetricsLog::WINDOW_DESTROY;
1469 break;
1470
1471 default:
[email protected]a063c102010-07-22 22:20:191472 NOTREACHED();
[email protected]68d74f02009-02-13 01:36:501473 return;
initial.commit09911bf2008-07-26 23:55:291474 }
1475
[email protected]534e54b2008-08-13 15:40:091476 // TODO(brettw) we should have some kind of ID for the parent.
[email protected]cac267c2011-09-29 15:18:101477 log_manager_.current_log()->RecordWindowEvent(window_type, controller_id, 0);
initial.commit09911bf2008-07-26 23:55:291478}
1479
[email protected]6c2381d2011-10-19 02:52:531480void MetricsService::LogLoadComplete(
1481 int type,
1482 const content::NotificationSource& source,
1483 const content::NotificationDetails& details) {
[email protected]ad50def52011-10-19 23:17:071484 if (details == content::NotificationService::NoDetails())
initial.commit09911bf2008-07-26 23:55:291485 return;
1486
[email protected]68475e602008-08-22 03:21:151487 // TODO(jar): There is a bug causing this to be called too many times, and
1488 // the log overflows. For now, we won't record these events.
[email protected]553dba62009-02-24 19:08:231489 UMA_HISTOGRAM_COUNTS("UMA.LogLoadComplete called", 1);
[email protected]68475e602008-08-22 03:21:151490 return;
1491
[email protected]6c2381d2011-10-19 02:52:531492 const content::Details<LoadNotificationDetails> load_details(details);
[email protected]534e54b2008-08-13 15:40:091493 int controller_id = window_map_[details.map_key()];
[email protected]cac267c2011-09-29 15:18:101494 log_manager_.current_log()->RecordLoadEvent(controller_id,
[email protected]09d31d52012-03-11 22:30:271495 load_details->url,
1496 load_details->origin,
1497 load_details->session_index,
1498 load_details->load_time);
initial.commit09911bf2008-07-26 23:55:291499}
1500
[email protected]57ecc4b2010-08-11 03:02:511501void MetricsService::IncrementPrefValue(const char* path) {
[email protected]e73c01972008-08-13 00:18:241502 PrefService* pref = g_browser_process->local_state();
1503 DCHECK(pref);
1504 int value = pref->GetInteger(path);
1505 pref->SetInteger(path, value + 1);
1506}
1507
[email protected]57ecc4b2010-08-11 03:02:511508void MetricsService::IncrementLongPrefsValue(const char* path) {
[email protected]0bb1a622009-03-04 03:22:321509 PrefService* pref = g_browser_process->local_state();
1510 DCHECK(pref);
1511 int64 value = pref->GetInt64(path);
[email protected]b42c5e42010-06-03 20:43:251512 pref->SetInt64(path, value + 1);
[email protected]0bb1a622009-03-04 03:22:321513}
1514
initial.commit09911bf2008-07-26 23:55:291515void MetricsService::LogLoadStarted() {
[email protected]dd8d12a2011-09-02 02:10:151516 HISTOGRAM_ENUMERATION("Chrome.UmaPageloadCounter", 1, 2);
[email protected]e73c01972008-08-13 00:18:241517 IncrementPrefValue(prefs::kStabilityPageLoadCount);
[email protected]0bb1a622009-03-04 03:22:321518 IncrementLongPrefsValue(prefs::kUninstallMetricsPageLoadCount);
[email protected]0b33f80b2008-12-17 21:34:361519 // We need to save the prefs, as page load count is a critical stat, and it
1520 // might be lost due to a crash :-(.
initial.commit09911bf2008-07-26 23:55:291521}
1522
[email protected]c3721482012-03-23 16:21:481523void MetricsService::LogRendererCrash(content::RenderProcessHost* host,
1524 base::TerminationStatus status,
1525 bool was_alive) {
[email protected]f3b1a082011-11-18 00:34:301526 Profile* profile = Profile::FromBrowserContext(host->GetBrowserContext());
[email protected]6f371442011-11-09 06:45:461527 ExtensionService* service = profile->GetExtensionService();
1528 bool was_extension_process =
[email protected]f3b1a082011-11-18 00:34:301529 service && service->process_map()->Contains(host->GetID());
[email protected]c3721482012-03-23 16:21:481530 if (status == base::TERMINATION_STATUS_PROCESS_CRASHED ||
1531 status == base::TERMINATION_STATUS_ABNORMAL_TERMINATION) {
1532 if (was_extension_process)
[email protected]718eab62011-10-05 21:16:521533 IncrementPrefValue(prefs::kStabilityExtensionRendererCrashCount);
[email protected]c3721482012-03-23 16:21:481534 else
[email protected]718eab62011-10-05 21:16:521535 IncrementPrefValue(prefs::kStabilityRendererCrashCount);
initial.commit09911bf2008-07-26 23:55:291536
[email protected]718eab62011-10-05 21:16:521537 UMA_HISTOGRAM_PERCENTAGE("BrowserRenderProcessHost.ChildCrashes",
1538 was_extension_process ? 2 : 1);
[email protected]c3721482012-03-23 16:21:481539 if (was_alive) {
[email protected]718eab62011-10-05 21:16:521540 UMA_HISTOGRAM_PERCENTAGE("BrowserRenderProcessHost.ChildCrashesWasAlive",
1541 was_extension_process ? 2 : 1);
1542 }
[email protected]c3721482012-03-23 16:21:481543 } else if (status == base::TERMINATION_STATUS_PROCESS_WAS_KILLED) {
[email protected]718eab62011-10-05 21:16:521544 UMA_HISTOGRAM_PERCENTAGE("BrowserRenderProcessHost.ChildKills",
1545 was_extension_process ? 2 : 1);
[email protected]c3721482012-03-23 16:21:481546 if (was_alive) {
[email protected]718eab62011-10-05 21:16:521547 UMA_HISTOGRAM_PERCENTAGE("BrowserRenderProcessHost.ChildKillsWasAlive",
1548 was_extension_process ? 2 : 1);
1549 }
1550 }
[email protected]1f085622009-12-04 05:33:451551}
1552
initial.commit09911bf2008-07-26 23:55:291553void MetricsService::LogRendererHang() {
[email protected]e73c01972008-08-13 00:18:241554 IncrementPrefValue(prefs::kStabilityRendererHangCount);
initial.commit09911bf2008-07-26 23:55:291555}
1556
[email protected]c0c55e92011-09-10 18:47:301557void MetricsService::LogNeedForCleanShutdown() {
1558 PrefService* pref = g_browser_process->local_state();
1559 pref->SetBoolean(prefs::kStabilityExitedCleanly, false);
1560 // Redundant setting to be sure we call for a clean shutdown.
1561 clean_shutdown_status_ = NEED_TO_SHUTDOWN;
1562}
1563
1564bool MetricsService::UmaMetricsProperlyShutdown() {
1565 CHECK(clean_shutdown_status_ == CLEANLY_SHUTDOWN ||
1566 clean_shutdown_status_ == NEED_TO_SHUTDOWN);
1567 return clean_shutdown_status_ == CLEANLY_SHUTDOWN;
1568}
1569
[email protected]67c4e952011-09-17 00:44:271570// For use in hack in LogCleanShutdown.
1571static void Signal(base::WaitableEvent* event) {
1572 event->Signal();
1573}
1574
[email protected]466f3c12011-03-23 21:20:381575void MetricsService::LogCleanShutdown() {
[email protected]acd55b32011-09-05 17:35:311576 // Redundant hack to write pref ASAP.
1577 PrefService* pref = g_browser_process->local_state();
1578 pref->SetBoolean(prefs::kStabilityExitedCleanly, true);
[email protected]fbe17c8a2011-12-27 16:41:481579 pref->CommitPendingWrite();
[email protected]67c4e952011-09-17 00:44:271580 // Hack: TBD: Remove this wait.
1581 // We are so concerned that the pref gets written, we are now willing to stall
1582 // the UI thread until we get assurance that a pref-writing task has
1583 // completed.
1584 base::WaitableEvent done_writing(false, false);
1585 BrowserThread::PostTask(BrowserThread::FILE, FROM_HERE,
[email protected]8454aeb2011-11-19 23:38:201586 base::Bind(Signal, &done_writing));
[email protected]3a7b66d2012-04-26 16:34:161587 // http://crbug.com/124954
1588 base::ThreadRestrictions::ScopedAllowWait allow_wait;
[email protected]67c4e952011-09-17 00:44:271589 done_writing.TimedWait(base::TimeDelta::FromHours(1));
1590
[email protected]c0c55e92011-09-10 18:47:301591 // Redundant setting to assure that we always reset this value at shutdown
1592 // (and that we don't use some alternate path, and not call LogCleanShutdown).
1593 clean_shutdown_status_ = CLEANLY_SHUTDOWN;
[email protected]acd55b32011-09-05 17:35:311594
[email protected]466f3c12011-03-23 21:20:381595 RecordBooleanPrefValue(prefs::kStabilityExitedCleanly, true);
1596}
1597
[email protected]c1834a92011-01-21 18:21:031598#if defined(OS_CHROMEOS)
1599void MetricsService::LogChromeOSCrash(const std::string &crash_type) {
1600 if (crash_type == "user")
1601 IncrementPrefValue(prefs::kStabilityOtherUserCrashCount);
1602 else if (crash_type == "kernel")
1603 IncrementPrefValue(prefs::kStabilityKernelCrashCount);
1604 else if (crash_type == "uncleanshutdown")
1605 IncrementPrefValue(prefs::kStabilitySystemUncleanShutdownCount);
1606 else
1607 NOTREACHED() << "Unexpected Chrome OS crash type " << crash_type;
1608 // Wake up metrics logs sending if necessary now that new
1609 // log data is available.
1610 HandleIdleSinceLastTransmission(false);
1611}
1612#endif // OS_CHROMEOS
1613
[email protected]a27a9382009-02-11 23:55:101614void MetricsService::LogChildProcessChange(
[email protected]432115822011-07-10 15:52:271615 int type,
[email protected]6c2381d2011-10-19 02:52:531616 const content::NotificationSource& source,
1617 const content::NotificationDetails& details) {
[email protected]4967f792012-01-20 22:14:401618 content::Details<ChildProcessData> child_details(details);
[email protected]4306c3792011-12-02 01:57:531619 const string16& child_name = child_details->name;
[email protected]0d84c5d2009-10-09 01:10:421620
[email protected]a27a9382009-02-11 23:55:101621 if (child_process_stats_buffer_.find(child_name) ==
1622 child_process_stats_buffer_.end()) {
[email protected]0d84c5d2009-10-09 01:10:421623 child_process_stats_buffer_[child_name] =
[email protected]4306c3792011-12-02 01:57:531624 ChildProcessStats(child_details->type);
initial.commit09911bf2008-07-26 23:55:291625 }
1626
[email protected]a27a9382009-02-11 23:55:101627 ChildProcessStats& stats = child_process_stats_buffer_[child_name];
[email protected]432115822011-07-10 15:52:271628 switch (type) {
1629 case content::NOTIFICATION_CHILD_PROCESS_HOST_CONNECTED:
initial.commit09911bf2008-07-26 23:55:291630 stats.process_launches++;
1631 break;
1632
[email protected]432115822011-07-10 15:52:271633 case content::NOTIFICATION_CHILD_INSTANCE_CREATED:
initial.commit09911bf2008-07-26 23:55:291634 stats.instances++;
1635 break;
1636
[email protected]432115822011-07-10 15:52:271637 case content::NOTIFICATION_CHILD_PROCESS_CRASHED:
initial.commit09911bf2008-07-26 23:55:291638 stats.process_crashes++;
[email protected]1f085622009-12-04 05:33:451639 // Exclude plugin crashes from the count below because we report them via
1640 // a separate UMA metric.
[email protected]4306c3792011-12-02 01:57:531641 if (!IsPluginProcess(child_details->type)) {
[email protected]1f085622009-12-04 05:33:451642 IncrementPrefValue(prefs::kStabilityChildProcessCrashCount);
1643 }
initial.commit09911bf2008-07-26 23:55:291644 break;
1645
1646 default:
[email protected]432115822011-07-10 15:52:271647 NOTREACHED() << "Unexpected notification type " << type;
initial.commit09911bf2008-07-26 23:55:291648 return;
1649 }
1650}
1651
1652// Recursively counts the number of bookmarks and folders in node.
[email protected]b3c33d462009-06-26 22:29:201653static void CountBookmarks(const BookmarkNode* node,
1654 int* bookmarks,
1655 int* folders) {
[email protected]0890e60e2011-06-27 14:55:211656 if (node->is_url())
initial.commit09911bf2008-07-26 23:55:291657 (*bookmarks)++;
1658 else
1659 (*folders)++;
[email protected]9c1a75a2011-03-10 02:38:121660 for (int i = 0; i < node->child_count(); ++i)
initial.commit09911bf2008-07-26 23:55:291661 CountBookmarks(node->GetChild(i), bookmarks, folders);
1662}
1663
[email protected]b3c33d462009-06-26 22:29:201664void MetricsService::LogBookmarks(const BookmarkNode* node,
[email protected]57ecc4b2010-08-11 03:02:511665 const char* num_bookmarks_key,
1666 const char* num_folders_key) {
initial.commit09911bf2008-07-26 23:55:291667 DCHECK(node);
1668 int num_bookmarks = 0;
1669 int num_folders = 0;
1670 CountBookmarks(node, &num_bookmarks, &num_folders);
1671 num_folders--; // Don't include the root folder in the count.
1672
1673 PrefService* pref = g_browser_process->local_state();
1674 DCHECK(pref);
1675 pref->SetInteger(num_bookmarks_key, num_bookmarks);
1676 pref->SetInteger(num_folders_key, num_folders);
1677}
1678
[email protected]d8e41ed2008-09-11 15:22:321679void MetricsService::LogBookmarks(BookmarkModel* model) {
initial.commit09911bf2008-07-26 23:55:291680 DCHECK(model);
[email protected]72bdcfe2011-07-22 17:21:581681 LogBookmarks(model->bookmark_bar_node(),
initial.commit09911bf2008-07-26 23:55:291682 prefs::kNumBookmarksOnBookmarkBar,
1683 prefs::kNumFoldersOnBookmarkBar);
1684 LogBookmarks(model->other_node(),
1685 prefs::kNumBookmarksInOtherBookmarkFolder,
1686 prefs::kNumFoldersInOtherBookmarkFolder);
1687 ScheduleNextStateSave();
1688}
1689
[email protected]604d8a062012-03-16 21:37:461690void MetricsService::LogKeywordCount(size_t keyword_count) {
initial.commit09911bf2008-07-26 23:55:291691 PrefService* pref = g_browser_process->local_state();
1692 DCHECK(pref);
[email protected]604d8a062012-03-16 21:37:461693 pref->SetInteger(prefs::kNumKeywords, static_cast<int>(keyword_count));
initial.commit09911bf2008-07-26 23:55:291694 ScheduleNextStateSave();
1695}
1696
1697void MetricsService::RecordPluginChanges(PrefService* pref) {
[email protected]f8628c22011-04-05 12:10:181698 ListPrefUpdate update(pref, prefs::kStabilityPluginStats);
1699 ListValue* plugins = update.Get();
initial.commit09911bf2008-07-26 23:55:291700 DCHECK(plugins);
1701
1702 for (ListValue::iterator value_iter = plugins->begin();
1703 value_iter != plugins->end(); ++value_iter) {
1704 if (!(*value_iter)->IsType(Value::TYPE_DICTIONARY)) {
[email protected]a063c102010-07-22 22:20:191705 NOTREACHED();
initial.commit09911bf2008-07-26 23:55:291706 continue;
1707 }
1708
1709 DictionaryValue* plugin_dict = static_cast<DictionaryValue*>(*value_iter);
[email protected]57ecc4b2010-08-11 03:02:511710 std::string plugin_name;
[email protected]8e50b602009-03-03 22:59:431711 plugin_dict->GetString(prefs::kStabilityPluginName, &plugin_name);
[email protected]6470ee8f2009-03-03 20:46:401712 if (plugin_name.empty()) {
[email protected]a063c102010-07-22 22:20:191713 NOTREACHED();
initial.commit09911bf2008-07-26 23:55:291714 continue;
1715 }
1716
[email protected]57ecc4b2010-08-11 03:02:511717 // TODO(viettrungluu): remove conversions
[email protected]68b9e72b2011-08-05 23:08:221718 string16 name16 = UTF8ToUTF16(plugin_name);
1719 if (child_process_stats_buffer_.find(name16) ==
1720 child_process_stats_buffer_.end()) {
initial.commit09911bf2008-07-26 23:55:291721 continue;
[email protected]68b9e72b2011-08-05 23:08:221722 }
initial.commit09911bf2008-07-26 23:55:291723
[email protected]68b9e72b2011-08-05 23:08:221724 ChildProcessStats stats = child_process_stats_buffer_[name16];
initial.commit09911bf2008-07-26 23:55:291725 if (stats.process_launches) {
1726 int launches = 0;
[email protected]8e50b602009-03-03 22:59:431727 plugin_dict->GetInteger(prefs::kStabilityPluginLaunches, &launches);
initial.commit09911bf2008-07-26 23:55:291728 launches += stats.process_launches;
[email protected]8e50b602009-03-03 22:59:431729 plugin_dict->SetInteger(prefs::kStabilityPluginLaunches, launches);
initial.commit09911bf2008-07-26 23:55:291730 }
1731 if (stats.process_crashes) {
1732 int crashes = 0;
[email protected]8e50b602009-03-03 22:59:431733 plugin_dict->GetInteger(prefs::kStabilityPluginCrashes, &crashes);
initial.commit09911bf2008-07-26 23:55:291734 crashes += stats.process_crashes;
[email protected]8e50b602009-03-03 22:59:431735 plugin_dict->SetInteger(prefs::kStabilityPluginCrashes, crashes);
initial.commit09911bf2008-07-26 23:55:291736 }
1737 if (stats.instances) {
1738 int instances = 0;
[email protected]8e50b602009-03-03 22:59:431739 plugin_dict->GetInteger(prefs::kStabilityPluginInstances, &instances);
initial.commit09911bf2008-07-26 23:55:291740 instances += stats.instances;
[email protected]8e50b602009-03-03 22:59:431741 plugin_dict->SetInteger(prefs::kStabilityPluginInstances, instances);
initial.commit09911bf2008-07-26 23:55:291742 }
1743
[email protected]68b9e72b2011-08-05 23:08:221744 child_process_stats_buffer_.erase(name16);
initial.commit09911bf2008-07-26 23:55:291745 }
1746
1747 // Now go through and add dictionaries for plugins that didn't already have
1748 // reports in Local State.
[email protected]68b9e72b2011-08-05 23:08:221749 for (std::map<string16, ChildProcessStats>::iterator cache_iter =
[email protected]a27a9382009-02-11 23:55:101750 child_process_stats_buffer_.begin();
1751 cache_iter != child_process_stats_buffer_.end(); ++cache_iter) {
[email protected]a27a9382009-02-11 23:55:101752 ChildProcessStats stats = cache_iter->second;
[email protected]0d84c5d2009-10-09 01:10:421753
1754 // Insert only plugins information into the plugins list.
[email protected]8d5f1dae2011-11-11 14:30:411755 if (!IsPluginProcess(stats.process_type))
[email protected]0d84c5d2009-10-09 01:10:421756 continue;
1757
[email protected]57ecc4b2010-08-11 03:02:511758 // TODO(viettrungluu): remove conversion
[email protected]68b9e72b2011-08-05 23:08:221759 std::string plugin_name = UTF16ToUTF8(cache_iter->first);
[email protected]0d84c5d2009-10-09 01:10:421760
initial.commit09911bf2008-07-26 23:55:291761 DictionaryValue* plugin_dict = new DictionaryValue;
1762
[email protected]8e50b602009-03-03 22:59:431763 plugin_dict->SetString(prefs::kStabilityPluginName, plugin_name);
1764 plugin_dict->SetInteger(prefs::kStabilityPluginLaunches,
initial.commit09911bf2008-07-26 23:55:291765 stats.process_launches);
[email protected]8e50b602009-03-03 22:59:431766 plugin_dict->SetInteger(prefs::kStabilityPluginCrashes,
initial.commit09911bf2008-07-26 23:55:291767 stats.process_crashes);
[email protected]8e50b602009-03-03 22:59:431768 plugin_dict->SetInteger(prefs::kStabilityPluginInstances,
initial.commit09911bf2008-07-26 23:55:291769 stats.instances);
1770 plugins->Append(plugin_dict);
1771 }
[email protected]a27a9382009-02-11 23:55:101772 child_process_stats_buffer_.clear();
initial.commit09911bf2008-07-26 23:55:291773}
1774
[email protected]6c2381d2011-10-19 02:52:531775bool MetricsService::CanLogNotification(
1776 int type,
1777 const content::NotificationSource& source,
1778 const content::NotificationDetails& details) {
[email protected]2c910b72011-03-08 21:16:321779 // We simply don't log anything to UMA if there is a single incognito
initial.commit09911bf2008-07-26 23:55:291780 // session visible. The problem is that we always notify using the orginal
1781 // profile in order to simplify notification processing.
1782 return !BrowserList::IsOffTheRecordSessionActive();
1783}
1784
[email protected]57ecc4b2010-08-11 03:02:511785void MetricsService::RecordBooleanPrefValue(const char* path, bool value) {
initial.commit09911bf2008-07-26 23:55:291786 DCHECK(IsSingleThreaded());
1787
1788 PrefService* pref = g_browser_process->local_state();
1789 DCHECK(pref);
1790
1791 pref->SetBoolean(path, value);
1792 RecordCurrentState(pref);
1793}
1794
1795void MetricsService::RecordCurrentState(PrefService* pref) {
[email protected]0bb1a622009-03-04 03:22:321796 pref->SetInt64(prefs::kStabilityLastTimestampSec, Time::Now().ToTimeT());
initial.commit09911bf2008-07-26 23:55:291797
1798 RecordPluginChanges(pref);
1799}
1800
[email protected]8d5f1dae2011-11-11 14:30:411801// static
[email protected]bd5d6cf2011-12-01 00:39:121802bool MetricsService::IsPluginProcess(content::ProcessType type) {
1803 return (type == content::PROCESS_TYPE_PLUGIN||
1804 type == content::PROCESS_TYPE_PPAPI_PLUGIN);
[email protected]8d5f1dae2011-11-11 14:30:411805}
1806
[email protected]5ccaa412009-11-13 22:00:161807#if defined(OS_CHROMEOS)
[email protected]29cf16772010-04-21 15:13:471808void MetricsService::StartExternalMetrics() {
[email protected]5ccaa412009-11-13 22:00:161809 external_metrics_ = new chromeos::ExternalMetrics;
[email protected]29cf16772010-04-21 15:13:471810 external_metrics_->Start();
[email protected]5ccaa412009-11-13 22:00:161811}
1812#endif
[email protected]3819f2ee2011-08-21 09:44:381813
1814// static
1815bool MetricsServiceHelper::IsMetricsReportingEnabled() {
1816 bool result = false;
1817 const PrefService* local_state = g_browser_process->local_state();
1818 if (local_state) {
1819 const PrefService::Preference* uma_pref =
1820 local_state->FindPreference(prefs::kMetricsReportingEnabled);
1821 if (uma_pref) {
1822 bool success = uma_pref->GetValue()->GetAsBoolean(&result);
1823 DCHECK(success);
1824 }
1825 }
1826 return result;
1827}