blob: 61a42b902936ffaa9f890902f19f7af77a2f4eac [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]d7c1fa62012-06-15 23:35:30147#include <algorithm>
148
[email protected]7f7f1962011-04-20 15:58:16149#include "base/bind.h"
150#include "base/callback.h"
[email protected]5d91c9e2010-07-28 17:25:28151#include "base/command_line.h"
[email protected]3dc1bc42012-06-19 08:20:53152#include "base/guid.h"
[email protected]46f89e142010-07-19 08:00:42153#include "base/md5.h"
[email protected]835d7c82010-10-14 04:38:38154#include "base/metrics/histogram.h"
[email protected]567d30e2012-07-13 21:48:29155#include "base/metrics/statistics_recorder.h"
[email protected]e61003a2012-05-24 17:03:19156#include "base/rand_util.h"
[email protected]528c56d2010-07-30 19:28:44157#include "base/string_number_conversions.h"
[email protected]ce072a72010-12-31 20:02:16158#include "base/threading/platform_thread.h"
[email protected]b3841c502011-03-09 01:21:31159#include "base/threading/thread.h"
[email protected]3a7b66d2012-04-26 16:34:16160#include "base/threading/thread_restrictions.h"
[email protected]ed0fd002012-04-25 23:10:34161#include "base/tracked_objects.h"
[email protected]440b37b22010-08-30 05:31:40162#include "base/utf_string_conversions.h"
[email protected]679082052010-07-21 21:30:13163#include "base/values.h"
[email protected]19871a92012-06-27 19:50:32164#include "chrome/browser/autocomplete/autocomplete_log.h"
[email protected]d8e41ed2008-09-11 15:22:32165#include "chrome/browser/bookmarks/bookmark_model.h"
[email protected]e07f2da2012-08-01 22:46:12166#include "chrome/browser/bookmarks/bookmark_model_factory.h"
initial.commit09911bf2008-07-26 23:55:29167#include "chrome/browser/browser_process.h"
[email protected]6f371442011-11-09 06:45:46168#include "chrome/browser/extensions/extension_service.h"
169#include "chrome/browser/extensions/process_map.h"
[email protected]b8ddb052012-04-19 02:36:06170#include "chrome/browser/io_thread.h"
[email protected]84c988a2011-04-19 17:56:33171#include "chrome/browser/memory_details.h"
[email protected]679082052010-07-21 21:30:13172#include "chrome/browser/metrics/metrics_log.h"
[email protected]cac267c2011-09-29 15:18:10173#include "chrome/browser/metrics/metrics_log_serializer.h"
[email protected]7f7f1962011-04-20 15:58:16174#include "chrome/browser/metrics/metrics_reporting_scheduler.h"
[email protected]ed0fd002012-04-25 23:10:34175#include "chrome/browser/metrics/tracking_synchronizer.h"
[email protected]adbb3762012-03-09 22:20:08176#include "chrome/browser/net/http_pipelining_compatibility_client.h"
[email protected]d67d1052011-06-09 05:11:41177#include "chrome/browser/net/network_stats.h"
[email protected]37858e52010-08-26 00:22:02178#include "chrome/browser/prefs/pref_service.h"
[email protected]f8628c22011-04-05 12:10:18179#include "chrome/browser/prefs/scoped_user_pref_update.h"
[email protected]8ecad5e2010-12-02 21:18:33180#include "chrome/browser/profiles/profile.h"
[email protected]8e5c89a2011-06-07 18:13:33181#include "chrome/browser/search_engines/template_url_service.h"
[email protected]71b73f02011-04-06 15:57:29182#include "chrome/browser/ui/browser_list.h"
[email protected]10b132b02012-07-27 20:46:18183#include "chrome/browser/ui/browser_otr_state.h"
[email protected]157d5472009-11-05 22:31:03184#include "chrome/common/child_process_logging.h"
[email protected]432115822011-07-10 15:52:27185#include "chrome/common/chrome_notification_types.h"
[email protected]d7c1fa62012-06-15 23:35:30186#include "chrome/common/chrome_result_codes.h"
[email protected]92745242009-06-12 16:52:21187#include "chrome/common/chrome_switches.h"
[email protected]2e4cd1a2012-01-12 08:51:03188#include "chrome/common/metrics/metrics_log_manager.h"
[email protected]b4a72d842012-03-22 20:09:09189#include "chrome/common/net/test_server_locations.h"
initial.commit09911bf2008-07-26 23:55:29190#include "chrome/common/pref_names.h"
[email protected]e09ba552009-02-05 03:26:29191#include "chrome/common/render_messages.h"
[email protected]4967f792012-01-20 22:14:40192#include "content/public/browser/child_process_data.h"
[email protected]83ab4a282012-07-12 18:19:45193#include "content/public/browser/histogram_fetcher.h"
[email protected]09d31d52012-03-11 22:30:27194#include "content/public/browser/load_notification_details.h"
[email protected]ad50def52011-10-19 23:17:07195#include "content/public/browser/notification_service.h"
[email protected]3a5180ae2011-12-21 02:39:38196#include "content/public/browser/plugin_service.h"
[email protected]f3b1a082011-11-18 00:34:30197#include "content/public/browser/render_process_host.h"
[email protected]fe58acc22012-02-29 01:29:58198#include "net/base/load_flags.h"
[email protected]3dc1bc42012-06-19 08:20:53199#include "net/url_request/url_fetcher.h"
[email protected]91d9f3d2011-08-14 05:24:44200#include "webkit/plugins/webplugininfo.h"
initial.commit09911bf2008-07-26 23:55:29201
[email protected]e06131d2010-02-10 18:40:33202// TODO(port): port browser_distribution.h.
203#if !defined(OS_POSIX)
[email protected]79bf0b72009-04-27 21:30:55204#include "chrome/installer/util/browser_distribution.h"
[email protected]dc6f4962009-02-13 01:25:50205#endif
206
[email protected]5ccaa412009-11-13 22:00:16207#if defined(OS_CHROMEOS)
[email protected]db342d52010-08-09 21:19:37208#include "chrome/browser/chromeos/cros/cros_library.h"
[email protected]5ccaa412009-11-13 22:00:16209#include "chrome/browser/chromeos/external_metrics.h"
[email protected]d43970a72011-07-10 06:24:52210#include "chrome/browser/chromeos/system/statistics_provider.h"
[email protected]5ccaa412009-11-13 22:00:16211#endif
212
[email protected]d7c1fa62012-06-15 23:35:30213#if defined(OS_WIN)
214#include <windows.h> // Needed for STATUS_* codes
215#endif
216
[email protected]e1acf6f2008-10-27 20:43:33217using base::Time;
[email protected]631bb742011-11-02 11:29:39218using content::BrowserThread;
[email protected]4967f792012-01-20 22:14:40219using content::ChildProcessData;
[email protected]09d31d52012-03-11 22:30:27220using content::LoadNotificationDetails;
[email protected]3a5180ae2011-12-21 02:39:38221using content::PluginService;
[email protected]e1acf6f2008-10-27 20:43:33222
[email protected]fe58acc22012-02-29 01:29:58223namespace {
[email protected]b2a4812d2012-02-28 05:31:31224
[email protected]fe58acc22012-02-29 01:29:58225// Check to see that we're being called on only one thread.
226bool IsSingleThreaded() {
227 static base::PlatformThreadId thread_id = 0;
228 if (!thread_id)
229 thread_id = base::PlatformThread::CurrentId();
230 return base::PlatformThread::CurrentId() == thread_id;
231}
232
[email protected]7f7f1962011-04-20 15:58:16233// The delay, in seconds, after starting recording before doing expensive
234// initialization work.
[email protected]fe58acc22012-02-29 01:29:58235const int kInitializationDelaySeconds = 30;
[email protected]252873ef2008-08-04 21:59:45236
[email protected]c9a3ef82009-05-28 22:02:46237// This specifies the amount of time to wait for all renderers to send their
238// data.
[email protected]fe58acc22012-02-29 01:29:58239const int kMaxHistogramGatheringWaitDuration = 60000; // 60 seconds.
[email protected]c9a3ef82009-05-28 22:02:46240
[email protected]54702c92011-04-15 15:06:43241// The maximum number of events in a log uploaded to the UMA server.
[email protected]fe58acc22012-02-29 01:29:58242const int kEventLimit = 2400;
[email protected]68475e602008-08-22 03:21:15243
244// If an upload fails, and the transmission was over this byte count, then we
245// will discard the log, and not try to retransmit it. We also don't persist
246// the log to the prefs for transmission during the next chrome session if this
247// limit is exceeded.
[email protected]fe58acc22012-02-29 01:29:58248const size_t kUploadLogAvoidRetransmitSize = 50000;
initial.commit09911bf2008-07-26 23:55:29249
[email protected]fc4252a72012-01-12 21:58:47250// Interval, in minutes, between state saves.
[email protected]fe58acc22012-02-29 01:29:58251const int kSaveStateIntervalMinutes = 5;
252
[email protected]4266def22012-05-17 01:02:40253enum ResponseStatus {
254 UNKNOWN_FAILURE,
255 SUCCESS,
256 BAD_REQUEST, // Invalid syntax or log too large.
[email protected]9f5c1ce82012-05-23 23:11:28257 NO_RESPONSE,
[email protected]4266def22012-05-17 01:02:40258 NUM_RESPONSE_STATUSES
259};
260
261ResponseStatus ResponseCodeToStatus(int response_code) {
262 switch (response_code) {
263 case 200:
264 return SUCCESS;
265 case 400:
266 return BAD_REQUEST;
[email protected]9f5c1ce82012-05-23 23:11:28267 case net::URLFetcher::RESPONSE_CODE_INVALID:
268 return NO_RESPONSE;
[email protected]4266def22012-05-17 01:02:40269 default:
270 return UNKNOWN_FAILURE;
271 }
272}
273
[email protected]e61003a2012-05-24 17:03:19274// The argument used to generate a non-identifying entropy source. We want no
275// more than 13 bits of entropy, so use this max to return a number between 1
276// and 2^13 = 8192 as the entropy source.
277const uint32 kMaxEntropySize = (1 << 13);
278
279// Generates a new non-identifying entropy source used to seed persistent
280// activities.
281int GenerateLowEntropySource() {
282 return base::RandInt(1, kMaxEntropySize);
283}
284
[email protected]d7c1fa62012-06-15 23:35:30285// Converts an exit code into something that can be inserted into our
286// histograms (which expect non-negative numbers less than MAX_INT).
287int MapCrashExitCodeForHistogram(int exit_code) {
288#if defined(OS_WIN)
289 // Since |abs(STATUS_GUARD_PAGE_VIOLATION) == MAX_INT| it causes problems in
290 // histograms.cc. Solve this by remapping it to a smaller value, which
291 // hopefully doesn't conflict with other codes.
292 if (exit_code == STATUS_GUARD_PAGE_VIOLATION)
293 return 0x1FCF7EC3; // Randomly picked number.
294#endif
295
296 return std::abs(exit_code);
297}
298
299// Returns a list of all the likely exit codes for crashed renderer processes.
300// The exit codes are all positive, since that is what histograms expect.
301std::vector<int> GetAllCrashExitCodes() {
302 std::vector<int> codes;
303
304 // Chrome defines its own exit codes in the range
305 // 1 to RESULT_CODE_CHROME_LAST_CODE.
306 for (int i = 1; i < chrome::RESULT_CODE_CHROME_LAST_CODE; ++i)
307 codes.push_back(i);
308
309#if defined(OS_WIN)
310 // The exit code when crashing will be one of the Windows exception codes.
311 int kExceptionCodes[] = {
312 0xe06d7363, // C++ EH exception
313 STATUS_ACCESS_VIOLATION,
314 STATUS_ARRAY_BOUNDS_EXCEEDED,
315 STATUS_BREAKPOINT,
316 STATUS_CONTROL_C_EXIT,
317 STATUS_DATATYPE_MISALIGNMENT,
318 STATUS_FLOAT_DENORMAL_OPERAND,
319 STATUS_FLOAT_DIVIDE_BY_ZERO,
320 STATUS_FLOAT_INEXACT_RESULT,
321 STATUS_FLOAT_INVALID_OPERATION,
322 STATUS_FLOAT_OVERFLOW,
323 STATUS_FLOAT_STACK_CHECK,
324 STATUS_FLOAT_UNDERFLOW,
325 STATUS_GUARD_PAGE_VIOLATION,
326 STATUS_ILLEGAL_INSTRUCTION,
327 STATUS_INTEGER_DIVIDE_BY_ZERO,
328 STATUS_INTEGER_OVERFLOW,
329 STATUS_INVALID_DISPOSITION,
330 STATUS_INVALID_HANDLE,
331 STATUS_INVALID_PARAMETER,
332 STATUS_IN_PAGE_ERROR,
333 STATUS_NONCONTINUABLE_EXCEPTION,
334 STATUS_NO_MEMORY,
335 STATUS_PRIVILEGED_INSTRUCTION,
336 STATUS_SINGLE_STEP,
337 STATUS_STACK_OVERFLOW,
338 };
339
340 for (size_t i = 0; i < arraysize(kExceptionCodes); ++i)
341 codes.push_back(MapCrashExitCodeForHistogram(kExceptionCodes[i]));
342#endif
343
344 return codes;
345}
346
[email protected]fe58acc22012-02-29 01:29:58347}
initial.commit09911bf2008-07-26 23:55:29348
[email protected]c0c55e92011-09-10 18:47:30349// static
350MetricsService::ShutdownCleanliness MetricsService::clean_shutdown_status_ =
351 MetricsService::CLEANLY_SHUTDOWN;
352
[email protected]679082052010-07-21 21:30:13353// This is used to quickly log stats from child process related notifications in
354// MetricsService::child_stats_buffer_. The buffer's contents are transferred
355// out when Local State is periodically saved. The information is then
356// reported to the UMA server on next launch.
357struct MetricsService::ChildProcessStats {
358 public:
[email protected]bd5d6cf2011-12-01 00:39:12359 explicit ChildProcessStats(content::ProcessType type)
[email protected]679082052010-07-21 21:30:13360 : process_launches(0),
361 process_crashes(0),
362 instances(0),
[email protected]cd937072012-07-02 09:00:29363 loading_errors(0),
[email protected]679082052010-07-21 21:30:13364 process_type(type) {}
365
366 // This constructor is only used by the map to return some default value for
367 // an index for which no value has been assigned.
368 ChildProcessStats()
369 : process_launches(0),
[email protected]d88bf0a2011-08-30 23:55:57370 process_crashes(0),
371 instances(0),
[email protected]cd937072012-07-02 09:00:29372 loading_errors(0),
[email protected]bd5d6cf2011-12-01 00:39:12373 process_type(content::PROCESS_TYPE_UNKNOWN) {}
[email protected]679082052010-07-21 21:30:13374
375 // The number of times that the given child process has been launched
376 int process_launches;
377
378 // The number of times that the given child process has crashed
379 int process_crashes;
380
381 // The number of instances of this child process that have been created.
382 // An instance is a DOM object rendered by this child process during a page
383 // load.
384 int instances;
385
[email protected]cd937072012-07-02 09:00:29386 // The number of times there was an error loading an instance of this child
387 // process.
388 int loading_errors;
389
[email protected]bd5d6cf2011-12-01 00:39:12390 content::ProcessType process_type;
[email protected]679082052010-07-21 21:30:13391};
initial.commit09911bf2008-07-26 23:55:29392
[email protected]84c988a2011-04-19 17:56:33393// Handles asynchronous fetching of memory details.
394// Will run the provided task after finished.
395class MetricsMemoryDetails : public MemoryDetails {
396 public:
[email protected]2226c222011-11-22 00:08:40397 explicit MetricsMemoryDetails(const base::Closure& callback)
398 : callback_(callback) {}
[email protected]84c988a2011-04-19 17:56:33399
400 virtual void OnDetailsAvailable() {
[email protected]2226c222011-11-22 00:08:40401 MessageLoop::current()->PostTask(FROM_HERE, callback_);
[email protected]84c988a2011-04-19 17:56:33402 }
403
404 private:
405 ~MetricsMemoryDetails() {}
406
[email protected]2226c222011-11-22 00:08:40407 base::Closure callback_;
[email protected]84c988a2011-04-19 17:56:33408 DISALLOW_COPY_AND_ASSIGN(MetricsMemoryDetails);
409};
410
initial.commit09911bf2008-07-26 23:55:29411// static
412void MetricsService::RegisterPrefs(PrefService* local_state) {
413 DCHECK(IsSingleThreaded());
[email protected]20ce516d2010-06-18 02:20:04414 local_state->RegisterStringPref(prefs::kMetricsClientID, "");
[email protected]e61003a2012-05-24 17:03:19415 local_state->RegisterIntegerPref(prefs::kMetricsLowEntropySource, 0);
[email protected]0bb1a622009-03-04 03:22:32416 local_state->RegisterInt64Pref(prefs::kMetricsClientIDTimestamp, 0);
417 local_state->RegisterInt64Pref(prefs::kStabilityLaunchTimeSec, 0);
418 local_state->RegisterInt64Pref(prefs::kStabilityLastTimestampSec, 0);
[email protected]20ce516d2010-06-18 02:20:04419 local_state->RegisterStringPref(prefs::kStabilityStatsVersion, "");
[email protected]225c50842010-01-19 21:19:13420 local_state->RegisterInt64Pref(prefs::kStabilityStatsBuildTime, 0);
initial.commit09911bf2008-07-26 23:55:29421 local_state->RegisterBooleanPref(prefs::kStabilityExitedCleanly, true);
422 local_state->RegisterBooleanPref(prefs::kStabilitySessionEndCompleted, true);
423 local_state->RegisterIntegerPref(prefs::kMetricsSessionID, -1);
424 local_state->RegisterIntegerPref(prefs::kStabilityLaunchCount, 0);
425 local_state->RegisterIntegerPref(prefs::kStabilityCrashCount, 0);
426 local_state->RegisterIntegerPref(prefs::kStabilityIncompleteSessionEndCount,
427 0);
428 local_state->RegisterIntegerPref(prefs::kStabilityPageLoadCount, 0);
initial.commit09911bf2008-07-26 23:55:29429 local_state->RegisterIntegerPref(prefs::kStabilityRendererCrashCount, 0);
[email protected]1f085622009-12-04 05:33:45430 local_state->RegisterIntegerPref(prefs::kStabilityExtensionRendererCrashCount,
431 0);
initial.commit09911bf2008-07-26 23:55:29432 local_state->RegisterIntegerPref(prefs::kStabilityRendererHangCount, 0);
[email protected]1f085622009-12-04 05:33:45433 local_state->RegisterIntegerPref(prefs::kStabilityChildProcessCrashCount, 0);
[email protected]e73c01972008-08-13 00:18:24434 local_state->RegisterIntegerPref(prefs::kStabilityBreakpadRegistrationFail,
435 0);
436 local_state->RegisterIntegerPref(prefs::kStabilityBreakpadRegistrationSuccess,
437 0);
438 local_state->RegisterIntegerPref(prefs::kStabilityDebuggerPresent, 0);
439 local_state->RegisterIntegerPref(prefs::kStabilityDebuggerNotPresent, 0);
[email protected]c1834a92011-01-21 18:21:03440#if defined(OS_CHROMEOS)
441 local_state->RegisterIntegerPref(prefs::kStabilityOtherUserCrashCount, 0);
442 local_state->RegisterIntegerPref(prefs::kStabilityKernelCrashCount, 0);
443 local_state->RegisterIntegerPref(prefs::kStabilitySystemUncleanShutdownCount,
444 0);
445#endif // OS_CHROMEOS
[email protected]e73c01972008-08-13 00:18:24446
initial.commit09911bf2008-07-26 23:55:29447 local_state->RegisterDictionaryPref(prefs::kProfileMetrics);
448 local_state->RegisterIntegerPref(prefs::kNumBookmarksOnBookmarkBar, 0);
449 local_state->RegisterIntegerPref(prefs::kNumFoldersOnBookmarkBar, 0);
450 local_state->RegisterIntegerPref(prefs::kNumBookmarksInOtherBookmarkFolder,
451 0);
452 local_state->RegisterIntegerPref(prefs::kNumFoldersInOtherBookmarkFolder, 0);
453 local_state->RegisterIntegerPref(prefs::kNumKeywords, 0);
[email protected]fe58acc22012-02-29 01:29:58454 local_state->RegisterListPref(prefs::kMetricsInitialLogsXml);
455 local_state->RegisterListPref(prefs::kMetricsOngoingLogsXml);
456 local_state->RegisterListPref(prefs::kMetricsInitialLogsProto);
457 local_state->RegisterListPref(prefs::kMetricsOngoingLogsProto);
[email protected]0bb1a622009-03-04 03:22:32458
459 local_state->RegisterInt64Pref(prefs::kUninstallMetricsPageLoadCount, 0);
460 local_state->RegisterInt64Pref(prefs::kUninstallLaunchCount, 0);
[email protected]6b5f21d2009-04-13 17:01:35461 local_state->RegisterInt64Pref(prefs::kUninstallMetricsInstallDate, 0);
[email protected]0bb1a622009-03-04 03:22:32462 local_state->RegisterInt64Pref(prefs::kUninstallMetricsUptimeSec, 0);
463 local_state->RegisterInt64Pref(prefs::kUninstallLastLaunchTimeSec, 0);
464 local_state->RegisterInt64Pref(prefs::kUninstallLastObservedRunTimeSec, 0);
initial.commit09911bf2008-07-26 23:55:29465}
466
[email protected]541f77922009-02-23 21:14:38467// static
468void MetricsService::DiscardOldStabilityStats(PrefService* local_state) {
469 local_state->SetBoolean(prefs::kStabilityExitedCleanly, true);
[email protected]c9abf242009-07-18 06:00:38470 local_state->SetBoolean(prefs::kStabilitySessionEndCompleted, true);
[email protected]541f77922009-02-23 21:14:38471
472 local_state->SetInteger(prefs::kStabilityIncompleteSessionEndCount, 0);
473 local_state->SetInteger(prefs::kStabilityBreakpadRegistrationSuccess, 0);
474 local_state->SetInteger(prefs::kStabilityBreakpadRegistrationFail, 0);
475 local_state->SetInteger(prefs::kStabilityDebuggerPresent, 0);
476 local_state->SetInteger(prefs::kStabilityDebuggerNotPresent, 0);
477
478 local_state->SetInteger(prefs::kStabilityLaunchCount, 0);
479 local_state->SetInteger(prefs::kStabilityCrashCount, 0);
480
481 local_state->SetInteger(prefs::kStabilityPageLoadCount, 0);
482 local_state->SetInteger(prefs::kStabilityRendererCrashCount, 0);
483 local_state->SetInteger(prefs::kStabilityRendererHangCount, 0);
484
[email protected]9165f742010-03-10 22:55:01485 local_state->SetInt64(prefs::kStabilityLaunchTimeSec, 0);
486 local_state->SetInt64(prefs::kStabilityLastTimestampSec, 0);
[email protected]541f77922009-02-23 21:14:38487
488 local_state->ClearPref(prefs::kStabilityPluginStats);
[email protected]ae155cb92009-06-19 06:10:37489
[email protected]fe58acc22012-02-29 01:29:58490 local_state->ClearPref(prefs::kMetricsInitialLogsXml);
491 local_state->ClearPref(prefs::kMetricsOngoingLogsXml);
492 local_state->ClearPref(prefs::kMetricsInitialLogsProto);
493 local_state->ClearPref(prefs::kMetricsOngoingLogsProto);
[email protected]541f77922009-02-23 21:14:38494}
495
initial.commit09911bf2008-07-26 23:55:29496MetricsService::MetricsService()
[email protected]d01b8732008-10-16 02:18:07497 : recording_active_(false),
498 reporting_active_(false),
[email protected]d01b8732008-10-16 02:18:07499 state_(INITIALIZED),
[email protected]e61003a2012-05-24 17:03:19500 low_entropy_source_(0),
[email protected]d01b8732008-10-16 02:18:07501 idle_since_last_transmission_(false),
initial.commit09911bf2008-07-26 23:55:29502 next_window_id_(0),
[email protected]c94d7382012-02-28 08:43:40503 ALLOW_THIS_IN_INITIALIZER_LIST(self_ptr_factory_(this)),
[email protected]40bcc302009-03-02 20:50:39504 ALLOW_THIS_IN_INITIALIZER_LIST(state_saver_factory_(this)),
[email protected]e5354322012-08-09 23:07:37505 waiting_for_asynchronous_reporting_step_(false),
506 entropy_source_returned_(LAST_ENTROPY_NONE) {
initial.commit09911bf2008-07-26 23:55:29507 DCHECK(IsSingleThreaded());
508 InitializeMetricsState();
[email protected]7f7f1962011-04-20 15:58:16509
510 base::Closure callback = base::Bind(&MetricsService::StartScheduledUpload,
[email protected]c94d7382012-02-28 08:43:40511 self_ptr_factory_.GetWeakPtr());
[email protected]7f7f1962011-04-20 15:58:16512 scheduler_.reset(new MetricsReportingScheduler(callback));
[email protected]cac267c2011-09-29 15:18:10513 log_manager_.set_log_serializer(new MetricsLogSerializer());
514 log_manager_.set_max_ongoing_log_store_size(kUploadLogAvoidRetransmitSize);
initial.commit09911bf2008-07-26 23:55:29515}
516
517MetricsService::~MetricsService() {
518 SetRecording(false);
519}
520
[email protected]d01b8732008-10-16 02:18:07521void MetricsService::Start() {
[email protected]b1c8dc02011-04-13 18:32:04522 HandleIdleSinceLastTransmission(false);
[email protected]d01b8732008-10-16 02:18:07523 SetRecording(true);
524 SetReporting(true);
525}
526
527void MetricsService::StartRecordingOnly() {
528 SetRecording(true);
529 SetReporting(false);
530}
531
532void MetricsService::Stop() {
[email protected]b1c8dc02011-04-13 18:32:04533 HandleIdleSinceLastTransmission(false);
[email protected]d01b8732008-10-16 02:18:07534 SetReporting(false);
535 SetRecording(false);
536}
537
[email protected]edafd4c2011-05-10 17:18:53538std::string MetricsService::GetClientId() {
539 return client_id_;
540}
541
[email protected]e5354322012-08-09 23:07:37542std::string MetricsService::GetEntropySource(bool reporting_will_be_enabled) {
[email protected]29d81ee02012-05-25 05:45:42543 // For metrics reporting-enabled users, we combine the client ID and low
544 // entropy source to get the final entropy source. Otherwise, only use the low
545 // entropy source.
546 // This has two useful properties:
[email protected]e61003a2012-05-24 17:03:19547 // 1) It makes the entropy source less identifiable for parties that do not
548 // know the low entropy source.
549 // 2) It makes the final entropy source resettable.
[email protected]29d81ee02012-05-25 05:45:42550 std::string low_entropy_source = base::IntToString(GetLowEntropySource());
[email protected]e5354322012-08-09 23:07:37551 if (reporting_will_be_enabled) {
[email protected]5fbffb72012-08-18 01:59:18552 if (entropy_source_returned_ == LAST_ENTROPY_NONE)
553 entropy_source_returned_ = LAST_ENTROPY_HIGH;
554 DCHECK_EQ(LAST_ENTROPY_HIGH, entropy_source_returned_);
[email protected]29d81ee02012-05-25 05:45:42555 return client_id_ + low_entropy_source;
[email protected]e5354322012-08-09 23:07:37556 }
[email protected]5fbffb72012-08-18 01:59:18557 if (entropy_source_returned_ == LAST_ENTROPY_NONE)
558 entropy_source_returned_ = LAST_ENTROPY_LOW;
559 DCHECK_EQ(LAST_ENTROPY_LOW, entropy_source_returned_);
[email protected]29d81ee02012-05-25 05:45:42560 return low_entropy_source;
[email protected]e61003a2012-05-24 17:03:19561}
562
[email protected]5cbeeef72012-02-08 02:05:18563void MetricsService::ForceClientIdCreation() {
564 if (!client_id_.empty())
565 return;
566 PrefService* pref = g_browser_process->local_state();
567 client_id_ = pref->GetString(prefs::kMetricsClientID);
568 if (!client_id_.empty())
569 return;
570
571 client_id_ = GenerateClientID();
572 pref->SetString(prefs::kMetricsClientID, client_id_);
573
574 // Might as well make a note of how long this ID has existed
575 pref->SetString(prefs::kMetricsClientIDTimestamp,
576 base::Int64ToString(Time::Now().ToTimeT()));
577}
578
initial.commit09911bf2008-07-26 23:55:29579void MetricsService::SetRecording(bool enabled) {
580 DCHECK(IsSingleThreaded());
581
[email protected]d01b8732008-10-16 02:18:07582 if (enabled == recording_active_)
initial.commit09911bf2008-07-26 23:55:29583 return;
584
585 if (enabled) {
[email protected]5cbeeef72012-02-08 02:05:18586 ForceClientIdCreation();
[email protected]157d5472009-11-05 22:31:03587 child_process_logging::SetClientId(client_id_);
initial.commit09911bf2008-07-26 23:55:29588 StartRecording();
[email protected]005ef3e2009-05-22 20:55:46589
[email protected]3ffd3ae2011-03-17 22:17:52590 SetUpNotifications(&registrar_, this);
initial.commit09911bf2008-07-26 23:55:29591 } else {
[email protected]005ef3e2009-05-22 20:55:46592 registrar_.RemoveAll();
[email protected]cac267c2011-09-29 15:18:10593 PushPendingLogsToPersistentStorage();
594 DCHECK(!log_manager_.has_staged_log());
initial.commit09911bf2008-07-26 23:55:29595 }
[email protected]d01b8732008-10-16 02:18:07596 recording_active_ = enabled;
initial.commit09911bf2008-07-26 23:55:29597}
598
[email protected]d01b8732008-10-16 02:18:07599bool MetricsService::recording_active() const {
initial.commit09911bf2008-07-26 23:55:29600 DCHECK(IsSingleThreaded());
[email protected]d01b8732008-10-16 02:18:07601 return recording_active_;
initial.commit09911bf2008-07-26 23:55:29602}
603
[email protected]d01b8732008-10-16 02:18:07604void MetricsService::SetReporting(bool enable) {
605 if (reporting_active_ != enable) {
606 reporting_active_ = enable;
607 if (reporting_active_)
[email protected]7f7f1962011-04-20 15:58:16608 StartSchedulerIfNecessary();
initial.commit09911bf2008-07-26 23:55:29609 }
[email protected]d01b8732008-10-16 02:18:07610}
611
612bool MetricsService::reporting_active() const {
613 DCHECK(IsSingleThreaded());
614 return reporting_active_;
initial.commit09911bf2008-07-26 23:55:29615}
616
[email protected]87ef9ea2011-02-26 03:15:15617// static
[email protected]6c2381d2011-10-19 02:52:53618void MetricsService::SetUpNotifications(
619 content::NotificationRegistrar* registrar,
620 content::NotificationObserver* observer) {
621 registrar->Add(observer, chrome::NOTIFICATION_BROWSER_OPENED,
[email protected]ad50def52011-10-19 23:17:07622 content::NotificationService::AllBrowserContextsAndSources());
[email protected]6c2381d2011-10-19 02:52:53623 registrar->Add(observer, chrome::NOTIFICATION_BROWSER_CLOSED,
[email protected]ad50def52011-10-19 23:17:07624 content::NotificationService::AllSources());
[email protected]6c2381d2011-10-19 02:52:53625 registrar->Add(observer, content::NOTIFICATION_USER_ACTION,
[email protected]ad50def52011-10-19 23:17:07626 content::NotificationService::AllSources());
[email protected]884033e2012-04-16 19:38:42627 registrar->Add(observer, chrome::NOTIFICATION_TAB_PARENTED,
[email protected]ad50def52011-10-19 23:17:07628 content::NotificationService::AllSources());
[email protected]884033e2012-04-16 19:38:42629 registrar->Add(observer, chrome::NOTIFICATION_TAB_CLOSING,
[email protected]ad50def52011-10-19 23:17:07630 content::NotificationService::AllSources());
[email protected]6c2381d2011-10-19 02:52:53631 registrar->Add(observer, content::NOTIFICATION_LOAD_START,
[email protected]ad50def52011-10-19 23:17:07632 content::NotificationService::AllSources());
[email protected]6c2381d2011-10-19 02:52:53633 registrar->Add(observer, content::NOTIFICATION_LOAD_STOP,
[email protected]ad50def52011-10-19 23:17:07634 content::NotificationService::AllSources());
[email protected]6c2381d2011-10-19 02:52:53635 registrar->Add(observer, content::NOTIFICATION_RENDERER_PROCESS_CLOSED,
[email protected]ad50def52011-10-19 23:17:07636 content::NotificationService::AllSources());
[email protected]6c2381d2011-10-19 02:52:53637 registrar->Add(observer, content::NOTIFICATION_RENDERER_PROCESS_HANG,
[email protected]ad50def52011-10-19 23:17:07638 content::NotificationService::AllSources());
[email protected]6c2381d2011-10-19 02:52:53639 registrar->Add(observer, content::NOTIFICATION_CHILD_PROCESS_HOST_CONNECTED,
[email protected]ad50def52011-10-19 23:17:07640 content::NotificationService::AllSources());
[email protected]6c2381d2011-10-19 02:52:53641 registrar->Add(observer, content::NOTIFICATION_CHILD_INSTANCE_CREATED,
[email protected]ad50def52011-10-19 23:17:07642 content::NotificationService::AllSources());
[email protected]6c2381d2011-10-19 02:52:53643 registrar->Add(observer, content::NOTIFICATION_CHILD_PROCESS_CRASHED,
[email protected]ad50def52011-10-19 23:17:07644 content::NotificationService::AllSources());
[email protected]6c2381d2011-10-19 02:52:53645 registrar->Add(observer, chrome::NOTIFICATION_TEMPLATE_URL_SERVICE_LOADED,
[email protected]ad50def52011-10-19 23:17:07646 content::NotificationService::AllSources());
[email protected]6c2381d2011-10-19 02:52:53647 registrar->Add(observer, chrome::NOTIFICATION_OMNIBOX_OPENED_URL,
[email protected]ad50def52011-10-19 23:17:07648 content::NotificationService::AllSources());
[email protected]6c2381d2011-10-19 02:52:53649 registrar->Add(observer, chrome::NOTIFICATION_BOOKMARK_MODEL_LOADED,
[email protected]ad50def52011-10-19 23:17:07650 content::NotificationService::AllBrowserContextsAndSources());
[email protected]87ef9ea2011-02-26 03:15:15651}
652
[email protected]432115822011-07-10 15:52:27653void MetricsService::Observe(int type,
[email protected]6c2381d2011-10-19 02:52:53654 const content::NotificationSource& source,
655 const content::NotificationDetails& details) {
[email protected]cac267c2011-09-29 15:18:10656 DCHECK(log_manager_.current_log());
initial.commit09911bf2008-07-26 23:55:29657 DCHECK(IsSingleThreaded());
658
659 if (!CanLogNotification(type, source, details))
660 return;
661
[email protected]432115822011-07-10 15:52:27662 switch (type) {
663 case content::NOTIFICATION_USER_ACTION:
[email protected]cac267c2011-09-29 15:18:10664 log_manager_.current_log()->RecordUserAction(
[email protected]6c2381d2011-10-19 02:52:53665 *content::Details<const char*>(details).ptr());
initial.commit09911bf2008-07-26 23:55:29666 break;
667
[email protected]432115822011-07-10 15:52:27668 case chrome::NOTIFICATION_BROWSER_OPENED:
669 case chrome::NOTIFICATION_BROWSER_CLOSED:
initial.commit09911bf2008-07-26 23:55:29670 LogWindowChange(type, source, details);
671 break;
672
[email protected]884033e2012-04-16 19:38:42673 case chrome::NOTIFICATION_TAB_PARENTED:
674 case chrome::NOTIFICATION_TAB_CLOSING:
initial.commit09911bf2008-07-26 23:55:29675 LogWindowChange(type, source, details);
676 break;
677
[email protected]432115822011-07-10 15:52:27678 case content::NOTIFICATION_LOAD_STOP:
initial.commit09911bf2008-07-26 23:55:29679 LogLoadComplete(type, source, details);
680 break;
681
[email protected]432115822011-07-10 15:52:27682 case content::NOTIFICATION_LOAD_START:
initial.commit09911bf2008-07-26 23:55:29683 LogLoadStarted();
684 break;
685
[email protected]432115822011-07-10 15:52:27686 case content::NOTIFICATION_RENDERER_PROCESS_CLOSED: {
[email protected]f3b1a082011-11-18 00:34:30687 content::RenderProcessHost::RendererClosedDetails* process_details =
688 content::Details<
689 content::RenderProcessHost::RendererClosedDetails>(
690 details).ptr();
691 content::RenderProcessHost* host =
692 content::Source<content::RenderProcessHost>(source).ptr();
[email protected]c3721482012-03-23 16:21:48693 LogRendererCrash(
[email protected]f1675202012-07-09 15:18:00694 host, process_details->status, process_details->exit_code);
[email protected]1f085622009-12-04 05:33:45695 }
initial.commit09911bf2008-07-26 23:55:29696 break;
697
[email protected]432115822011-07-10 15:52:27698 case content::NOTIFICATION_RENDERER_PROCESS_HANG:
initial.commit09911bf2008-07-26 23:55:29699 LogRendererHang();
700 break;
701
[email protected]432115822011-07-10 15:52:27702 case content::NOTIFICATION_CHILD_PROCESS_HOST_CONNECTED:
703 case content::NOTIFICATION_CHILD_PROCESS_CRASHED:
704 case content::NOTIFICATION_CHILD_INSTANCE_CREATED:
[email protected]a27a9382009-02-11 23:55:10705 LogChildProcessChange(type, source, details);
initial.commit09911bf2008-07-26 23:55:29706 break;
707
[email protected]432115822011-07-10 15:52:27708 case chrome::NOTIFICATION_TEMPLATE_URL_SERVICE_LOADED:
[email protected]604d8a062012-03-16 21:37:46709 LogKeywordCount(content::Source<TemplateURLService>(
710 source)->GetTemplateURLs().size());
initial.commit09911bf2008-07-26 23:55:29711 break;
712
[email protected]432115822011-07-10 15:52:27713 case chrome::NOTIFICATION_OMNIBOX_OPENED_URL: {
[email protected]279703f2012-01-20 22:23:26714 MetricsLog* current_log =
715 static_cast<MetricsLog*>(log_manager_.current_log());
[email protected]1226abb2010-06-10 18:01:28716 DCHECK(current_log);
717 current_log->RecordOmniboxOpenedURL(
[email protected]6c2381d2011-10-19 02:52:53718 *content::Details<AutocompleteLog>(details).ptr());
initial.commit09911bf2008-07-26 23:55:29719 break;
[email protected]1226abb2010-06-10 18:01:28720 }
initial.commit09911bf2008-07-26 23:55:29721
[email protected]432115822011-07-10 15:52:27722 case chrome::NOTIFICATION_BOOKMARK_MODEL_LOADED: {
[email protected]6c2381d2011-10-19 02:52:53723 Profile* p = content::Source<Profile>(source).ptr();
[email protected]b61236c62009-04-09 22:43:55724 if (p)
[email protected]e07f2da2012-08-01 22:46:12725 LogBookmarks(BookmarkModelFactory::GetForProfile(p));
initial.commit09911bf2008-07-26 23:55:29726 break;
[email protected]b61236c62009-04-09 22:43:55727 }
initial.commit09911bf2008-07-26 23:55:29728 default:
[email protected]a063c102010-07-22 22:20:19729 NOTREACHED();
initial.commit09911bf2008-07-26 23:55:29730 break;
731 }
[email protected]d01b8732008-10-16 02:18:07732
733 HandleIdleSinceLastTransmission(false);
[email protected]d01b8732008-10-16 02:18:07734}
735
736void MetricsService::HandleIdleSinceLastTransmission(bool in_idle) {
737 // If there wasn't a lot of action, maybe the computer was asleep, in which
738 // case, the log transmissions should have stopped. Here we start them up
739 // again.
[email protected]cac78842008-11-27 01:02:20740 if (!in_idle && idle_since_last_transmission_)
[email protected]7f7f1962011-04-20 15:58:16741 StartSchedulerIfNecessary();
[email protected]cac78842008-11-27 01:02:20742 idle_since_last_transmission_ = in_idle;
initial.commit09911bf2008-07-26 23:55:29743}
744
initial.commit09911bf2008-07-26 23:55:29745void MetricsService::RecordStartOfSessionEnd() {
[email protected]466f3c12011-03-23 21:20:38746 LogCleanShutdown();
initial.commit09911bf2008-07-26 23:55:29747 RecordBooleanPrefValue(prefs::kStabilitySessionEndCompleted, false);
748}
749
750void MetricsService::RecordCompletedSessionEnd() {
[email protected]466f3c12011-03-23 21:20:38751 LogCleanShutdown();
initial.commit09911bf2008-07-26 23:55:29752 RecordBooleanPrefValue(prefs::kStabilitySessionEndCompleted, true);
753}
754
[email protected]117fbdf22012-06-26 18:36:39755#if defined(OS_ANDROID)
756void MetricsService::OnAppEnterBackground() {
757 scheduler_->Stop();
758
759 PrefService* pref = g_browser_process->local_state();
760 pref->SetBoolean(prefs::kStabilityExitedCleanly, true);
761
762 // At this point, there's no way of knowing when the process will be
763 // killed, so this has to be treated similar to a shutdown, closing and
764 // persisting all logs. Unlinke a shutdown, the state is primed to be ready
765 // to continue logging and uploading if the process does return.
766 if (recording_active() && state_ >= INITIAL_LOG_READY) {
767 PushPendingLogsToPersistentStorage();
[email protected]117fbdf22012-06-26 18:36:39768 // Persisting logs stops recording, so start recording a new log immediately
769 // to capture any background work that might be done before the process is
770 // killed.
771 StartRecording();
772 }
773
774 // Start writing right away (write happens on a different thread).
775 pref->CommitPendingWrite();
776}
777
778void MetricsService::OnAppEnterForeground() {
779 PrefService* pref = g_browser_process->local_state();
780 pref->SetBoolean(prefs::kStabilityExitedCleanly, false);
781
782 StartSchedulerIfNecessary();
783}
784#endif
785
[email protected]7f7f1962011-04-20 15:58:16786void MetricsService::RecordBreakpadRegistration(bool success) {
[email protected]68475e602008-08-22 03:21:15787 if (!success)
[email protected]e73c01972008-08-13 00:18:24788 IncrementPrefValue(prefs::kStabilityBreakpadRegistrationFail);
789 else
790 IncrementPrefValue(prefs::kStabilityBreakpadRegistrationSuccess);
791}
792
793void MetricsService::RecordBreakpadHasDebugger(bool has_debugger) {
794 if (!has_debugger)
795 IncrementPrefValue(prefs::kStabilityDebuggerNotPresent);
796 else
[email protected]68475e602008-08-22 03:21:15797 IncrementPrefValue(prefs::kStabilityDebuggerPresent);
[email protected]e73c01972008-08-13 00:18:24798}
799
initial.commit09911bf2008-07-26 23:55:29800//------------------------------------------------------------------------------
801// private methods
802//------------------------------------------------------------------------------
803
804
805//------------------------------------------------------------------------------
806// Initialization methods
807
808void MetricsService::InitializeMetricsState() {
[email protected]79bf0b72009-04-27 21:30:55809#if defined(OS_POSIX)
[email protected]fe58acc22012-02-29 01:29:58810 server_url_xml_ = ASCIIToUTF16(kServerUrlXml);
811 server_url_proto_ = ASCIIToUTF16(kServerUrlProto);
[email protected]b4a72d842012-03-22 20:09:09812 network_stats_server_ = chrome_common_net::kEchoTestServerLocation;
813 http_pipelining_test_server_ = chrome_common_net::kPipelineTestServerBaseUrl;
[email protected]79bf0b72009-04-27 21:30:55814#else
815 BrowserDistribution* dist = BrowserDistribution::GetDistribution();
[email protected]fe58acc22012-02-29 01:29:58816 server_url_xml_ = dist->GetStatsServerURL();
817 server_url_proto_ = ASCIIToUTF16(kServerUrlProto);
[email protected]d67d1052011-06-09 05:11:41818 network_stats_server_ = dist->GetNetworkStatsServer();
[email protected]adbb3762012-03-09 22:20:08819 http_pipelining_test_server_ = dist->GetHttpPipeliningTestServer();
[email protected]79bf0b72009-04-27 21:30:55820#endif
821
initial.commit09911bf2008-07-26 23:55:29822 PrefService* pref = g_browser_process->local_state();
823 DCHECK(pref);
824
[email protected]225c50842010-01-19 21:19:13825 if ((pref->GetInt64(prefs::kStabilityStatsBuildTime)
826 != MetricsLog::GetBuildTime()) ||
[email protected]ddd231e2010-06-29 20:35:19827 (pref->GetString(prefs::kStabilityStatsVersion)
[email protected]225c50842010-01-19 21:19:13828 != MetricsLog::GetVersionString())) {
[email protected]541f77922009-02-23 21:14:38829 // This is a new version, so we don't want to confuse the stats about the
830 // old version with info that we upload.
831 DiscardOldStabilityStats(pref);
832 pref->SetString(prefs::kStabilityStatsVersion,
[email protected]ddd231e2010-06-29 20:35:19833 MetricsLog::GetVersionString());
[email protected]225c50842010-01-19 21:19:13834 pref->SetInt64(prefs::kStabilityStatsBuildTime,
835 MetricsLog::GetBuildTime());
[email protected]541f77922009-02-23 21:14:38836 }
837
initial.commit09911bf2008-07-26 23:55:29838 // Update session ID
839 session_id_ = pref->GetInteger(prefs::kMetricsSessionID);
840 ++session_id_;
841 pref->SetInteger(prefs::kMetricsSessionID, session_id_);
842
initial.commit09911bf2008-07-26 23:55:29843 // Stability bookkeeping
[email protected]e73c01972008-08-13 00:18:24844 IncrementPrefValue(prefs::kStabilityLaunchCount);
initial.commit09911bf2008-07-26 23:55:29845
[email protected]e73c01972008-08-13 00:18:24846 if (!pref->GetBoolean(prefs::kStabilityExitedCleanly)) {
847 IncrementPrefValue(prefs::kStabilityCrashCount);
[email protected]c0c55e92011-09-10 18:47:30848 // Reset flag, and wait until we call LogNeedForCleanShutdown() before
849 // monitoring.
850 pref->SetBoolean(prefs::kStabilityExitedCleanly, true);
initial.commit09911bf2008-07-26 23:55:29851 }
[email protected]e73c01972008-08-13 00:18:24852
[email protected]e73c01972008-08-13 00:18:24853 if (!pref->GetBoolean(prefs::kStabilitySessionEndCompleted)) {
854 IncrementPrefValue(prefs::kStabilityIncompleteSessionEndCount);
[email protected]c9abf242009-07-18 06:00:38855 // This is marked false when we get a WM_ENDSESSION.
856 pref->SetBoolean(prefs::kStabilitySessionEndCompleted, true);
initial.commit09911bf2008-07-26 23:55:29857 }
initial.commit09911bf2008-07-26 23:55:29858
[email protected]9165f742010-03-10 22:55:01859 // Initialize uptime counters.
860 int64 startup_uptime = MetricsLog::GetIncrementalUptime(pref);
[email protected]ae393ec702010-06-27 16:23:14861 DCHECK_EQ(0, startup_uptime);
[email protected]9165f742010-03-10 22:55:01862 // For backwards compatibility, leave this intact in case Omaha is checking
863 // them. prefs::kStabilityLastTimestampSec may also be useless now.
864 // TODO(jar): Delete these if they have no uses.
[email protected]0bb1a622009-03-04 03:22:32865 pref->SetInt64(prefs::kStabilityLaunchTimeSec, Time::Now().ToTimeT());
866
867 // Bookkeeping for the uninstall metrics.
868 IncrementLongPrefsValue(prefs::kUninstallLaunchCount);
initial.commit09911bf2008-07-26 23:55:29869
870 // Save profile metrics.
871 PrefService* prefs = g_browser_process->local_state();
872 if (prefs) {
873 // Remove the current dictionary and store it for use when sending data to
874 // server. By removing the value we prune potentially dead profiles
875 // (and keys). All valid values are added back once services startup.
876 const DictionaryValue* profile_dictionary =
877 prefs->GetDictionary(prefs::kProfileMetrics);
878 if (profile_dictionary) {
879 // Do a deep copy of profile_dictionary since ClearPref will delete it.
880 profile_dictionary_.reset(static_cast<DictionaryValue*>(
881 profile_dictionary->DeepCopy()));
882 prefs->ClearPref(prefs::kProfileMetrics);
883 }
884 }
885
[email protected]92745242009-06-12 16:52:21886 // Get stats on use of command line.
887 const CommandLine* command_line(CommandLine::ForCurrentProcess());
888 size_t common_commands = 0;
889 if (command_line->HasSwitch(switches::kUserDataDir)) {
890 ++common_commands;
891 UMA_HISTOGRAM_COUNTS_100("Chrome.CommandLineDatDirCount", 1);
892 }
893
894 if (command_line->HasSwitch(switches::kApp)) {
895 ++common_commands;
896 UMA_HISTOGRAM_COUNTS_100("Chrome.CommandLineAppModeCount", 1);
897 }
898
[email protected]62b4e522011-07-13 21:46:32899 size_t switch_count = command_line->GetSwitches().size();
900 UMA_HISTOGRAM_COUNTS_100("Chrome.CommandLineFlagCount", switch_count);
[email protected]92745242009-06-12 16:52:21901 UMA_HISTOGRAM_COUNTS_100("Chrome.CommandLineUncommonFlagCount",
[email protected]62b4e522011-07-13 21:46:32902 switch_count - common_commands);
[email protected]92745242009-06-12 16:52:21903
initial.commit09911bf2008-07-26 23:55:29904 // Kick off the process of saving the state (so the uptime numbers keep
905 // getting updated) every n minutes.
906 ScheduleNextStateSave();
907}
908
[email protected]c94d7382012-02-28 08:43:40909// static
[email protected]d33e7cc2011-09-23 01:43:56910void MetricsService::InitTaskGetHardwareClass(
[email protected]c94d7382012-02-28 08:43:40911 base::WeakPtr<MetricsService> self,
[email protected]d33e7cc2011-09-23 01:43:56912 base::MessageLoopProxy* target_loop) {
[email protected]d33e7cc2011-09-23 01:43:56913 DCHECK(BrowserThread::CurrentlyOn(BrowserThread::FILE));
914
915 std::string hardware_class;
916#if defined(OS_CHROMEOS)
917 chromeos::system::StatisticsProvider::GetInstance()->GetMachineStatistic(
918 "hardware_class", &hardware_class);
919#endif // OS_CHROMEOS
920
921 target_loop->PostTask(FROM_HERE,
922 base::Bind(&MetricsService::OnInitTaskGotHardwareClass,
[email protected]c94d7382012-02-28 08:43:40923 self, hardware_class));
[email protected]d33e7cc2011-09-23 01:43:56924}
925
926void MetricsService::OnInitTaskGotHardwareClass(
927 const std::string& hardware_class) {
[email protected]ed0fd002012-04-25 23:10:34928 DCHECK_EQ(INIT_TASK_SCHEDULED, state_);
[email protected]85ed9d42010-06-08 22:37:44929 hardware_class_ = hardware_class;
[email protected]d33e7cc2011-09-23 01:43:56930
931 // Start the next part of the init task: loading plugin information.
932 PluginService::GetInstance()->GetPlugins(
933 base::Bind(&MetricsService::OnInitTaskGotPluginInfo,
[email protected]c94d7382012-02-28 08:43:40934 self_ptr_factory_.GetWeakPtr()));
[email protected]d33e7cc2011-09-23 01:43:56935}
936
937void MetricsService::OnInitTaskGotPluginInfo(
938 const std::vector<webkit::WebPluginInfo>& plugins) {
[email protected]ed0fd002012-04-25 23:10:34939 DCHECK_EQ(INIT_TASK_SCHEDULED, state_);
[email protected]35fa6a22009-08-15 00:04:01940 plugins_ = plugins;
[email protected]d33e7cc2011-09-23 01:43:56941
[email protected]197c0772012-05-14 23:50:51942 // Schedules a task on a blocking pool thread to gather Google Update
943 // statistics (requires Registry reads).
944 BrowserThread::PostBlockingPoolTask(
945 FROM_HERE,
946 base::Bind(&MetricsService::InitTaskGetGoogleUpdateData,
947 self_ptr_factory_.GetWeakPtr(),
948 MessageLoop::current()->message_loop_proxy()));
949}
950
951// static
952void MetricsService::InitTaskGetGoogleUpdateData(
953 base::WeakPtr<MetricsService> self,
954 base::MessageLoopProxy* target_loop) {
955 GoogleUpdateMetrics google_update_metrics;
956
957#if defined(OS_WIN) && defined(GOOGLE_CHROME_BUILD)
958 const bool system_install = GoogleUpdateSettings::IsSystemInstall();
959
960 google_update_metrics.is_system_install = system_install;
961 google_update_metrics.last_started_au =
962 GoogleUpdateSettings::GetGoogleUpdateLastStartedAU(system_install);
963 google_update_metrics.last_checked =
964 GoogleUpdateSettings::GetGoogleUpdateLastChecked(system_install);
965 GoogleUpdateSettings::GetUpdateDetailForGoogleUpdate(
966 system_install,
967 &google_update_metrics.google_update_data);
968 GoogleUpdateSettings::GetUpdateDetail(
969 system_install,
970 &google_update_metrics.product_data);
971#endif // defined(OS_WIN) && defined(GOOGLE_CHROME_BUILD)
972
973 target_loop->PostTask(FROM_HERE,
974 base::Bind(&MetricsService::OnInitTaskGotGoogleUpdateData,
975 self, google_update_metrics));
976}
977
978void MetricsService::OnInitTaskGotGoogleUpdateData(
979 const GoogleUpdateMetrics& google_update_metrics) {
980 DCHECK_EQ(INIT_TASK_SCHEDULED, state_);
981
982 google_update_metrics_ = google_update_metrics;
983
[email protected]ed0fd002012-04-25 23:10:34984 // Start the next part of the init task: fetching performance data. This will
985 // call into |FinishedReceivingProfilerData()| when the task completes.
986 chrome_browser_metrics::TrackingSynchronizer::FetchProfilerDataAsynchronously(
987 self_ptr_factory_.GetWeakPtr());
988}
989
990void MetricsService::ReceivedProfilerData(
991 const tracked_objects::ProcessDataSnapshot& process_data,
992 content::ProcessType process_type) {
993 DCHECK_EQ(INIT_TASK_SCHEDULED, state_);
994
995 // Upon the first callback, create the initial log so that we can immediately
996 // save the profiler data.
997 if (!initial_log_.get())
998 initial_log_.reset(new MetricsLog(client_id_, session_id_));
999
1000 initial_log_->RecordProfilerData(process_data, process_type);
1001}
1002
1003void MetricsService::FinishedReceivingProfilerData() {
1004 DCHECK_EQ(INIT_TASK_SCHEDULED, state_);
[email protected]3a7b66d2012-04-26 16:34:161005 state_ = INIT_TASK_DONE;
initial.commit09911bf2008-07-26 23:55:291006}
1007
[email protected]e61003a2012-05-24 17:03:191008int MetricsService::GetLowEntropySource() {
1009 // Note that the default value for the low entropy source and the default pref
1010 // value are both zero, which is used to identify if the value has been set
1011 // or not. Valid values start at 1.
1012 if (low_entropy_source_)
1013 return low_entropy_source_;
1014
1015 PrefService* pref = g_browser_process->local_state();
1016 const CommandLine* command_line(CommandLine::ForCurrentProcess());
1017 // Only try to load the value from prefs if the user did not request a reset.
1018 // Otherwise, skip to generating a new value.
1019 if (!command_line->HasSwitch(switches::kResetVariationState)) {
1020 low_entropy_source_ = pref->GetInteger(prefs::kMetricsLowEntropySource);
1021 if (low_entropy_source_)
1022 return low_entropy_source_;
1023 }
1024
1025 low_entropy_source_ = GenerateLowEntropySource();
1026 pref->SetInteger(prefs::kMetricsLowEntropySource, low_entropy_source_);
1027
1028 return low_entropy_source_;
1029}
1030
1031// static
initial.commit09911bf2008-07-26 23:55:291032std::string MetricsService::GenerateClientID() {
[email protected]7e49ad32012-06-14 14:22:071033 return base::GenerateGUID();
initial.commit09911bf2008-07-26 23:55:291034}
1035
initial.commit09911bf2008-07-26 23:55:291036//------------------------------------------------------------------------------
1037// State save methods
1038
1039void MetricsService::ScheduleNextStateSave() {
[email protected]8454aeb2011-11-19 23:38:201040 state_saver_factory_.InvalidateWeakPtrs();
initial.commit09911bf2008-07-26 23:55:291041
1042 MessageLoop::current()->PostDelayedTask(FROM_HERE,
[email protected]8454aeb2011-11-19 23:38:201043 base::Bind(&MetricsService::SaveLocalState,
1044 state_saver_factory_.GetWeakPtr()),
[email protected]fc4252a72012-01-12 21:58:471045 base::TimeDelta::FromMinutes(kSaveStateIntervalMinutes));
initial.commit09911bf2008-07-26 23:55:291046}
1047
1048void MetricsService::SaveLocalState() {
1049 PrefService* pref = g_browser_process->local_state();
1050 if (!pref) {
[email protected]a063c102010-07-22 22:20:191051 NOTREACHED();
initial.commit09911bf2008-07-26 23:55:291052 return;
1053 }
1054
1055 RecordCurrentState(pref);
initial.commit09911bf2008-07-26 23:55:291056
[email protected]fc4252a72012-01-12 21:58:471057 // TODO(jar):110021 Does this run down the batteries????
initial.commit09911bf2008-07-26 23:55:291058 ScheduleNextStateSave();
1059}
1060
1061
1062//------------------------------------------------------------------------------
1063// Recording control methods
1064
1065void MetricsService::StartRecording() {
[email protected]cac267c2011-09-29 15:18:101066 if (log_manager_.current_log())
initial.commit09911bf2008-07-26 23:55:291067 return;
1068
[email protected]29948262012-03-01 12:15:081069 log_manager_.BeginLoggingWithLog(new MetricsLog(client_id_, session_id_),
1070 MetricsLogManager::ONGOING_LOG);
initial.commit09911bf2008-07-26 23:55:291071 if (state_ == INITIALIZED) {
1072 // We only need to schedule that run once.
[email protected]85ed9d42010-06-08 22:37:441073 state_ = INIT_TASK_SCHEDULED;
initial.commit09911bf2008-07-26 23:55:291074
[email protected]85ed9d42010-06-08 22:37:441075 // Schedules a task on the file thread for execution of slower
1076 // initialization steps (such as plugin list generation) necessary
1077 // for sending the initial log. This avoids blocking the main UI
1078 // thread.
[email protected]ed10dd12011-12-07 12:03:421079 BrowserThread::PostDelayedTask(
1080 BrowserThread::FILE,
1081 FROM_HERE,
[email protected]d33e7cc2011-09-23 01:43:561082 base::Bind(&MetricsService::InitTaskGetHardwareClass,
[email protected]c94d7382012-02-28 08:43:401083 self_ptr_factory_.GetWeakPtr(),
[email protected]d33e7cc2011-09-23 01:43:561084 MessageLoop::current()->message_loop_proxy()),
[email protected]7e560102012-03-08 20:58:421085 base::TimeDelta::FromSeconds(kInitializationDelaySeconds));
initial.commit09911bf2008-07-26 23:55:291086 }
1087}
1088
[email protected]024b5cd2011-05-27 03:29:381089void MetricsService::StopRecording() {
[email protected]cac267c2011-09-29 15:18:101090 if (!log_manager_.current_log())
initial.commit09911bf2008-07-26 23:55:291091 return;
1092
[email protected]68475e602008-08-22 03:21:151093 // TODO(jar): Integrate bounds on log recording more consistently, so that we
1094 // can stop recording logs that are too big much sooner.
[email protected]cac267c2011-09-29 15:18:101095 if (log_manager_.current_log()->num_events() > kEventLimit) {
[email protected]553dba62009-02-24 19:08:231096 UMA_HISTOGRAM_COUNTS("UMA.Discarded Log Events",
[email protected]cac267c2011-09-29 15:18:101097 log_manager_.current_log()->num_events());
1098 log_manager_.DiscardCurrentLog();
[email protected]68475e602008-08-22 03:21:151099 StartRecording(); // Start trivial log to hold our histograms.
1100 }
1101
[email protected]cac267c2011-09-29 15:18:101102 // Adds to ongoing logs.
1103 log_manager_.current_log()->set_hardware_class(hardware_class_);
[email protected]accdfa62011-09-20 01:56:521104
[email protected]0b33f80b2008-12-17 21:34:361105 // Put incremental data (histogram deltas, and realtime stats deltas) at the
[email protected]147bbc0b2009-01-06 19:37:401106 // end of all log transmissions (initial log handles this separately).
[email protected]024b5cd2011-05-27 03:29:381107 // RecordIncrementalStabilityElements only exists on the derived
1108 // MetricsLog class.
[email protected]279703f2012-01-20 22:23:261109 MetricsLog* current_log =
1110 static_cast<MetricsLog*>(log_manager_.current_log());
[email protected]024b5cd2011-05-27 03:29:381111 DCHECK(current_log);
[email protected]197c0772012-05-14 23:50:511112 current_log->RecordEnvironmentProto(plugins_, google_update_metrics_);
[email protected]fe58acc22012-02-29 01:29:581113 current_log->RecordIncrementalStabilityElements(plugins_);
[email protected]024b5cd2011-05-27 03:29:381114 RecordCurrentHistograms();
initial.commit09911bf2008-07-26 23:55:291115
[email protected]29948262012-03-01 12:15:081116 log_manager_.FinishCurrentLog();
initial.commit09911bf2008-07-26 23:55:291117}
1118
[email protected]cac267c2011-09-29 15:18:101119void MetricsService::PushPendingLogsToPersistentStorage() {
initial.commit09911bf2008-07-26 23:55:291120 if (state_ < INITIAL_LOG_READY)
[email protected]28ab7f92009-01-06 21:39:041121 return; // We didn't and still don't have time to get plugin list etc.
initial.commit09911bf2008-07-26 23:55:291122
[email protected]cac267c2011-09-29 15:18:101123 if (log_manager_.has_staged_log()) {
[email protected]7d41ae6d2012-06-26 08:53:031124 // We may race here, and send second copy of the log later.
[email protected]dc61fe92012-06-12 00:13:501125 MetricsLogManager::StoreType store_type;
1126 if (current_fetch_xml_.get() || current_fetch_proto_.get())
1127 store_type = MetricsLogManager::PROVISIONAL_STORE;
1128 else
1129 store_type = MetricsLogManager::NORMAL_STORE;
[email protected]e7508d82012-05-03 15:59:531130 log_manager_.StoreStagedLogAsUnsent(store_type);
initial.commit09911bf2008-07-26 23:55:291131 }
[email protected]cac267c2011-09-29 15:18:101132 DCHECK(!log_manager_.has_staged_log());
[email protected]024b5cd2011-05-27 03:29:381133 StopRecording();
initial.commit09911bf2008-07-26 23:55:291134 StoreUnsentLogs();
[email protected]7d41ae6d2012-06-26 08:53:031135
1136 // If there was a staged and/or current log, then there is now at least one
1137 // log waiting to be uploaded.
1138 if (log_manager_.has_unsent_logs())
1139 state_ = SENDING_OLD_LOGS;
initial.commit09911bf2008-07-26 23:55:291140}
1141
1142//------------------------------------------------------------------------------
1143// Transmission of logs methods
1144
[email protected]7f7f1962011-04-20 15:58:161145void MetricsService::StartSchedulerIfNecessary() {
1146 if (reporting_active() && recording_active())
1147 scheduler_->Start();
initial.commit09911bf2008-07-26 23:55:291148}
1149
[email protected]7f7f1962011-04-20 15:58:161150void MetricsService::StartScheduledUpload() {
[email protected]cd1ac712012-06-26 08:26:471151 // If we're getting no notifications, then the log won't have much in it, and
1152 // it's possible the computer is about to go to sleep, so don't upload and
1153 // stop the scheduler.
1154 // Similarly, if logs should no longer be uploaded, stop here.
1155 // TODO(stuartmorgan): Call Stop() on the schedule when reporting and/or
1156 // recording are turned off instead of letting it fire and then aborting.
1157 if (idle_since_last_transmission_ ||
1158 !recording_active() || !reporting_active()) {
[email protected]7f7f1962011-04-20 15:58:161159 scheduler_->Stop();
1160 scheduler_->UploadCancelled();
1161 return;
1162 }
1163
[email protected]c15faf372012-07-11 06:01:341164 // If the callback was to upload an old log, but there no longer is one,
1165 // just report success back to the scheduler to begin the ongoing log
1166 // callbacks.
1167 // TODO(stuartmorgan): Consider removing the distinction between
1168 // SENDING_OLD_LOGS and SENDING_CURRENT_LOGS to simplify the state machine
1169 // now that the log upload flow is the same for both modes.
1170 if (state_ == SENDING_OLD_LOGS && !log_manager_.has_unsent_logs()) {
1171 state_ = SENDING_CURRENT_LOGS;
1172 scheduler_->UploadFinished(true /* healthy */, false /* no unsent logs */);
1173 return;
1174 }
[email protected]cd1ac712012-06-26 08:26:471175 // If there are unsent logs, send the next one. If not, start the asynchronous
1176 // process of finalizing the current log for upload.
1177 if (state_ == SENDING_OLD_LOGS) {
1178 DCHECK(log_manager_.has_unsent_logs());
1179 log_manager_.StageNextLogForUpload();
1180 SendStagedLog();
1181 } else {
1182 StartFinalLogInfoCollection();
1183 }
[email protected]29948262012-03-01 12:15:081184}
1185
1186void MetricsService::StartFinalLogInfoCollection() {
1187 // Begin the multi-step process of collecting memory usage histograms:
1188 // First spawn a task to collect the memory details; when that task is
1189 // finished, it will call OnMemoryDetailCollectionDone. That will in turn
1190 // call HistogramSynchronization to collect histograms from all renderers and
1191 // then call OnHistogramSynchronizationDone to continue processing.
[email protected]d119f222012-06-08 02:33:271192 DCHECK(!waiting_for_asynchronous_reporting_step_);
1193 waiting_for_asynchronous_reporting_step_ = true;
[email protected]7f7f1962011-04-20 15:58:161194
[email protected]2226c222011-11-22 00:08:401195 base::Closure callback =
1196 base::Bind(&MetricsService::OnMemoryDetailCollectionDone,
[email protected]c94d7382012-02-28 08:43:401197 self_ptr_factory_.GetWeakPtr());
[email protected]84c988a2011-04-19 17:56:331198
[email protected]2226c222011-11-22 00:08:401199 scoped_refptr<MetricsMemoryDetails> details(
1200 new MetricsMemoryDetails(callback));
[email protected]4306df72012-04-20 18:58:571201 details->StartFetch(MemoryDetails::UPDATE_USER_METRICS);
[email protected]84c988a2011-04-19 17:56:331202
1203 // Collect WebCore cache information to put into a histogram.
[email protected]f3b1a082011-11-18 00:34:301204 for (content::RenderProcessHost::iterator i(
1205 content::RenderProcessHost::AllHostsIterator());
[email protected]84c988a2011-04-19 17:56:331206 !i.IsAtEnd(); i.Advance())
[email protected]2ccf45c2011-08-19 23:35:501207 i.GetCurrentValue()->Send(new ChromeViewMsg_GetCacheResourceStats());
[email protected]84c988a2011-04-19 17:56:331208}
1209
1210void MetricsService::OnMemoryDetailCollectionDone() {
[email protected]c9a3ef82009-05-28 22:02:461211 DCHECK(IsSingleThreaded());
[email protected]7f7f1962011-04-20 15:58:161212 // This function should only be called as the callback from an ansynchronous
1213 // step.
[email protected]d119f222012-06-08 02:33:271214 DCHECK(waiting_for_asynchronous_reporting_step_);
[email protected]c9a3ef82009-05-28 22:02:461215
[email protected]c9a3ef82009-05-28 22:02:461216 // Create a callback_task for OnHistogramSynchronizationDone.
[email protected]2226c222011-11-22 00:08:401217 base::Closure callback = base::Bind(
1218 &MetricsService::OnHistogramSynchronizationDone,
[email protected]c94d7382012-02-28 08:43:401219 self_ptr_factory_.GetWeakPtr());
[email protected]c9a3ef82009-05-28 22:02:461220
[email protected]908de522011-10-20 00:55:001221 base::StatisticsRecorder::CollectHistogramStats("Browser");
1222
[email protected]c9a3ef82009-05-28 22:02:461223 // Set up the callback to task to call after we receive histograms from all
[email protected]83ab4a282012-07-12 18:19:451224 // child processes. Wait time specifies how long to wait before absolutely
[email protected]c9a3ef82009-05-28 22:02:461225 // calling us back on the task.
[email protected]83ab4a282012-07-12 18:19:451226 content::FetchHistogramsAsynchronously(
[email protected]2226c222011-11-22 00:08:401227 MessageLoop::current(), callback,
[email protected]7e560102012-03-08 20:58:421228 base::TimeDelta::FromMilliseconds(kMaxHistogramGatheringWaitDuration));
[email protected]c9a3ef82009-05-28 22:02:461229}
1230
1231void MetricsService::OnHistogramSynchronizationDone() {
initial.commit09911bf2008-07-26 23:55:291232 DCHECK(IsSingleThreaded());
[email protected]29948262012-03-01 12:15:081233 // This function should only be called as the callback from an ansynchronous
1234 // step.
[email protected]d119f222012-06-08 02:33:271235 DCHECK(waiting_for_asynchronous_reporting_step_);
initial.commit09911bf2008-07-26 23:55:291236
[email protected]d119f222012-06-08 02:33:271237 waiting_for_asynchronous_reporting_step_ = false;
[email protected]29948262012-03-01 12:15:081238 OnFinalLogInfoCollectionDone();
1239}
1240
1241void MetricsService::OnFinalLogInfoCollectionDone() {
[email protected]7f7f1962011-04-20 15:58:161242 // If somehow there is a fetch in progress, we return and hope things work
1243 // out. The scheduler isn't informed since if this happens, the scheduler
1244 // will get a response from the upload.
[email protected]fe58acc22012-02-29 01:29:581245 DCHECK(!current_fetch_xml_.get());
1246 DCHECK(!current_fetch_proto_.get());
1247 if (current_fetch_xml_.get() || current_fetch_proto_.get())
[email protected]7f7f1962011-04-20 15:58:161248 return;
1249
[email protected]cd1ac712012-06-26 08:26:471250 // Abort if metrics were turned off during the final info gathering.
1251 if (!recording_active() || !reporting_active()) {
[email protected]7f7f1962011-04-20 15:58:161252 scheduler_->Stop();
1253 scheduler_->UploadCancelled();
[email protected]d01b8732008-10-16 02:18:071254 return;
1255 }
1256
[email protected]cd1ac712012-06-26 08:26:471257 StageNewLog();
[email protected]29948262012-03-01 12:15:081258 SendStagedLog();
1259}
1260
[email protected]cd1ac712012-06-26 08:26:471261void MetricsService::StageNewLog() {
[email protected]29948262012-03-01 12:15:081262 if (log_manager_.has_staged_log())
1263 return;
1264
1265 switch (state_) {
1266 case INITIALIZED:
1267 case INIT_TASK_SCHEDULED: // We should be further along by now.
[email protected]dc61fe92012-06-12 00:13:501268 NOTREACHED();
[email protected]29948262012-03-01 12:15:081269 return;
1270
1271 case INIT_TASK_DONE:
[email protected]29948262012-03-01 12:15:081272 PrepareInitialLog();
[email protected]ed0fd002012-04-25 23:10:341273 DCHECK_EQ(INIT_TASK_DONE, state_);
[email protected]29948262012-03-01 12:15:081274 log_manager_.LoadPersistedUnsentLogs();
1275 state_ = INITIAL_LOG_READY;
1276 break;
1277
1278 case SENDING_OLD_LOGS:
[email protected]cd1ac712012-06-26 08:26:471279 NOTREACHED(); // Shouldn't be staging a new log during old log sending.
1280 return;
[email protected]29948262012-03-01 12:15:081281
1282 case SENDING_CURRENT_LOGS:
1283 StopRecording();
1284 StartRecording();
1285 log_manager_.StageNextLogForUpload();
1286 break;
1287
1288 default:
1289 NOTREACHED();
1290 return;
1291 }
1292
1293 DCHECK(log_manager_.has_staged_log());
1294}
1295
1296void MetricsService::PrepareInitialLog() {
[email protected]ed0fd002012-04-25 23:10:341297 DCHECK_EQ(INIT_TASK_DONE, state_);
[email protected]29948262012-03-01 12:15:081298
[email protected]ed0fd002012-04-25 23:10:341299 DCHECK(initial_log_.get());
1300 initial_log_->set_hardware_class(hardware_class_);
[email protected]197c0772012-05-14 23:50:511301 initial_log_->RecordEnvironment(plugins_, google_update_metrics_,
1302 profile_dictionary_.get());
[email protected]29948262012-03-01 12:15:081303
1304 // Histograms only get written to the current log, so make the new log current
1305 // before writing them.
1306 log_manager_.PauseCurrentLog();
[email protected]ed0fd002012-04-25 23:10:341307 log_manager_.BeginLoggingWithLog(initial_log_.release(),
1308 MetricsLogManager::INITIAL_LOG);
[email protected]29948262012-03-01 12:15:081309 RecordCurrentHistograms();
1310 log_manager_.FinishCurrentLog();
1311 log_manager_.ResumePausedLog();
1312
1313 DCHECK(!log_manager_.has_staged_log());
1314 log_manager_.StageNextLogForUpload();
1315}
1316
1317void MetricsService::StoreUnsentLogs() {
1318 if (state_ < INITIAL_LOG_READY)
1319 return; // We never Recalled the prior unsent logs.
1320
1321 log_manager_.PersistUnsentLogs();
1322}
1323
1324void MetricsService::SendStagedLog() {
1325 DCHECK(log_manager_.has_staged_log());
1326
[email protected]cac267c2011-09-29 15:18:101327 PrepareFetchWithStagedLog();
[email protected]d01b8732008-10-16 02:18:071328
[email protected]d6bebb92012-06-13 23:14:551329 bool upload_created = current_fetch_xml_.get() || current_fetch_proto_.get();
1330 UMA_HISTOGRAM_BOOLEAN("UMA.UploadCreation", upload_created);
1331 if (!upload_created) {
[email protected]d01b8732008-10-16 02:18:071332 // Compression failed, and log discarded :-/.
[email protected]dc61fe92012-06-12 00:13:501333 // Skip this upload and hope things work out next time.
[email protected]cac267c2011-09-29 15:18:101334 log_manager_.DiscardStagedLog();
[email protected]7f7f1962011-04-20 15:58:161335 scheduler_->UploadCancelled();
[email protected]d01b8732008-10-16 02:18:071336 return;
1337 }
1338
[email protected]d119f222012-06-08 02:33:271339 DCHECK(!waiting_for_asynchronous_reporting_step_);
[email protected]d119f222012-06-08 02:33:271340 waiting_for_asynchronous_reporting_step_ = true;
[email protected]dc61fe92012-06-12 00:13:501341
1342 if (current_fetch_xml_.get())
1343 current_fetch_xml_->Start();
[email protected]fe58acc22012-02-29 01:29:581344 if (current_fetch_proto_.get())
1345 current_fetch_proto_->Start();
[email protected]d01b8732008-10-16 02:18:071346
1347 HandleIdleSinceLastTransmission(true);
1348}
1349
[email protected]cac267c2011-09-29 15:18:101350void MetricsService::PrepareFetchWithStagedLog() {
[email protected]dc61fe92012-06-12 00:13:501351 DCHECK(log_manager_.has_staged_log());
[email protected]cac78842008-11-27 01:02:201352
[email protected]fe58acc22012-02-29 01:29:581353 // Prepare the XML version.
1354 DCHECK(!current_fetch_xml_.get());
[email protected]dc61fe92012-06-12 00:13:501355 if (log_manager_.has_staged_log_xml()) {
[email protected]3dc1bc42012-06-19 08:20:531356 current_fetch_xml_.reset(net::URLFetcher::Create(
[email protected]dc61fe92012-06-12 00:13:501357 GURL(server_url_xml_), net::URLFetcher::POST, this));
1358 current_fetch_xml_->SetRequestContext(
1359 g_browser_process->system_request_context());
1360 current_fetch_xml_->SetUploadData(kMimeTypeXml,
1361 log_manager_.staged_log_text().xml);
1362 // We already drop cookies server-side, but we might as well strip them out
1363 // client-side as well.
1364 current_fetch_xml_->SetLoadFlags(net::LOAD_DO_NOT_SAVE_COOKIES |
1365 net::LOAD_DO_NOT_SEND_COOKIES);
1366 }
[email protected]fe58acc22012-02-29 01:29:581367
1368 // Prepare the protobuf version.
1369 DCHECK(!current_fetch_proto_.get());
1370 if (log_manager_.has_staged_log_proto()) {
[email protected]3dc1bc42012-06-19 08:20:531371 current_fetch_proto_.reset(net::URLFetcher::Create(
[email protected]d3ec669b2012-05-23 07:12:141372 GURL(server_url_proto_), net::URLFetcher::POST, this));
[email protected]fe58acc22012-02-29 01:29:581373 current_fetch_proto_->SetRequestContext(
1374 g_browser_process->system_request_context());
[email protected]448ca4d2012-05-09 19:53:121375 current_fetch_proto_->SetUploadData(kMimeTypeProto,
[email protected]fe58acc22012-02-29 01:29:581376 log_manager_.staged_log_text().proto);
1377 // We already drop cookies server-side, but we might as well strip them out
1378 // client-side as well.
1379 current_fetch_proto_->SetLoadFlags(net::LOAD_DO_NOT_SAVE_COOKIES |
1380 net::LOAD_DO_NOT_SEND_COOKIES);
[email protected]fe58acc22012-02-29 01:29:581381 }
initial.commit09911bf2008-07-26 23:55:291382}
1383
[email protected]fe58acc22012-02-29 01:29:581384// We need to wait for two responses: the response to the XML upload, and the
[email protected]dc61fe92012-06-12 00:13:501385// response to the protobuf upload. In the case that exactly one of the uploads
1386// fails and needs to be retried, we "zap" the other pipeline's staged log to
1387// avoid incorrectly re-uploading it as well.
[email protected]10c2d692012-05-11 05:32:231388void MetricsService::OnURLFetchComplete(const net::URLFetcher* source) {
[email protected]d119f222012-06-08 02:33:271389 DCHECK(waiting_for_asynchronous_reporting_step_);
[email protected]fe58acc22012-02-29 01:29:581390
1391 // We're not allowed to re-use the existing |URLFetcher|s, so free them here.
[email protected]4266def22012-05-17 01:02:401392 // Note however that |source| is aliased to one of these, so we should be
1393 // careful not to delete it too early.
[email protected]15fb2aa2012-05-22 22:52:591394 scoped_ptr<net::URLFetcher> s;
[email protected]dc61fe92012-06-12 00:13:501395 bool is_xml;
[email protected]fe58acc22012-02-29 01:29:581396 if (source == current_fetch_xml_.get()) {
1397 s.reset(current_fetch_xml_.release());
[email protected]dc61fe92012-06-12 00:13:501398 is_xml = true;
[email protected]fe58acc22012-02-29 01:29:581399 } else if (source == current_fetch_proto_.get()) {
1400 s.reset(current_fetch_proto_.release());
[email protected]dc61fe92012-06-12 00:13:501401 is_xml = false;
[email protected]fe58acc22012-02-29 01:29:581402 } else {
1403 NOTREACHED();
1404 return;
1405 }
1406
[email protected]dc61fe92012-06-12 00:13:501407 int response_code = source->GetResponseCode();
[email protected]fe58acc22012-02-29 01:29:581408
[email protected]dc61fe92012-06-12 00:13:501409 // Log a histogram to track response success vs. failure rates.
1410 if (is_xml) {
1411 UMA_HISTOGRAM_ENUMERATION("UMA.UploadResponseStatus.XML",
1412 ResponseCodeToStatus(response_code),
1413 NUM_RESPONSE_STATUSES);
1414 } else {
1415 UMA_HISTOGRAM_ENUMERATION("UMA.UploadResponseStatus.Protobuf",
1416 ResponseCodeToStatus(response_code),
1417 NUM_RESPONSE_STATUSES);
1418 }
[email protected]fe58acc22012-02-29 01:29:581419
[email protected]e7508d82012-05-03 15:59:531420 // If the upload was provisionally stored, drop it now that the upload is
1421 // known to have gone through.
1422 log_manager_.DiscardLastProvisionalStore();
initial.commit09911bf2008-07-26 23:55:291423
[email protected]dc61fe92012-06-12 00:13:501424 bool upload_succeeded = response_code == 200;
[email protected]7f7f1962011-04-20 15:58:161425
[email protected]0eb34fee2009-01-21 08:04:381426 // Provide boolean for error recovery (allow us to ignore response_code).
[email protected]dc6f4962009-02-13 01:25:501427 bool discard_log = false;
[email protected]dc61fe92012-06-12 00:13:501428 const size_t log_size = is_xml ?
1429 log_manager_.staged_log_text().xml.length() :
1430 log_manager_.staged_log_text().proto.length();
1431 if (!upload_succeeded && log_size > kUploadLogAvoidRetransmitSize) {
1432 UMA_HISTOGRAM_COUNTS("UMA.Large Rejected Log was Discarded",
1433 static_cast<int>(log_size));
[email protected]0eb34fee2009-01-21 08:04:381434 discard_log = true;
[email protected]dc61fe92012-06-12 00:13:501435 } else if (response_code == 400) {
[email protected]0eb34fee2009-01-21 08:04:381436 // Bad syntax. Retransmission won't work.
[email protected]0eb34fee2009-01-21 08:04:381437 discard_log = true;
[email protected]68475e602008-08-22 03:21:151438 }
1439
[email protected]bf02f922012-06-13 23:25:311440 if (upload_succeeded || discard_log) {
[email protected]dc61fe92012-06-12 00:13:501441 if (is_xml)
1442 log_manager_.DiscardStagedLogXml();
1443 else
1444 log_manager_.DiscardStagedLogProto();
1445 }
1446
1447 // If we're still waiting for one of the responses, keep waiting...
1448 if (current_fetch_xml_.get() || current_fetch_proto_.get())
1449 return;
1450
1451 waiting_for_asynchronous_reporting_step_ = false;
1452
1453 if (!log_manager_.has_staged_log()) {
initial.commit09911bf2008-07-26 23:55:291454 switch (state_) {
1455 case INITIAL_LOG_READY:
[email protected]cd1ac712012-06-26 08:26:471456 state_ = log_manager_.has_unsent_logs() ? SENDING_OLD_LOGS
1457 : SENDING_CURRENT_LOGS;
initial.commit09911bf2008-07-26 23:55:291458 break;
1459
initial.commit09911bf2008-07-26 23:55:291460 case SENDING_OLD_LOGS:
[email protected]d53e2232011-06-30 15:54:571461 // Store the updated list to disk now that the removed log is uploaded.
initial.commit09911bf2008-07-26 23:55:291462 StoreUnsentLogs();
[email protected]cd1ac712012-06-26 08:26:471463 if (!log_manager_.has_unsent_logs())
1464 state_ = SENDING_CURRENT_LOGS;
initial.commit09911bf2008-07-26 23:55:291465 break;
1466
1467 case SENDING_CURRENT_LOGS:
1468 break;
1469
1470 default:
[email protected]a063c102010-07-22 22:20:191471 NOTREACHED();
initial.commit09911bf2008-07-26 23:55:291472 break;
1473 }
[email protected]d01b8732008-10-16 02:18:071474
[email protected]cac267c2011-09-29 15:18:101475 if (log_manager_.has_unsent_logs())
[email protected]ed0fd002012-04-25 23:10:341476 DCHECK_LT(state_, SENDING_CURRENT_LOGS);
initial.commit09911bf2008-07-26 23:55:291477 }
[email protected]252873ef2008-08-04 21:59:451478
[email protected]7f7f1962011-04-20 15:58:161479 // Error 400 indicates a problem with the log, not with the server, so
1480 // don't consider that a sign that the server is in trouble.
[email protected]dc61fe92012-06-12 00:13:501481 bool server_is_healthy = upload_succeeded || response_code == 400;
[email protected]7f7f1962011-04-20 15:58:161482
[email protected]dc61fe92012-06-12 00:13:501483 // Note that we are essentially randomly choosing to report either the XML or
1484 // the protobuf server's health status, but this is ok: In the case that the
1485 // two statuses are not the same, one of the uploads succeeded but the other
1486 // did not. In this case, we'll re-try only the upload that failed. This first
1487 // re-try might ignore the server's unhealthiness; but the response to the
1488 // re-tried upload will correctly propagate the server's health status for any
1489 // subsequent re-tries. Hence, we'll at most delay slowing the upload rate by
1490 // one re-try, which is fine.
1491 scheduler_->UploadFinished(server_is_healthy, log_manager_.has_unsent_logs());
[email protected]d67d1052011-06-09 05:11:411492
1493 // Collect network stats if UMA upload succeeded.
[email protected]b8ddb052012-04-19 02:36:061494 IOThread* io_thread = g_browser_process->io_thread();
1495 if (server_is_healthy && io_thread) {
1496 chrome_browser_net::CollectNetworkStats(network_stats_server_, io_thread);
[email protected]adbb3762012-03-09 22:20:081497 chrome_browser_net::CollectPipeliningCapabilityStatsOnUIThread(
[email protected]b8ddb052012-04-19 02:36:061498 http_pipelining_test_server_, io_thread);
[email protected]adbb3762012-03-09 22:20:081499 }
initial.commit09911bf2008-07-26 23:55:291500}
1501
[email protected]6c2381d2011-10-19 02:52:531502void MetricsService::LogWindowChange(
1503 int type,
1504 const content::NotificationSource& source,
1505 const content::NotificationDetails& details) {
[email protected]534e54b2008-08-13 15:40:091506 int controller_id = -1;
1507 uintptr_t window_or_tab = source.map_key();
initial.commit09911bf2008-07-26 23:55:291508 MetricsLog::WindowEventType window_type;
1509
1510 // Note: since we stop all logging when a single OTR session is active, it is
1511 // possible that we start getting notifications about a window that we don't
1512 // know about.
[email protected]534e54b2008-08-13 15:40:091513 if (window_map_.find(window_or_tab) == window_map_.end()) {
1514 controller_id = next_window_id_++;
1515 window_map_[window_or_tab] = controller_id;
initial.commit09911bf2008-07-26 23:55:291516 } else {
[email protected]534e54b2008-08-13 15:40:091517 controller_id = window_map_[window_or_tab];
initial.commit09911bf2008-07-26 23:55:291518 }
[email protected]92745242009-06-12 16:52:211519 DCHECK_NE(controller_id, -1);
initial.commit09911bf2008-07-26 23:55:291520
[email protected]432115822011-07-10 15:52:271521 switch (type) {
[email protected]884033e2012-04-16 19:38:421522 case chrome::NOTIFICATION_TAB_PARENTED:
[email protected]432115822011-07-10 15:52:271523 case chrome::NOTIFICATION_BROWSER_OPENED:
initial.commit09911bf2008-07-26 23:55:291524 window_type = MetricsLog::WINDOW_CREATE;
1525 break;
1526
[email protected]884033e2012-04-16 19:38:421527 case chrome::NOTIFICATION_TAB_CLOSING:
[email protected]432115822011-07-10 15:52:271528 case chrome::NOTIFICATION_BROWSER_CLOSED:
[email protected]534e54b2008-08-13 15:40:091529 window_map_.erase(window_map_.find(window_or_tab));
initial.commit09911bf2008-07-26 23:55:291530 window_type = MetricsLog::WINDOW_DESTROY;
1531 break;
1532
1533 default:
[email protected]a063c102010-07-22 22:20:191534 NOTREACHED();
[email protected]68d74f02009-02-13 01:36:501535 return;
initial.commit09911bf2008-07-26 23:55:291536 }
1537
[email protected]534e54b2008-08-13 15:40:091538 // TODO(brettw) we should have some kind of ID for the parent.
[email protected]cac267c2011-09-29 15:18:101539 log_manager_.current_log()->RecordWindowEvent(window_type, controller_id, 0);
initial.commit09911bf2008-07-26 23:55:291540}
1541
[email protected]6c2381d2011-10-19 02:52:531542void MetricsService::LogLoadComplete(
1543 int type,
1544 const content::NotificationSource& source,
1545 const content::NotificationDetails& details) {
[email protected]ad50def52011-10-19 23:17:071546 if (details == content::NotificationService::NoDetails())
initial.commit09911bf2008-07-26 23:55:291547 return;
1548
[email protected]68475e602008-08-22 03:21:151549 // TODO(jar): There is a bug causing this to be called too many times, and
1550 // the log overflows. For now, we won't record these events.
[email protected]553dba62009-02-24 19:08:231551 UMA_HISTOGRAM_COUNTS("UMA.LogLoadComplete called", 1);
[email protected]68475e602008-08-22 03:21:151552 return;
1553
[email protected]6c2381d2011-10-19 02:52:531554 const content::Details<LoadNotificationDetails> load_details(details);
[email protected]534e54b2008-08-13 15:40:091555 int controller_id = window_map_[details.map_key()];
[email protected]cac267c2011-09-29 15:18:101556 log_manager_.current_log()->RecordLoadEvent(controller_id,
[email protected]09d31d52012-03-11 22:30:271557 load_details->url,
1558 load_details->origin,
1559 load_details->session_index,
1560 load_details->load_time);
initial.commit09911bf2008-07-26 23:55:291561}
1562
[email protected]57ecc4b2010-08-11 03:02:511563void MetricsService::IncrementPrefValue(const char* path) {
[email protected]e73c01972008-08-13 00:18:241564 PrefService* pref = g_browser_process->local_state();
1565 DCHECK(pref);
1566 int value = pref->GetInteger(path);
1567 pref->SetInteger(path, value + 1);
1568}
1569
[email protected]57ecc4b2010-08-11 03:02:511570void MetricsService::IncrementLongPrefsValue(const char* path) {
[email protected]0bb1a622009-03-04 03:22:321571 PrefService* pref = g_browser_process->local_state();
1572 DCHECK(pref);
1573 int64 value = pref->GetInt64(path);
[email protected]b42c5e42010-06-03 20:43:251574 pref->SetInt64(path, value + 1);
[email protected]0bb1a622009-03-04 03:22:321575}
1576
initial.commit09911bf2008-07-26 23:55:291577void MetricsService::LogLoadStarted() {
[email protected]dd8d12a2011-09-02 02:10:151578 HISTOGRAM_ENUMERATION("Chrome.UmaPageloadCounter", 1, 2);
[email protected]e73c01972008-08-13 00:18:241579 IncrementPrefValue(prefs::kStabilityPageLoadCount);
[email protected]0bb1a622009-03-04 03:22:321580 IncrementLongPrefsValue(prefs::kUninstallMetricsPageLoadCount);
[email protected]0b33f80b2008-12-17 21:34:361581 // We need to save the prefs, as page load count is a critical stat, and it
1582 // might be lost due to a crash :-(.
initial.commit09911bf2008-07-26 23:55:291583}
1584
[email protected]c3721482012-03-23 16:21:481585void MetricsService::LogRendererCrash(content::RenderProcessHost* host,
1586 base::TerminationStatus status,
[email protected]f1675202012-07-09 15:18:001587 int exit_code) {
[email protected]f3b1a082011-11-18 00:34:301588 Profile* profile = Profile::FromBrowserContext(host->GetBrowserContext());
[email protected]6f371442011-11-09 06:45:461589 ExtensionService* service = profile->GetExtensionService();
1590 bool was_extension_process =
[email protected]f3b1a082011-11-18 00:34:301591 service && service->process_map()->Contains(host->GetID());
[email protected]c3721482012-03-23 16:21:481592 if (status == base::TERMINATION_STATUS_PROCESS_CRASHED ||
1593 status == base::TERMINATION_STATUS_ABNORMAL_TERMINATION) {
[email protected]d7c1fa62012-06-15 23:35:301594 if (was_extension_process) {
[email protected]718eab62011-10-05 21:16:521595 IncrementPrefValue(prefs::kStabilityExtensionRendererCrashCount);
[email protected]d7c1fa62012-06-15 23:35:301596
1597 UMA_HISTOGRAM_CUSTOM_ENUMERATION("CrashExitCodes.Extension",
1598 MapCrashExitCodeForHistogram(exit_code),
1599 GetAllCrashExitCodes());
1600 } else {
[email protected]718eab62011-10-05 21:16:521601 IncrementPrefValue(prefs::kStabilityRendererCrashCount);
initial.commit09911bf2008-07-26 23:55:291602
[email protected]d7c1fa62012-06-15 23:35:301603 UMA_HISTOGRAM_CUSTOM_ENUMERATION("CrashExitCodes.Renderer",
1604 MapCrashExitCodeForHistogram(exit_code),
1605 GetAllCrashExitCodes());
1606 }
1607
[email protected]718eab62011-10-05 21:16:521608 UMA_HISTOGRAM_PERCENTAGE("BrowserRenderProcessHost.ChildCrashes",
1609 was_extension_process ? 2 : 1);
[email protected]c3721482012-03-23 16:21:481610 } else if (status == base::TERMINATION_STATUS_PROCESS_WAS_KILLED) {
[email protected]718eab62011-10-05 21:16:521611 UMA_HISTOGRAM_PERCENTAGE("BrowserRenderProcessHost.ChildKills",
1612 was_extension_process ? 2 : 1);
[email protected]f1675202012-07-09 15:18:001613 } else if (status == base::TERMINATION_STATUS_STILL_RUNNING) {
1614 UMA_HISTOGRAM_PERCENTAGE("BrowserRenderProcessHost.DisconnectedAlive",
[email protected]718eab62011-10-05 21:16:521615 was_extension_process ? 2 : 1);
1616 }
1617 }
[email protected]1f085622009-12-04 05:33:451618
initial.commit09911bf2008-07-26 23:55:291619void MetricsService::LogRendererHang() {
[email protected]e73c01972008-08-13 00:18:241620 IncrementPrefValue(prefs::kStabilityRendererHangCount);
initial.commit09911bf2008-07-26 23:55:291621}
1622
[email protected]c0c55e92011-09-10 18:47:301623void MetricsService::LogNeedForCleanShutdown() {
1624 PrefService* pref = g_browser_process->local_state();
1625 pref->SetBoolean(prefs::kStabilityExitedCleanly, false);
1626 // Redundant setting to be sure we call for a clean shutdown.
1627 clean_shutdown_status_ = NEED_TO_SHUTDOWN;
1628}
1629
1630bool MetricsService::UmaMetricsProperlyShutdown() {
1631 CHECK(clean_shutdown_status_ == CLEANLY_SHUTDOWN ||
1632 clean_shutdown_status_ == NEED_TO_SHUTDOWN);
1633 return clean_shutdown_status_ == CLEANLY_SHUTDOWN;
1634}
1635
[email protected]67c4e952011-09-17 00:44:271636// For use in hack in LogCleanShutdown.
1637static void Signal(base::WaitableEvent* event) {
1638 event->Signal();
1639}
1640
[email protected]466f3c12011-03-23 21:20:381641void MetricsService::LogCleanShutdown() {
[email protected]acd55b32011-09-05 17:35:311642 // Redundant hack to write pref ASAP.
1643 PrefService* pref = g_browser_process->local_state();
1644 pref->SetBoolean(prefs::kStabilityExitedCleanly, true);
[email protected]fbe17c8a2011-12-27 16:41:481645 pref->CommitPendingWrite();
[email protected]67c4e952011-09-17 00:44:271646 // Hack: TBD: Remove this wait.
1647 // We are so concerned that the pref gets written, we are now willing to stall
1648 // the UI thread until we get assurance that a pref-writing task has
1649 // completed.
1650 base::WaitableEvent done_writing(false, false);
1651 BrowserThread::PostTask(BrowserThread::FILE, FROM_HERE,
[email protected]8454aeb2011-11-19 23:38:201652 base::Bind(Signal, &done_writing));
[email protected]3a7b66d2012-04-26 16:34:161653 // http://crbug.com/124954
1654 base::ThreadRestrictions::ScopedAllowWait allow_wait;
[email protected]67c4e952011-09-17 00:44:271655 done_writing.TimedWait(base::TimeDelta::FromHours(1));
1656
[email protected]c0c55e92011-09-10 18:47:301657 // Redundant setting to assure that we always reset this value at shutdown
1658 // (and that we don't use some alternate path, and not call LogCleanShutdown).
1659 clean_shutdown_status_ = CLEANLY_SHUTDOWN;
[email protected]acd55b32011-09-05 17:35:311660
[email protected]466f3c12011-03-23 21:20:381661 RecordBooleanPrefValue(prefs::kStabilityExitedCleanly, true);
1662}
1663
[email protected]c1834a92011-01-21 18:21:031664#if defined(OS_CHROMEOS)
1665void MetricsService::LogChromeOSCrash(const std::string &crash_type) {
1666 if (crash_type == "user")
1667 IncrementPrefValue(prefs::kStabilityOtherUserCrashCount);
1668 else if (crash_type == "kernel")
1669 IncrementPrefValue(prefs::kStabilityKernelCrashCount);
1670 else if (crash_type == "uncleanshutdown")
1671 IncrementPrefValue(prefs::kStabilitySystemUncleanShutdownCount);
1672 else
1673 NOTREACHED() << "Unexpected Chrome OS crash type " << crash_type;
1674 // Wake up metrics logs sending if necessary now that new
1675 // log data is available.
1676 HandleIdleSinceLastTransmission(false);
1677}
1678#endif // OS_CHROMEOS
1679
[email protected]cd937072012-07-02 09:00:291680void MetricsService::LogPluginLoadingError(const FilePath& plugin_path) {
1681 webkit::WebPluginInfo plugin;
1682 bool success =
1683 content::PluginService::GetInstance()->GetPluginInfoByPath(plugin_path,
1684 &plugin);
1685 DCHECK(success);
1686 ChildProcessStats& stats = child_process_stats_buffer_[plugin.name];
1687 // Initialize the type if this entry is new.
1688 if (stats.process_type == content::PROCESS_TYPE_UNKNOWN) {
1689 // The plug-in process might not actually of type PLUGIN (which means
1690 // NPAPI), but we only care that it is *a* plug-in process.
1691 stats.process_type = content::PROCESS_TYPE_PLUGIN;
1692 } else {
1693 DCHECK(IsPluginProcess(stats.process_type));
1694 }
1695 stats.loading_errors++;
1696}
1697
[email protected]a27a9382009-02-11 23:55:101698void MetricsService::LogChildProcessChange(
[email protected]432115822011-07-10 15:52:271699 int type,
[email protected]6c2381d2011-10-19 02:52:531700 const content::NotificationSource& source,
1701 const content::NotificationDetails& details) {
[email protected]4967f792012-01-20 22:14:401702 content::Details<ChildProcessData> child_details(details);
[email protected]4306c3792011-12-02 01:57:531703 const string16& child_name = child_details->name;
[email protected]0d84c5d2009-10-09 01:10:421704
[email protected]a27a9382009-02-11 23:55:101705 if (child_process_stats_buffer_.find(child_name) ==
1706 child_process_stats_buffer_.end()) {
[email protected]0d84c5d2009-10-09 01:10:421707 child_process_stats_buffer_[child_name] =
[email protected]4306c3792011-12-02 01:57:531708 ChildProcessStats(child_details->type);
initial.commit09911bf2008-07-26 23:55:291709 }
1710
[email protected]a27a9382009-02-11 23:55:101711 ChildProcessStats& stats = child_process_stats_buffer_[child_name];
[email protected]432115822011-07-10 15:52:271712 switch (type) {
1713 case content::NOTIFICATION_CHILD_PROCESS_HOST_CONNECTED:
initial.commit09911bf2008-07-26 23:55:291714 stats.process_launches++;
1715 break;
1716
[email protected]432115822011-07-10 15:52:271717 case content::NOTIFICATION_CHILD_INSTANCE_CREATED:
initial.commit09911bf2008-07-26 23:55:291718 stats.instances++;
1719 break;
1720
[email protected]432115822011-07-10 15:52:271721 case content::NOTIFICATION_CHILD_PROCESS_CRASHED:
initial.commit09911bf2008-07-26 23:55:291722 stats.process_crashes++;
[email protected]1f085622009-12-04 05:33:451723 // Exclude plugin crashes from the count below because we report them via
1724 // a separate UMA metric.
[email protected]4306c3792011-12-02 01:57:531725 if (!IsPluginProcess(child_details->type)) {
[email protected]1f085622009-12-04 05:33:451726 IncrementPrefValue(prefs::kStabilityChildProcessCrashCount);
1727 }
initial.commit09911bf2008-07-26 23:55:291728 break;
1729
1730 default:
[email protected]432115822011-07-10 15:52:271731 NOTREACHED() << "Unexpected notification type " << type;
initial.commit09911bf2008-07-26 23:55:291732 return;
1733 }
1734}
1735
1736// Recursively counts the number of bookmarks and folders in node.
[email protected]b3c33d462009-06-26 22:29:201737static void CountBookmarks(const BookmarkNode* node,
1738 int* bookmarks,
1739 int* folders) {
[email protected]0890e60e2011-06-27 14:55:211740 if (node->is_url())
initial.commit09911bf2008-07-26 23:55:291741 (*bookmarks)++;
1742 else
1743 (*folders)++;
[email protected]9c1a75a2011-03-10 02:38:121744 for (int i = 0; i < node->child_count(); ++i)
initial.commit09911bf2008-07-26 23:55:291745 CountBookmarks(node->GetChild(i), bookmarks, folders);
1746}
1747
[email protected]b3c33d462009-06-26 22:29:201748void MetricsService::LogBookmarks(const BookmarkNode* node,
[email protected]57ecc4b2010-08-11 03:02:511749 const char* num_bookmarks_key,
1750 const char* num_folders_key) {
initial.commit09911bf2008-07-26 23:55:291751 DCHECK(node);
1752 int num_bookmarks = 0;
1753 int num_folders = 0;
1754 CountBookmarks(node, &num_bookmarks, &num_folders);
1755 num_folders--; // Don't include the root folder in the count.
1756
1757 PrefService* pref = g_browser_process->local_state();
1758 DCHECK(pref);
1759 pref->SetInteger(num_bookmarks_key, num_bookmarks);
1760 pref->SetInteger(num_folders_key, num_folders);
1761}
1762
[email protected]d8e41ed2008-09-11 15:22:321763void MetricsService::LogBookmarks(BookmarkModel* model) {
initial.commit09911bf2008-07-26 23:55:291764 DCHECK(model);
[email protected]72bdcfe2011-07-22 17:21:581765 LogBookmarks(model->bookmark_bar_node(),
initial.commit09911bf2008-07-26 23:55:291766 prefs::kNumBookmarksOnBookmarkBar,
1767 prefs::kNumFoldersOnBookmarkBar);
1768 LogBookmarks(model->other_node(),
1769 prefs::kNumBookmarksInOtherBookmarkFolder,
1770 prefs::kNumFoldersInOtherBookmarkFolder);
1771 ScheduleNextStateSave();
1772}
1773
[email protected]604d8a062012-03-16 21:37:461774void MetricsService::LogKeywordCount(size_t keyword_count) {
initial.commit09911bf2008-07-26 23:55:291775 PrefService* pref = g_browser_process->local_state();
1776 DCHECK(pref);
[email protected]604d8a062012-03-16 21:37:461777 pref->SetInteger(prefs::kNumKeywords, static_cast<int>(keyword_count));
initial.commit09911bf2008-07-26 23:55:291778 ScheduleNextStateSave();
1779}
1780
1781void MetricsService::RecordPluginChanges(PrefService* pref) {
[email protected]f8628c22011-04-05 12:10:181782 ListPrefUpdate update(pref, prefs::kStabilityPluginStats);
1783 ListValue* plugins = update.Get();
initial.commit09911bf2008-07-26 23:55:291784 DCHECK(plugins);
1785
1786 for (ListValue::iterator value_iter = plugins->begin();
1787 value_iter != plugins->end(); ++value_iter) {
1788 if (!(*value_iter)->IsType(Value::TYPE_DICTIONARY)) {
[email protected]a063c102010-07-22 22:20:191789 NOTREACHED();
initial.commit09911bf2008-07-26 23:55:291790 continue;
1791 }
1792
1793 DictionaryValue* plugin_dict = static_cast<DictionaryValue*>(*value_iter);
[email protected]57ecc4b2010-08-11 03:02:511794 std::string plugin_name;
[email protected]8e50b602009-03-03 22:59:431795 plugin_dict->GetString(prefs::kStabilityPluginName, &plugin_name);
[email protected]6470ee8f2009-03-03 20:46:401796 if (plugin_name.empty()) {
[email protected]a063c102010-07-22 22:20:191797 NOTREACHED();
initial.commit09911bf2008-07-26 23:55:291798 continue;
1799 }
1800
[email protected]57ecc4b2010-08-11 03:02:511801 // TODO(viettrungluu): remove conversions
[email protected]68b9e72b2011-08-05 23:08:221802 string16 name16 = UTF8ToUTF16(plugin_name);
1803 if (child_process_stats_buffer_.find(name16) ==
1804 child_process_stats_buffer_.end()) {
initial.commit09911bf2008-07-26 23:55:291805 continue;
[email protected]68b9e72b2011-08-05 23:08:221806 }
initial.commit09911bf2008-07-26 23:55:291807
[email protected]68b9e72b2011-08-05 23:08:221808 ChildProcessStats stats = child_process_stats_buffer_[name16];
initial.commit09911bf2008-07-26 23:55:291809 if (stats.process_launches) {
1810 int launches = 0;
[email protected]8e50b602009-03-03 22:59:431811 plugin_dict->GetInteger(prefs::kStabilityPluginLaunches, &launches);
initial.commit09911bf2008-07-26 23:55:291812 launches += stats.process_launches;
[email protected]8e50b602009-03-03 22:59:431813 plugin_dict->SetInteger(prefs::kStabilityPluginLaunches, launches);
initial.commit09911bf2008-07-26 23:55:291814 }
1815 if (stats.process_crashes) {
1816 int crashes = 0;
[email protected]8e50b602009-03-03 22:59:431817 plugin_dict->GetInteger(prefs::kStabilityPluginCrashes, &crashes);
initial.commit09911bf2008-07-26 23:55:291818 crashes += stats.process_crashes;
[email protected]8e50b602009-03-03 22:59:431819 plugin_dict->SetInteger(prefs::kStabilityPluginCrashes, crashes);
initial.commit09911bf2008-07-26 23:55:291820 }
1821 if (stats.instances) {
1822 int instances = 0;
[email protected]8e50b602009-03-03 22:59:431823 plugin_dict->GetInteger(prefs::kStabilityPluginInstances, &instances);
initial.commit09911bf2008-07-26 23:55:291824 instances += stats.instances;
[email protected]8e50b602009-03-03 22:59:431825 plugin_dict->SetInteger(prefs::kStabilityPluginInstances, instances);
initial.commit09911bf2008-07-26 23:55:291826 }
[email protected]cd937072012-07-02 09:00:291827 if (stats.loading_errors) {
1828 int loading_errors = 0;
1829 plugin_dict->GetInteger(prefs::kStabilityPluginLoadingErrors,
1830 &loading_errors);
1831 loading_errors += stats.loading_errors;
1832 plugin_dict->SetInteger(prefs::kStabilityPluginLoadingErrors,
1833 loading_errors);
1834 }
initial.commit09911bf2008-07-26 23:55:291835
[email protected]68b9e72b2011-08-05 23:08:221836 child_process_stats_buffer_.erase(name16);
initial.commit09911bf2008-07-26 23:55:291837 }
1838
1839 // Now go through and add dictionaries for plugins that didn't already have
1840 // reports in Local State.
[email protected]68b9e72b2011-08-05 23:08:221841 for (std::map<string16, ChildProcessStats>::iterator cache_iter =
[email protected]a27a9382009-02-11 23:55:101842 child_process_stats_buffer_.begin();
1843 cache_iter != child_process_stats_buffer_.end(); ++cache_iter) {
[email protected]a27a9382009-02-11 23:55:101844 ChildProcessStats stats = cache_iter->second;
[email protected]0d84c5d2009-10-09 01:10:421845
1846 // Insert only plugins information into the plugins list.
[email protected]8d5f1dae2011-11-11 14:30:411847 if (!IsPluginProcess(stats.process_type))
[email protected]0d84c5d2009-10-09 01:10:421848 continue;
1849
[email protected]57ecc4b2010-08-11 03:02:511850 // TODO(viettrungluu): remove conversion
[email protected]68b9e72b2011-08-05 23:08:221851 std::string plugin_name = UTF16ToUTF8(cache_iter->first);
[email protected]0d84c5d2009-10-09 01:10:421852
initial.commit09911bf2008-07-26 23:55:291853 DictionaryValue* plugin_dict = new DictionaryValue;
1854
[email protected]8e50b602009-03-03 22:59:431855 plugin_dict->SetString(prefs::kStabilityPluginName, plugin_name);
1856 plugin_dict->SetInteger(prefs::kStabilityPluginLaunches,
initial.commit09911bf2008-07-26 23:55:291857 stats.process_launches);
[email protected]8e50b602009-03-03 22:59:431858 plugin_dict->SetInteger(prefs::kStabilityPluginCrashes,
initial.commit09911bf2008-07-26 23:55:291859 stats.process_crashes);
[email protected]8e50b602009-03-03 22:59:431860 plugin_dict->SetInteger(prefs::kStabilityPluginInstances,
initial.commit09911bf2008-07-26 23:55:291861 stats.instances);
[email protected]cd937072012-07-02 09:00:291862 plugin_dict->SetInteger(prefs::kStabilityPluginLoadingErrors,
1863 stats.loading_errors);
initial.commit09911bf2008-07-26 23:55:291864 plugins->Append(plugin_dict);
1865 }
[email protected]a27a9382009-02-11 23:55:101866 child_process_stats_buffer_.clear();
initial.commit09911bf2008-07-26 23:55:291867}
1868
[email protected]6c2381d2011-10-19 02:52:531869bool MetricsService::CanLogNotification(
1870 int type,
1871 const content::NotificationSource& source,
1872 const content::NotificationDetails& details) {
[email protected]2c910b72011-03-08 21:16:321873 // We simply don't log anything to UMA if there is a single incognito
initial.commit09911bf2008-07-26 23:55:291874 // session visible. The problem is that we always notify using the orginal
1875 // profile in order to simplify notification processing.
[email protected]e764e582012-08-01 03:01:291876 return !chrome::IsOffTheRecordSessionActive();
initial.commit09911bf2008-07-26 23:55:291877}
1878
[email protected]57ecc4b2010-08-11 03:02:511879void MetricsService::RecordBooleanPrefValue(const char* path, bool value) {
initial.commit09911bf2008-07-26 23:55:291880 DCHECK(IsSingleThreaded());
1881
1882 PrefService* pref = g_browser_process->local_state();
1883 DCHECK(pref);
1884
1885 pref->SetBoolean(path, value);
1886 RecordCurrentState(pref);
1887}
1888
1889void MetricsService::RecordCurrentState(PrefService* pref) {
[email protected]0bb1a622009-03-04 03:22:321890 pref->SetInt64(prefs::kStabilityLastTimestampSec, Time::Now().ToTimeT());
initial.commit09911bf2008-07-26 23:55:291891
1892 RecordPluginChanges(pref);
1893}
1894
[email protected]8d5f1dae2011-11-11 14:30:411895// static
[email protected]bd5d6cf2011-12-01 00:39:121896bool MetricsService::IsPluginProcess(content::ProcessType type) {
[email protected]cd937072012-07-02 09:00:291897 return (type == content::PROCESS_TYPE_PLUGIN ||
1898 type == content::PROCESS_TYPE_PPAPI_PLUGIN ||
1899 type == content::PROCESS_TYPE_PPAPI_BROKER);
[email protected]8d5f1dae2011-11-11 14:30:411900}
1901
[email protected]5ccaa412009-11-13 22:00:161902#if defined(OS_CHROMEOS)
[email protected]29cf16772010-04-21 15:13:471903void MetricsService::StartExternalMetrics() {
[email protected]5ccaa412009-11-13 22:00:161904 external_metrics_ = new chromeos::ExternalMetrics;
[email protected]29cf16772010-04-21 15:13:471905 external_metrics_->Start();
[email protected]5ccaa412009-11-13 22:00:161906}
1907#endif
[email protected]3819f2ee2011-08-21 09:44:381908
1909// static
1910bool MetricsServiceHelper::IsMetricsReportingEnabled() {
1911 bool result = false;
1912 const PrefService* local_state = g_browser_process->local_state();
1913 if (local_state) {
1914 const PrefService::Preference* uma_pref =
1915 local_state->FindPreference(prefs::kMetricsReportingEnabled);
1916 if (uma_pref) {
1917 bool success = uma_pref->GetValue()->GetAsBoolean(&result);
1918 DCHECK(success);
1919 }
1920 }
1921 return result;
1922}