blob: a89c1f1d481239755fa7e0fdc9eb8a8fa098947d [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() {
[email protected]29d81ee02012-05-25 05:45:42468 // For metrics reporting-enabled users, we combine the client ID and low
469 // entropy source to get the final entropy source. Otherwise, only use the low
470 // entropy source.
471 // This has two useful properties:
[email protected]e61003a2012-05-24 17:03:19472 // 1) It makes the entropy source less identifiable for parties that do not
473 // know the low entropy source.
474 // 2) It makes the final entropy source resettable.
[email protected]29d81ee02012-05-25 05:45:42475 std::string low_entropy_source = base::IntToString(GetLowEntropySource());
476 if (reporting_active())
477 return client_id_ + low_entropy_source;
478 return low_entropy_source;
[email protected]e61003a2012-05-24 17:03:19479}
480
[email protected]5cbeeef72012-02-08 02:05:18481void MetricsService::ForceClientIdCreation() {
482 if (!client_id_.empty())
483 return;
484 PrefService* pref = g_browser_process->local_state();
485 client_id_ = pref->GetString(prefs::kMetricsClientID);
486 if (!client_id_.empty())
487 return;
488
489 client_id_ = GenerateClientID();
490 pref->SetString(prefs::kMetricsClientID, client_id_);
491
492 // Might as well make a note of how long this ID has existed
493 pref->SetString(prefs::kMetricsClientIDTimestamp,
494 base::Int64ToString(Time::Now().ToTimeT()));
495}
496
initial.commit09911bf2008-07-26 23:55:29497void MetricsService::SetRecording(bool enabled) {
498 DCHECK(IsSingleThreaded());
499
[email protected]d01b8732008-10-16 02:18:07500 if (enabled == recording_active_)
initial.commit09911bf2008-07-26 23:55:29501 return;
502
503 if (enabled) {
[email protected]5cbeeef72012-02-08 02:05:18504 ForceClientIdCreation();
[email protected]157d5472009-11-05 22:31:03505 child_process_logging::SetClientId(client_id_);
initial.commit09911bf2008-07-26 23:55:29506 StartRecording();
[email protected]005ef3e2009-05-22 20:55:46507
[email protected]3ffd3ae2011-03-17 22:17:52508 SetUpNotifications(&registrar_, this);
initial.commit09911bf2008-07-26 23:55:29509 } else {
[email protected]005ef3e2009-05-22 20:55:46510 registrar_.RemoveAll();
[email protected]cac267c2011-09-29 15:18:10511 PushPendingLogsToPersistentStorage();
512 DCHECK(!log_manager_.has_staged_log());
513 if (state_ > INITIAL_LOG_READY && log_manager_.has_unsent_logs())
514 state_ = SENDING_OLD_LOGS;
initial.commit09911bf2008-07-26 23:55:29515 }
[email protected]d01b8732008-10-16 02:18:07516 recording_active_ = enabled;
initial.commit09911bf2008-07-26 23:55:29517}
518
[email protected]d01b8732008-10-16 02:18:07519bool MetricsService::recording_active() const {
initial.commit09911bf2008-07-26 23:55:29520 DCHECK(IsSingleThreaded());
[email protected]d01b8732008-10-16 02:18:07521 return recording_active_;
initial.commit09911bf2008-07-26 23:55:29522}
523
[email protected]d01b8732008-10-16 02:18:07524void MetricsService::SetReporting(bool enable) {
525 if (reporting_active_ != enable) {
526 reporting_active_ = enable;
527 if (reporting_active_)
[email protected]7f7f1962011-04-20 15:58:16528 StartSchedulerIfNecessary();
initial.commit09911bf2008-07-26 23:55:29529 }
[email protected]d01b8732008-10-16 02:18:07530}
531
532bool MetricsService::reporting_active() const {
533 DCHECK(IsSingleThreaded());
534 return reporting_active_;
initial.commit09911bf2008-07-26 23:55:29535}
536
[email protected]87ef9ea2011-02-26 03:15:15537// static
[email protected]6c2381d2011-10-19 02:52:53538void MetricsService::SetUpNotifications(
539 content::NotificationRegistrar* registrar,
540 content::NotificationObserver* observer) {
541 registrar->Add(observer, chrome::NOTIFICATION_BROWSER_OPENED,
[email protected]ad50def52011-10-19 23:17:07542 content::NotificationService::AllBrowserContextsAndSources());
[email protected]6c2381d2011-10-19 02:52:53543 registrar->Add(observer, chrome::NOTIFICATION_BROWSER_CLOSED,
[email protected]ad50def52011-10-19 23:17:07544 content::NotificationService::AllSources());
[email protected]6c2381d2011-10-19 02:52:53545 registrar->Add(observer, content::NOTIFICATION_USER_ACTION,
[email protected]ad50def52011-10-19 23:17:07546 content::NotificationService::AllSources());
[email protected]884033e2012-04-16 19:38:42547 registrar->Add(observer, chrome::NOTIFICATION_TAB_PARENTED,
[email protected]ad50def52011-10-19 23:17:07548 content::NotificationService::AllSources());
[email protected]884033e2012-04-16 19:38:42549 registrar->Add(observer, chrome::NOTIFICATION_TAB_CLOSING,
[email protected]ad50def52011-10-19 23:17:07550 content::NotificationService::AllSources());
[email protected]6c2381d2011-10-19 02:52:53551 registrar->Add(observer, content::NOTIFICATION_LOAD_START,
[email protected]ad50def52011-10-19 23:17:07552 content::NotificationService::AllSources());
[email protected]6c2381d2011-10-19 02:52:53553 registrar->Add(observer, content::NOTIFICATION_LOAD_STOP,
[email protected]ad50def52011-10-19 23:17:07554 content::NotificationService::AllSources());
[email protected]6c2381d2011-10-19 02:52:53555 registrar->Add(observer, content::NOTIFICATION_RENDERER_PROCESS_CLOSED,
[email protected]ad50def52011-10-19 23:17:07556 content::NotificationService::AllSources());
[email protected]6c2381d2011-10-19 02:52:53557 registrar->Add(observer, content::NOTIFICATION_RENDERER_PROCESS_HANG,
[email protected]ad50def52011-10-19 23:17:07558 content::NotificationService::AllSources());
[email protected]6c2381d2011-10-19 02:52:53559 registrar->Add(observer, content::NOTIFICATION_CHILD_PROCESS_HOST_CONNECTED,
[email protected]ad50def52011-10-19 23:17:07560 content::NotificationService::AllSources());
[email protected]6c2381d2011-10-19 02:52:53561 registrar->Add(observer, content::NOTIFICATION_CHILD_INSTANCE_CREATED,
[email protected]ad50def52011-10-19 23:17:07562 content::NotificationService::AllSources());
[email protected]6c2381d2011-10-19 02:52:53563 registrar->Add(observer, content::NOTIFICATION_CHILD_PROCESS_CRASHED,
[email protected]ad50def52011-10-19 23:17:07564 content::NotificationService::AllSources());
[email protected]6c2381d2011-10-19 02:52:53565 registrar->Add(observer, chrome::NOTIFICATION_TEMPLATE_URL_SERVICE_LOADED,
[email protected]ad50def52011-10-19 23:17:07566 content::NotificationService::AllSources());
[email protected]6c2381d2011-10-19 02:52:53567 registrar->Add(observer, chrome::NOTIFICATION_OMNIBOX_OPENED_URL,
[email protected]ad50def52011-10-19 23:17:07568 content::NotificationService::AllSources());
[email protected]6c2381d2011-10-19 02:52:53569 registrar->Add(observer, chrome::NOTIFICATION_BOOKMARK_MODEL_LOADED,
[email protected]ad50def52011-10-19 23:17:07570 content::NotificationService::AllBrowserContextsAndSources());
[email protected]87ef9ea2011-02-26 03:15:15571}
572
[email protected]432115822011-07-10 15:52:27573void MetricsService::Observe(int type,
[email protected]6c2381d2011-10-19 02:52:53574 const content::NotificationSource& source,
575 const content::NotificationDetails& details) {
[email protected]cac267c2011-09-29 15:18:10576 DCHECK(log_manager_.current_log());
initial.commit09911bf2008-07-26 23:55:29577 DCHECK(IsSingleThreaded());
578
579 if (!CanLogNotification(type, source, details))
580 return;
581
[email protected]432115822011-07-10 15:52:27582 switch (type) {
583 case content::NOTIFICATION_USER_ACTION:
[email protected]cac267c2011-09-29 15:18:10584 log_manager_.current_log()->RecordUserAction(
[email protected]6c2381d2011-10-19 02:52:53585 *content::Details<const char*>(details).ptr());
initial.commit09911bf2008-07-26 23:55:29586 break;
587
[email protected]432115822011-07-10 15:52:27588 case chrome::NOTIFICATION_BROWSER_OPENED:
589 case chrome::NOTIFICATION_BROWSER_CLOSED:
initial.commit09911bf2008-07-26 23:55:29590 LogWindowChange(type, source, details);
591 break;
592
[email protected]884033e2012-04-16 19:38:42593 case chrome::NOTIFICATION_TAB_PARENTED:
594 case chrome::NOTIFICATION_TAB_CLOSING:
initial.commit09911bf2008-07-26 23:55:29595 LogWindowChange(type, source, details);
596 break;
597
[email protected]432115822011-07-10 15:52:27598 case content::NOTIFICATION_LOAD_STOP:
initial.commit09911bf2008-07-26 23:55:29599 LogLoadComplete(type, source, details);
600 break;
601
[email protected]432115822011-07-10 15:52:27602 case content::NOTIFICATION_LOAD_START:
initial.commit09911bf2008-07-26 23:55:29603 LogLoadStarted();
604 break;
605
[email protected]432115822011-07-10 15:52:27606 case content::NOTIFICATION_RENDERER_PROCESS_CLOSED: {
[email protected]f3b1a082011-11-18 00:34:30607 content::RenderProcessHost::RendererClosedDetails* process_details =
608 content::Details<
609 content::RenderProcessHost::RendererClosedDetails>(
610 details).ptr();
611 content::RenderProcessHost* host =
612 content::Source<content::RenderProcessHost>(source).ptr();
[email protected]c3721482012-03-23 16:21:48613 LogRendererCrash(
614 host, process_details->status, process_details->was_alive);
[email protected]1f085622009-12-04 05:33:45615 }
initial.commit09911bf2008-07-26 23:55:29616 break;
617
[email protected]432115822011-07-10 15:52:27618 case content::NOTIFICATION_RENDERER_PROCESS_HANG:
initial.commit09911bf2008-07-26 23:55:29619 LogRendererHang();
620 break;
621
[email protected]432115822011-07-10 15:52:27622 case content::NOTIFICATION_CHILD_PROCESS_HOST_CONNECTED:
623 case content::NOTIFICATION_CHILD_PROCESS_CRASHED:
624 case content::NOTIFICATION_CHILD_INSTANCE_CREATED:
[email protected]a27a9382009-02-11 23:55:10625 LogChildProcessChange(type, source, details);
initial.commit09911bf2008-07-26 23:55:29626 break;
627
[email protected]432115822011-07-10 15:52:27628 case chrome::NOTIFICATION_TEMPLATE_URL_SERVICE_LOADED:
[email protected]604d8a062012-03-16 21:37:46629 LogKeywordCount(content::Source<TemplateURLService>(
630 source)->GetTemplateURLs().size());
initial.commit09911bf2008-07-26 23:55:29631 break;
632
[email protected]432115822011-07-10 15:52:27633 case chrome::NOTIFICATION_OMNIBOX_OPENED_URL: {
[email protected]279703f2012-01-20 22:23:26634 MetricsLog* current_log =
635 static_cast<MetricsLog*>(log_manager_.current_log());
[email protected]1226abb2010-06-10 18:01:28636 DCHECK(current_log);
637 current_log->RecordOmniboxOpenedURL(
[email protected]6c2381d2011-10-19 02:52:53638 *content::Details<AutocompleteLog>(details).ptr());
initial.commit09911bf2008-07-26 23:55:29639 break;
[email protected]1226abb2010-06-10 18:01:28640 }
initial.commit09911bf2008-07-26 23:55:29641
[email protected]432115822011-07-10 15:52:27642 case chrome::NOTIFICATION_BOOKMARK_MODEL_LOADED: {
[email protected]6c2381d2011-10-19 02:52:53643 Profile* p = content::Source<Profile>(source).ptr();
[email protected]b61236c62009-04-09 22:43:55644 if (p)
645 LogBookmarks(p->GetBookmarkModel());
initial.commit09911bf2008-07-26 23:55:29646 break;
[email protected]b61236c62009-04-09 22:43:55647 }
initial.commit09911bf2008-07-26 23:55:29648 default:
[email protected]a063c102010-07-22 22:20:19649 NOTREACHED();
initial.commit09911bf2008-07-26 23:55:29650 break;
651 }
[email protected]d01b8732008-10-16 02:18:07652
653 HandleIdleSinceLastTransmission(false);
654
[email protected]cac267c2011-09-29 15:18:10655 if (log_manager_.current_log())
656 DVLOG(1) << "METRICS: NUMBER OF EVENTS = "
657 << log_manager_.current_log()->num_events();
[email protected]d01b8732008-10-16 02:18:07658}
659
660void MetricsService::HandleIdleSinceLastTransmission(bool in_idle) {
661 // If there wasn't a lot of action, maybe the computer was asleep, in which
662 // case, the log transmissions should have stopped. Here we start them up
663 // again.
[email protected]cac78842008-11-27 01:02:20664 if (!in_idle && idle_since_last_transmission_)
[email protected]7f7f1962011-04-20 15:58:16665 StartSchedulerIfNecessary();
[email protected]cac78842008-11-27 01:02:20666 idle_since_last_transmission_ = in_idle;
initial.commit09911bf2008-07-26 23:55:29667}
668
initial.commit09911bf2008-07-26 23:55:29669void MetricsService::RecordStartOfSessionEnd() {
[email protected]466f3c12011-03-23 21:20:38670 LogCleanShutdown();
initial.commit09911bf2008-07-26 23:55:29671 RecordBooleanPrefValue(prefs::kStabilitySessionEndCompleted, false);
672}
673
674void MetricsService::RecordCompletedSessionEnd() {
[email protected]466f3c12011-03-23 21:20:38675 LogCleanShutdown();
initial.commit09911bf2008-07-26 23:55:29676 RecordBooleanPrefValue(prefs::kStabilitySessionEndCompleted, true);
677}
678
[email protected]7f7f1962011-04-20 15:58:16679void MetricsService::RecordBreakpadRegistration(bool success) {
[email protected]68475e602008-08-22 03:21:15680 if (!success)
[email protected]e73c01972008-08-13 00:18:24681 IncrementPrefValue(prefs::kStabilityBreakpadRegistrationFail);
682 else
683 IncrementPrefValue(prefs::kStabilityBreakpadRegistrationSuccess);
684}
685
686void MetricsService::RecordBreakpadHasDebugger(bool has_debugger) {
687 if (!has_debugger)
688 IncrementPrefValue(prefs::kStabilityDebuggerNotPresent);
689 else
[email protected]68475e602008-08-22 03:21:15690 IncrementPrefValue(prefs::kStabilityDebuggerPresent);
[email protected]e73c01972008-08-13 00:18:24691}
692
initial.commit09911bf2008-07-26 23:55:29693//------------------------------------------------------------------------------
694// private methods
695//------------------------------------------------------------------------------
696
697
698//------------------------------------------------------------------------------
699// Initialization methods
700
701void MetricsService::InitializeMetricsState() {
[email protected]79bf0b72009-04-27 21:30:55702#if defined(OS_POSIX)
[email protected]fe58acc22012-02-29 01:29:58703 server_url_xml_ = ASCIIToUTF16(kServerUrlXml);
704 server_url_proto_ = ASCIIToUTF16(kServerUrlProto);
[email protected]b4a72d842012-03-22 20:09:09705 network_stats_server_ = chrome_common_net::kEchoTestServerLocation;
706 http_pipelining_test_server_ = chrome_common_net::kPipelineTestServerBaseUrl;
[email protected]79bf0b72009-04-27 21:30:55707#else
708 BrowserDistribution* dist = BrowserDistribution::GetDistribution();
[email protected]fe58acc22012-02-29 01:29:58709 server_url_xml_ = dist->GetStatsServerURL();
710 server_url_proto_ = ASCIIToUTF16(kServerUrlProto);
[email protected]d67d1052011-06-09 05:11:41711 network_stats_server_ = dist->GetNetworkStatsServer();
[email protected]adbb3762012-03-09 22:20:08712 http_pipelining_test_server_ = dist->GetHttpPipeliningTestServer();
[email protected]79bf0b72009-04-27 21:30:55713#endif
714
initial.commit09911bf2008-07-26 23:55:29715 PrefService* pref = g_browser_process->local_state();
716 DCHECK(pref);
717
[email protected]225c50842010-01-19 21:19:13718 if ((pref->GetInt64(prefs::kStabilityStatsBuildTime)
719 != MetricsLog::GetBuildTime()) ||
[email protected]ddd231e2010-06-29 20:35:19720 (pref->GetString(prefs::kStabilityStatsVersion)
[email protected]225c50842010-01-19 21:19:13721 != MetricsLog::GetVersionString())) {
[email protected]541f77922009-02-23 21:14:38722 // This is a new version, so we don't want to confuse the stats about the
723 // old version with info that we upload.
724 DiscardOldStabilityStats(pref);
725 pref->SetString(prefs::kStabilityStatsVersion,
[email protected]ddd231e2010-06-29 20:35:19726 MetricsLog::GetVersionString());
[email protected]225c50842010-01-19 21:19:13727 pref->SetInt64(prefs::kStabilityStatsBuildTime,
728 MetricsLog::GetBuildTime());
[email protected]541f77922009-02-23 21:14:38729 }
730
initial.commit09911bf2008-07-26 23:55:29731 // Update session ID
732 session_id_ = pref->GetInteger(prefs::kMetricsSessionID);
733 ++session_id_;
734 pref->SetInteger(prefs::kMetricsSessionID, session_id_);
735
initial.commit09911bf2008-07-26 23:55:29736 // Stability bookkeeping
[email protected]e73c01972008-08-13 00:18:24737 IncrementPrefValue(prefs::kStabilityLaunchCount);
initial.commit09911bf2008-07-26 23:55:29738
[email protected]e73c01972008-08-13 00:18:24739 if (!pref->GetBoolean(prefs::kStabilityExitedCleanly)) {
740 IncrementPrefValue(prefs::kStabilityCrashCount);
[email protected]c0c55e92011-09-10 18:47:30741 // Reset flag, and wait until we call LogNeedForCleanShutdown() before
742 // monitoring.
743 pref->SetBoolean(prefs::kStabilityExitedCleanly, true);
initial.commit09911bf2008-07-26 23:55:29744 }
[email protected]e73c01972008-08-13 00:18:24745
[email protected]e73c01972008-08-13 00:18:24746 if (!pref->GetBoolean(prefs::kStabilitySessionEndCompleted)) {
747 IncrementPrefValue(prefs::kStabilityIncompleteSessionEndCount);
[email protected]c9abf242009-07-18 06:00:38748 // This is marked false when we get a WM_ENDSESSION.
749 pref->SetBoolean(prefs::kStabilitySessionEndCompleted, true);
initial.commit09911bf2008-07-26 23:55:29750 }
initial.commit09911bf2008-07-26 23:55:29751
[email protected]9165f742010-03-10 22:55:01752 // Initialize uptime counters.
753 int64 startup_uptime = MetricsLog::GetIncrementalUptime(pref);
[email protected]ae393ec702010-06-27 16:23:14754 DCHECK_EQ(0, startup_uptime);
[email protected]9165f742010-03-10 22:55:01755 // For backwards compatibility, leave this intact in case Omaha is checking
756 // them. prefs::kStabilityLastTimestampSec may also be useless now.
757 // TODO(jar): Delete these if they have no uses.
[email protected]0bb1a622009-03-04 03:22:32758 pref->SetInt64(prefs::kStabilityLaunchTimeSec, Time::Now().ToTimeT());
759
760 // Bookkeeping for the uninstall metrics.
761 IncrementLongPrefsValue(prefs::kUninstallLaunchCount);
initial.commit09911bf2008-07-26 23:55:29762
763 // Save profile metrics.
764 PrefService* prefs = g_browser_process->local_state();
765 if (prefs) {
766 // Remove the current dictionary and store it for use when sending data to
767 // server. By removing the value we prune potentially dead profiles
768 // (and keys). All valid values are added back once services startup.
769 const DictionaryValue* profile_dictionary =
770 prefs->GetDictionary(prefs::kProfileMetrics);
771 if (profile_dictionary) {
772 // Do a deep copy of profile_dictionary since ClearPref will delete it.
773 profile_dictionary_.reset(static_cast<DictionaryValue*>(
774 profile_dictionary->DeepCopy()));
775 prefs->ClearPref(prefs::kProfileMetrics);
776 }
777 }
778
[email protected]92745242009-06-12 16:52:21779 // Get stats on use of command line.
780 const CommandLine* command_line(CommandLine::ForCurrentProcess());
781 size_t common_commands = 0;
782 if (command_line->HasSwitch(switches::kUserDataDir)) {
783 ++common_commands;
784 UMA_HISTOGRAM_COUNTS_100("Chrome.CommandLineDatDirCount", 1);
785 }
786
787 if (command_line->HasSwitch(switches::kApp)) {
788 ++common_commands;
789 UMA_HISTOGRAM_COUNTS_100("Chrome.CommandLineAppModeCount", 1);
790 }
791
[email protected]62b4e522011-07-13 21:46:32792 size_t switch_count = command_line->GetSwitches().size();
793 UMA_HISTOGRAM_COUNTS_100("Chrome.CommandLineFlagCount", switch_count);
[email protected]92745242009-06-12 16:52:21794 UMA_HISTOGRAM_COUNTS_100("Chrome.CommandLineUncommonFlagCount",
[email protected]62b4e522011-07-13 21:46:32795 switch_count - common_commands);
[email protected]92745242009-06-12 16:52:21796
initial.commit09911bf2008-07-26 23:55:29797 // Kick off the process of saving the state (so the uptime numbers keep
798 // getting updated) every n minutes.
799 ScheduleNextStateSave();
800}
801
[email protected]c94d7382012-02-28 08:43:40802// static
[email protected]d33e7cc2011-09-23 01:43:56803void MetricsService::InitTaskGetHardwareClass(
[email protected]c94d7382012-02-28 08:43:40804 base::WeakPtr<MetricsService> self,
[email protected]d33e7cc2011-09-23 01:43:56805 base::MessageLoopProxy* target_loop) {
[email protected]d33e7cc2011-09-23 01:43:56806 DCHECK(BrowserThread::CurrentlyOn(BrowserThread::FILE));
807
808 std::string hardware_class;
809#if defined(OS_CHROMEOS)
810 chromeos::system::StatisticsProvider::GetInstance()->GetMachineStatistic(
811 "hardware_class", &hardware_class);
812#endif // OS_CHROMEOS
813
814 target_loop->PostTask(FROM_HERE,
815 base::Bind(&MetricsService::OnInitTaskGotHardwareClass,
[email protected]c94d7382012-02-28 08:43:40816 self, hardware_class));
[email protected]d33e7cc2011-09-23 01:43:56817}
818
819void MetricsService::OnInitTaskGotHardwareClass(
820 const std::string& hardware_class) {
[email protected]ed0fd002012-04-25 23:10:34821 DCHECK_EQ(INIT_TASK_SCHEDULED, state_);
[email protected]85ed9d42010-06-08 22:37:44822 hardware_class_ = hardware_class;
[email protected]d33e7cc2011-09-23 01:43:56823
824 // Start the next part of the init task: loading plugin information.
825 PluginService::GetInstance()->GetPlugins(
826 base::Bind(&MetricsService::OnInitTaskGotPluginInfo,
[email protected]c94d7382012-02-28 08:43:40827 self_ptr_factory_.GetWeakPtr()));
[email protected]d33e7cc2011-09-23 01:43:56828}
829
830void MetricsService::OnInitTaskGotPluginInfo(
831 const std::vector<webkit::WebPluginInfo>& plugins) {
[email protected]ed0fd002012-04-25 23:10:34832 DCHECK_EQ(INIT_TASK_SCHEDULED, state_);
[email protected]35fa6a22009-08-15 00:04:01833 plugins_ = plugins;
[email protected]d33e7cc2011-09-23 01:43:56834
[email protected]197c0772012-05-14 23:50:51835 // Schedules a task on a blocking pool thread to gather Google Update
836 // statistics (requires Registry reads).
837 BrowserThread::PostBlockingPoolTask(
838 FROM_HERE,
839 base::Bind(&MetricsService::InitTaskGetGoogleUpdateData,
840 self_ptr_factory_.GetWeakPtr(),
841 MessageLoop::current()->message_loop_proxy()));
842}
843
844// static
845void MetricsService::InitTaskGetGoogleUpdateData(
846 base::WeakPtr<MetricsService> self,
847 base::MessageLoopProxy* target_loop) {
848 GoogleUpdateMetrics google_update_metrics;
849
850#if defined(OS_WIN) && defined(GOOGLE_CHROME_BUILD)
851 const bool system_install = GoogleUpdateSettings::IsSystemInstall();
852
853 google_update_metrics.is_system_install = system_install;
854 google_update_metrics.last_started_au =
855 GoogleUpdateSettings::GetGoogleUpdateLastStartedAU(system_install);
856 google_update_metrics.last_checked =
857 GoogleUpdateSettings::GetGoogleUpdateLastChecked(system_install);
858 GoogleUpdateSettings::GetUpdateDetailForGoogleUpdate(
859 system_install,
860 &google_update_metrics.google_update_data);
861 GoogleUpdateSettings::GetUpdateDetail(
862 system_install,
863 &google_update_metrics.product_data);
864#endif // defined(OS_WIN) && defined(GOOGLE_CHROME_BUILD)
865
866 target_loop->PostTask(FROM_HERE,
867 base::Bind(&MetricsService::OnInitTaskGotGoogleUpdateData,
868 self, google_update_metrics));
869}
870
871void MetricsService::OnInitTaskGotGoogleUpdateData(
872 const GoogleUpdateMetrics& google_update_metrics) {
873 DCHECK_EQ(INIT_TASK_SCHEDULED, state_);
874
875 google_update_metrics_ = google_update_metrics;
876
[email protected]ed0fd002012-04-25 23:10:34877 // Start the next part of the init task: fetching performance data. This will
878 // call into |FinishedReceivingProfilerData()| when the task completes.
879 chrome_browser_metrics::TrackingSynchronizer::FetchProfilerDataAsynchronously(
880 self_ptr_factory_.GetWeakPtr());
881}
882
883void MetricsService::ReceivedProfilerData(
884 const tracked_objects::ProcessDataSnapshot& process_data,
885 content::ProcessType process_type) {
886 DCHECK_EQ(INIT_TASK_SCHEDULED, state_);
887
888 // Upon the first callback, create the initial log so that we can immediately
889 // save the profiler data.
890 if (!initial_log_.get())
891 initial_log_.reset(new MetricsLog(client_id_, session_id_));
892
893 initial_log_->RecordProfilerData(process_data, process_type);
894}
895
896void MetricsService::FinishedReceivingProfilerData() {
897 DCHECK_EQ(INIT_TASK_SCHEDULED, state_);
[email protected]3a7b66d2012-04-26 16:34:16898 state_ = INIT_TASK_DONE;
initial.commit09911bf2008-07-26 23:55:29899}
900
[email protected]e61003a2012-05-24 17:03:19901int MetricsService::GetLowEntropySource() {
902 // Note that the default value for the low entropy source and the default pref
903 // value are both zero, which is used to identify if the value has been set
904 // or not. Valid values start at 1.
905 if (low_entropy_source_)
906 return low_entropy_source_;
907
908 PrefService* pref = g_browser_process->local_state();
909 const CommandLine* command_line(CommandLine::ForCurrentProcess());
910 // Only try to load the value from prefs if the user did not request a reset.
911 // Otherwise, skip to generating a new value.
912 if (!command_line->HasSwitch(switches::kResetVariationState)) {
913 low_entropy_source_ = pref->GetInteger(prefs::kMetricsLowEntropySource);
914 if (low_entropy_source_)
915 return low_entropy_source_;
916 }
917
918 low_entropy_source_ = GenerateLowEntropySource();
919 pref->SetInteger(prefs::kMetricsLowEntropySource, low_entropy_source_);
920
921 return low_entropy_source_;
922}
923
924// static
initial.commit09911bf2008-07-26 23:55:29925std::string MetricsService::GenerateClientID() {
[email protected]3469e7e2010-10-14 20:34:59926 return guid::GenerateGUID();
initial.commit09911bf2008-07-26 23:55:29927}
928
initial.commit09911bf2008-07-26 23:55:29929//------------------------------------------------------------------------------
930// State save methods
931
932void MetricsService::ScheduleNextStateSave() {
[email protected]8454aeb2011-11-19 23:38:20933 state_saver_factory_.InvalidateWeakPtrs();
initial.commit09911bf2008-07-26 23:55:29934
935 MessageLoop::current()->PostDelayedTask(FROM_HERE,
[email protected]8454aeb2011-11-19 23:38:20936 base::Bind(&MetricsService::SaveLocalState,
937 state_saver_factory_.GetWeakPtr()),
[email protected]fc4252a72012-01-12 21:58:47938 base::TimeDelta::FromMinutes(kSaveStateIntervalMinutes));
initial.commit09911bf2008-07-26 23:55:29939}
940
941void MetricsService::SaveLocalState() {
942 PrefService* pref = g_browser_process->local_state();
943 if (!pref) {
[email protected]a063c102010-07-22 22:20:19944 NOTREACHED();
initial.commit09911bf2008-07-26 23:55:29945 return;
946 }
947
948 RecordCurrentState(pref);
initial.commit09911bf2008-07-26 23:55:29949
[email protected]fc4252a72012-01-12 21:58:47950 // TODO(jar):110021 Does this run down the batteries????
initial.commit09911bf2008-07-26 23:55:29951 ScheduleNextStateSave();
952}
953
954
955//------------------------------------------------------------------------------
956// Recording control methods
957
958void MetricsService::StartRecording() {
[email protected]cac267c2011-09-29 15:18:10959 if (log_manager_.current_log())
initial.commit09911bf2008-07-26 23:55:29960 return;
961
[email protected]29948262012-03-01 12:15:08962 log_manager_.BeginLoggingWithLog(new MetricsLog(client_id_, session_id_),
963 MetricsLogManager::ONGOING_LOG);
initial.commit09911bf2008-07-26 23:55:29964 if (state_ == INITIALIZED) {
965 // We only need to schedule that run once.
[email protected]85ed9d42010-06-08 22:37:44966 state_ = INIT_TASK_SCHEDULED;
initial.commit09911bf2008-07-26 23:55:29967
[email protected]85ed9d42010-06-08 22:37:44968 // Schedules a task on the file thread for execution of slower
969 // initialization steps (such as plugin list generation) necessary
970 // for sending the initial log. This avoids blocking the main UI
971 // thread.
[email protected]ed10dd12011-12-07 12:03:42972 BrowserThread::PostDelayedTask(
973 BrowserThread::FILE,
974 FROM_HERE,
[email protected]d33e7cc2011-09-23 01:43:56975 base::Bind(&MetricsService::InitTaskGetHardwareClass,
[email protected]c94d7382012-02-28 08:43:40976 self_ptr_factory_.GetWeakPtr(),
[email protected]d33e7cc2011-09-23 01:43:56977 MessageLoop::current()->message_loop_proxy()),
[email protected]7e560102012-03-08 20:58:42978 base::TimeDelta::FromSeconds(kInitializationDelaySeconds));
initial.commit09911bf2008-07-26 23:55:29979 }
980}
981
[email protected]024b5cd2011-05-27 03:29:38982void MetricsService::StopRecording() {
[email protected]cac267c2011-09-29 15:18:10983 if (!log_manager_.current_log())
initial.commit09911bf2008-07-26 23:55:29984 return;
985
[email protected]68475e602008-08-22 03:21:15986 // TODO(jar): Integrate bounds on log recording more consistently, so that we
987 // can stop recording logs that are too big much sooner.
[email protected]cac267c2011-09-29 15:18:10988 if (log_manager_.current_log()->num_events() > kEventLimit) {
[email protected]553dba62009-02-24 19:08:23989 UMA_HISTOGRAM_COUNTS("UMA.Discarded Log Events",
[email protected]cac267c2011-09-29 15:18:10990 log_manager_.current_log()->num_events());
991 log_manager_.DiscardCurrentLog();
[email protected]68475e602008-08-22 03:21:15992 StartRecording(); // Start trivial log to hold our histograms.
993 }
994
[email protected]cac267c2011-09-29 15:18:10995 // Adds to ongoing logs.
996 log_manager_.current_log()->set_hardware_class(hardware_class_);
[email protected]accdfa62011-09-20 01:56:52997
[email protected]0b33f80b2008-12-17 21:34:36998 // Put incremental data (histogram deltas, and realtime stats deltas) at the
[email protected]147bbc0b2009-01-06 19:37:40999 // end of all log transmissions (initial log handles this separately).
[email protected]024b5cd2011-05-27 03:29:381000 // RecordIncrementalStabilityElements only exists on the derived
1001 // MetricsLog class.
[email protected]279703f2012-01-20 22:23:261002 MetricsLog* current_log =
1003 static_cast<MetricsLog*>(log_manager_.current_log());
[email protected]024b5cd2011-05-27 03:29:381004 DCHECK(current_log);
[email protected]197c0772012-05-14 23:50:511005 current_log->RecordEnvironmentProto(plugins_, google_update_metrics_);
[email protected]fe58acc22012-02-29 01:29:581006 current_log->RecordIncrementalStabilityElements(plugins_);
[email protected]024b5cd2011-05-27 03:29:381007 RecordCurrentHistograms();
initial.commit09911bf2008-07-26 23:55:291008
[email protected]29948262012-03-01 12:15:081009 log_manager_.FinishCurrentLog();
initial.commit09911bf2008-07-26 23:55:291010}
1011
[email protected]cac267c2011-09-29 15:18:101012void MetricsService::PushPendingLogsToPersistentStorage() {
initial.commit09911bf2008-07-26 23:55:291013 if (state_ < INITIAL_LOG_READY)
[email protected]28ab7f92009-01-06 21:39:041014 return; // We didn't and still don't have time to get plugin list etc.
initial.commit09911bf2008-07-26 23:55:291015
[email protected]cac267c2011-09-29 15:18:101016 if (log_manager_.has_staged_log()) {
[email protected]29948262012-03-01 12:15:081017 // We may race here, and send second copy of initial log later.
1018 if (state_ == INITIAL_LOG_READY)
[email protected]cac267c2011-09-29 15:18:101019 state_ = SENDING_OLD_LOGS;
[email protected]e7508d82012-05-03 15:59:531020 MetricsLogManager::StoreType store_type = current_fetch_xml_.get() ?
1021 MetricsLogManager::PROVISIONAL_STORE : MetricsLogManager::NORMAL_STORE;
1022 log_manager_.StoreStagedLogAsUnsent(store_type);
initial.commit09911bf2008-07-26 23:55:291023 }
[email protected]cac267c2011-09-29 15:18:101024 DCHECK(!log_manager_.has_staged_log());
[email protected]024b5cd2011-05-27 03:29:381025 StopRecording();
initial.commit09911bf2008-07-26 23:55:291026 StoreUnsentLogs();
1027}
1028
1029//------------------------------------------------------------------------------
1030// Transmission of logs methods
1031
[email protected]7f7f1962011-04-20 15:58:161032void MetricsService::StartSchedulerIfNecessary() {
1033 if (reporting_active() && recording_active())
1034 scheduler_->Start();
initial.commit09911bf2008-07-26 23:55:291035}
1036
[email protected]7f7f1962011-04-20 15:58:161037void MetricsService::StartScheduledUpload() {
1038 // If reporting has been turned off, the scheduler doesn't need to run.
1039 if (!reporting_active() || !recording_active()) {
1040 scheduler_->Stop();
1041 scheduler_->UploadCancelled();
1042 return;
1043 }
1044
[email protected]29948262012-03-01 12:15:081045 StartFinalLogInfoCollection();
1046}
1047
1048void MetricsService::StartFinalLogInfoCollection() {
1049 // Begin the multi-step process of collecting memory usage histograms:
1050 // First spawn a task to collect the memory details; when that task is
1051 // finished, it will call OnMemoryDetailCollectionDone. That will in turn
1052 // call HistogramSynchronization to collect histograms from all renderers and
1053 // then call OnHistogramSynchronizationDone to continue processing.
[email protected]7f7f1962011-04-20 15:58:161054 DCHECK(!waiting_for_asynchronus_reporting_step_);
1055 waiting_for_asynchronus_reporting_step_ = true;
1056
[email protected]2226c222011-11-22 00:08:401057 base::Closure callback =
1058 base::Bind(&MetricsService::OnMemoryDetailCollectionDone,
[email protected]c94d7382012-02-28 08:43:401059 self_ptr_factory_.GetWeakPtr());
[email protected]84c988a2011-04-19 17:56:331060
[email protected]2226c222011-11-22 00:08:401061 scoped_refptr<MetricsMemoryDetails> details(
1062 new MetricsMemoryDetails(callback));
[email protected]4306df72012-04-20 18:58:571063 details->StartFetch(MemoryDetails::UPDATE_USER_METRICS);
[email protected]84c988a2011-04-19 17:56:331064
1065 // Collect WebCore cache information to put into a histogram.
[email protected]f3b1a082011-11-18 00:34:301066 for (content::RenderProcessHost::iterator i(
1067 content::RenderProcessHost::AllHostsIterator());
[email protected]84c988a2011-04-19 17:56:331068 !i.IsAtEnd(); i.Advance())
[email protected]2ccf45c2011-08-19 23:35:501069 i.GetCurrentValue()->Send(new ChromeViewMsg_GetCacheResourceStats());
[email protected]84c988a2011-04-19 17:56:331070}
1071
1072void MetricsService::OnMemoryDetailCollectionDone() {
[email protected]c9a3ef82009-05-28 22:02:461073 DCHECK(IsSingleThreaded());
[email protected]7f7f1962011-04-20 15:58:161074 // This function should only be called as the callback from an ansynchronous
1075 // step.
1076 DCHECK(waiting_for_asynchronus_reporting_step_);
[email protected]c9a3ef82009-05-28 22:02:461077
[email protected]c9a3ef82009-05-28 22:02:461078 // Create a callback_task for OnHistogramSynchronizationDone.
[email protected]2226c222011-11-22 00:08:401079 base::Closure callback = base::Bind(
1080 &MetricsService::OnHistogramSynchronizationDone,
[email protected]c94d7382012-02-28 08:43:401081 self_ptr_factory_.GetWeakPtr());
[email protected]c9a3ef82009-05-28 22:02:461082
[email protected]908de522011-10-20 00:55:001083 base::StatisticsRecorder::CollectHistogramStats("Browser");
1084
[email protected]c9a3ef82009-05-28 22:02:461085 // Set up the callback to task to call after we receive histograms from all
1086 // renderer processes. Wait time specifies how long to wait before absolutely
1087 // calling us back on the task.
1088 HistogramSynchronizer::FetchRendererHistogramsAsynchronously(
[email protected]2226c222011-11-22 00:08:401089 MessageLoop::current(), callback,
[email protected]7e560102012-03-08 20:58:421090 base::TimeDelta::FromMilliseconds(kMaxHistogramGatheringWaitDuration));
[email protected]c9a3ef82009-05-28 22:02:461091}
1092
1093void MetricsService::OnHistogramSynchronizationDone() {
initial.commit09911bf2008-07-26 23:55:291094 DCHECK(IsSingleThreaded());
[email protected]29948262012-03-01 12:15:081095 // This function should only be called as the callback from an ansynchronous
1096 // step.
1097 DCHECK(waiting_for_asynchronus_reporting_step_);
initial.commit09911bf2008-07-26 23:55:291098
[email protected]29948262012-03-01 12:15:081099 waiting_for_asynchronus_reporting_step_ = false;
1100 OnFinalLogInfoCollectionDone();
1101}
1102
1103void MetricsService::OnFinalLogInfoCollectionDone() {
[email protected]7f7f1962011-04-20 15:58:161104 // If somehow there is a fetch in progress, we return and hope things work
1105 // out. The scheduler isn't informed since if this happens, the scheduler
1106 // will get a response from the upload.
[email protected]fe58acc22012-02-29 01:29:581107 DCHECK(!current_fetch_xml_.get());
1108 DCHECK(!current_fetch_proto_.get());
1109 if (current_fetch_xml_.get() || current_fetch_proto_.get())
[email protected]7f7f1962011-04-20 15:58:161110 return;
1111
[email protected]d01b8732008-10-16 02:18:071112 // If we're getting no notifications, then the log won't have much in it, and
1113 // it's possible the computer is about to go to sleep, so don't upload and
[email protected]7f7f1962011-04-20 15:58:161114 // stop the scheduler.
1115 // Similarly, if logs should no longer be uploaded, stop here.
1116 if (idle_since_last_transmission_ ||
1117 !recording_active() || !reporting_active()) {
1118 scheduler_->Stop();
1119 scheduler_->UploadCancelled();
[email protected]d01b8732008-10-16 02:18:071120 return;
1121 }
1122
[email protected]cac267c2011-09-29 15:18:101123 MakeStagedLog();
initial.commit09911bf2008-07-26 23:55:291124
[email protected]cac267c2011-09-29 15:18:101125 // MakeStagedLog should have prepared log text; if it didn't, skip this
1126 // upload and hope things work out next time.
1127 if (log_manager_.staged_log_text().empty()) {
[email protected]7f7f1962011-04-20 15:58:161128 scheduler_->UploadCancelled();
[email protected]d01b8732008-10-16 02:18:071129 return;
1130 }
initial.commit09911bf2008-07-26 23:55:291131
[email protected]29948262012-03-01 12:15:081132 SendStagedLog();
1133}
1134
1135void MetricsService::MakeStagedLog() {
1136 if (log_manager_.has_staged_log())
1137 return;
1138
1139 switch (state_) {
1140 case INITIALIZED:
1141 case INIT_TASK_SCHEDULED: // We should be further along by now.
1142 DCHECK(false);
1143 return;
1144
1145 case INIT_TASK_DONE:
1146 // We need to wait for the initial log to be ready before sending
1147 // anything, because the server will tell us whether it wants to hear
1148 // from us.
1149 PrepareInitialLog();
[email protected]ed0fd002012-04-25 23:10:341150 DCHECK_EQ(INIT_TASK_DONE, state_);
[email protected]29948262012-03-01 12:15:081151 log_manager_.LoadPersistedUnsentLogs();
1152 state_ = INITIAL_LOG_READY;
1153 break;
1154
1155 case SENDING_OLD_LOGS:
1156 if (log_manager_.has_unsent_logs()) {
1157 log_manager_.StageNextLogForUpload();
1158 break;
1159 }
1160 state_ = SENDING_CURRENT_LOGS;
1161 // Fall through.
1162
1163 case SENDING_CURRENT_LOGS:
1164 StopRecording();
1165 StartRecording();
1166 log_manager_.StageNextLogForUpload();
1167 break;
1168
1169 default:
1170 NOTREACHED();
1171 return;
1172 }
1173
1174 DCHECK(log_manager_.has_staged_log());
1175}
1176
1177void MetricsService::PrepareInitialLog() {
[email protected]ed0fd002012-04-25 23:10:341178 DCHECK_EQ(INIT_TASK_DONE, state_);
[email protected]29948262012-03-01 12:15:081179
[email protected]ed0fd002012-04-25 23:10:341180 DCHECK(initial_log_.get());
1181 initial_log_->set_hardware_class(hardware_class_);
[email protected]197c0772012-05-14 23:50:511182 initial_log_->RecordEnvironment(plugins_, google_update_metrics_,
1183 profile_dictionary_.get());
[email protected]29948262012-03-01 12:15:081184
1185 // Histograms only get written to the current log, so make the new log current
1186 // before writing them.
1187 log_manager_.PauseCurrentLog();
[email protected]ed0fd002012-04-25 23:10:341188 log_manager_.BeginLoggingWithLog(initial_log_.release(),
1189 MetricsLogManager::INITIAL_LOG);
[email protected]29948262012-03-01 12:15:081190 RecordCurrentHistograms();
1191 log_manager_.FinishCurrentLog();
1192 log_manager_.ResumePausedLog();
1193
1194 DCHECK(!log_manager_.has_staged_log());
1195 log_manager_.StageNextLogForUpload();
1196}
1197
1198void MetricsService::StoreUnsentLogs() {
1199 if (state_ < INITIAL_LOG_READY)
1200 return; // We never Recalled the prior unsent logs.
1201
1202 log_manager_.PersistUnsentLogs();
1203}
1204
1205void MetricsService::SendStagedLog() {
1206 DCHECK(log_manager_.has_staged_log());
1207
[email protected]cac267c2011-09-29 15:18:101208 PrepareFetchWithStagedLog();
[email protected]d01b8732008-10-16 02:18:071209
[email protected]fe58acc22012-02-29 01:29:581210 if (!current_fetch_xml_.get()) {
1211 DCHECK(!current_fetch_proto_.get());
[email protected]d01b8732008-10-16 02:18:071212 // Compression failed, and log discarded :-/.
[email protected]cac267c2011-09-29 15:18:101213 log_manager_.DiscardStagedLog();
[email protected]7f7f1962011-04-20 15:58:161214 scheduler_->UploadCancelled();
[email protected]d01b8732008-10-16 02:18:071215 // TODO(jar): If compression failed, we should have created a tiny log and
1216 // compressed that, so that we can signal that we're losing logs.
1217 return;
1218 }
[email protected]fe58acc22012-02-29 01:29:581219 // Currently, the staged log for the protobuf version of the data is discarded
1220 // after we create the URL request, so that there is no chance for
1221 // re-transmission in case the corresponding XML request fails. We will
1222 // handle protobuf failures more carefully once that becomes the main
1223 // pipeline, i.e. once we switch away from the XML pipeline.
1224 DCHECK(current_fetch_proto_.get() || !log_manager_.has_staged_log_proto());
[email protected]d01b8732008-10-16 02:18:071225
[email protected]7f7f1962011-04-20 15:58:161226 DCHECK(!waiting_for_asynchronus_reporting_step_);
[email protected]d01b8732008-10-16 02:18:071227
[email protected]7f7f1962011-04-20 15:58:161228 waiting_for_asynchronus_reporting_step_ = true;
[email protected]fe58acc22012-02-29 01:29:581229 current_fetch_xml_->Start();
1230 if (current_fetch_proto_.get())
1231 current_fetch_proto_->Start();
[email protected]d01b8732008-10-16 02:18:071232
1233 HandleIdleSinceLastTransmission(true);
1234}
1235
[email protected]cac267c2011-09-29 15:18:101236void MetricsService::PrepareFetchWithStagedLog() {
1237 DCHECK(!log_manager_.staged_log_text().empty());
[email protected]cac78842008-11-27 01:02:201238
[email protected]fe58acc22012-02-29 01:29:581239 // Prepare the XML version.
1240 DCHECK(!current_fetch_xml_.get());
1241 current_fetch_xml_.reset(content::URLFetcher::Create(
[email protected]d3ec669b2012-05-23 07:12:141242 GURL(server_url_xml_), net::URLFetcher::POST, this));
[email protected]fe58acc22012-02-29 01:29:581243 current_fetch_xml_->SetRequestContext(
[email protected]8ef3d8052011-07-22 09:03:001244 g_browser_process->system_request_context());
[email protected]448ca4d2012-05-09 19:53:121245 current_fetch_xml_->SetUploadData(kMimeTypeXml,
[email protected]fe58acc22012-02-29 01:29:581246 log_manager_.staged_log_text().xml);
1247 // We already drop cookies server-side, but we might as well strip them out
1248 // client-side as well.
1249 current_fetch_xml_->SetLoadFlags(net::LOAD_DO_NOT_SAVE_COOKIES |
1250 net::LOAD_DO_NOT_SEND_COOKIES);
1251
1252 // Prepare the protobuf version.
1253 DCHECK(!current_fetch_proto_.get());
1254 if (log_manager_.has_staged_log_proto()) {
1255 current_fetch_proto_.reset(content::URLFetcher::Create(
[email protected]d3ec669b2012-05-23 07:12:141256 GURL(server_url_proto_), net::URLFetcher::POST, this));
[email protected]fe58acc22012-02-29 01:29:581257 current_fetch_proto_->SetRequestContext(
1258 g_browser_process->system_request_context());
[email protected]448ca4d2012-05-09 19:53:121259 current_fetch_proto_->SetUploadData(kMimeTypeProto,
[email protected]fe58acc22012-02-29 01:29:581260 log_manager_.staged_log_text().proto);
1261 // We already drop cookies server-side, but we might as well strip them out
1262 // client-side as well.
1263 current_fetch_proto_->SetLoadFlags(net::LOAD_DO_NOT_SAVE_COOKIES |
1264 net::LOAD_DO_NOT_SEND_COOKIES);
1265
1266 // Discard the protobuf version of the staged log, so that we will avoid
1267 // re-uploading it even if we need to re-upload the XML version.
1268 // TODO(isherman): Handle protobuf upload failures more gracefully once we
1269 // transition away from the XML-based pipeline.
1270 log_manager_.DiscardStagedLogProto();
1271 }
initial.commit09911bf2008-07-26 23:55:291272}
1273
[email protected]f90bf0d92011-01-13 02:12:441274static const char* StatusToString(const net::URLRequestStatus& status) {
initial.commit09911bf2008-07-26 23:55:291275 switch (status.status()) {
[email protected]f90bf0d92011-01-13 02:12:441276 case net::URLRequestStatus::SUCCESS:
initial.commit09911bf2008-07-26 23:55:291277 return "SUCCESS";
1278
[email protected]f90bf0d92011-01-13 02:12:441279 case net::URLRequestStatus::IO_PENDING:
initial.commit09911bf2008-07-26 23:55:291280 return "IO_PENDING";
1281
[email protected]f90bf0d92011-01-13 02:12:441282 case net::URLRequestStatus::HANDLED_EXTERNALLY:
initial.commit09911bf2008-07-26 23:55:291283 return "HANDLED_EXTERNALLY";
1284
[email protected]f90bf0d92011-01-13 02:12:441285 case net::URLRequestStatus::CANCELED:
initial.commit09911bf2008-07-26 23:55:291286 return "CANCELED";
1287
[email protected]f90bf0d92011-01-13 02:12:441288 case net::URLRequestStatus::FAILED:
initial.commit09911bf2008-07-26 23:55:291289 return "FAILED";
1290
1291 default:
[email protected]a063c102010-07-22 22:20:191292 NOTREACHED();
initial.commit09911bf2008-07-26 23:55:291293 return "Unknown";
1294 }
1295}
1296
[email protected]fe58acc22012-02-29 01:29:581297// We need to wait for two responses: the response to the XML upload, and the
1298// response to the protobuf upload. For now, only the XML upload's response
1299// affects decisions like whether to retry the upload, whether to abandon the
1300// upload because it is too large, etc. However, we still need to wait for the
1301// protobuf upload, as we cannot reset |current_fetch_proto_| until we have
1302// confirmation that the network request was sent; and the easiest way to do
1303// that is to wait for the response. In case the XML upload's response arrives
1304// first, we cache that response until the protobuf upload's response also
1305// arrives.
1306//
1307// Note that if the XML upload succeeds but the protobuf upload fails, we will
1308// not retry the protobuf upload. If the XML upload fails while the protobuf
1309// upload succeeds, we will still avoid re-uploading the protobuf data because
1310// we "zap" the data after the first upload attempt. This means that we might
1311// lose protobuf uploads when XML ones succeed; but we will never duplicate any
1312// protobuf uploads. Protobuf failures should be rare enough to where this
1313// should be ok while we have the two pipelines running in parallel.
[email protected]10c2d692012-05-11 05:32:231314void MetricsService::OnURLFetchComplete(const net::URLFetcher* source) {
[email protected]7f7f1962011-04-20 15:58:161315 DCHECK(waiting_for_asynchronus_reporting_step_);
[email protected]fe58acc22012-02-29 01:29:581316
1317 // We're not allowed to re-use the existing |URLFetcher|s, so free them here.
[email protected]4266def22012-05-17 01:02:401318 // Note however that |source| is aliased to one of these, so we should be
1319 // careful not to delete it too early.
[email protected]15fb2aa2012-05-22 22:52:591320 scoped_ptr<net::URLFetcher> s;
[email protected]fe58acc22012-02-29 01:29:581321 if (source == current_fetch_xml_.get()) {
1322 s.reset(current_fetch_xml_.release());
1323
1324 // Cache the XML responses, in case we still need to wait for the protobuf
1325 // response.
1326 response_code_ = source->GetResponseCode();
1327 response_status_ = StatusToString(source->GetStatus());
1328 source->GetResponseAsString(&response_data_);
[email protected]4266def22012-05-17 01:02:401329
1330 // Log a histogram to track response success vs. failure rates.
1331 UMA_HISTOGRAM_ENUMERATION("UMA.UploadResponseStatus.XML",
1332 ResponseCodeToStatus(response_code_),
1333 NUM_RESPONSE_STATUSES);
[email protected]fe58acc22012-02-29 01:29:581334 } else if (source == current_fetch_proto_.get()) {
1335 s.reset(current_fetch_proto_.release());
[email protected]4266def22012-05-17 01:02:401336
1337 // Log a histogram to track response success vs. failure rates.
1338 UMA_HISTOGRAM_ENUMERATION("UMA.UploadResponseStatus.Protobuf",
1339 ResponseCodeToStatus(source->GetResponseCode()),
1340 NUM_RESPONSE_STATUSES);
[email protected]fe58acc22012-02-29 01:29:581341 } else {
1342 NOTREACHED();
1343 return;
1344 }
1345
1346 // If we're still waiting for one of the responses, keep waiting...
1347 if (current_fetch_xml_.get() || current_fetch_proto_.get())
1348 return;
1349
1350 // We should only be able to reach here once we've received responses to both
1351 // the XML and the protobuf requests. We should always have the response code
1352 // available.
[email protected]6b44e9b52012-03-27 07:46:191353 DCHECK_NE(response_code_, kNoResponseCode);
[email protected]7f7f1962011-04-20 15:58:161354 waiting_for_asynchronus_reporting_step_ = false;
[email protected]fe58acc22012-02-29 01:29:581355
[email protected]e7508d82012-05-03 15:59:531356 // If the upload was provisionally stored, drop it now that the upload is
1357 // known to have gone through.
1358 log_manager_.DiscardLastProvisionalStore();
initial.commit09911bf2008-07-26 23:55:291359
1360 // Confirm send so that we can move on.
[email protected]4266def22012-05-17 01:02:401361 VLOG(1) << "Metrics response code: " << response_code_
[email protected]fe58acc22012-02-29 01:29:581362 << " status=" << response_status_;
[email protected]252873ef2008-08-04 21:59:451363
[email protected]fe58acc22012-02-29 01:29:581364 bool upload_succeeded = response_code_ == 200;
[email protected]7f7f1962011-04-20 15:58:161365
[email protected]0eb34fee2009-01-21 08:04:381366 // Provide boolean for error recovery (allow us to ignore response_code).
[email protected]dc6f4962009-02-13 01:25:501367 bool discard_log = false;
[email protected]0eb34fee2009-01-21 08:04:381368
[email protected]7f7f1962011-04-20 15:58:161369 if (!upload_succeeded &&
[email protected]fe58acc22012-02-29 01:29:581370 log_manager_.staged_log_text().xml.length() >
1371 kUploadLogAvoidRetransmitSize) {
[email protected]cac267c2011-09-29 15:18:101372 UMA_HISTOGRAM_COUNTS(
1373 "UMA.Large Rejected Log was Discarded",
[email protected]fe58acc22012-02-29 01:29:581374 static_cast<int>(log_manager_.staged_log_text().xml.length()));
[email protected]0eb34fee2009-01-21 08:04:381375 discard_log = true;
[email protected]fe58acc22012-02-29 01:29:581376 } else if (response_code_ == 400) {
[email protected]0eb34fee2009-01-21 08:04:381377 // Bad syntax. Retransmission won't work.
[email protected]0eb34fee2009-01-21 08:04:381378 discard_log = true;
[email protected]68475e602008-08-22 03:21:151379 }
1380
[email protected]7f7f1962011-04-20 15:58:161381 if (!upload_succeeded && !discard_log) {
[email protected]4266def22012-05-17 01:02:401382 VLOG(1) << "Metrics: transmission attempt returned a failure code: "
[email protected]fe58acc22012-02-29 01:29:581383 << response_code_ << ". Verify network connectivity";
[email protected]7f7f1962011-04-20 15:58:161384 LogBadResponseCode();
[email protected]0eb34fee2009-01-21 08:04:381385 } else { // Successful receipt (or we are discarding log).
[email protected]4266def22012-05-17 01:02:401386 VLOG(1) << "Metrics response data: " << response_data_;
initial.commit09911bf2008-07-26 23:55:291387 switch (state_) {
1388 case INITIAL_LOG_READY:
[email protected]cac267c2011-09-29 15:18:101389 state_ = SENDING_OLD_LOGS;
initial.commit09911bf2008-07-26 23:55:291390 break;
1391
initial.commit09911bf2008-07-26 23:55:291392 case SENDING_OLD_LOGS:
[email protected]d53e2232011-06-30 15:54:571393 // Store the updated list to disk now that the removed log is uploaded.
initial.commit09911bf2008-07-26 23:55:291394 StoreUnsentLogs();
1395 break;
1396
1397 case SENDING_CURRENT_LOGS:
1398 break;
1399
1400 default:
[email protected]a063c102010-07-22 22:20:191401 NOTREACHED();
initial.commit09911bf2008-07-26 23:55:291402 break;
1403 }
[email protected]d01b8732008-10-16 02:18:071404
[email protected]cac267c2011-09-29 15:18:101405 log_manager_.DiscardStagedLog();
[email protected]252873ef2008-08-04 21:59:451406
[email protected]cac267c2011-09-29 15:18:101407 if (log_manager_.has_unsent_logs())
[email protected]ed0fd002012-04-25 23:10:341408 DCHECK_LT(state_, SENDING_CURRENT_LOGS);
initial.commit09911bf2008-07-26 23:55:291409 }
[email protected]252873ef2008-08-04 21:59:451410
[email protected]7f7f1962011-04-20 15:58:161411 // Error 400 indicates a problem with the log, not with the server, so
1412 // don't consider that a sign that the server is in trouble.
[email protected]fe58acc22012-02-29 01:29:581413 bool server_is_healthy = upload_succeeded || response_code_ == 400;
[email protected]7f7f1962011-04-20 15:58:161414
[email protected]cac267c2011-09-29 15:18:101415 scheduler_->UploadFinished(server_is_healthy,
1416 log_manager_.has_unsent_logs());
[email protected]d67d1052011-06-09 05:11:411417
1418 // Collect network stats if UMA upload succeeded.
[email protected]b8ddb052012-04-19 02:36:061419 IOThread* io_thread = g_browser_process->io_thread();
1420 if (server_is_healthy && io_thread) {
1421 chrome_browser_net::CollectNetworkStats(network_stats_server_, io_thread);
[email protected]adbb3762012-03-09 22:20:081422 chrome_browser_net::CollectPipeliningCapabilityStatsOnUIThread(
[email protected]b8ddb052012-04-19 02:36:061423 http_pipelining_test_server_, io_thread);
[email protected]adbb3762012-03-09 22:20:081424 }
[email protected]fe58acc22012-02-29 01:29:581425
1426 // Reset the cached response data.
[email protected]6b44e9b52012-03-27 07:46:191427 response_code_ = kNoResponseCode;
[email protected]fe58acc22012-02-29 01:29:581428 response_data_ = std::string();
1429 response_status_ = std::string();
initial.commit09911bf2008-07-26 23:55:291430}
1431
[email protected]7f7f1962011-04-20 15:58:161432void MetricsService::LogBadResponseCode() {
[email protected]666205032010-10-21 20:56:581433 VLOG(1) << "Verify your metrics logs are formatted correctly. Verify server "
[email protected]fe58acc22012-02-29 01:29:581434 "is active at " << server_url_xml_;
[email protected]cac267c2011-09-29 15:18:101435 if (!log_manager_.has_staged_log()) {
[email protected]666205032010-10-21 20:56:581436 VLOG(1) << "METRICS: Recorder shutdown during log transmission.";
[email protected]252873ef2008-08-04 21:59:451437 } else {
[email protected]7f7f1962011-04-20 15:58:161438 VLOG(1) << "METRICS: transmission retry being scheduled for "
[email protected]fe58acc22012-02-29 01:29:581439 << log_manager_.staged_log_text().xml;
initial.commit09911bf2008-07-26 23:55:291440 }
initial.commit09911bf2008-07-26 23:55:291441}
1442
[email protected]6c2381d2011-10-19 02:52:531443void MetricsService::LogWindowChange(
1444 int type,
1445 const content::NotificationSource& source,
1446 const content::NotificationDetails& details) {
[email protected]534e54b2008-08-13 15:40:091447 int controller_id = -1;
1448 uintptr_t window_or_tab = source.map_key();
initial.commit09911bf2008-07-26 23:55:291449 MetricsLog::WindowEventType window_type;
1450
1451 // Note: since we stop all logging when a single OTR session is active, it is
1452 // possible that we start getting notifications about a window that we don't
1453 // know about.
[email protected]534e54b2008-08-13 15:40:091454 if (window_map_.find(window_or_tab) == window_map_.end()) {
1455 controller_id = next_window_id_++;
1456 window_map_[window_or_tab] = controller_id;
initial.commit09911bf2008-07-26 23:55:291457 } else {
[email protected]534e54b2008-08-13 15:40:091458 controller_id = window_map_[window_or_tab];
initial.commit09911bf2008-07-26 23:55:291459 }
[email protected]92745242009-06-12 16:52:211460 DCHECK_NE(controller_id, -1);
initial.commit09911bf2008-07-26 23:55:291461
[email protected]432115822011-07-10 15:52:271462 switch (type) {
[email protected]884033e2012-04-16 19:38:421463 case chrome::NOTIFICATION_TAB_PARENTED:
[email protected]432115822011-07-10 15:52:271464 case chrome::NOTIFICATION_BROWSER_OPENED:
initial.commit09911bf2008-07-26 23:55:291465 window_type = MetricsLog::WINDOW_CREATE;
1466 break;
1467
[email protected]884033e2012-04-16 19:38:421468 case chrome::NOTIFICATION_TAB_CLOSING:
[email protected]432115822011-07-10 15:52:271469 case chrome::NOTIFICATION_BROWSER_CLOSED:
[email protected]534e54b2008-08-13 15:40:091470 window_map_.erase(window_map_.find(window_or_tab));
initial.commit09911bf2008-07-26 23:55:291471 window_type = MetricsLog::WINDOW_DESTROY;
1472 break;
1473
1474 default:
[email protected]a063c102010-07-22 22:20:191475 NOTREACHED();
[email protected]68d74f02009-02-13 01:36:501476 return;
initial.commit09911bf2008-07-26 23:55:291477 }
1478
[email protected]534e54b2008-08-13 15:40:091479 // TODO(brettw) we should have some kind of ID for the parent.
[email protected]cac267c2011-09-29 15:18:101480 log_manager_.current_log()->RecordWindowEvent(window_type, controller_id, 0);
initial.commit09911bf2008-07-26 23:55:291481}
1482
[email protected]6c2381d2011-10-19 02:52:531483void MetricsService::LogLoadComplete(
1484 int type,
1485 const content::NotificationSource& source,
1486 const content::NotificationDetails& details) {
[email protected]ad50def52011-10-19 23:17:071487 if (details == content::NotificationService::NoDetails())
initial.commit09911bf2008-07-26 23:55:291488 return;
1489
[email protected]68475e602008-08-22 03:21:151490 // TODO(jar): There is a bug causing this to be called too many times, and
1491 // the log overflows. For now, we won't record these events.
[email protected]553dba62009-02-24 19:08:231492 UMA_HISTOGRAM_COUNTS("UMA.LogLoadComplete called", 1);
[email protected]68475e602008-08-22 03:21:151493 return;
1494
[email protected]6c2381d2011-10-19 02:52:531495 const content::Details<LoadNotificationDetails> load_details(details);
[email protected]534e54b2008-08-13 15:40:091496 int controller_id = window_map_[details.map_key()];
[email protected]cac267c2011-09-29 15:18:101497 log_manager_.current_log()->RecordLoadEvent(controller_id,
[email protected]09d31d52012-03-11 22:30:271498 load_details->url,
1499 load_details->origin,
1500 load_details->session_index,
1501 load_details->load_time);
initial.commit09911bf2008-07-26 23:55:291502}
1503
[email protected]57ecc4b2010-08-11 03:02:511504void MetricsService::IncrementPrefValue(const char* path) {
[email protected]e73c01972008-08-13 00:18:241505 PrefService* pref = g_browser_process->local_state();
1506 DCHECK(pref);
1507 int value = pref->GetInteger(path);
1508 pref->SetInteger(path, value + 1);
1509}
1510
[email protected]57ecc4b2010-08-11 03:02:511511void MetricsService::IncrementLongPrefsValue(const char* path) {
[email protected]0bb1a622009-03-04 03:22:321512 PrefService* pref = g_browser_process->local_state();
1513 DCHECK(pref);
1514 int64 value = pref->GetInt64(path);
[email protected]b42c5e42010-06-03 20:43:251515 pref->SetInt64(path, value + 1);
[email protected]0bb1a622009-03-04 03:22:321516}
1517
initial.commit09911bf2008-07-26 23:55:291518void MetricsService::LogLoadStarted() {
[email protected]dd8d12a2011-09-02 02:10:151519 HISTOGRAM_ENUMERATION("Chrome.UmaPageloadCounter", 1, 2);
[email protected]e73c01972008-08-13 00:18:241520 IncrementPrefValue(prefs::kStabilityPageLoadCount);
[email protected]0bb1a622009-03-04 03:22:321521 IncrementLongPrefsValue(prefs::kUninstallMetricsPageLoadCount);
[email protected]0b33f80b2008-12-17 21:34:361522 // We need to save the prefs, as page load count is a critical stat, and it
1523 // might be lost due to a crash :-(.
initial.commit09911bf2008-07-26 23:55:291524}
1525
[email protected]c3721482012-03-23 16:21:481526void MetricsService::LogRendererCrash(content::RenderProcessHost* host,
1527 base::TerminationStatus status,
1528 bool was_alive) {
[email protected]f3b1a082011-11-18 00:34:301529 Profile* profile = Profile::FromBrowserContext(host->GetBrowserContext());
[email protected]6f371442011-11-09 06:45:461530 ExtensionService* service = profile->GetExtensionService();
1531 bool was_extension_process =
[email protected]f3b1a082011-11-18 00:34:301532 service && service->process_map()->Contains(host->GetID());
[email protected]c3721482012-03-23 16:21:481533 if (status == base::TERMINATION_STATUS_PROCESS_CRASHED ||
1534 status == base::TERMINATION_STATUS_ABNORMAL_TERMINATION) {
1535 if (was_extension_process)
[email protected]718eab62011-10-05 21:16:521536 IncrementPrefValue(prefs::kStabilityExtensionRendererCrashCount);
[email protected]c3721482012-03-23 16:21:481537 else
[email protected]718eab62011-10-05 21:16:521538 IncrementPrefValue(prefs::kStabilityRendererCrashCount);
initial.commit09911bf2008-07-26 23:55:291539
[email protected]718eab62011-10-05 21:16:521540 UMA_HISTOGRAM_PERCENTAGE("BrowserRenderProcessHost.ChildCrashes",
1541 was_extension_process ? 2 : 1);
[email protected]c3721482012-03-23 16:21:481542 if (was_alive) {
[email protected]718eab62011-10-05 21:16:521543 UMA_HISTOGRAM_PERCENTAGE("BrowserRenderProcessHost.ChildCrashesWasAlive",
1544 was_extension_process ? 2 : 1);
1545 }
[email protected]c3721482012-03-23 16:21:481546 } else if (status == base::TERMINATION_STATUS_PROCESS_WAS_KILLED) {
[email protected]718eab62011-10-05 21:16:521547 UMA_HISTOGRAM_PERCENTAGE("BrowserRenderProcessHost.ChildKills",
1548 was_extension_process ? 2 : 1);
[email protected]c3721482012-03-23 16:21:481549 if (was_alive) {
[email protected]718eab62011-10-05 21:16:521550 UMA_HISTOGRAM_PERCENTAGE("BrowserRenderProcessHost.ChildKillsWasAlive",
1551 was_extension_process ? 2 : 1);
1552 }
1553 }
[email protected]1f085622009-12-04 05:33:451554}
1555
initial.commit09911bf2008-07-26 23:55:291556void MetricsService::LogRendererHang() {
[email protected]e73c01972008-08-13 00:18:241557 IncrementPrefValue(prefs::kStabilityRendererHangCount);
initial.commit09911bf2008-07-26 23:55:291558}
1559
[email protected]c0c55e92011-09-10 18:47:301560void MetricsService::LogNeedForCleanShutdown() {
1561 PrefService* pref = g_browser_process->local_state();
1562 pref->SetBoolean(prefs::kStabilityExitedCleanly, false);
1563 // Redundant setting to be sure we call for a clean shutdown.
1564 clean_shutdown_status_ = NEED_TO_SHUTDOWN;
1565}
1566
1567bool MetricsService::UmaMetricsProperlyShutdown() {
1568 CHECK(clean_shutdown_status_ == CLEANLY_SHUTDOWN ||
1569 clean_shutdown_status_ == NEED_TO_SHUTDOWN);
1570 return clean_shutdown_status_ == CLEANLY_SHUTDOWN;
1571}
1572
[email protected]67c4e952011-09-17 00:44:271573// For use in hack in LogCleanShutdown.
1574static void Signal(base::WaitableEvent* event) {
1575 event->Signal();
1576}
1577
[email protected]466f3c12011-03-23 21:20:381578void MetricsService::LogCleanShutdown() {
[email protected]acd55b32011-09-05 17:35:311579 // Redundant hack to write pref ASAP.
1580 PrefService* pref = g_browser_process->local_state();
1581 pref->SetBoolean(prefs::kStabilityExitedCleanly, true);
[email protected]fbe17c8a2011-12-27 16:41:481582 pref->CommitPendingWrite();
[email protected]67c4e952011-09-17 00:44:271583 // Hack: TBD: Remove this wait.
1584 // We are so concerned that the pref gets written, we are now willing to stall
1585 // the UI thread until we get assurance that a pref-writing task has
1586 // completed.
1587 base::WaitableEvent done_writing(false, false);
1588 BrowserThread::PostTask(BrowserThread::FILE, FROM_HERE,
[email protected]8454aeb2011-11-19 23:38:201589 base::Bind(Signal, &done_writing));
[email protected]3a7b66d2012-04-26 16:34:161590 // http://crbug.com/124954
1591 base::ThreadRestrictions::ScopedAllowWait allow_wait;
[email protected]67c4e952011-09-17 00:44:271592 done_writing.TimedWait(base::TimeDelta::FromHours(1));
1593
[email protected]c0c55e92011-09-10 18:47:301594 // Redundant setting to assure that we always reset this value at shutdown
1595 // (and that we don't use some alternate path, and not call LogCleanShutdown).
1596 clean_shutdown_status_ = CLEANLY_SHUTDOWN;
[email protected]acd55b32011-09-05 17:35:311597
[email protected]466f3c12011-03-23 21:20:381598 RecordBooleanPrefValue(prefs::kStabilityExitedCleanly, true);
1599}
1600
[email protected]c1834a92011-01-21 18:21:031601#if defined(OS_CHROMEOS)
1602void MetricsService::LogChromeOSCrash(const std::string &crash_type) {
1603 if (crash_type == "user")
1604 IncrementPrefValue(prefs::kStabilityOtherUserCrashCount);
1605 else if (crash_type == "kernel")
1606 IncrementPrefValue(prefs::kStabilityKernelCrashCount);
1607 else if (crash_type == "uncleanshutdown")
1608 IncrementPrefValue(prefs::kStabilitySystemUncleanShutdownCount);
1609 else
1610 NOTREACHED() << "Unexpected Chrome OS crash type " << crash_type;
1611 // Wake up metrics logs sending if necessary now that new
1612 // log data is available.
1613 HandleIdleSinceLastTransmission(false);
1614}
1615#endif // OS_CHROMEOS
1616
[email protected]a27a9382009-02-11 23:55:101617void MetricsService::LogChildProcessChange(
[email protected]432115822011-07-10 15:52:271618 int type,
[email protected]6c2381d2011-10-19 02:52:531619 const content::NotificationSource& source,
1620 const content::NotificationDetails& details) {
[email protected]4967f792012-01-20 22:14:401621 content::Details<ChildProcessData> child_details(details);
[email protected]4306c3792011-12-02 01:57:531622 const string16& child_name = child_details->name;
[email protected]0d84c5d2009-10-09 01:10:421623
[email protected]a27a9382009-02-11 23:55:101624 if (child_process_stats_buffer_.find(child_name) ==
1625 child_process_stats_buffer_.end()) {
[email protected]0d84c5d2009-10-09 01:10:421626 child_process_stats_buffer_[child_name] =
[email protected]4306c3792011-12-02 01:57:531627 ChildProcessStats(child_details->type);
initial.commit09911bf2008-07-26 23:55:291628 }
1629
[email protected]a27a9382009-02-11 23:55:101630 ChildProcessStats& stats = child_process_stats_buffer_[child_name];
[email protected]432115822011-07-10 15:52:271631 switch (type) {
1632 case content::NOTIFICATION_CHILD_PROCESS_HOST_CONNECTED:
initial.commit09911bf2008-07-26 23:55:291633 stats.process_launches++;
1634 break;
1635
[email protected]432115822011-07-10 15:52:271636 case content::NOTIFICATION_CHILD_INSTANCE_CREATED:
initial.commit09911bf2008-07-26 23:55:291637 stats.instances++;
1638 break;
1639
[email protected]432115822011-07-10 15:52:271640 case content::NOTIFICATION_CHILD_PROCESS_CRASHED:
initial.commit09911bf2008-07-26 23:55:291641 stats.process_crashes++;
[email protected]1f085622009-12-04 05:33:451642 // Exclude plugin crashes from the count below because we report them via
1643 // a separate UMA metric.
[email protected]4306c3792011-12-02 01:57:531644 if (!IsPluginProcess(child_details->type)) {
[email protected]1f085622009-12-04 05:33:451645 IncrementPrefValue(prefs::kStabilityChildProcessCrashCount);
1646 }
initial.commit09911bf2008-07-26 23:55:291647 break;
1648
1649 default:
[email protected]432115822011-07-10 15:52:271650 NOTREACHED() << "Unexpected notification type " << type;
initial.commit09911bf2008-07-26 23:55:291651 return;
1652 }
1653}
1654
1655// Recursively counts the number of bookmarks and folders in node.
[email protected]b3c33d462009-06-26 22:29:201656static void CountBookmarks(const BookmarkNode* node,
1657 int* bookmarks,
1658 int* folders) {
[email protected]0890e60e2011-06-27 14:55:211659 if (node->is_url())
initial.commit09911bf2008-07-26 23:55:291660 (*bookmarks)++;
1661 else
1662 (*folders)++;
[email protected]9c1a75a2011-03-10 02:38:121663 for (int i = 0; i < node->child_count(); ++i)
initial.commit09911bf2008-07-26 23:55:291664 CountBookmarks(node->GetChild(i), bookmarks, folders);
1665}
1666
[email protected]b3c33d462009-06-26 22:29:201667void MetricsService::LogBookmarks(const BookmarkNode* node,
[email protected]57ecc4b2010-08-11 03:02:511668 const char* num_bookmarks_key,
1669 const char* num_folders_key) {
initial.commit09911bf2008-07-26 23:55:291670 DCHECK(node);
1671 int num_bookmarks = 0;
1672 int num_folders = 0;
1673 CountBookmarks(node, &num_bookmarks, &num_folders);
1674 num_folders--; // Don't include the root folder in the count.
1675
1676 PrefService* pref = g_browser_process->local_state();
1677 DCHECK(pref);
1678 pref->SetInteger(num_bookmarks_key, num_bookmarks);
1679 pref->SetInteger(num_folders_key, num_folders);
1680}
1681
[email protected]d8e41ed2008-09-11 15:22:321682void MetricsService::LogBookmarks(BookmarkModel* model) {
initial.commit09911bf2008-07-26 23:55:291683 DCHECK(model);
[email protected]72bdcfe2011-07-22 17:21:581684 LogBookmarks(model->bookmark_bar_node(),
initial.commit09911bf2008-07-26 23:55:291685 prefs::kNumBookmarksOnBookmarkBar,
1686 prefs::kNumFoldersOnBookmarkBar);
1687 LogBookmarks(model->other_node(),
1688 prefs::kNumBookmarksInOtherBookmarkFolder,
1689 prefs::kNumFoldersInOtherBookmarkFolder);
1690 ScheduleNextStateSave();
1691}
1692
[email protected]604d8a062012-03-16 21:37:461693void MetricsService::LogKeywordCount(size_t keyword_count) {
initial.commit09911bf2008-07-26 23:55:291694 PrefService* pref = g_browser_process->local_state();
1695 DCHECK(pref);
[email protected]604d8a062012-03-16 21:37:461696 pref->SetInteger(prefs::kNumKeywords, static_cast<int>(keyword_count));
initial.commit09911bf2008-07-26 23:55:291697 ScheduleNextStateSave();
1698}
1699
1700void MetricsService::RecordPluginChanges(PrefService* pref) {
[email protected]f8628c22011-04-05 12:10:181701 ListPrefUpdate update(pref, prefs::kStabilityPluginStats);
1702 ListValue* plugins = update.Get();
initial.commit09911bf2008-07-26 23:55:291703 DCHECK(plugins);
1704
1705 for (ListValue::iterator value_iter = plugins->begin();
1706 value_iter != plugins->end(); ++value_iter) {
1707 if (!(*value_iter)->IsType(Value::TYPE_DICTIONARY)) {
[email protected]a063c102010-07-22 22:20:191708 NOTREACHED();
initial.commit09911bf2008-07-26 23:55:291709 continue;
1710 }
1711
1712 DictionaryValue* plugin_dict = static_cast<DictionaryValue*>(*value_iter);
[email protected]57ecc4b2010-08-11 03:02:511713 std::string plugin_name;
[email protected]8e50b602009-03-03 22:59:431714 plugin_dict->GetString(prefs::kStabilityPluginName, &plugin_name);
[email protected]6470ee8f2009-03-03 20:46:401715 if (plugin_name.empty()) {
[email protected]a063c102010-07-22 22:20:191716 NOTREACHED();
initial.commit09911bf2008-07-26 23:55:291717 continue;
1718 }
1719
[email protected]57ecc4b2010-08-11 03:02:511720 // TODO(viettrungluu): remove conversions
[email protected]68b9e72b2011-08-05 23:08:221721 string16 name16 = UTF8ToUTF16(plugin_name);
1722 if (child_process_stats_buffer_.find(name16) ==
1723 child_process_stats_buffer_.end()) {
initial.commit09911bf2008-07-26 23:55:291724 continue;
[email protected]68b9e72b2011-08-05 23:08:221725 }
initial.commit09911bf2008-07-26 23:55:291726
[email protected]68b9e72b2011-08-05 23:08:221727 ChildProcessStats stats = child_process_stats_buffer_[name16];
initial.commit09911bf2008-07-26 23:55:291728 if (stats.process_launches) {
1729 int launches = 0;
[email protected]8e50b602009-03-03 22:59:431730 plugin_dict->GetInteger(prefs::kStabilityPluginLaunches, &launches);
initial.commit09911bf2008-07-26 23:55:291731 launches += stats.process_launches;
[email protected]8e50b602009-03-03 22:59:431732 plugin_dict->SetInteger(prefs::kStabilityPluginLaunches, launches);
initial.commit09911bf2008-07-26 23:55:291733 }
1734 if (stats.process_crashes) {
1735 int crashes = 0;
[email protected]8e50b602009-03-03 22:59:431736 plugin_dict->GetInteger(prefs::kStabilityPluginCrashes, &crashes);
initial.commit09911bf2008-07-26 23:55:291737 crashes += stats.process_crashes;
[email protected]8e50b602009-03-03 22:59:431738 plugin_dict->SetInteger(prefs::kStabilityPluginCrashes, crashes);
initial.commit09911bf2008-07-26 23:55:291739 }
1740 if (stats.instances) {
1741 int instances = 0;
[email protected]8e50b602009-03-03 22:59:431742 plugin_dict->GetInteger(prefs::kStabilityPluginInstances, &instances);
initial.commit09911bf2008-07-26 23:55:291743 instances += stats.instances;
[email protected]8e50b602009-03-03 22:59:431744 plugin_dict->SetInteger(prefs::kStabilityPluginInstances, instances);
initial.commit09911bf2008-07-26 23:55:291745 }
1746
[email protected]68b9e72b2011-08-05 23:08:221747 child_process_stats_buffer_.erase(name16);
initial.commit09911bf2008-07-26 23:55:291748 }
1749
1750 // Now go through and add dictionaries for plugins that didn't already have
1751 // reports in Local State.
[email protected]68b9e72b2011-08-05 23:08:221752 for (std::map<string16, ChildProcessStats>::iterator cache_iter =
[email protected]a27a9382009-02-11 23:55:101753 child_process_stats_buffer_.begin();
1754 cache_iter != child_process_stats_buffer_.end(); ++cache_iter) {
[email protected]a27a9382009-02-11 23:55:101755 ChildProcessStats stats = cache_iter->second;
[email protected]0d84c5d2009-10-09 01:10:421756
1757 // Insert only plugins information into the plugins list.
[email protected]8d5f1dae2011-11-11 14:30:411758 if (!IsPluginProcess(stats.process_type))
[email protected]0d84c5d2009-10-09 01:10:421759 continue;
1760
[email protected]57ecc4b2010-08-11 03:02:511761 // TODO(viettrungluu): remove conversion
[email protected]68b9e72b2011-08-05 23:08:221762 std::string plugin_name = UTF16ToUTF8(cache_iter->first);
[email protected]0d84c5d2009-10-09 01:10:421763
initial.commit09911bf2008-07-26 23:55:291764 DictionaryValue* plugin_dict = new DictionaryValue;
1765
[email protected]8e50b602009-03-03 22:59:431766 plugin_dict->SetString(prefs::kStabilityPluginName, plugin_name);
1767 plugin_dict->SetInteger(prefs::kStabilityPluginLaunches,
initial.commit09911bf2008-07-26 23:55:291768 stats.process_launches);
[email protected]8e50b602009-03-03 22:59:431769 plugin_dict->SetInteger(prefs::kStabilityPluginCrashes,
initial.commit09911bf2008-07-26 23:55:291770 stats.process_crashes);
[email protected]8e50b602009-03-03 22:59:431771 plugin_dict->SetInteger(prefs::kStabilityPluginInstances,
initial.commit09911bf2008-07-26 23:55:291772 stats.instances);
1773 plugins->Append(plugin_dict);
1774 }
[email protected]a27a9382009-02-11 23:55:101775 child_process_stats_buffer_.clear();
initial.commit09911bf2008-07-26 23:55:291776}
1777
[email protected]6c2381d2011-10-19 02:52:531778bool MetricsService::CanLogNotification(
1779 int type,
1780 const content::NotificationSource& source,
1781 const content::NotificationDetails& details) {
[email protected]2c910b72011-03-08 21:16:321782 // We simply don't log anything to UMA if there is a single incognito
initial.commit09911bf2008-07-26 23:55:291783 // session visible. The problem is that we always notify using the orginal
1784 // profile in order to simplify notification processing.
1785 return !BrowserList::IsOffTheRecordSessionActive();
1786}
1787
[email protected]57ecc4b2010-08-11 03:02:511788void MetricsService::RecordBooleanPrefValue(const char* path, bool value) {
initial.commit09911bf2008-07-26 23:55:291789 DCHECK(IsSingleThreaded());
1790
1791 PrefService* pref = g_browser_process->local_state();
1792 DCHECK(pref);
1793
1794 pref->SetBoolean(path, value);
1795 RecordCurrentState(pref);
1796}
1797
1798void MetricsService::RecordCurrentState(PrefService* pref) {
[email protected]0bb1a622009-03-04 03:22:321799 pref->SetInt64(prefs::kStabilityLastTimestampSec, Time::Now().ToTimeT());
initial.commit09911bf2008-07-26 23:55:291800
1801 RecordPluginChanges(pref);
1802}
1803
[email protected]8d5f1dae2011-11-11 14:30:411804// static
[email protected]bd5d6cf2011-12-01 00:39:121805bool MetricsService::IsPluginProcess(content::ProcessType type) {
1806 return (type == content::PROCESS_TYPE_PLUGIN||
1807 type == content::PROCESS_TYPE_PPAPI_PLUGIN);
[email protected]8d5f1dae2011-11-11 14:30:411808}
1809
[email protected]5ccaa412009-11-13 22:00:161810#if defined(OS_CHROMEOS)
[email protected]29cf16772010-04-21 15:13:471811void MetricsService::StartExternalMetrics() {
[email protected]5ccaa412009-11-13 22:00:161812 external_metrics_ = new chromeos::ExternalMetrics;
[email protected]29cf16772010-04-21 15:13:471813 external_metrics_->Start();
[email protected]5ccaa412009-11-13 22:00:161814}
1815#endif
[email protected]3819f2ee2011-08-21 09:44:381816
1817// static
1818bool MetricsServiceHelper::IsMetricsReportingEnabled() {
1819 bool result = false;
1820 const PrefService* local_state = g_browser_process->local_state();
1821 if (local_state) {
1822 const PrefService::Preference* uma_pref =
1823 local_state->FindPreference(prefs::kMetricsReportingEnabled);
1824 if (uma_pref) {
1825 bool success = uma_pref->GetValue()->GetAsBoolean(&result);
1826 DCHECK(success);
1827 }
1828 }
1829 return result;
1830}