blob: 88a82ab9ba3ca4a0b1b4d2ecf39bbdc7617a9e1e [file] [log] [blame]
[email protected]f90bf0d92011-01-13 02:12:441// Copyright (c) 2011 The Chromium Authors. All rights reserved.
license.botbf09a502008-08-24 00:55:552// Use of this source code is governed by a BSD-style license that can be
3// found in the LICENSE file.
initial.commit09911bf2008-07-26 23:55:294
initial.commit09911bf2008-07-26 23:55:295//------------------------------------------------------------------------------
6// Description of the life cycle of a instance of MetricsService.
7//
8// OVERVIEW
9//
10// A MetricsService instance is typically created at application startup. It
11// is the central controller for the acquisition of log data, and the automatic
12// transmission of that log data to an external server. Its major job is to
13// manage logs, grouping them for transmission, and transmitting them. As part
14// of its grouping, MS finalizes logs by including some just-in-time gathered
15// memory statistics, snapshotting the current stats of numerous histograms,
16// closing the logs, translating to XML text, and compressing the results for
17// transmission. Transmission includes submitting a compressed log as data in a
[email protected]281d2882009-01-20 20:32:4218// URL-post, and retransmitting (or retaining at process termination) if the
initial.commit09911bf2008-07-26 23:55:2919// attempted transmission failed. Retention across process terminations is done
[email protected]46f89e142010-07-19 08:00:4220// using the the PrefServices facilities. The retained logs (the ones that never
21// got transmitted) are compressed and base64-encoded before being persisted.
initial.commit09911bf2008-07-26 23:55:2922//
[email protected]281d2882009-01-20 20:32:4223// Logs fall into one of two categories: "initial logs," and "ongoing logs."
24// There is at most one initial log sent for each complete run of the chromium
initial.commit09911bf2008-07-26 23:55:2925// product (from startup, to browser shutdown). An initial log is generally
26// transmitted some short time (1 minute?) after startup, and includes stats
27// such as recent crash info, the number and types of plugins, etc. The
[email protected]281d2882009-01-20 20:32:4228// external server's response to the initial log conceptually tells this MS if
29// it should continue transmitting logs (during this session). The server
30// response can actually be much more detailed, and always includes (at a
31// minimum) how often additional ongoing logs should be sent.
initial.commit09911bf2008-07-26 23:55:2932//
33// After the above initial log, a series of ongoing logs will be transmitted.
34// The first ongoing log actually begins to accumulate information stating when
35// the MS was first constructed. Note that even though the initial log is
36// commonly sent a full minute after startup, the initial log does not include
37// much in the way of user stats. The most common interlog period (delay)
[email protected]0b33f80b2008-12-17 21:34:3638// is 20 minutes. That time period starts when the first user action causes a
initial.commit09911bf2008-07-26 23:55:2939// logging event. This means that if there is no user action, there may be long
[email protected]281d2882009-01-20 20:32:4240// periods without any (ongoing) log transmissions. Ongoing logs typically
initial.commit09911bf2008-07-26 23:55:2941// contain very detailed records of user activities (ex: opened tab, closed
42// tab, fetched URL, maximized window, etc.) In addition, just before an
43// ongoing log is closed out, a call is made to gather memory statistics. Those
44// memory statistics are deposited into a histogram, and the log finalization
45// code is then called. In the finalization, a call to a Histogram server
46// acquires a list of all local histograms that have been flagged for upload
[email protected]281d2882009-01-20 20:32:4247// to the UMA server. The finalization also acquires a the most recent number
48// of page loads, along with any counts of renderer or plugin crashes.
initial.commit09911bf2008-07-26 23:55:2949//
50// When the browser shuts down, there will typically be a fragment of an ongoing
51// log that has not yet been transmitted. At shutdown time, that fragment
[email protected]cac267c2011-09-29 15:18:1052// is closed (including snapshotting histograms), and persisted, for
initial.commit09911bf2008-07-26 23:55:2953// potential transmission during a future run of the product.
54//
55// There are two slightly abnormal shutdown conditions. There is a
56// "disconnected scenario," and a "really fast startup and shutdown" scenario.
57// In the "never connected" situation, the user has (during the running of the
58// process) never established an internet connection. As a result, attempts to
59// transmit the initial log have failed, and a lot(?) of data has accumulated in
60// the ongoing log (which didn't yet get closed, because there was never even a
61// contemplation of sending it). There is also a kindred "lost connection"
62// situation, where a loss of connection prevented an ongoing log from being
63// transmitted, and a (still open) log was stuck accumulating a lot(?) of data,
64// while the earlier log retried its transmission. In both of these
65// disconnected situations, two logs need to be, and are, persistently stored
66// for future transmission.
67//
68// The other unusual shutdown condition, termed "really fast startup and
69// shutdown," involves the deliberate user termination of the process before
70// the initial log is even formed or transmitted. In that situation, no logging
71// is done, but the historical crash statistics remain (unlogged) for inclusion
72// in a future run's initial log. (i.e., we don't lose crash stats).
73//
74// With the above overview, we can now describe the state machine's various
75// stats, based on the State enum specified in the state_ member. Those states
76// are:
77//
78// INITIALIZED, // Constructor was called.
[email protected]85ed9d42010-06-08 22:37:4479// INIT_TASK_SCHEDULED, // Waiting for deferred init tasks to complete.
80// INIT_TASK_DONE, // Waiting for timer to send initial log.
initial.commit09911bf2008-07-26 23:55:2981// INITIAL_LOG_READY, // Initial log generated, and waiting for reply.
initial.commit09911bf2008-07-26 23:55:2982// SENDING_OLD_LOGS, // Sending unsent logs from previous session.
83// SENDING_CURRENT_LOGS, // Sending standard current logs as they accrue.
84//
85// In more detail, we have:
86//
87// INITIALIZED, // Constructor was called.
88// The MS has been constructed, but has taken no actions to compose the
89// initial log.
90//
[email protected]85ed9d42010-06-08 22:37:4491// INIT_TASK_SCHEDULED, // Waiting for deferred init tasks to complete.
initial.commit09911bf2008-07-26 23:55:2992// Typically about 30 seconds after startup, a task is sent to a second thread
[email protected]85ed9d42010-06-08 22:37:4493// (the file thread) to perform deferred (lower priority and slower)
94// initialization steps such as getting the list of plugins. That task will
95// (when complete) make an async callback (via a Task) to indicate the
96// completion.
initial.commit09911bf2008-07-26 23:55:2997//
[email protected]85ed9d42010-06-08 22:37:4498// INIT_TASK_DONE, // Waiting for timer to send initial log.
initial.commit09911bf2008-07-26 23:55:2999// The callback has arrived, and it is now possible for an initial log to be
100// created. This callback typically arrives back less than one second after
[email protected]85ed9d42010-06-08 22:37:44101// the deferred init task is dispatched.
initial.commit09911bf2008-07-26 23:55:29102//
103// INITIAL_LOG_READY, // Initial log generated, and waiting for reply.
104// This state is entered only after an initial log has been composed, and
105// prepared for transmission. It is also the case that any previously unsent
106// logs have been loaded into instance variables for possible transmission.
107//
initial.commit09911bf2008-07-26 23:55:29108// SENDING_OLD_LOGS, // Sending unsent logs from previous session.
[email protected]cac267c2011-09-29 15:18:10109// This state indicates that the initial log for this session has been
110// successfully sent and it is now time to send any logs that were
111// saved from previous sessions. All such logs will be transmitted before
112// exiting this state, and proceeding with ongoing logs from the current session
113// (see next state).
initial.commit09911bf2008-07-26 23:55:29114//
115// SENDING_CURRENT_LOGS, // Sending standard current logs as they accrue.
[email protected]0b33f80b2008-12-17 21:34:36116// Current logs are being accumulated. Typically every 20 minutes a log is
initial.commit09911bf2008-07-26 23:55:29117// closed and finalized for transmission, at the same time as a new log is
118// started.
119//
120// The progression through the above states is simple, and sequential, in the
121// most common use cases. States proceed from INITIAL to SENDING_CURRENT_LOGS,
122// and remain in the latter until shutdown.
123//
124// The one unusual case is when the user asks that we stop logging. When that
[email protected]cac267c2011-09-29 15:18:10125// happens, any staged (transmission in progress) log is persisted, and any log
126// log that is currently accumulating is also finalized and persisted. We then
127// regress back to the SEND_OLD_LOGS state in case the user enables log
128// recording again during this session. This way anything we have persisted
129// will be sent automatically if/when we progress back to SENDING_CURRENT_LOG
130// state.
initial.commit09911bf2008-07-26 23:55:29131//
[email protected]cac267c2011-09-29 15:18:10132// Also note that whenever we successfully send an old log, we mirror the list
133// of logs into the PrefService. This ensures that IF we crash, we won't start
134// up and retransmit our old logs again.
initial.commit09911bf2008-07-26 23:55:29135//
136// Due to race conditions, it is always possible that a log file could be sent
137// twice. For example, if a log file is sent, but not yet acknowledged by
138// the external server, and the user shuts down, then a copy of the log may be
139// saved for re-transmission. These duplicates could be filtered out server
[email protected]281d2882009-01-20 20:32:42140// side, but are not expected to be a significant problem.
initial.commit09911bf2008-07-26 23:55:29141//
142//
143//------------------------------------------------------------------------------
144
[email protected]40bcc302009-03-02 20:50:39145#include "chrome/browser/metrics/metrics_service.h"
146
[email protected]7f7f1962011-04-20 15:58:16147#include "base/bind.h"
148#include "base/callback.h"
[email protected]5d91c9e2010-07-28 17:25:28149#include "base/command_line.h"
[email protected]46f89e142010-07-19 08:00:42150#include "base/md5.h"
[email protected]835d7c82010-10-14 04:38:38151#include "base/metrics/histogram.h"
[email protected]528c56d2010-07-30 19:28:44152#include "base/string_number_conversions.h"
[email protected]ce072a72010-12-31 20:02:16153#include "base/threading/platform_thread.h"
[email protected]b3841c502011-03-09 01:21:31154#include "base/threading/thread.h"
[email protected]440b37b22010-08-30 05:31:40155#include "base/utf_string_conversions.h"
[email protected]679082052010-07-21 21:30:13156#include "base/values.h"
[email protected]d8e41ed2008-09-11 15:22:32157#include "chrome/browser/bookmarks/bookmark_model.h"
initial.commit09911bf2008-07-26 23:55:29158#include "chrome/browser/browser_process.h"
[email protected]84c988a2011-04-19 17:56:33159#include "chrome/browser/memory_details.h"
[email protected]7c927b62010-02-24 09:54:13160#include "chrome/browser/metrics/histogram_synchronizer.h"
[email protected]679082052010-07-21 21:30:13161#include "chrome/browser/metrics/metrics_log.h"
[email protected]cac267c2011-09-29 15:18:10162#include "chrome/browser/metrics/metrics_log_serializer.h"
[email protected]7f7f1962011-04-20 15:58:16163#include "chrome/browser/metrics/metrics_reporting_scheduler.h"
[email protected]d67d1052011-06-09 05:11:41164#include "chrome/browser/net/network_stats.h"
[email protected]37858e52010-08-26 00:22:02165#include "chrome/browser/prefs/pref_service.h"
[email protected]f8628c22011-04-05 12:10:18166#include "chrome/browser/prefs/scoped_user_pref_update.h"
[email protected]8ecad5e2010-12-02 21:18:33167#include "chrome/browser/profiles/profile.h"
[email protected]8e5c89a2011-06-07 18:13:33168#include "chrome/browser/search_engines/template_url_service.h"
[email protected]71b73f02011-04-06 15:57:29169#include "chrome/browser/ui/browser_list.h"
[email protected]157d5472009-11-05 22:31:03170#include "chrome/common/child_process_logging.h"
[email protected]432115822011-07-10 15:52:27171#include "chrome/common/chrome_notification_types.h"
[email protected]92745242009-06-12 16:52:21172#include "chrome/common/chrome_switches.h"
[email protected]3eb0d8f72010-12-15 23:38:25173#include "chrome/common/guid.h"
[email protected]cac267c2011-09-29 15:18:10174#include "chrome/common/metrics_log_manager.h"
initial.commit09911bf2008-07-26 23:55:29175#include "chrome/common/pref_names.h"
[email protected]e09ba552009-02-05 03:26:29176#include "chrome/common/render_messages.h"
[email protected]35e251d2011-05-24 21:01:04177#include "content/browser/load_notification_details.h"
[email protected]d33e7cc2011-09-23 01:43:56178#include "content/browser/plugin_service.h"
[email protected]5de634712011-03-02 00:20:19179#include "content/browser/renderer_host/render_process_host.h"
[email protected]6faf7b12011-03-09 19:24:14180#include "content/common/child_process_info.h"
[email protected]b3841c502011-03-09 01:21:31181#include "content/common/notification_service.h"
[email protected]191eb3f72010-12-21 06:27:50182#include "webkit/plugins/npapi/plugin_list.h"
[email protected]91d9f3d2011-08-14 05:24:44183#include "webkit/plugins/webplugininfo.h"
initial.commit09911bf2008-07-26 23:55:29184
[email protected]e06131d2010-02-10 18:40:33185// TODO(port): port browser_distribution.h.
186#if !defined(OS_POSIX)
[email protected]79bf0b72009-04-27 21:30:55187#include "chrome/installer/util/browser_distribution.h"
[email protected]dc6f4962009-02-13 01:25:50188#endif
189
[email protected]5ccaa412009-11-13 22:00:16190#if defined(OS_CHROMEOS)
[email protected]db342d52010-08-09 21:19:37191#include "chrome/browser/chromeos/cros/cros_library.h"
[email protected]5ccaa412009-11-13 22:00:16192#include "chrome/browser/chromeos/external_metrics.h"
[email protected]d43970a72011-07-10 06:24:52193#include "chrome/browser/chromeos/system/statistics_provider.h"
[email protected]5ccaa412009-11-13 22:00:16194#endif
195
[email protected]e1acf6f2008-10-27 20:43:33196using base::Time;
[email protected]e1acf6f2008-10-27 20:43:33197
initial.commit09911bf2008-07-26 23:55:29198// Check to see that we're being called on only one thread.
199static bool IsSingleThreaded();
200
initial.commit09911bf2008-07-26 23:55:29201static const char kMetricsType[] = "application/vnd.mozilla.metrics.bz2";
202
[email protected]7f7f1962011-04-20 15:58:16203// The delay, in seconds, after starting recording before doing expensive
204// initialization work.
205static const int kInitializationDelaySeconds = 30;
[email protected]252873ef2008-08-04 21:59:45206
[email protected]c9a3ef82009-05-28 22:02:46207// This specifies the amount of time to wait for all renderers to send their
208// data.
209static const int kMaxHistogramGatheringWaitDuration = 60000; // 60 seconds.
210
[email protected]54702c92011-04-15 15:06:43211// The maximum number of events in a log uploaded to the UMA server.
[email protected]7d770852011-09-20 23:56:58212static const int kEventLimit = 2400;
[email protected]68475e602008-08-22 03:21:15213
214// If an upload fails, and the transmission was over this byte count, then we
215// will discard the log, and not try to retransmit it. We also don't persist
216// the log to the prefs for transmission during the next chrome session if this
217// limit is exceeded.
218static const int kUploadLogAvoidRetransmitSize = 50000;
initial.commit09911bf2008-07-26 23:55:29219
initial.commit09911bf2008-07-26 23:55:29220// Interval, in seconds, between state saves.
221static const int kSaveStateInterval = 5 * 60; // five minutes
222
[email protected]c0c55e92011-09-10 18:47:30223// static
224MetricsService::ShutdownCleanliness MetricsService::clean_shutdown_status_ =
225 MetricsService::CLEANLY_SHUTDOWN;
226
[email protected]679082052010-07-21 21:30:13227// This is used to quickly log stats from child process related notifications in
228// MetricsService::child_stats_buffer_. The buffer's contents are transferred
229// out when Local State is periodically saved. The information is then
230// reported to the UMA server on next launch.
231struct MetricsService::ChildProcessStats {
232 public:
233 explicit ChildProcessStats(ChildProcessInfo::ProcessType type)
234 : process_launches(0),
235 process_crashes(0),
236 instances(0),
237 process_type(type) {}
238
239 // This constructor is only used by the map to return some default value for
240 // an index for which no value has been assigned.
241 ChildProcessStats()
242 : process_launches(0),
[email protected]d88bf0a2011-08-30 23:55:57243 process_crashes(0),
244 instances(0),
245 process_type(ChildProcessInfo::UNKNOWN_PROCESS) {}
[email protected]679082052010-07-21 21:30:13246
247 // The number of times that the given child process has been launched
248 int process_launches;
249
250 // The number of times that the given child process has crashed
251 int process_crashes;
252
253 // The number of instances of this child process that have been created.
254 // An instance is a DOM object rendered by this child process during a page
255 // load.
256 int instances;
257
258 ChildProcessInfo::ProcessType process_type;
259};
initial.commit09911bf2008-07-26 23:55:29260
[email protected]84c988a2011-04-19 17:56:33261// Handles asynchronous fetching of memory details.
262// Will run the provided task after finished.
263class MetricsMemoryDetails : public MemoryDetails {
264 public:
265 explicit MetricsMemoryDetails(Task* completion) : completion_(completion) {}
266
267 virtual void OnDetailsAvailable() {
268 MessageLoop::current()->PostTask(FROM_HERE, completion_);
269 }
270
271 private:
272 ~MetricsMemoryDetails() {}
273
274 Task* completion_;
275 DISALLOW_COPY_AND_ASSIGN(MetricsMemoryDetails);
276};
277
initial.commit09911bf2008-07-26 23:55:29278// static
279void MetricsService::RegisterPrefs(PrefService* local_state) {
280 DCHECK(IsSingleThreaded());
[email protected]20ce516d2010-06-18 02:20:04281 local_state->RegisterStringPref(prefs::kMetricsClientID, "");
[email protected]0bb1a622009-03-04 03:22:32282 local_state->RegisterInt64Pref(prefs::kMetricsClientIDTimestamp, 0);
283 local_state->RegisterInt64Pref(prefs::kStabilityLaunchTimeSec, 0);
284 local_state->RegisterInt64Pref(prefs::kStabilityLastTimestampSec, 0);
[email protected]20ce516d2010-06-18 02:20:04285 local_state->RegisterStringPref(prefs::kStabilityStatsVersion, "");
[email protected]225c50842010-01-19 21:19:13286 local_state->RegisterInt64Pref(prefs::kStabilityStatsBuildTime, 0);
initial.commit09911bf2008-07-26 23:55:29287 local_state->RegisterBooleanPref(prefs::kStabilityExitedCleanly, true);
288 local_state->RegisterBooleanPref(prefs::kStabilitySessionEndCompleted, true);
289 local_state->RegisterIntegerPref(prefs::kMetricsSessionID, -1);
290 local_state->RegisterIntegerPref(prefs::kStabilityLaunchCount, 0);
291 local_state->RegisterIntegerPref(prefs::kStabilityCrashCount, 0);
292 local_state->RegisterIntegerPref(prefs::kStabilityIncompleteSessionEndCount,
293 0);
294 local_state->RegisterIntegerPref(prefs::kStabilityPageLoadCount, 0);
initial.commit09911bf2008-07-26 23:55:29295 local_state->RegisterIntegerPref(prefs::kStabilityRendererCrashCount, 0);
[email protected]1f085622009-12-04 05:33:45296 local_state->RegisterIntegerPref(prefs::kStabilityExtensionRendererCrashCount,
297 0);
initial.commit09911bf2008-07-26 23:55:29298 local_state->RegisterIntegerPref(prefs::kStabilityRendererHangCount, 0);
[email protected]1f085622009-12-04 05:33:45299 local_state->RegisterIntegerPref(prefs::kStabilityChildProcessCrashCount, 0);
[email protected]e73c01972008-08-13 00:18:24300 local_state->RegisterIntegerPref(prefs::kStabilityBreakpadRegistrationFail,
301 0);
302 local_state->RegisterIntegerPref(prefs::kStabilityBreakpadRegistrationSuccess,
303 0);
304 local_state->RegisterIntegerPref(prefs::kStabilityDebuggerPresent, 0);
305 local_state->RegisterIntegerPref(prefs::kStabilityDebuggerNotPresent, 0);
[email protected]c1834a92011-01-21 18:21:03306#if defined(OS_CHROMEOS)
307 local_state->RegisterIntegerPref(prefs::kStabilityOtherUserCrashCount, 0);
308 local_state->RegisterIntegerPref(prefs::kStabilityKernelCrashCount, 0);
309 local_state->RegisterIntegerPref(prefs::kStabilitySystemUncleanShutdownCount,
310 0);
311#endif // OS_CHROMEOS
[email protected]e73c01972008-08-13 00:18:24312
initial.commit09911bf2008-07-26 23:55:29313 local_state->RegisterDictionaryPref(prefs::kProfileMetrics);
314 local_state->RegisterIntegerPref(prefs::kNumBookmarksOnBookmarkBar, 0);
315 local_state->RegisterIntegerPref(prefs::kNumFoldersOnBookmarkBar, 0);
316 local_state->RegisterIntegerPref(prefs::kNumBookmarksInOtherBookmarkFolder,
317 0);
318 local_state->RegisterIntegerPref(prefs::kNumFoldersInOtherBookmarkFolder, 0);
319 local_state->RegisterIntegerPref(prefs::kNumKeywords, 0);
320 local_state->RegisterListPref(prefs::kMetricsInitialLogs);
321 local_state->RegisterListPref(prefs::kMetricsOngoingLogs);
[email protected]0bb1a622009-03-04 03:22:32322
323 local_state->RegisterInt64Pref(prefs::kUninstallMetricsPageLoadCount, 0);
324 local_state->RegisterInt64Pref(prefs::kUninstallLaunchCount, 0);
[email protected]6b5f21d2009-04-13 17:01:35325 local_state->RegisterInt64Pref(prefs::kUninstallMetricsInstallDate, 0);
[email protected]0bb1a622009-03-04 03:22:32326 local_state->RegisterInt64Pref(prefs::kUninstallMetricsUptimeSec, 0);
327 local_state->RegisterInt64Pref(prefs::kUninstallLastLaunchTimeSec, 0);
328 local_state->RegisterInt64Pref(prefs::kUninstallLastObservedRunTimeSec, 0);
initial.commit09911bf2008-07-26 23:55:29329}
330
[email protected]541f77922009-02-23 21:14:38331// static
332void MetricsService::DiscardOldStabilityStats(PrefService* local_state) {
333 local_state->SetBoolean(prefs::kStabilityExitedCleanly, true);
[email protected]c9abf242009-07-18 06:00:38334 local_state->SetBoolean(prefs::kStabilitySessionEndCompleted, true);
[email protected]541f77922009-02-23 21:14:38335
336 local_state->SetInteger(prefs::kStabilityIncompleteSessionEndCount, 0);
337 local_state->SetInteger(prefs::kStabilityBreakpadRegistrationSuccess, 0);
338 local_state->SetInteger(prefs::kStabilityBreakpadRegistrationFail, 0);
339 local_state->SetInteger(prefs::kStabilityDebuggerPresent, 0);
340 local_state->SetInteger(prefs::kStabilityDebuggerNotPresent, 0);
341
342 local_state->SetInteger(prefs::kStabilityLaunchCount, 0);
343 local_state->SetInteger(prefs::kStabilityCrashCount, 0);
344
345 local_state->SetInteger(prefs::kStabilityPageLoadCount, 0);
346 local_state->SetInteger(prefs::kStabilityRendererCrashCount, 0);
347 local_state->SetInteger(prefs::kStabilityRendererHangCount, 0);
348
[email protected]9165f742010-03-10 22:55:01349 local_state->SetInt64(prefs::kStabilityLaunchTimeSec, 0);
350 local_state->SetInt64(prefs::kStabilityLastTimestampSec, 0);
[email protected]541f77922009-02-23 21:14:38351
352 local_state->ClearPref(prefs::kStabilityPluginStats);
[email protected]ae155cb92009-06-19 06:10:37353
[email protected]f8628c22011-04-05 12:10:18354 local_state->ClearPref(prefs::kMetricsInitialLogs);
355 local_state->ClearPref(prefs::kMetricsOngoingLogs);
[email protected]541f77922009-02-23 21:14:38356}
357
initial.commit09911bf2008-07-26 23:55:29358MetricsService::MetricsService()
[email protected]d01b8732008-10-16 02:18:07359 : recording_active_(false),
360 reporting_active_(false),
[email protected]d01b8732008-10-16 02:18:07361 state_(INITIALIZED),
initial.commit09911bf2008-07-26 23:55:29362 current_fetch_(NULL),
[email protected]d67d1052011-06-09 05:11:41363 io_thread_(NULL),
[email protected]d01b8732008-10-16 02:18:07364 idle_since_last_transmission_(false),
initial.commit09911bf2008-07-26 23:55:29365 next_window_id_(0),
[email protected]40bcc302009-03-02 20:50:39366 ALLOW_THIS_IN_INITIALIZER_LIST(log_sender_factory_(this)),
367 ALLOW_THIS_IN_INITIALIZER_LIST(state_saver_factory_(this)),
[email protected]7f7f1962011-04-20 15:58:16368 waiting_for_asynchronus_reporting_step_(false) {
initial.commit09911bf2008-07-26 23:55:29369 DCHECK(IsSingleThreaded());
370 InitializeMetricsState();
[email protected]7f7f1962011-04-20 15:58:16371
372 base::Closure callback = base::Bind(&MetricsService::StartScheduledUpload,
373 base::Unretained(this));
374 scheduler_.reset(new MetricsReportingScheduler(callback));
[email protected]cac267c2011-09-29 15:18:10375 log_manager_.set_log_serializer(new MetricsLogSerializer());
376 log_manager_.set_max_ongoing_log_store_size(kUploadLogAvoidRetransmitSize);
initial.commit09911bf2008-07-26 23:55:29377}
378
379MetricsService::~MetricsService() {
380 SetRecording(false);
381}
382
[email protected]d01b8732008-10-16 02:18:07383void MetricsService::Start() {
[email protected]b1c8dc02011-04-13 18:32:04384 HandleIdleSinceLastTransmission(false);
[email protected]d01b8732008-10-16 02:18:07385 SetRecording(true);
386 SetReporting(true);
387}
388
389void MetricsService::StartRecordingOnly() {
390 SetRecording(true);
391 SetReporting(false);
392}
393
394void MetricsService::Stop() {
[email protected]b1c8dc02011-04-13 18:32:04395 HandleIdleSinceLastTransmission(false);
[email protected]d01b8732008-10-16 02:18:07396 SetReporting(false);
397 SetRecording(false);
398}
399
[email protected]edafd4c2011-05-10 17:18:53400std::string MetricsService::GetClientId() {
401 return client_id_;
402}
403
initial.commit09911bf2008-07-26 23:55:29404void MetricsService::SetRecording(bool enabled) {
405 DCHECK(IsSingleThreaded());
406
[email protected]d01b8732008-10-16 02:18:07407 if (enabled == recording_active_)
initial.commit09911bf2008-07-26 23:55:29408 return;
409
410 if (enabled) {
[email protected]b0c819f2009-03-08 04:52:15411 if (client_id_.empty()) {
412 PrefService* pref = g_browser_process->local_state();
413 DCHECK(pref);
[email protected]ddd231e2010-06-29 20:35:19414 client_id_ = pref->GetString(prefs::kMetricsClientID);
[email protected]b0c819f2009-03-08 04:52:15415 if (client_id_.empty()) {
416 client_id_ = GenerateClientID();
[email protected]ddd231e2010-06-29 20:35:19417 pref->SetString(prefs::kMetricsClientID, client_id_);
[email protected]b0c819f2009-03-08 04:52:15418
419 // Might as well make a note of how long this ID has existed
420 pref->SetString(prefs::kMetricsClientIDTimestamp,
[email protected]528c56d2010-07-30 19:28:44421 base::Int64ToString(Time::Now().ToTimeT()));
[email protected]b0c819f2009-03-08 04:52:15422 }
423 }
[email protected]157d5472009-11-05 22:31:03424 child_process_logging::SetClientId(client_id_);
initial.commit09911bf2008-07-26 23:55:29425 StartRecording();
[email protected]005ef3e2009-05-22 20:55:46426
[email protected]3ffd3ae2011-03-17 22:17:52427 SetUpNotifications(&registrar_, this);
initial.commit09911bf2008-07-26 23:55:29428 } else {
[email protected]005ef3e2009-05-22 20:55:46429 registrar_.RemoveAll();
[email protected]cac267c2011-09-29 15:18:10430 PushPendingLogsToPersistentStorage();
431 DCHECK(!log_manager_.has_staged_log());
432 if (state_ > INITIAL_LOG_READY && log_manager_.has_unsent_logs())
433 state_ = SENDING_OLD_LOGS;
initial.commit09911bf2008-07-26 23:55:29434 }
[email protected]d01b8732008-10-16 02:18:07435 recording_active_ = enabled;
initial.commit09911bf2008-07-26 23:55:29436}
437
[email protected]d01b8732008-10-16 02:18:07438bool MetricsService::recording_active() const {
initial.commit09911bf2008-07-26 23:55:29439 DCHECK(IsSingleThreaded());
[email protected]d01b8732008-10-16 02:18:07440 return recording_active_;
initial.commit09911bf2008-07-26 23:55:29441}
442
[email protected]d01b8732008-10-16 02:18:07443void MetricsService::SetReporting(bool enable) {
444 if (reporting_active_ != enable) {
445 reporting_active_ = enable;
446 if (reporting_active_)
[email protected]7f7f1962011-04-20 15:58:16447 StartSchedulerIfNecessary();
initial.commit09911bf2008-07-26 23:55:29448 }
[email protected]d01b8732008-10-16 02:18:07449}
450
451bool MetricsService::reporting_active() const {
452 DCHECK(IsSingleThreaded());
453 return reporting_active_;
initial.commit09911bf2008-07-26 23:55:29454}
455
[email protected]87ef9ea2011-02-26 03:15:15456// static
[email protected]3ffd3ae2011-03-17 22:17:52457void MetricsService::SetUpNotifications(NotificationRegistrar* registrar,
[email protected]87ef9ea2011-02-26 03:15:15458 NotificationObserver* observer) {
[email protected]432115822011-07-10 15:52:27459 registrar->Add(observer, chrome::NOTIFICATION_BROWSER_OPENED,
[email protected]04024e2c2011-08-12 19:32:10460 NotificationService::AllBrowserContextsAndSources());
[email protected]432115822011-07-10 15:52:27461 registrar->Add(observer, chrome::NOTIFICATION_BROWSER_CLOSED,
[email protected]87ef9ea2011-02-26 03:15:15462 NotificationService::AllSources());
[email protected]432115822011-07-10 15:52:27463 registrar->Add(observer, content::NOTIFICATION_USER_ACTION,
[email protected]87ef9ea2011-02-26 03:15:15464 NotificationService::AllSources());
[email protected]432115822011-07-10 15:52:27465 registrar->Add(observer, content::NOTIFICATION_TAB_PARENTED,
[email protected]87ef9ea2011-02-26 03:15:15466 NotificationService::AllSources());
[email protected]432115822011-07-10 15:52:27467 registrar->Add(observer, content::NOTIFICATION_TAB_CLOSING,
[email protected]87ef9ea2011-02-26 03:15:15468 NotificationService::AllSources());
[email protected]432115822011-07-10 15:52:27469 registrar->Add(observer, content::NOTIFICATION_LOAD_START,
[email protected]87ef9ea2011-02-26 03:15:15470 NotificationService::AllSources());
[email protected]432115822011-07-10 15:52:27471 registrar->Add(observer, content::NOTIFICATION_LOAD_STOP,
[email protected]87ef9ea2011-02-26 03:15:15472 NotificationService::AllSources());
[email protected]432115822011-07-10 15:52:27473 registrar->Add(observer, content::NOTIFICATION_RENDERER_PROCESS_CLOSED,
[email protected]87ef9ea2011-02-26 03:15:15474 NotificationService::AllSources());
[email protected]432115822011-07-10 15:52:27475 registrar->Add(observer, content::NOTIFICATION_RENDERER_PROCESS_HANG,
[email protected]87ef9ea2011-02-26 03:15:15476 NotificationService::AllSources());
[email protected]432115822011-07-10 15:52:27477 registrar->Add(observer, content::NOTIFICATION_CHILD_PROCESS_HOST_CONNECTED,
[email protected]87ef9ea2011-02-26 03:15:15478 NotificationService::AllSources());
[email protected]432115822011-07-10 15:52:27479 registrar->Add(observer, content::NOTIFICATION_CHILD_INSTANCE_CREATED,
[email protected]87ef9ea2011-02-26 03:15:15480 NotificationService::AllSources());
[email protected]432115822011-07-10 15:52:27481 registrar->Add(observer, content::NOTIFICATION_CHILD_PROCESS_CRASHED,
[email protected]87ef9ea2011-02-26 03:15:15482 NotificationService::AllSources());
[email protected]432115822011-07-10 15:52:27483 registrar->Add(observer, chrome::NOTIFICATION_TEMPLATE_URL_SERVICE_LOADED,
[email protected]87ef9ea2011-02-26 03:15:15484 NotificationService::AllSources());
[email protected]432115822011-07-10 15:52:27485 registrar->Add(observer, chrome::NOTIFICATION_OMNIBOX_OPENED_URL,
[email protected]87ef9ea2011-02-26 03:15:15486 NotificationService::AllSources());
[email protected]432115822011-07-10 15:52:27487 registrar->Add(observer, chrome::NOTIFICATION_BOOKMARK_MODEL_LOADED,
[email protected]2f35a312011-08-09 20:21:29488 NotificationService::AllBrowserContextsAndSources());
[email protected]87ef9ea2011-02-26 03:15:15489}
490
[email protected]432115822011-07-10 15:52:27491void MetricsService::Observe(int type,
initial.commit09911bf2008-07-26 23:55:29492 const NotificationSource& source,
493 const NotificationDetails& details) {
[email protected]cac267c2011-09-29 15:18:10494 DCHECK(log_manager_.current_log());
initial.commit09911bf2008-07-26 23:55:29495 DCHECK(IsSingleThreaded());
496
497 if (!CanLogNotification(type, source, details))
498 return;
499
[email protected]432115822011-07-10 15:52:27500 switch (type) {
501 case content::NOTIFICATION_USER_ACTION:
[email protected]cac267c2011-09-29 15:18:10502 log_manager_.current_log()->RecordUserAction(
503 *Details<const char*>(details).ptr());
initial.commit09911bf2008-07-26 23:55:29504 break;
505
[email protected]432115822011-07-10 15:52:27506 case chrome::NOTIFICATION_BROWSER_OPENED:
507 case chrome::NOTIFICATION_BROWSER_CLOSED:
initial.commit09911bf2008-07-26 23:55:29508 LogWindowChange(type, source, details);
509 break;
510
[email protected]432115822011-07-10 15:52:27511 case content::NOTIFICATION_TAB_PARENTED:
512 case content::NOTIFICATION_TAB_CLOSING:
initial.commit09911bf2008-07-26 23:55:29513 LogWindowChange(type, source, details);
514 break;
515
[email protected]432115822011-07-10 15:52:27516 case content::NOTIFICATION_LOAD_STOP:
initial.commit09911bf2008-07-26 23:55:29517 LogLoadComplete(type, source, details);
518 break;
519
[email protected]432115822011-07-10 15:52:27520 case content::NOTIFICATION_LOAD_START:
initial.commit09911bf2008-07-26 23:55:29521 LogLoadStarted();
522 break;
523
[email protected]432115822011-07-10 15:52:27524 case content::NOTIFICATION_RENDERER_PROCESS_CLOSED: {
[email protected]cd69619b2010-05-05 02:41:38525 RenderProcessHost::RendererClosedDetails* process_details =
526 Details<RenderProcessHost::RendererClosedDetails>(details).ptr();
[email protected]443b80e2010-12-14 00:42:23527 if (process_details->status ==
528 base::TERMINATION_STATUS_PROCESS_CRASHED ||
529 process_details->status ==
530 base::TERMINATION_STATUS_ABNORMAL_TERMINATION) {
[email protected]cd69619b2010-05-05 02:41:38531 if (process_details->was_extension_renderer) {
532 LogExtensionRendererCrash();
533 } else {
534 LogRendererCrash();
535 }
536 }
[email protected]1f085622009-12-04 05:33:45537 }
initial.commit09911bf2008-07-26 23:55:29538 break;
539
[email protected]432115822011-07-10 15:52:27540 case content::NOTIFICATION_RENDERER_PROCESS_HANG:
initial.commit09911bf2008-07-26 23:55:29541 LogRendererHang();
542 break;
543
[email protected]432115822011-07-10 15:52:27544 case content::NOTIFICATION_CHILD_PROCESS_HOST_CONNECTED:
545 case content::NOTIFICATION_CHILD_PROCESS_CRASHED:
546 case content::NOTIFICATION_CHILD_INSTANCE_CREATED:
[email protected]a27a9382009-02-11 23:55:10547 LogChildProcessChange(type, source, details);
initial.commit09911bf2008-07-26 23:55:29548 break;
549
[email protected]432115822011-07-10 15:52:27550 case chrome::NOTIFICATION_TEMPLATE_URL_SERVICE_LOADED:
[email protected]8e5c89a2011-06-07 18:13:33551 LogKeywords(Source<TemplateURLService>(source).ptr());
initial.commit09911bf2008-07-26 23:55:29552 break;
553
[email protected]432115822011-07-10 15:52:27554 case chrome::NOTIFICATION_OMNIBOX_OPENED_URL: {
[email protected]cac267c2011-09-29 15:18:10555 MetricsLog* current_log = log_manager_.current_log()->AsMetricsLog();
[email protected]1226abb2010-06-10 18:01:28556 DCHECK(current_log);
557 current_log->RecordOmniboxOpenedURL(
initial.commit09911bf2008-07-26 23:55:29558 *Details<AutocompleteLog>(details).ptr());
559 break;
[email protected]1226abb2010-06-10 18:01:28560 }
initial.commit09911bf2008-07-26 23:55:29561
[email protected]432115822011-07-10 15:52:27562 case chrome::NOTIFICATION_BOOKMARK_MODEL_LOADED: {
[email protected]b61236c62009-04-09 22:43:55563 Profile* p = Source<Profile>(source).ptr();
564 if (p)
565 LogBookmarks(p->GetBookmarkModel());
initial.commit09911bf2008-07-26 23:55:29566 break;
[email protected]b61236c62009-04-09 22:43:55567 }
initial.commit09911bf2008-07-26 23:55:29568 default:
[email protected]a063c102010-07-22 22:20:19569 NOTREACHED();
initial.commit09911bf2008-07-26 23:55:29570 break;
571 }
[email protected]d01b8732008-10-16 02:18:07572
573 HandleIdleSinceLastTransmission(false);
574
[email protected]cac267c2011-09-29 15:18:10575 if (log_manager_.current_log())
576 DVLOG(1) << "METRICS: NUMBER OF EVENTS = "
577 << log_manager_.current_log()->num_events();
[email protected]d01b8732008-10-16 02:18:07578}
579
580void MetricsService::HandleIdleSinceLastTransmission(bool in_idle) {
581 // If there wasn't a lot of action, maybe the computer was asleep, in which
582 // case, the log transmissions should have stopped. Here we start them up
583 // again.
[email protected]cac78842008-11-27 01:02:20584 if (!in_idle && idle_since_last_transmission_)
[email protected]7f7f1962011-04-20 15:58:16585 StartSchedulerIfNecessary();
[email protected]cac78842008-11-27 01:02:20586 idle_since_last_transmission_ = in_idle;
initial.commit09911bf2008-07-26 23:55:29587}
588
initial.commit09911bf2008-07-26 23:55:29589void MetricsService::RecordStartOfSessionEnd() {
[email protected]466f3c12011-03-23 21:20:38590 LogCleanShutdown();
initial.commit09911bf2008-07-26 23:55:29591 RecordBooleanPrefValue(prefs::kStabilitySessionEndCompleted, false);
592}
593
594void MetricsService::RecordCompletedSessionEnd() {
[email protected]466f3c12011-03-23 21:20:38595 LogCleanShutdown();
initial.commit09911bf2008-07-26 23:55:29596 RecordBooleanPrefValue(prefs::kStabilitySessionEndCompleted, true);
597}
598
[email protected]7f7f1962011-04-20 15:58:16599void MetricsService::RecordBreakpadRegistration(bool success) {
[email protected]68475e602008-08-22 03:21:15600 if (!success)
[email protected]e73c01972008-08-13 00:18:24601 IncrementPrefValue(prefs::kStabilityBreakpadRegistrationFail);
602 else
603 IncrementPrefValue(prefs::kStabilityBreakpadRegistrationSuccess);
604}
605
606void MetricsService::RecordBreakpadHasDebugger(bool has_debugger) {
607 if (!has_debugger)
608 IncrementPrefValue(prefs::kStabilityDebuggerNotPresent);
609 else
[email protected]68475e602008-08-22 03:21:15610 IncrementPrefValue(prefs::kStabilityDebuggerPresent);
[email protected]e73c01972008-08-13 00:18:24611}
612
initial.commit09911bf2008-07-26 23:55:29613//------------------------------------------------------------------------------
614// private methods
615//------------------------------------------------------------------------------
616
617
618//------------------------------------------------------------------------------
619// Initialization methods
620
621void MetricsService::InitializeMetricsState() {
[email protected]79bf0b72009-04-27 21:30:55622#if defined(OS_POSIX)
623 server_url_ = L"https://clients4.google.com/firefox/metrics/collect";
[email protected]d67d1052011-06-09 05:11:41624 // TODO(rtenneti): Return the network stats server name.
625 network_stats_server_ = "";
[email protected]79bf0b72009-04-27 21:30:55626#else
627 BrowserDistribution* dist = BrowserDistribution::GetDistribution();
628 server_url_ = dist->GetStatsServerURL();
[email protected]d67d1052011-06-09 05:11:41629 network_stats_server_ = dist->GetNetworkStatsServer();
[email protected]79bf0b72009-04-27 21:30:55630#endif
631
initial.commit09911bf2008-07-26 23:55:29632 PrefService* pref = g_browser_process->local_state();
633 DCHECK(pref);
634
[email protected]225c50842010-01-19 21:19:13635 if ((pref->GetInt64(prefs::kStabilityStatsBuildTime)
636 != MetricsLog::GetBuildTime()) ||
[email protected]ddd231e2010-06-29 20:35:19637 (pref->GetString(prefs::kStabilityStatsVersion)
[email protected]225c50842010-01-19 21:19:13638 != MetricsLog::GetVersionString())) {
[email protected]541f77922009-02-23 21:14:38639 // This is a new version, so we don't want to confuse the stats about the
640 // old version with info that we upload.
641 DiscardOldStabilityStats(pref);
642 pref->SetString(prefs::kStabilityStatsVersion,
[email protected]ddd231e2010-06-29 20:35:19643 MetricsLog::GetVersionString());
[email protected]225c50842010-01-19 21:19:13644 pref->SetInt64(prefs::kStabilityStatsBuildTime,
645 MetricsLog::GetBuildTime());
[email protected]541f77922009-02-23 21:14:38646 }
647
initial.commit09911bf2008-07-26 23:55:29648 // Update session ID
649 session_id_ = pref->GetInteger(prefs::kMetricsSessionID);
650 ++session_id_;
651 pref->SetInteger(prefs::kMetricsSessionID, session_id_);
652
initial.commit09911bf2008-07-26 23:55:29653 // Stability bookkeeping
[email protected]e73c01972008-08-13 00:18:24654 IncrementPrefValue(prefs::kStabilityLaunchCount);
initial.commit09911bf2008-07-26 23:55:29655
[email protected]e73c01972008-08-13 00:18:24656 if (!pref->GetBoolean(prefs::kStabilityExitedCleanly)) {
657 IncrementPrefValue(prefs::kStabilityCrashCount);
[email protected]c0c55e92011-09-10 18:47:30658 // Reset flag, and wait until we call LogNeedForCleanShutdown() before
659 // monitoring.
660 pref->SetBoolean(prefs::kStabilityExitedCleanly, true);
initial.commit09911bf2008-07-26 23:55:29661 }
[email protected]e73c01972008-08-13 00:18:24662
[email protected]e73c01972008-08-13 00:18:24663 if (!pref->GetBoolean(prefs::kStabilitySessionEndCompleted)) {
664 IncrementPrefValue(prefs::kStabilityIncompleteSessionEndCount);
[email protected]c9abf242009-07-18 06:00:38665 // This is marked false when we get a WM_ENDSESSION.
666 pref->SetBoolean(prefs::kStabilitySessionEndCompleted, true);
initial.commit09911bf2008-07-26 23:55:29667 }
initial.commit09911bf2008-07-26 23:55:29668
[email protected]9165f742010-03-10 22:55:01669 // Initialize uptime counters.
670 int64 startup_uptime = MetricsLog::GetIncrementalUptime(pref);
[email protected]ae393ec702010-06-27 16:23:14671 DCHECK_EQ(0, startup_uptime);
[email protected]9165f742010-03-10 22:55:01672 // For backwards compatibility, leave this intact in case Omaha is checking
673 // them. prefs::kStabilityLastTimestampSec may also be useless now.
674 // TODO(jar): Delete these if they have no uses.
[email protected]0bb1a622009-03-04 03:22:32675 pref->SetInt64(prefs::kStabilityLaunchTimeSec, Time::Now().ToTimeT());
676
677 // Bookkeeping for the uninstall metrics.
678 IncrementLongPrefsValue(prefs::kUninstallLaunchCount);
initial.commit09911bf2008-07-26 23:55:29679
680 // Save profile metrics.
681 PrefService* prefs = g_browser_process->local_state();
682 if (prefs) {
683 // Remove the current dictionary and store it for use when sending data to
684 // server. By removing the value we prune potentially dead profiles
685 // (and keys). All valid values are added back once services startup.
686 const DictionaryValue* profile_dictionary =
687 prefs->GetDictionary(prefs::kProfileMetrics);
688 if (profile_dictionary) {
689 // Do a deep copy of profile_dictionary since ClearPref will delete it.
690 profile_dictionary_.reset(static_cast<DictionaryValue*>(
691 profile_dictionary->DeepCopy()));
692 prefs->ClearPref(prefs::kProfileMetrics);
693 }
694 }
695
[email protected]92745242009-06-12 16:52:21696 // Get stats on use of command line.
697 const CommandLine* command_line(CommandLine::ForCurrentProcess());
698 size_t common_commands = 0;
699 if (command_line->HasSwitch(switches::kUserDataDir)) {
700 ++common_commands;
701 UMA_HISTOGRAM_COUNTS_100("Chrome.CommandLineDatDirCount", 1);
702 }
703
704 if (command_line->HasSwitch(switches::kApp)) {
705 ++common_commands;
706 UMA_HISTOGRAM_COUNTS_100("Chrome.CommandLineAppModeCount", 1);
707 }
708
[email protected]62b4e522011-07-13 21:46:32709 size_t switch_count = command_line->GetSwitches().size();
710 UMA_HISTOGRAM_COUNTS_100("Chrome.CommandLineFlagCount", switch_count);
[email protected]92745242009-06-12 16:52:21711 UMA_HISTOGRAM_COUNTS_100("Chrome.CommandLineUncommonFlagCount",
[email protected]62b4e522011-07-13 21:46:32712 switch_count - common_commands);
[email protected]92745242009-06-12 16:52:21713
initial.commit09911bf2008-07-26 23:55:29714 // Kick off the process of saving the state (so the uptime numbers keep
715 // getting updated) every n minutes.
716 ScheduleNextStateSave();
717}
718
[email protected]d33e7cc2011-09-23 01:43:56719void MetricsService::InitTaskGetHardwareClass(
720 base::MessageLoopProxy* target_loop) {
721 DCHECK(state_ == INIT_TASK_SCHEDULED);
722 DCHECK(BrowserThread::CurrentlyOn(BrowserThread::FILE));
723
724 std::string hardware_class;
725#if defined(OS_CHROMEOS)
726 chromeos::system::StatisticsProvider::GetInstance()->GetMachineStatistic(
727 "hardware_class", &hardware_class);
728#endif // OS_CHROMEOS
729
730 target_loop->PostTask(FROM_HERE,
731 base::Bind(&MetricsService::OnInitTaskGotHardwareClass,
732 base::Unretained(this), hardware_class));
733}
734
735void MetricsService::OnInitTaskGotHardwareClass(
736 const std::string& hardware_class) {
[email protected]85ed9d42010-06-08 22:37:44737 DCHECK(state_ == INIT_TASK_SCHEDULED);
738 hardware_class_ = hardware_class;
[email protected]d33e7cc2011-09-23 01:43:56739
740 // Start the next part of the init task: loading plugin information.
741 PluginService::GetInstance()->GetPlugins(
742 base::Bind(&MetricsService::OnInitTaskGotPluginInfo,
743 base::Unretained(this)));
744}
745
746void MetricsService::OnInitTaskGotPluginInfo(
747 const std::vector<webkit::WebPluginInfo>& plugins) {
748 DCHECK(state_ == INIT_TASK_SCHEDULED);
[email protected]35fa6a22009-08-15 00:04:01749 plugins_ = plugins;
[email protected]d33e7cc2011-09-23 01:43:56750
[email protected]d67d1052011-06-09 05:11:41751 io_thread_ = g_browser_process->io_thread();
[email protected]85ed9d42010-06-08 22:37:44752 if (state_ == INIT_TASK_SCHEDULED)
753 state_ = INIT_TASK_DONE;
initial.commit09911bf2008-07-26 23:55:29754}
755
756std::string MetricsService::GenerateClientID() {
[email protected]3469e7e2010-10-14 20:34:59757 return guid::GenerateGUID();
initial.commit09911bf2008-07-26 23:55:29758}
759
initial.commit09911bf2008-07-26 23:55:29760//------------------------------------------------------------------------------
761// State save methods
762
763void MetricsService::ScheduleNextStateSave() {
764 state_saver_factory_.RevokeAll();
765
766 MessageLoop::current()->PostDelayedTask(FROM_HERE,
767 state_saver_factory_.NewRunnableMethod(&MetricsService::SaveLocalState),
768 kSaveStateInterval * 1000);
769}
770
771void MetricsService::SaveLocalState() {
772 PrefService* pref = g_browser_process->local_state();
773 if (!pref) {
[email protected]a063c102010-07-22 22:20:19774 NOTREACHED();
initial.commit09911bf2008-07-26 23:55:29775 return;
776 }
777
778 RecordCurrentState(pref);
[email protected]6faa0e0d2009-04-28 06:50:36779 pref->ScheduleSavePersistentPrefs();
initial.commit09911bf2008-07-26 23:55:29780
[email protected]281d2882009-01-20 20:32:42781 // TODO(jar): Does this run down the batteries????
initial.commit09911bf2008-07-26 23:55:29782 ScheduleNextStateSave();
783}
784
785
786//------------------------------------------------------------------------------
787// Recording control methods
788
789void MetricsService::StartRecording() {
[email protected]cac267c2011-09-29 15:18:10790 if (log_manager_.current_log())
initial.commit09911bf2008-07-26 23:55:29791 return;
792
[email protected]cac267c2011-09-29 15:18:10793 log_manager_.BeginLoggingWithLog(new MetricsLog(client_id_, session_id_));
initial.commit09911bf2008-07-26 23:55:29794 if (state_ == INITIALIZED) {
795 // We only need to schedule that run once.
[email protected]85ed9d42010-06-08 22:37:44796 state_ = INIT_TASK_SCHEDULED;
initial.commit09911bf2008-07-26 23:55:29797
[email protected]85ed9d42010-06-08 22:37:44798 // Schedules a task on the file thread for execution of slower
799 // initialization steps (such as plugin list generation) necessary
800 // for sending the initial log. This avoids blocking the main UI
801 // thread.
[email protected]a65a33a2011-10-01 16:46:17802 g_browser_process->file_thread()->message_loop()->PostDelayedTask(FROM_HERE,
[email protected]d33e7cc2011-09-23 01:43:56803 base::Bind(&MetricsService::InitTaskGetHardwareClass,
804 base::Unretained(this),
805 MessageLoop::current()->message_loop_proxy()),
[email protected]7f7f1962011-04-20 15:58:16806 kInitializationDelaySeconds * 1000);
initial.commit09911bf2008-07-26 23:55:29807 }
808}
809
[email protected]024b5cd2011-05-27 03:29:38810void MetricsService::StopRecording() {
[email protected]cac267c2011-09-29 15:18:10811 if (!log_manager_.current_log())
initial.commit09911bf2008-07-26 23:55:29812 return;
813
[email protected]68475e602008-08-22 03:21:15814 // TODO(jar): Integrate bounds on log recording more consistently, so that we
815 // can stop recording logs that are too big much sooner.
[email protected]cac267c2011-09-29 15:18:10816 if (log_manager_.current_log()->num_events() > kEventLimit) {
[email protected]553dba62009-02-24 19:08:23817 UMA_HISTOGRAM_COUNTS("UMA.Discarded Log Events",
[email protected]cac267c2011-09-29 15:18:10818 log_manager_.current_log()->num_events());
819 log_manager_.DiscardCurrentLog();
[email protected]68475e602008-08-22 03:21:15820 StartRecording(); // Start trivial log to hold our histograms.
821 }
822
[email protected]cac267c2011-09-29 15:18:10823 // Adds to ongoing logs.
824 log_manager_.current_log()->set_hardware_class(hardware_class_);
[email protected]accdfa62011-09-20 01:56:52825
[email protected]0b33f80b2008-12-17 21:34:36826 // Put incremental data (histogram deltas, and realtime stats deltas) at the
[email protected]147bbc0b2009-01-06 19:37:40827 // end of all log transmissions (initial log handles this separately).
[email protected]024b5cd2011-05-27 03:29:38828 // RecordIncrementalStabilityElements only exists on the derived
829 // MetricsLog class.
[email protected]cac267c2011-09-29 15:18:10830 MetricsLog* current_log = log_manager_.current_log()->AsMetricsLog();
[email protected]024b5cd2011-05-27 03:29:38831 DCHECK(current_log);
832 current_log->RecordIncrementalStabilityElements();
833 RecordCurrentHistograms();
initial.commit09911bf2008-07-26 23:55:29834
[email protected]cac267c2011-09-29 15:18:10835 log_manager_.StageCurrentLogForUpload();
initial.commit09911bf2008-07-26 23:55:29836}
837
[email protected]cac267c2011-09-29 15:18:10838void MetricsService::PushPendingLogsToPersistentStorage() {
initial.commit09911bf2008-07-26 23:55:29839 if (state_ < INITIAL_LOG_READY)
[email protected]28ab7f92009-01-06 21:39:04840 return; // We didn't and still don't have time to get plugin list etc.
initial.commit09911bf2008-07-26 23:55:29841
[email protected]cac267c2011-09-29 15:18:10842 if (log_manager_.has_staged_log()) {
initial.commit09911bf2008-07-26 23:55:29843 if (state_ == INITIAL_LOG_READY) {
844 // We may race here, and send second copy of initial log later.
[email protected]cac267c2011-09-29 15:18:10845 log_manager_.StoreStagedLogAsUnsent(MetricsLogManager::INITIAL_LOG);
846 state_ = SENDING_OLD_LOGS;
initial.commit09911bf2008-07-26 23:55:29847 } else {
[email protected]281d2882009-01-20 20:32:42848 // TODO(jar): Verify correctness in other states, including sending unsent
[email protected]541f77922009-02-23 21:14:38849 // initial logs.
[email protected]cac267c2011-09-29 15:18:10850 log_manager_.StoreStagedLogAsUnsent(MetricsLogManager::ONGOING_LOG);
initial.commit09911bf2008-07-26 23:55:29851 }
initial.commit09911bf2008-07-26 23:55:29852 }
[email protected]cac267c2011-09-29 15:18:10853 DCHECK(!log_manager_.has_staged_log());
[email protected]024b5cd2011-05-27 03:29:38854 StopRecording();
[email protected]cac267c2011-09-29 15:18:10855 log_manager_.StoreStagedLogAsUnsent(MetricsLogManager::ONGOING_LOG);
initial.commit09911bf2008-07-26 23:55:29856 StoreUnsentLogs();
857}
858
initial.commit09911bf2008-07-26 23:55:29859//------------------------------------------------------------------------------
860// Transmission of logs methods
861
[email protected]7f7f1962011-04-20 15:58:16862void MetricsService::StartSchedulerIfNecessary() {
863 if (reporting_active() && recording_active())
864 scheduler_->Start();
initial.commit09911bf2008-07-26 23:55:29865}
866
[email protected]7f7f1962011-04-20 15:58:16867void MetricsService::StartScheduledUpload() {
868 // If reporting has been turned off, the scheduler doesn't need to run.
869 if (!reporting_active() || !recording_active()) {
870 scheduler_->Stop();
871 scheduler_->UploadCancelled();
872 return;
873 }
874
875 DCHECK(!waiting_for_asynchronus_reporting_step_);
876 waiting_for_asynchronus_reporting_step_ = true;
877
[email protected]84c988a2011-04-19 17:56:33878 Task* task = log_sender_factory_.
879 NewRunnableMethod(&MetricsService::OnMemoryDetailCollectionDone);
880
881 scoped_refptr<MetricsMemoryDetails> details(new MetricsMemoryDetails(task));
882 details->StartFetch();
883
884 // Collect WebCore cache information to put into a histogram.
885 for (RenderProcessHost::iterator i(RenderProcessHost::AllHostsIterator());
886 !i.IsAtEnd(); i.Advance())
[email protected]2ccf45c2011-08-19 23:35:50887 i.GetCurrentValue()->Send(new ChromeViewMsg_GetCacheResourceStats());
[email protected]84c988a2011-04-19 17:56:33888}
889
890void MetricsService::OnMemoryDetailCollectionDone() {
[email protected]c9a3ef82009-05-28 22:02:46891 DCHECK(IsSingleThreaded());
[email protected]7f7f1962011-04-20 15:58:16892 // This function should only be called as the callback from an ansynchronous
893 // step.
894 DCHECK(waiting_for_asynchronus_reporting_step_);
[email protected]c9a3ef82009-05-28 22:02:46895
[email protected]7f7f1962011-04-20 15:58:16896 // Right before the UMA transmission gets started, there's one more thing we'd
897 // like to record: the histogram of memory usage, so we spawn a task to
898 // collect the memory details and when that task is finished, it will call
899 // OnMemoryDetailCollectionDone, which will call HistogramSynchronization to
900 // collect histograms from all renderers and then we will call
901 // OnHistogramSynchronizationDone to continue processing.
[email protected]c9a3ef82009-05-28 22:02:46902
903 // Create a callback_task for OnHistogramSynchronizationDone.
904 Task* callback_task = log_sender_factory_.NewRunnableMethod(
905 &MetricsService::OnHistogramSynchronizationDone);
906
907 // Set up the callback to task to call after we receive histograms from all
908 // renderer processes. Wait time specifies how long to wait before absolutely
909 // calling us back on the task.
910 HistogramSynchronizer::FetchRendererHistogramsAsynchronously(
911 MessageLoop::current(), callback_task,
912 kMaxHistogramGatheringWaitDuration);
913}
914
915void MetricsService::OnHistogramSynchronizationDone() {
initial.commit09911bf2008-07-26 23:55:29916 DCHECK(IsSingleThreaded());
917
[email protected]7f7f1962011-04-20 15:58:16918 // If somehow there is a fetch in progress, we return and hope things work
919 // out. The scheduler isn't informed since if this happens, the scheduler
920 // will get a response from the upload.
initial.commit09911bf2008-07-26 23:55:29921 DCHECK(!current_fetch_.get());
[email protected]7f7f1962011-04-20 15:58:16922 if (current_fetch_.get())
923 return;
924
925 // This function should only be called as the callback from an ansynchronous
926 // step.
927 DCHECK(waiting_for_asynchronus_reporting_step_);
928 waiting_for_asynchronus_reporting_step_ = false;
initial.commit09911bf2008-07-26 23:55:29929
[email protected]d01b8732008-10-16 02:18:07930 // If we're getting no notifications, then the log won't have much in it, and
931 // it's possible the computer is about to go to sleep, so don't upload and
[email protected]7f7f1962011-04-20 15:58:16932 // stop the scheduler.
933 // Similarly, if logs should no longer be uploaded, stop here.
934 if (idle_since_last_transmission_ ||
935 !recording_active() || !reporting_active()) {
936 scheduler_->Stop();
937 scheduler_->UploadCancelled();
[email protected]d01b8732008-10-16 02:18:07938 return;
939 }
940
[email protected]cac267c2011-09-29 15:18:10941 MakeStagedLog();
initial.commit09911bf2008-07-26 23:55:29942
[email protected]cac267c2011-09-29 15:18:10943 // MakeStagedLog should have prepared log text; if it didn't, skip this
944 // upload and hope things work out next time.
945 if (log_manager_.staged_log_text().empty()) {
[email protected]7f7f1962011-04-20 15:58:16946 scheduler_->UploadCancelled();
[email protected]d01b8732008-10-16 02:18:07947 return;
948 }
initial.commit09911bf2008-07-26 23:55:29949
[email protected]cac267c2011-09-29 15:18:10950 PrepareFetchWithStagedLog();
[email protected]d01b8732008-10-16 02:18:07951
952 if (!current_fetch_.get()) {
953 // Compression failed, and log discarded :-/.
[email protected]cac267c2011-09-29 15:18:10954 log_manager_.DiscardStagedLog();
[email protected]7f7f1962011-04-20 15:58:16955 scheduler_->UploadCancelled();
[email protected]d01b8732008-10-16 02:18:07956 // TODO(jar): If compression failed, we should have created a tiny log and
957 // compressed that, so that we can signal that we're losing logs.
958 return;
959 }
960
[email protected]7f7f1962011-04-20 15:58:16961 DCHECK(!waiting_for_asynchronus_reporting_step_);
[email protected]d01b8732008-10-16 02:18:07962
[email protected]7f7f1962011-04-20 15:58:16963 waiting_for_asynchronus_reporting_step_ = true;
[email protected]d01b8732008-10-16 02:18:07964 current_fetch_->Start();
965
966 HandleIdleSinceLastTransmission(true);
967}
968
969
[email protected]cac267c2011-09-29 15:18:10970void MetricsService::MakeStagedLog() {
971 if (log_manager_.has_staged_log())
[email protected]d01b8732008-10-16 02:18:07972 return;
973
974 switch (state_) {
975 case INITIALIZED:
[email protected]85ed9d42010-06-08 22:37:44976 case INIT_TASK_SCHEDULED: // We should be further along by now.
[email protected]d01b8732008-10-16 02:18:07977 DCHECK(false);
978 return;
979
[email protected]85ed9d42010-06-08 22:37:44980 case INIT_TASK_DONE:
[email protected]d01b8732008-10-16 02:18:07981 // We need to wait for the initial log to be ready before sending
982 // anything, because the server will tell us whether it wants to hear
983 // from us.
984 PrepareInitialLog();
[email protected]85ed9d42010-06-08 22:37:44985 DCHECK(state_ == INIT_TASK_DONE);
[email protected]cac267c2011-09-29 15:18:10986 log_manager_.LoadPersistedUnsentLogs();
[email protected]d01b8732008-10-16 02:18:07987 state_ = INITIAL_LOG_READY;
988 break;
989
[email protected]d01b8732008-10-16 02:18:07990 case SENDING_OLD_LOGS:
[email protected]cac267c2011-09-29 15:18:10991 if (log_manager_.has_unsent_logs()) {
992 log_manager_.StageNextStoredLogForUpload();
[email protected]d01b8732008-10-16 02:18:07993 break;
994 }
995 state_ = SENDING_CURRENT_LOGS;
996 // Fall through.
997
998 case SENDING_CURRENT_LOGS:
[email protected]024b5cd2011-05-27 03:29:38999 StopRecording();
[email protected]d01b8732008-10-16 02:18:071000 StartRecording();
1001 break;
1002
1003 default:
[email protected]a063c102010-07-22 22:20:191004 NOTREACHED();
[email protected]d01b8732008-10-16 02:18:071005 return;
1006 }
1007
[email protected]cac267c2011-09-29 15:18:101008 DCHECK(log_manager_.has_staged_log());
[email protected]d01b8732008-10-16 02:18:071009}
1010
initial.commit09911bf2008-07-26 23:55:291011void MetricsService::PrepareInitialLog() {
[email protected]85ed9d42010-06-08 22:37:441012 DCHECK(state_ == INIT_TASK_DONE);
initial.commit09911bf2008-07-26 23:55:291013
1014 MetricsLog* log = new MetricsLog(client_id_, session_id_);
[email protected]85ed9d42010-06-08 22:37:441015 log->set_hardware_class(hardware_class_); // Adds to initial log.
[email protected]35fa6a22009-08-15 00:04:011016 log->RecordEnvironment(plugins_, profile_dictionary_.get());
initial.commit09911bf2008-07-26 23:55:291017
[email protected]cac267c2011-09-29 15:18:101018 // Histograms only get written to the current log, so make the new log current
1019 // before writing them.
1020 log_manager_.PauseCurrentLog();
1021 log_manager_.BeginLoggingWithLog(log);
1022 RecordCurrentHistograms();
initial.commit09911bf2008-07-26 23:55:291023
[email protected]cac267c2011-09-29 15:18:101024 DCHECK(!log_manager_.has_staged_log());
1025 log_manager_.StageCurrentLogForUpload();
1026 log_manager_.ResumePausedLog();
initial.commit09911bf2008-07-26 23:55:291027}
1028
1029void MetricsService::StoreUnsentLogs() {
1030 if (state_ < INITIAL_LOG_READY)
1031 return; // We never Recalled the prior unsent logs.
1032
[email protected]cac267c2011-09-29 15:18:101033 log_manager_.PersistUnsentLogs();
initial.commit09911bf2008-07-26 23:55:291034}
1035
[email protected]cac267c2011-09-29 15:18:101036void MetricsService::PrepareFetchWithStagedLog() {
1037 DCHECK(!log_manager_.staged_log_text().empty());
initial.commit09911bf2008-07-26 23:55:291038 DCHECK(!current_fetch_.get());
[email protected]cac78842008-11-27 01:02:201039
[email protected]79bf0b72009-04-27 21:30:551040 current_fetch_.reset(new URLFetcher(GURL(WideToUTF16(server_url_)),
1041 URLFetcher::POST,
initial.commit09911bf2008-07-26 23:55:291042 this));
[email protected]9abfa192011-07-20 15:48:531043 current_fetch_->set_request_context(
[email protected]8ef3d8052011-07-22 09:03:001044 g_browser_process->system_request_context());
[email protected]cac267c2011-09-29 15:18:101045 current_fetch_->set_upload_data(kMetricsType,
1046 log_manager_.staged_log_text());
initial.commit09911bf2008-07-26 23:55:291047}
1048
[email protected]f90bf0d92011-01-13 02:12:441049static const char* StatusToString(const net::URLRequestStatus& status) {
initial.commit09911bf2008-07-26 23:55:291050 switch (status.status()) {
[email protected]f90bf0d92011-01-13 02:12:441051 case net::URLRequestStatus::SUCCESS:
initial.commit09911bf2008-07-26 23:55:291052 return "SUCCESS";
1053
[email protected]f90bf0d92011-01-13 02:12:441054 case net::URLRequestStatus::IO_PENDING:
initial.commit09911bf2008-07-26 23:55:291055 return "IO_PENDING";
1056
[email protected]f90bf0d92011-01-13 02:12:441057 case net::URLRequestStatus::HANDLED_EXTERNALLY:
initial.commit09911bf2008-07-26 23:55:291058 return "HANDLED_EXTERNALLY";
1059
[email protected]f90bf0d92011-01-13 02:12:441060 case net::URLRequestStatus::CANCELED:
initial.commit09911bf2008-07-26 23:55:291061 return "CANCELED";
1062
[email protected]f90bf0d92011-01-13 02:12:441063 case net::URLRequestStatus::FAILED:
initial.commit09911bf2008-07-26 23:55:291064 return "FAILED";
1065
1066 default:
[email protected]a063c102010-07-22 22:20:191067 NOTREACHED();
initial.commit09911bf2008-07-26 23:55:291068 return "Unknown";
1069 }
1070}
1071
1072void MetricsService::OnURLFetchComplete(const URLFetcher* source,
1073 const GURL& url,
[email protected]f90bf0d92011-01-13 02:12:441074 const net::URLRequestStatus& status,
initial.commit09911bf2008-07-26 23:55:291075 int response_code,
[email protected]cb04f5e2011-05-06 01:10:001076 const net::ResponseCookies& cookies,
initial.commit09911bf2008-07-26 23:55:291077 const std::string& data) {
[email protected]7f7f1962011-04-20 15:58:161078 DCHECK(waiting_for_asynchronus_reporting_step_);
1079 waiting_for_asynchronus_reporting_step_ = false;
initial.commit09911bf2008-07-26 23:55:291080 DCHECK(current_fetch_.get());
1081 current_fetch_.reset(NULL); // We're not allowed to re-use it.
1082
1083 // Confirm send so that we can move on.
[email protected]666205032010-10-21 20:56:581084 VLOG(1) << "METRICS RESPONSE CODE: " << response_code
1085 << " status=" << StatusToString(status);
[email protected]252873ef2008-08-04 21:59:451086
[email protected]7f7f1962011-04-20 15:58:161087 bool upload_succeeded = response_code == 200;
1088
[email protected]0eb34fee2009-01-21 08:04:381089 // Provide boolean for error recovery (allow us to ignore response_code).
[email protected]dc6f4962009-02-13 01:25:501090 bool discard_log = false;
[email protected]0eb34fee2009-01-21 08:04:381091
[email protected]7f7f1962011-04-20 15:58:161092 if (!upload_succeeded &&
[email protected]cac267c2011-09-29 15:18:101093 (log_manager_.staged_log_text().length() >
[email protected]46f89e142010-07-19 08:00:421094 static_cast<size_t>(kUploadLogAvoidRetransmitSize))) {
[email protected]cac267c2011-09-29 15:18:101095 UMA_HISTOGRAM_COUNTS(
1096 "UMA.Large Rejected Log was Discarded",
1097 static_cast<int>(log_manager_.staged_log_text().length()));
[email protected]0eb34fee2009-01-21 08:04:381098 discard_log = true;
1099 } else if (response_code == 400) {
1100 // Bad syntax. Retransmission won't work.
[email protected]553dba62009-02-24 19:08:231101 UMA_HISTOGRAM_COUNTS("UMA.Unacceptable_Log_Discarded", state_);
[email protected]0eb34fee2009-01-21 08:04:381102 discard_log = true;
[email protected]68475e602008-08-22 03:21:151103 }
1104
[email protected]7f7f1962011-04-20 15:58:161105 if (!upload_succeeded && !discard_log) {
[email protected]666205032010-10-21 20:56:581106 VLOG(1) << "METRICS: transmission attempt returned a failure code: "
1107 << response_code << ". Verify network connectivity";
[email protected]7f7f1962011-04-20 15:58:161108 LogBadResponseCode();
[email protected]0eb34fee2009-01-21 08:04:381109 } else { // Successful receipt (or we are discarding log).
[email protected]666205032010-10-21 20:56:581110 VLOG(1) << "METRICS RESPONSE DATA: " << data;
initial.commit09911bf2008-07-26 23:55:291111 switch (state_) {
1112 case INITIAL_LOG_READY:
[email protected]cac267c2011-09-29 15:18:101113 state_ = SENDING_OLD_LOGS;
initial.commit09911bf2008-07-26 23:55:291114 break;
1115
initial.commit09911bf2008-07-26 23:55:291116 case SENDING_OLD_LOGS:
[email protected]d53e2232011-06-30 15:54:571117 // Store the updated list to disk now that the removed log is uploaded.
initial.commit09911bf2008-07-26 23:55:291118 StoreUnsentLogs();
1119 break;
1120
1121 case SENDING_CURRENT_LOGS:
1122 break;
1123
1124 default:
[email protected]a063c102010-07-22 22:20:191125 NOTREACHED();
initial.commit09911bf2008-07-26 23:55:291126 break;
1127 }
[email protected]d01b8732008-10-16 02:18:071128
[email protected]cac267c2011-09-29 15:18:101129 log_manager_.DiscardStagedLog();
[email protected]29be92552008-08-07 22:49:271130 // Since we sent a log, make sure our in-memory state is recorded to disk.
1131 PrefService* local_state = g_browser_process->local_state();
1132 DCHECK(local_state);
1133 if (local_state)
[email protected]6faa0e0d2009-04-28 06:50:361134 local_state->ScheduleSavePersistentPrefs();
[email protected]252873ef2008-08-04 21:59:451135
[email protected]cac267c2011-09-29 15:18:101136 if (log_manager_.has_unsent_logs())
initial.commit09911bf2008-07-26 23:55:291137 DCHECK(state_ < SENDING_CURRENT_LOGS);
initial.commit09911bf2008-07-26 23:55:291138 }
[email protected]252873ef2008-08-04 21:59:451139
[email protected]7f7f1962011-04-20 15:58:161140 // Error 400 indicates a problem with the log, not with the server, so
1141 // don't consider that a sign that the server is in trouble.
1142 bool server_is_healthy = upload_succeeded || response_code == 400;
1143
[email protected]cac267c2011-09-29 15:18:101144 scheduler_->UploadFinished(server_is_healthy,
1145 log_manager_.has_unsent_logs());
[email protected]d67d1052011-06-09 05:11:411146
1147 // Collect network stats if UMA upload succeeded.
1148 if (server_is_healthy && io_thread_)
1149 chrome_browser_net::CollectNetworkStats(network_stats_server_, io_thread_);
initial.commit09911bf2008-07-26 23:55:291150}
1151
[email protected]7f7f1962011-04-20 15:58:161152void MetricsService::LogBadResponseCode() {
[email protected]666205032010-10-21 20:56:581153 VLOG(1) << "Verify your metrics logs are formatted correctly. Verify server "
1154 "is active at " << server_url_;
[email protected]cac267c2011-09-29 15:18:101155 if (!log_manager_.has_staged_log()) {
[email protected]666205032010-10-21 20:56:581156 VLOG(1) << "METRICS: Recorder shutdown during log transmission.";
[email protected]252873ef2008-08-04 21:59:451157 } else {
[email protected]7f7f1962011-04-20 15:58:161158 VLOG(1) << "METRICS: transmission retry being scheduled for "
[email protected]cac267c2011-09-29 15:18:101159 << log_manager_.staged_log_text();
initial.commit09911bf2008-07-26 23:55:291160 }
initial.commit09911bf2008-07-26 23:55:291161}
1162
[email protected]432115822011-07-10 15:52:271163void MetricsService::LogWindowChange(int type,
initial.commit09911bf2008-07-26 23:55:291164 const NotificationSource& source,
1165 const NotificationDetails& details) {
[email protected]534e54b2008-08-13 15:40:091166 int controller_id = -1;
1167 uintptr_t window_or_tab = source.map_key();
initial.commit09911bf2008-07-26 23:55:291168 MetricsLog::WindowEventType window_type;
1169
1170 // Note: since we stop all logging when a single OTR session is active, it is
1171 // possible that we start getting notifications about a window that we don't
1172 // know about.
[email protected]534e54b2008-08-13 15:40:091173 if (window_map_.find(window_or_tab) == window_map_.end()) {
1174 controller_id = next_window_id_++;
1175 window_map_[window_or_tab] = controller_id;
initial.commit09911bf2008-07-26 23:55:291176 } else {
[email protected]534e54b2008-08-13 15:40:091177 controller_id = window_map_[window_or_tab];
initial.commit09911bf2008-07-26 23:55:291178 }
[email protected]92745242009-06-12 16:52:211179 DCHECK_NE(controller_id, -1);
initial.commit09911bf2008-07-26 23:55:291180
[email protected]432115822011-07-10 15:52:271181 switch (type) {
1182 case content::NOTIFICATION_TAB_PARENTED:
1183 case chrome::NOTIFICATION_BROWSER_OPENED:
initial.commit09911bf2008-07-26 23:55:291184 window_type = MetricsLog::WINDOW_CREATE;
1185 break;
1186
[email protected]432115822011-07-10 15:52:271187 case content::NOTIFICATION_TAB_CLOSING:
1188 case chrome::NOTIFICATION_BROWSER_CLOSED:
[email protected]534e54b2008-08-13 15:40:091189 window_map_.erase(window_map_.find(window_or_tab));
initial.commit09911bf2008-07-26 23:55:291190 window_type = MetricsLog::WINDOW_DESTROY;
1191 break;
1192
1193 default:
[email protected]a063c102010-07-22 22:20:191194 NOTREACHED();
[email protected]68d74f02009-02-13 01:36:501195 return;
initial.commit09911bf2008-07-26 23:55:291196 }
1197
[email protected]534e54b2008-08-13 15:40:091198 // TODO(brettw) we should have some kind of ID for the parent.
[email protected]cac267c2011-09-29 15:18:101199 log_manager_.current_log()->RecordWindowEvent(window_type, controller_id, 0);
initial.commit09911bf2008-07-26 23:55:291200}
1201
[email protected]432115822011-07-10 15:52:271202void MetricsService::LogLoadComplete(int type,
initial.commit09911bf2008-07-26 23:55:291203 const NotificationSource& source,
1204 const NotificationDetails& details) {
1205 if (details == NotificationService::NoDetails())
1206 return;
1207
[email protected]68475e602008-08-22 03:21:151208 // TODO(jar): There is a bug causing this to be called too many times, and
1209 // the log overflows. For now, we won't record these events.
[email protected]553dba62009-02-24 19:08:231210 UMA_HISTOGRAM_COUNTS("UMA.LogLoadComplete called", 1);
[email protected]68475e602008-08-22 03:21:151211 return;
1212
initial.commit09911bf2008-07-26 23:55:291213 const Details<LoadNotificationDetails> load_details(details);
[email protected]534e54b2008-08-13 15:40:091214 int controller_id = window_map_[details.map_key()];
[email protected]cac267c2011-09-29 15:18:101215 log_manager_.current_log()->RecordLoadEvent(controller_id,
1216 load_details->url(),
1217 load_details->origin(),
1218 load_details->session_index(),
1219 load_details->load_time());
initial.commit09911bf2008-07-26 23:55:291220}
1221
[email protected]57ecc4b2010-08-11 03:02:511222void MetricsService::IncrementPrefValue(const char* path) {
[email protected]e73c01972008-08-13 00:18:241223 PrefService* pref = g_browser_process->local_state();
1224 DCHECK(pref);
1225 int value = pref->GetInteger(path);
1226 pref->SetInteger(path, value + 1);
1227}
1228
[email protected]57ecc4b2010-08-11 03:02:511229void MetricsService::IncrementLongPrefsValue(const char* path) {
[email protected]0bb1a622009-03-04 03:22:321230 PrefService* pref = g_browser_process->local_state();
1231 DCHECK(pref);
1232 int64 value = pref->GetInt64(path);
[email protected]b42c5e42010-06-03 20:43:251233 pref->SetInt64(path, value + 1);
[email protected]0bb1a622009-03-04 03:22:321234}
1235
initial.commit09911bf2008-07-26 23:55:291236void MetricsService::LogLoadStarted() {
[email protected]dd8d12a2011-09-02 02:10:151237 HISTOGRAM_ENUMERATION("Chrome.UmaPageloadCounter", 1, 2);
[email protected]e73c01972008-08-13 00:18:241238 IncrementPrefValue(prefs::kStabilityPageLoadCount);
[email protected]0bb1a622009-03-04 03:22:321239 IncrementLongPrefsValue(prefs::kUninstallMetricsPageLoadCount);
[email protected]0b33f80b2008-12-17 21:34:361240 // We need to save the prefs, as page load count is a critical stat, and it
1241 // might be lost due to a crash :-(.
initial.commit09911bf2008-07-26 23:55:291242}
1243
initial.commit09911bf2008-07-26 23:55:291244void MetricsService::LogRendererCrash() {
[email protected]e73c01972008-08-13 00:18:241245 IncrementPrefValue(prefs::kStabilityRendererCrashCount);
initial.commit09911bf2008-07-26 23:55:291246}
1247
[email protected]1f085622009-12-04 05:33:451248void MetricsService::LogExtensionRendererCrash() {
1249 IncrementPrefValue(prefs::kStabilityExtensionRendererCrashCount);
1250}
1251
initial.commit09911bf2008-07-26 23:55:291252void MetricsService::LogRendererHang() {
[email protected]e73c01972008-08-13 00:18:241253 IncrementPrefValue(prefs::kStabilityRendererHangCount);
initial.commit09911bf2008-07-26 23:55:291254}
1255
[email protected]c0c55e92011-09-10 18:47:301256void MetricsService::LogNeedForCleanShutdown() {
1257 PrefService* pref = g_browser_process->local_state();
1258 pref->SetBoolean(prefs::kStabilityExitedCleanly, false);
1259 // Redundant setting to be sure we call for a clean shutdown.
1260 clean_shutdown_status_ = NEED_TO_SHUTDOWN;
1261}
1262
1263bool MetricsService::UmaMetricsProperlyShutdown() {
1264 CHECK(clean_shutdown_status_ == CLEANLY_SHUTDOWN ||
1265 clean_shutdown_status_ == NEED_TO_SHUTDOWN);
1266 return clean_shutdown_status_ == CLEANLY_SHUTDOWN;
1267}
1268
[email protected]67c4e952011-09-17 00:44:271269// For use in hack in LogCleanShutdown.
1270static void Signal(base::WaitableEvent* event) {
1271 event->Signal();
1272}
1273
[email protected]466f3c12011-03-23 21:20:381274void MetricsService::LogCleanShutdown() {
[email protected]acd55b32011-09-05 17:35:311275 // Redundant hack to write pref ASAP.
1276 PrefService* pref = g_browser_process->local_state();
1277 pref->SetBoolean(prefs::kStabilityExitedCleanly, true);
1278 pref->SavePersistentPrefs();
[email protected]67c4e952011-09-17 00:44:271279 // Hack: TBD: Remove this wait.
1280 // We are so concerned that the pref gets written, we are now willing to stall
1281 // the UI thread until we get assurance that a pref-writing task has
1282 // completed.
1283 base::WaitableEvent done_writing(false, false);
1284 BrowserThread::PostTask(BrowserThread::FILE, FROM_HERE,
1285 NewRunnableFunction(Signal, &done_writing));
1286 done_writing.TimedWait(base::TimeDelta::FromHours(1));
1287
[email protected]c0c55e92011-09-10 18:47:301288 // Redundant setting to assure that we always reset this value at shutdown
1289 // (and that we don't use some alternate path, and not call LogCleanShutdown).
1290 clean_shutdown_status_ = CLEANLY_SHUTDOWN;
[email protected]acd55b32011-09-05 17:35:311291
[email protected]466f3c12011-03-23 21:20:381292 RecordBooleanPrefValue(prefs::kStabilityExitedCleanly, true);
1293}
1294
[email protected]c1834a92011-01-21 18:21:031295#if defined(OS_CHROMEOS)
1296void MetricsService::LogChromeOSCrash(const std::string &crash_type) {
1297 if (crash_type == "user")
1298 IncrementPrefValue(prefs::kStabilityOtherUserCrashCount);
1299 else if (crash_type == "kernel")
1300 IncrementPrefValue(prefs::kStabilityKernelCrashCount);
1301 else if (crash_type == "uncleanshutdown")
1302 IncrementPrefValue(prefs::kStabilitySystemUncleanShutdownCount);
1303 else
1304 NOTREACHED() << "Unexpected Chrome OS crash type " << crash_type;
1305 // Wake up metrics logs sending if necessary now that new
1306 // log data is available.
1307 HandleIdleSinceLastTransmission(false);
1308}
1309#endif // OS_CHROMEOS
1310
[email protected]a27a9382009-02-11 23:55:101311void MetricsService::LogChildProcessChange(
[email protected]432115822011-07-10 15:52:271312 int type,
[email protected]a27a9382009-02-11 23:55:101313 const NotificationSource& source,
1314 const NotificationDetails& details) {
[email protected]0d84c5d2009-10-09 01:10:421315 Details<ChildProcessInfo> child_details(details);
[email protected]68b9e72b2011-08-05 23:08:221316 const string16& child_name = child_details->name();
[email protected]0d84c5d2009-10-09 01:10:421317
[email protected]a27a9382009-02-11 23:55:101318 if (child_process_stats_buffer_.find(child_name) ==
1319 child_process_stats_buffer_.end()) {
[email protected]0d84c5d2009-10-09 01:10:421320 child_process_stats_buffer_[child_name] =
1321 ChildProcessStats(child_details->type());
initial.commit09911bf2008-07-26 23:55:291322 }
1323
[email protected]a27a9382009-02-11 23:55:101324 ChildProcessStats& stats = child_process_stats_buffer_[child_name];
[email protected]432115822011-07-10 15:52:271325 switch (type) {
1326 case content::NOTIFICATION_CHILD_PROCESS_HOST_CONNECTED:
initial.commit09911bf2008-07-26 23:55:291327 stats.process_launches++;
1328 break;
1329
[email protected]432115822011-07-10 15:52:271330 case content::NOTIFICATION_CHILD_INSTANCE_CREATED:
initial.commit09911bf2008-07-26 23:55:291331 stats.instances++;
1332 break;
1333
[email protected]432115822011-07-10 15:52:271334 case content::NOTIFICATION_CHILD_PROCESS_CRASHED:
initial.commit09911bf2008-07-26 23:55:291335 stats.process_crashes++;
[email protected]1f085622009-12-04 05:33:451336 // Exclude plugin crashes from the count below because we report them via
1337 // a separate UMA metric.
1338 if (child_details->type() != ChildProcessInfo::PLUGIN_PROCESS) {
1339 IncrementPrefValue(prefs::kStabilityChildProcessCrashCount);
1340 }
initial.commit09911bf2008-07-26 23:55:291341 break;
1342
1343 default:
[email protected]432115822011-07-10 15:52:271344 NOTREACHED() << "Unexpected notification type " << type;
initial.commit09911bf2008-07-26 23:55:291345 return;
1346 }
1347}
1348
1349// Recursively counts the number of bookmarks and folders in node.
[email protected]b3c33d462009-06-26 22:29:201350static void CountBookmarks(const BookmarkNode* node,
1351 int* bookmarks,
1352 int* folders) {
[email protected]0890e60e2011-06-27 14:55:211353 if (node->is_url())
initial.commit09911bf2008-07-26 23:55:291354 (*bookmarks)++;
1355 else
1356 (*folders)++;
[email protected]9c1a75a2011-03-10 02:38:121357 for (int i = 0; i < node->child_count(); ++i)
initial.commit09911bf2008-07-26 23:55:291358 CountBookmarks(node->GetChild(i), bookmarks, folders);
1359}
1360
[email protected]b3c33d462009-06-26 22:29:201361void MetricsService::LogBookmarks(const BookmarkNode* node,
[email protected]57ecc4b2010-08-11 03:02:511362 const char* num_bookmarks_key,
1363 const char* num_folders_key) {
initial.commit09911bf2008-07-26 23:55:291364 DCHECK(node);
1365 int num_bookmarks = 0;
1366 int num_folders = 0;
1367 CountBookmarks(node, &num_bookmarks, &num_folders);
1368 num_folders--; // Don't include the root folder in the count.
1369
1370 PrefService* pref = g_browser_process->local_state();
1371 DCHECK(pref);
1372 pref->SetInteger(num_bookmarks_key, num_bookmarks);
1373 pref->SetInteger(num_folders_key, num_folders);
1374}
1375
[email protected]d8e41ed2008-09-11 15:22:321376void MetricsService::LogBookmarks(BookmarkModel* model) {
initial.commit09911bf2008-07-26 23:55:291377 DCHECK(model);
[email protected]72bdcfe2011-07-22 17:21:581378 LogBookmarks(model->bookmark_bar_node(),
initial.commit09911bf2008-07-26 23:55:291379 prefs::kNumBookmarksOnBookmarkBar,
1380 prefs::kNumFoldersOnBookmarkBar);
1381 LogBookmarks(model->other_node(),
1382 prefs::kNumBookmarksInOtherBookmarkFolder,
1383 prefs::kNumFoldersInOtherBookmarkFolder);
1384 ScheduleNextStateSave();
1385}
1386
[email protected]8e5c89a2011-06-07 18:13:331387void MetricsService::LogKeywords(const TemplateURLService* url_model) {
initial.commit09911bf2008-07-26 23:55:291388 DCHECK(url_model);
1389
1390 PrefService* pref = g_browser_process->local_state();
1391 DCHECK(pref);
1392 pref->SetInteger(prefs::kNumKeywords,
1393 static_cast<int>(url_model->GetTemplateURLs().size()));
1394 ScheduleNextStateSave();
1395}
1396
1397void MetricsService::RecordPluginChanges(PrefService* pref) {
[email protected]f8628c22011-04-05 12:10:181398 ListPrefUpdate update(pref, prefs::kStabilityPluginStats);
1399 ListValue* plugins = update.Get();
initial.commit09911bf2008-07-26 23:55:291400 DCHECK(plugins);
1401
1402 for (ListValue::iterator value_iter = plugins->begin();
1403 value_iter != plugins->end(); ++value_iter) {
1404 if (!(*value_iter)->IsType(Value::TYPE_DICTIONARY)) {
[email protected]a063c102010-07-22 22:20:191405 NOTREACHED();
initial.commit09911bf2008-07-26 23:55:291406 continue;
1407 }
1408
1409 DictionaryValue* plugin_dict = static_cast<DictionaryValue*>(*value_iter);
[email protected]57ecc4b2010-08-11 03:02:511410 std::string plugin_name;
[email protected]8e50b602009-03-03 22:59:431411 plugin_dict->GetString(prefs::kStabilityPluginName, &plugin_name);
[email protected]6470ee8f2009-03-03 20:46:401412 if (plugin_name.empty()) {
[email protected]a063c102010-07-22 22:20:191413 NOTREACHED();
initial.commit09911bf2008-07-26 23:55:291414 continue;
1415 }
1416
[email protected]57ecc4b2010-08-11 03:02:511417 // TODO(viettrungluu): remove conversions
[email protected]68b9e72b2011-08-05 23:08:221418 string16 name16 = UTF8ToUTF16(plugin_name);
1419 if (child_process_stats_buffer_.find(name16) ==
1420 child_process_stats_buffer_.end()) {
initial.commit09911bf2008-07-26 23:55:291421 continue;
[email protected]68b9e72b2011-08-05 23:08:221422 }
initial.commit09911bf2008-07-26 23:55:291423
[email protected]68b9e72b2011-08-05 23:08:221424 ChildProcessStats stats = child_process_stats_buffer_[name16];
initial.commit09911bf2008-07-26 23:55:291425 if (stats.process_launches) {
1426 int launches = 0;
[email protected]8e50b602009-03-03 22:59:431427 plugin_dict->GetInteger(prefs::kStabilityPluginLaunches, &launches);
initial.commit09911bf2008-07-26 23:55:291428 launches += stats.process_launches;
[email protected]8e50b602009-03-03 22:59:431429 plugin_dict->SetInteger(prefs::kStabilityPluginLaunches, launches);
initial.commit09911bf2008-07-26 23:55:291430 }
1431 if (stats.process_crashes) {
1432 int crashes = 0;
[email protected]8e50b602009-03-03 22:59:431433 plugin_dict->GetInteger(prefs::kStabilityPluginCrashes, &crashes);
initial.commit09911bf2008-07-26 23:55:291434 crashes += stats.process_crashes;
[email protected]8e50b602009-03-03 22:59:431435 plugin_dict->SetInteger(prefs::kStabilityPluginCrashes, crashes);
initial.commit09911bf2008-07-26 23:55:291436 }
1437 if (stats.instances) {
1438 int instances = 0;
[email protected]8e50b602009-03-03 22:59:431439 plugin_dict->GetInteger(prefs::kStabilityPluginInstances, &instances);
initial.commit09911bf2008-07-26 23:55:291440 instances += stats.instances;
[email protected]8e50b602009-03-03 22:59:431441 plugin_dict->SetInteger(prefs::kStabilityPluginInstances, instances);
initial.commit09911bf2008-07-26 23:55:291442 }
1443
[email protected]68b9e72b2011-08-05 23:08:221444 child_process_stats_buffer_.erase(name16);
initial.commit09911bf2008-07-26 23:55:291445 }
1446
1447 // Now go through and add dictionaries for plugins that didn't already have
1448 // reports in Local State.
[email protected]68b9e72b2011-08-05 23:08:221449 for (std::map<string16, ChildProcessStats>::iterator cache_iter =
[email protected]a27a9382009-02-11 23:55:101450 child_process_stats_buffer_.begin();
1451 cache_iter != child_process_stats_buffer_.end(); ++cache_iter) {
[email protected]a27a9382009-02-11 23:55:101452 ChildProcessStats stats = cache_iter->second;
[email protected]0d84c5d2009-10-09 01:10:421453
1454 // Insert only plugins information into the plugins list.
1455 if (ChildProcessInfo::PLUGIN_PROCESS != stats.process_type)
1456 continue;
1457
[email protected]57ecc4b2010-08-11 03:02:511458 // TODO(viettrungluu): remove conversion
[email protected]68b9e72b2011-08-05 23:08:221459 std::string plugin_name = UTF16ToUTF8(cache_iter->first);
[email protected]0d84c5d2009-10-09 01:10:421460
initial.commit09911bf2008-07-26 23:55:291461 DictionaryValue* plugin_dict = new DictionaryValue;
1462
[email protected]8e50b602009-03-03 22:59:431463 plugin_dict->SetString(prefs::kStabilityPluginName, plugin_name);
1464 plugin_dict->SetInteger(prefs::kStabilityPluginLaunches,
initial.commit09911bf2008-07-26 23:55:291465 stats.process_launches);
[email protected]8e50b602009-03-03 22:59:431466 plugin_dict->SetInteger(prefs::kStabilityPluginCrashes,
initial.commit09911bf2008-07-26 23:55:291467 stats.process_crashes);
[email protected]8e50b602009-03-03 22:59:431468 plugin_dict->SetInteger(prefs::kStabilityPluginInstances,
initial.commit09911bf2008-07-26 23:55:291469 stats.instances);
1470 plugins->Append(plugin_dict);
1471 }
[email protected]a27a9382009-02-11 23:55:101472 child_process_stats_buffer_.clear();
initial.commit09911bf2008-07-26 23:55:291473}
1474
[email protected]432115822011-07-10 15:52:271475bool MetricsService::CanLogNotification(int type,
initial.commit09911bf2008-07-26 23:55:291476 const NotificationSource& source,
1477 const NotificationDetails& details) {
[email protected]2c910b72011-03-08 21:16:321478 // We simply don't log anything to UMA if there is a single incognito
initial.commit09911bf2008-07-26 23:55:291479 // session visible. The problem is that we always notify using the orginal
1480 // profile in order to simplify notification processing.
1481 return !BrowserList::IsOffTheRecordSessionActive();
1482}
1483
[email protected]57ecc4b2010-08-11 03:02:511484void MetricsService::RecordBooleanPrefValue(const char* path, bool value) {
initial.commit09911bf2008-07-26 23:55:291485 DCHECK(IsSingleThreaded());
1486
1487 PrefService* pref = g_browser_process->local_state();
1488 DCHECK(pref);
1489
1490 pref->SetBoolean(path, value);
1491 RecordCurrentState(pref);
1492}
1493
1494void MetricsService::RecordCurrentState(PrefService* pref) {
[email protected]0bb1a622009-03-04 03:22:321495 pref->SetInt64(prefs::kStabilityLastTimestampSec, Time::Now().ToTimeT());
initial.commit09911bf2008-07-26 23:55:291496
1497 RecordPluginChanges(pref);
1498}
1499
initial.commit09911bf2008-07-26 23:55:291500static bool IsSingleThreaded() {
[email protected]ce072a72010-12-31 20:02:161501 static base::PlatformThreadId thread_id = 0;
initial.commit09911bf2008-07-26 23:55:291502 if (!thread_id)
[email protected]ce072a72010-12-31 20:02:161503 thread_id = base::PlatformThread::CurrentId();
1504 return base::PlatformThread::CurrentId() == thread_id;
initial.commit09911bf2008-07-26 23:55:291505}
[email protected]5ccaa412009-11-13 22:00:161506
1507#if defined(OS_CHROMEOS)
[email protected]29cf16772010-04-21 15:13:471508void MetricsService::StartExternalMetrics() {
[email protected]5ccaa412009-11-13 22:00:161509 external_metrics_ = new chromeos::ExternalMetrics;
[email protected]29cf16772010-04-21 15:13:471510 external_metrics_->Start();
[email protected]5ccaa412009-11-13 22:00:161511}
1512#endif
[email protected]3819f2ee2011-08-21 09:44:381513
1514// static
1515bool MetricsServiceHelper::IsMetricsReportingEnabled() {
1516 bool result = false;
1517 const PrefService* local_state = g_browser_process->local_state();
1518 if (local_state) {
1519 const PrefService::Preference* uma_pref =
1520 local_state->FindPreference(prefs::kMetricsReportingEnabled);
1521 if (uma_pref) {
1522 bool success = uma_pref->GetValue()->GetAsBoolean(&result);
1523 DCHECK(success);
1524 }
1525 }
1526 return result;
1527}