blob: 37b79b7662d7904479ab777259731655dc182d8e [file] [log] [blame]
tfarina@chromium.org4d818fee2010-06-06 13:32:271// Copyright (c) 2010 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
5
6
7//------------------------------------------------------------------------------
8// Description of the life cycle of a instance of MetricsService.
9//
10// OVERVIEW
11//
12// A MetricsService instance is typically created at application startup. It
13// is the central controller for the acquisition of log data, and the automatic
14// transmission of that log data to an external server. Its major job is to
15// manage logs, grouping them for transmission, and transmitting them. As part
16// of its grouping, MS finalizes logs by including some just-in-time gathered
17// memory statistics, snapshotting the current stats of numerous histograms,
18// closing the logs, translating to XML text, and compressing the results for
19// transmission. Transmission includes submitting a compressed log as data in a
jar@chromium.org281d2882009-01-20 20:32:4220// URL-post, and retransmitting (or retaining at process termination) if the
initial.commit09911bf2008-07-26 23:55:2921// attempted transmission failed. Retention across process terminations is done
ziadh@chromium.org46f89e142010-07-19 08:00:4222// using the the PrefServices facilities. The retained logs (the ones that never
23// got transmitted) are compressed and base64-encoded before being persisted.
initial.commit09911bf2008-07-26 23:55:2924//
jar@chromium.org281d2882009-01-20 20:32:4225// Logs fall into one of two categories: "initial logs," and "ongoing logs."
26// There is at most one initial log sent for each complete run of the chromium
initial.commit09911bf2008-07-26 23:55:2927// product (from startup, to browser shutdown). An initial log is generally
28// transmitted some short time (1 minute?) after startup, and includes stats
29// such as recent crash info, the number and types of plugins, etc. The
jar@chromium.org281d2882009-01-20 20:32:4230// external server's response to the initial log conceptually tells this MS if
31// it should continue transmitting logs (during this session). The server
32// response can actually be much more detailed, and always includes (at a
33// minimum) how often additional ongoing logs should be sent.
initial.commit09911bf2008-07-26 23:55:2934//
35// After the above initial log, a series of ongoing logs will be transmitted.
36// The first ongoing log actually begins to accumulate information stating when
37// the MS was first constructed. Note that even though the initial log is
38// commonly sent a full minute after startup, the initial log does not include
39// much in the way of user stats. The most common interlog period (delay)
jar@google.com0b33f80b2008-12-17 21:34:3640// is 20 minutes. That time period starts when the first user action causes a
initial.commit09911bf2008-07-26 23:55:2941// logging event. This means that if there is no user action, there may be long
jar@chromium.org281d2882009-01-20 20:32:4242// periods without any (ongoing) log transmissions. Ongoing logs typically
initial.commit09911bf2008-07-26 23:55:2943// contain very detailed records of user activities (ex: opened tab, closed
44// tab, fetched URL, maximized window, etc.) In addition, just before an
45// ongoing log is closed out, a call is made to gather memory statistics. Those
46// memory statistics are deposited into a histogram, and the log finalization
47// code is then called. In the finalization, a call to a Histogram server
48// acquires a list of all local histograms that have been flagged for upload
jar@chromium.org281d2882009-01-20 20:32:4249// to the UMA server. The finalization also acquires a the most recent number
50// of page loads, along with any counts of renderer or plugin crashes.
initial.commit09911bf2008-07-26 23:55:2951//
52// When the browser shuts down, there will typically be a fragment of an ongoing
53// log that has not yet been transmitted. At shutdown time, that fragment
54// is closed (including snapshotting histograms), and converted to text. Note
55// that memory stats are not gathered during shutdown, as gathering *might* be
56// too time consuming. The textual representation of the fragment of the
57// ongoing log is then stored persistently as a string in the PrefServices, for
58// potential transmission during a future run of the product.
59//
60// There are two slightly abnormal shutdown conditions. There is a
61// "disconnected scenario," and a "really fast startup and shutdown" scenario.
62// In the "never connected" situation, the user has (during the running of the
63// process) never established an internet connection. As a result, attempts to
64// transmit the initial log have failed, and a lot(?) of data has accumulated in
65// the ongoing log (which didn't yet get closed, because there was never even a
66// contemplation of sending it). There is also a kindred "lost connection"
67// situation, where a loss of connection prevented an ongoing log from being
68// transmitted, and a (still open) log was stuck accumulating a lot(?) of data,
69// while the earlier log retried its transmission. In both of these
70// disconnected situations, two logs need to be, and are, persistently stored
71// for future transmission.
72//
73// The other unusual shutdown condition, termed "really fast startup and
74// shutdown," involves the deliberate user termination of the process before
75// the initial log is even formed or transmitted. In that situation, no logging
76// is done, but the historical crash statistics remain (unlogged) for inclusion
77// in a future run's initial log. (i.e., we don't lose crash stats).
78//
79// With the above overview, we can now describe the state machine's various
80// stats, based on the State enum specified in the state_ member. Those states
81// are:
82//
83// INITIALIZED, // Constructor was called.
zelidrag@chromium.org85ed9d42010-06-08 22:37:4484// INIT_TASK_SCHEDULED, // Waiting for deferred init tasks to complete.
85// INIT_TASK_DONE, // Waiting for timer to send initial log.
initial.commit09911bf2008-07-26 23:55:2986// INITIAL_LOG_READY, // Initial log generated, and waiting for reply.
87// SEND_OLD_INITIAL_LOGS, // Sending unsent logs from previous session.
88// SENDING_OLD_LOGS, // Sending unsent logs from previous session.
89// SENDING_CURRENT_LOGS, // Sending standard current logs as they accrue.
90//
91// In more detail, we have:
92//
93// INITIALIZED, // Constructor was called.
94// The MS has been constructed, but has taken no actions to compose the
95// initial log.
96//
zelidrag@chromium.org85ed9d42010-06-08 22:37:4497// INIT_TASK_SCHEDULED, // Waiting for deferred init tasks to complete.
initial.commit09911bf2008-07-26 23:55:2998// Typically about 30 seconds after startup, a task is sent to a second thread
zelidrag@chromium.org85ed9d42010-06-08 22:37:4499// (the file thread) to perform deferred (lower priority and slower)
100// initialization steps such as getting the list of plugins. That task will
101// (when complete) make an async callback (via a Task) to indicate the
102// completion.
initial.commit09911bf2008-07-26 23:55:29103//
zelidrag@chromium.org85ed9d42010-06-08 22:37:44104// INIT_TASK_DONE, // Waiting for timer to send initial log.
initial.commit09911bf2008-07-26 23:55:29105// The callback has arrived, and it is now possible for an initial log to be
106// created. This callback typically arrives back less than one second after
zelidrag@chromium.org85ed9d42010-06-08 22:37:44107// the deferred init task is dispatched.
initial.commit09911bf2008-07-26 23:55:29108//
109// INITIAL_LOG_READY, // Initial log generated, and waiting for reply.
110// This state is entered only after an initial log has been composed, and
111// prepared for transmission. It is also the case that any previously unsent
112// logs have been loaded into instance variables for possible transmission.
113//
114// SEND_OLD_INITIAL_LOGS, // Sending unsent logs from previous session.
115// This state indicates that the initial log for this session has been
116// successfully sent and it is now time to send any "initial logs" that were
117// saved from previous sessions. Most commonly, there are none, but all old
118// logs that were "initial logs" must be sent before this state is exited.
119//
120// SENDING_OLD_LOGS, // Sending unsent logs from previous session.
121// This state indicates that there are no more unsent initial logs, and now any
122// ongoing logs from previous sessions should be transmitted. All such logs
123// will be transmitted before exiting this state, and proceeding with ongoing
124// logs from the current session (see next state).
125//
126// SENDING_CURRENT_LOGS, // Sending standard current logs as they accrue.
jar@google.com0b33f80b2008-12-17 21:34:36127// Current logs are being accumulated. Typically every 20 minutes a log is
initial.commit09911bf2008-07-26 23:55:29128// closed and finalized for transmission, at the same time as a new log is
129// started.
130//
131// The progression through the above states is simple, and sequential, in the
132// most common use cases. States proceed from INITIAL to SENDING_CURRENT_LOGS,
133// and remain in the latter until shutdown.
134//
135// The one unusual case is when the user asks that we stop logging. When that
136// happens, any pending (transmission in progress) log is pushed into the list
137// of old unsent logs (the appropriate list, depending on whether it is an
138// initial log, or an ongoing log). An addition, any log that is currently
139// accumulating is also finalized, and pushed into the unsent log list. With
jar@chromium.org281d2882009-01-20 20:32:42140// those pushes performed, we regress back to the SEND_OLD_INITIAL_LOGS state in
initial.commit09911bf2008-07-26 23:55:29141// case the user enables log recording again during this session. This way
142// anything we have "pushed back" will be sent automatically if/when we progress
143// back to SENDING_CURRENT_LOG state.
144//
145// Also note that whenever the member variables containing unsent logs are
146// modified (i.e., when we send an old log), we mirror the list of logs into
147// the PrefServices. This ensures that IF we crash, we won't start up and
148// retransmit our old logs again.
149//
150// Due to race conditions, it is always possible that a log file could be sent
151// twice. For example, if a log file is sent, but not yet acknowledged by
152// the external server, and the user shuts down, then a copy of the log may be
153// saved for re-transmission. These duplicates could be filtered out server
jar@chromium.org281d2882009-01-20 20:32:42154// side, but are not expected to be a significant problem.
initial.commit09911bf2008-07-26 23:55:29155//
156//
157//------------------------------------------------------------------------------
158
maruel@chromium.org40bcc302009-03-02 20:50:39159#include "chrome/browser/metrics/metrics_service.h"
160
ziadh@chromium.org46f89e142010-07-19 08:00:42161#include "base/base64.h"
erg@google.com5d91c9e2010-07-28 17:25:28162#include "base/command_line.h"
ziadh@chromium.org46f89e142010-07-19 08:00:42163#include "base/md5.h"
brettw@chromium.org835d7c82010-10-14 04:38:38164#include "base/metrics/histogram.h"
brettw@chromium.org528c56d2010-07-30 19:28:44165#include "base/string_number_conversions.h"
pkasting@chromium.org4d022ff2009-10-23 18:47:09166#include "base/thread.h"
viettrungluu@chromium.org440b37b22010-08-30 05:31:40167#include "base/utf_string_conversions.h"
erg@google.com679082052010-07-21 21:30:13168#include "base/values.h"
sky@google.comd8e41ed2008-09-11 15:22:32169#include "chrome/browser/bookmarks/bookmark_model.h"
initial.commit09911bf2008-07-26 23:55:29170#include "chrome/browser/browser_list.h"
171#include "chrome/browser/browser_process.h"
dhollowa@chromium.org3469e7e2010-10-14 20:34:59172#include "chrome/browser/guid.h"
initial.commit09911bf2008-07-26 23:55:29173#include "chrome/browser/load_notification_details.h"
174#include "chrome/browser/memory_details.h"
phajdan.jr@chromium.org7c927b62010-02-24 09:54:13175#include "chrome/browser/metrics/histogram_synchronizer.h"
erg@google.com679082052010-07-21 21:30:13176#include "chrome/browser/metrics/metrics_log.h"
evan@chromium.org37858e52010-08-26 00:22:02177#include "chrome/browser/prefs/pref_service.h"
initial.commit09911bf2008-07-26 23:55:29178#include "chrome/browser/profile.h"
brettw@chromium.org8c8657d62009-01-16 18:31:26179#include "chrome/browser/renderer_host/render_process_host.h"
ben@chromium.orgd54e03a52009-01-16 00:31:04180#include "chrome/browser/search_engines/template_url_model.h"
erg@google.com679082052010-07-21 21:30:13181#include "chrome/common/child_process_info.h"
kuchhal@chromium.org157d5472009-11-05 22:31:03182#include "chrome/common/child_process_logging.h"
jar@chromium.org92745242009-06-12 16:52:21183#include "chrome/common/chrome_switches.h"
brettw@chromium.orgbfd04a62009-02-01 18:16:56184#include "chrome/common/notification_service.h"
initial.commit09911bf2008-07-26 23:55:29185#include "chrome/common/pref_names.h"
jam@chromium.orge09ba552009-02-05 03:26:29186#include "chrome/common/render_messages.h"
jam@chromium.org35fa6a22009-08-15 00:04:01187#include "webkit/glue/plugins/plugin_list.h"
erg@google.com679082052010-07-21 21:30:13188#include "webkit/glue/plugins/webplugininfo.h"
mad@google.comae393ec702010-06-27 16:23:14189#include "libxml/xmlwriter.h"
initial.commit09911bf2008-07-26 23:55:29190
phajdan.jr@chromium.orge06131d2010-02-10 18:40:33191// TODO(port): port browser_distribution.h.
192#if !defined(OS_POSIX)
kuchhal@chromium.org79bf0b72009-04-27 21:30:55193#include "chrome/installer/util/browser_distribution.h"
paul@chromium.orgdc6f4962009-02-13 01:25:50194#endif
195
rvargas@google.com5ccaa412009-11-13 22:00:16196#if defined(OS_CHROMEOS)
stevenjb@chromium.orgdb342d52010-08-09 21:19:37197#include "chrome/browser/chromeos/cros/cros_library.h"
198#include "chrome/browser/chromeos/cros/system_library.h"
rvargas@google.com5ccaa412009-11-13 22:00:16199#include "chrome/browser/chromeos/external_metrics.h"
200#endif
201
ziadh@chromium.org46f89e142010-07-19 08:00:42202namespace {
203MetricsService::LogRecallStatus MakeRecallStatusHistogram(
204 MetricsService::LogRecallStatus status) {
205 UMA_HISTOGRAM_ENUMERATION("PrefService.PersistentLogRecall", status,
206 MetricsService::END_RECALL_STATUS);
207 return status;
208}
209
210// TODO(ziadh): Remove this when done with experiment.
211void MakeStoreStatusHistogram(MetricsService::LogStoreStatus status) {
ziadh@chromium.org4e95d202010-07-24 01:47:56212 UMA_HISTOGRAM_ENUMERATION("PrefService.PersistentLogStore2", status,
ziadh@chromium.org46f89e142010-07-19 08:00:42213 MetricsService::END_STORE_STATUS);
214}
215} // namespace
216
dsh@google.come1acf6f2008-10-27 20:43:33217using base::Time;
218using base::TimeDelta;
219
initial.commit09911bf2008-07-26 23:55:29220// Check to see that we're being called on only one thread.
221static bool IsSingleThreaded();
222
initial.commit09911bf2008-07-26 23:55:29223static const char kMetricsType[] = "application/vnd.mozilla.metrics.bz2";
224
225// The delay, in seconds, after startup before sending the first log message.
petersont@google.com252873ef2008-08-04 21:59:45226static const int kInitialInterlogDuration = 60; // one minute
227
jar@chromium.orgc9a3ef82009-05-28 22:02:46228// This specifies the amount of time to wait for all renderers to send their
229// data.
230static const int kMaxHistogramGatheringWaitDuration = 60000; // 60 seconds.
231
petersont@google.com252873ef2008-08-04 21:59:45232// The default maximum number of events in a log uploaded to the UMA server.
jar@google.com0b33f80b2008-12-17 21:34:36233static const int kInitialEventLimit = 2400;
jar@google.com68475e602008-08-22 03:21:15234
235// If an upload fails, and the transmission was over this byte count, then we
236// will discard the log, and not try to retransmit it. We also don't persist
237// the log to the prefs for transmission during the next chrome session if this
238// limit is exceeded.
239static const int kUploadLogAvoidRetransmitSize = 50000;
initial.commit09911bf2008-07-26 23:55:29240
241// When we have logs from previous Chrome sessions to send, how long should we
242// delay (in seconds) between each log transmission.
243static const int kUnsentLogDelay = 15; // 15 seconds
244
245// Minimum time a log typically exists before sending, in seconds.
246// This number is supplied by the server, but until we parse it out of a server
247// response, we use this duration to specify how long we should wait before
248// sending the next log. If the channel is busy, such as when there is a
249// failure during an attempt to transmit a previous log, then a log may wait
jar@chromium.org2fe42fe2010-05-07 19:22:39250// (and continue to accrue new log entries) for a much greater period of time.
251static const int kMinSecondsPerLog = 30 * 60; // Thirty minutes.
initial.commit09911bf2008-07-26 23:55:29252
initial.commit09911bf2008-07-26 23:55:29253// When we don't succeed at transmitting a log to a server, we progressively
254// wait longer and longer before sending the next log. This backoff process
255// help reduce load on the server, and makes the amount of backoff vary between
256// clients so that a collision (server overload?) on retransmit is less likely.
257// The following is the constant we use to expand that inter-log duration.
258static const double kBackoff = 1.1;
259// We limit the maximum backoff to be no greater than some multiple of the
260// default kMinSecondsPerLog. The following is that maximum ratio.
261static const int kMaxBackoff = 10;
262
263// Interval, in seconds, between state saves.
264static const int kSaveStateInterval = 5 * 60; // five minutes
265
266// The number of "initial" logs we're willing to save, and hope to send during
267// a future Chrome session. Initial logs contain crash stats, and are pretty
268// small.
269static const size_t kMaxInitialLogsPersisted = 20;
270
271// The number of ongoing logs we're willing to save persistently, and hope to
jar@chromium.org281d2882009-01-20 20:32:42272// send during a this or future sessions. Note that each log may be pretty
initial.commit09911bf2008-07-26 23:55:29273// large, as presumably the related "initial" log wasn't sent (probably nothing
274// was, as the user was probably off-line). As a result, the log probably kept
275// accumulating while the "initial" log was stalled (pending_), and couldn't be
276// sent. As a result, we don't want to save too many of these mega-logs.
277// A "standard shutdown" will create a small log, including just the data that
278// was not yet been transmitted, and that is normal (to have exactly one
279// ongoing_log_ at startup).
jar@chromium.org281d2882009-01-20 20:32:42280static const size_t kMaxOngoingLogsPersisted = 8;
initial.commit09911bf2008-07-26 23:55:29281
ziadh@chromium.org46f89e142010-07-19 08:00:42282// We append (2) more elements to persisted lists: the size of the list and a
283// checksum of the elements.
284static const size_t kChecksumEntryCount = 2;
285
erg@google.com679082052010-07-21 21:30:13286// This is used to quickly log stats from child process related notifications in
287// MetricsService::child_stats_buffer_. The buffer's contents are transferred
288// out when Local State is periodically saved. The information is then
289// reported to the UMA server on next launch.
290struct MetricsService::ChildProcessStats {
291 public:
292 explicit ChildProcessStats(ChildProcessInfo::ProcessType type)
293 : process_launches(0),
294 process_crashes(0),
295 instances(0),
296 process_type(type) {}
297
298 // This constructor is only used by the map to return some default value for
299 // an index for which no value has been assigned.
300 ChildProcessStats()
301 : process_launches(0),
302 process_crashes(0),
303 instances(0),
304 process_type(ChildProcessInfo::UNKNOWN_PROCESS) {}
305
306 // The number of times that the given child process has been launched
307 int process_launches;
308
309 // The number of times that the given child process has crashed
310 int process_crashes;
311
312 // The number of instances of this child process that have been created.
313 // An instance is a DOM object rendered by this child process during a page
314 // load.
315 int instances;
316
317 ChildProcessInfo::ProcessType process_type;
318};
initial.commit09911bf2008-07-26 23:55:29319
320// Handles asynchronous fetching of memory details.
321// Will run the provided task after finished.
322class MetricsMemoryDetails : public MemoryDetails {
323 public:
324 explicit MetricsMemoryDetails(Task* completion) : completion_(completion) {}
325
326 virtual void OnDetailsAvailable() {
327 MessageLoop::current()->PostTask(FROM_HERE, completion_);
328 }
329
330 private:
jam@chromium.orge6e6ba42009-11-07 01:56:19331 ~MetricsMemoryDetails() {}
332
initial.commit09911bf2008-07-26 23:55:29333 Task* completion_;
tfarina@chromium.org4d818fee2010-06-06 13:32:27334 DISALLOW_COPY_AND_ASSIGN(MetricsMemoryDetails);
initial.commit09911bf2008-07-26 23:55:29335};
336
zelidrag@chromium.org85ed9d42010-06-08 22:37:44337class MetricsService::InitTaskComplete : public Task {
jam@chromium.org35fa6a22009-08-15 00:04:01338 public:
zelidrag@chromium.org85ed9d42010-06-08 22:37:44339 explicit InitTaskComplete(const std::string& hardware_class,
340 const std::vector<WebPluginInfo>& plugins)
341 : hardware_class_(hardware_class), plugins_(plugins) {}
342
jamesr@chromium.org7f2e792e2009-11-30 23:18:29343 virtual void Run() {
zelidrag@chromium.org85ed9d42010-06-08 22:37:44344 g_browser_process->metrics_service()->OnInitTaskComplete(
345 hardware_class_, plugins_);
initial.commit09911bf2008-07-26 23:55:29346 }
jam@chromium.org35fa6a22009-08-15 00:04:01347
jamesr@chromium.org7f2e792e2009-11-30 23:18:29348 private:
zelidrag@chromium.org85ed9d42010-06-08 22:37:44349 std::string hardware_class_;
jamesr@chromium.org7f2e792e2009-11-30 23:18:29350 std::vector<WebPluginInfo> plugins_;
initial.commit09911bf2008-07-26 23:55:29351};
352
zelidrag@chromium.org85ed9d42010-06-08 22:37:44353class MetricsService::InitTask : public Task {
jamesr@chromium.org7f2e792e2009-11-30 23:18:29354 public:
zelidrag@chromium.org85ed9d42010-06-08 22:37:44355 explicit InitTask(MessageLoop* callback_loop)
jamesr@chromium.org7f2e792e2009-11-30 23:18:29356 : callback_loop_(callback_loop) {}
357
358 virtual void Run() {
359 std::vector<WebPluginInfo> plugins;
360 NPAPI::PluginList::Singleton()->GetPlugins(false, &plugins);
zelidrag@chromium.org85ed9d42010-06-08 22:37:44361 std::string hardware_class; // Empty string by default.
362#if defined(OS_CHROMEOS)
stevenjb@chromium.orgdb342d52010-08-09 21:19:37363 chromeos::SystemLibrary* system_library =
364 chromeos::CrosLibrary::Get()->GetSystemLibrary();
365 system_library->GetMachineStatistic("hardware_class", &hardware_class);
zelidrag@chromium.org85ed9d42010-06-08 22:37:44366#endif // OS_CHROMEOS
367 callback_loop_->PostTask(FROM_HERE, new InitTaskComplete(
368 hardware_class, plugins));
jamesr@chromium.org7f2e792e2009-11-30 23:18:29369 }
370
371 private:
372 MessageLoop* callback_loop_;
373};
evan@chromium.org90d41372009-11-30 21:52:32374
initial.commit09911bf2008-07-26 23:55:29375// static
376void MetricsService::RegisterPrefs(PrefService* local_state) {
377 DCHECK(IsSingleThreaded());
estade@chromium.org20ce516d2010-06-18 02:20:04378 local_state->RegisterStringPref(prefs::kMetricsClientID, "");
robertshield@google.com0bb1a622009-03-04 03:22:32379 local_state->RegisterInt64Pref(prefs::kMetricsClientIDTimestamp, 0);
380 local_state->RegisterInt64Pref(prefs::kStabilityLaunchTimeSec, 0);
381 local_state->RegisterInt64Pref(prefs::kStabilityLastTimestampSec, 0);
estade@chromium.org20ce516d2010-06-18 02:20:04382 local_state->RegisterStringPref(prefs::kStabilityStatsVersion, "");
jar@chromium.org225c50842010-01-19 21:19:13383 local_state->RegisterInt64Pref(prefs::kStabilityStatsBuildTime, 0);
initial.commit09911bf2008-07-26 23:55:29384 local_state->RegisterBooleanPref(prefs::kStabilityExitedCleanly, true);
385 local_state->RegisterBooleanPref(prefs::kStabilitySessionEndCompleted, true);
386 local_state->RegisterIntegerPref(prefs::kMetricsSessionID, -1);
387 local_state->RegisterIntegerPref(prefs::kStabilityLaunchCount, 0);
388 local_state->RegisterIntegerPref(prefs::kStabilityCrashCount, 0);
389 local_state->RegisterIntegerPref(prefs::kStabilityIncompleteSessionEndCount,
390 0);
391 local_state->RegisterIntegerPref(prefs::kStabilityPageLoadCount, 0);
initial.commit09911bf2008-07-26 23:55:29392 local_state->RegisterIntegerPref(prefs::kStabilityRendererCrashCount, 0);
asargent@chromium.org1f085622009-12-04 05:33:45393 local_state->RegisterIntegerPref(prefs::kStabilityExtensionRendererCrashCount,
394 0);
initial.commit09911bf2008-07-26 23:55:29395 local_state->RegisterIntegerPref(prefs::kStabilityRendererHangCount, 0);
asargent@chromium.org1f085622009-12-04 05:33:45396 local_state->RegisterIntegerPref(prefs::kStabilityChildProcessCrashCount, 0);
cpu@google.come73c01972008-08-13 00:18:24397 local_state->RegisterIntegerPref(prefs::kStabilityBreakpadRegistrationFail,
398 0);
399 local_state->RegisterIntegerPref(prefs::kStabilityBreakpadRegistrationSuccess,
400 0);
401 local_state->RegisterIntegerPref(prefs::kStabilityDebuggerPresent, 0);
402 local_state->RegisterIntegerPref(prefs::kStabilityDebuggerNotPresent, 0);
403
initial.commit09911bf2008-07-26 23:55:29404 local_state->RegisterDictionaryPref(prefs::kProfileMetrics);
405 local_state->RegisterIntegerPref(prefs::kNumBookmarksOnBookmarkBar, 0);
406 local_state->RegisterIntegerPref(prefs::kNumFoldersOnBookmarkBar, 0);
407 local_state->RegisterIntegerPref(prefs::kNumBookmarksInOtherBookmarkFolder,
408 0);
409 local_state->RegisterIntegerPref(prefs::kNumFoldersInOtherBookmarkFolder, 0);
410 local_state->RegisterIntegerPref(prefs::kNumKeywords, 0);
411 local_state->RegisterListPref(prefs::kMetricsInitialLogs);
412 local_state->RegisterListPref(prefs::kMetricsOngoingLogs);
robertshield@google.com0bb1a622009-03-04 03:22:32413
414 local_state->RegisterInt64Pref(prefs::kUninstallMetricsPageLoadCount, 0);
415 local_state->RegisterInt64Pref(prefs::kUninstallLaunchCount, 0);
robertshield@google.com6b5f21d2009-04-13 17:01:35416 local_state->RegisterInt64Pref(prefs::kUninstallMetricsInstallDate, 0);
robertshield@google.com0bb1a622009-03-04 03:22:32417 local_state->RegisterInt64Pref(prefs::kUninstallMetricsUptimeSec, 0);
418 local_state->RegisterInt64Pref(prefs::kUninstallLastLaunchTimeSec, 0);
419 local_state->RegisterInt64Pref(prefs::kUninstallLastObservedRunTimeSec, 0);
initial.commit09911bf2008-07-26 23:55:29420}
421
jar@chromium.org541f77922009-02-23 21:14:38422// static
423void MetricsService::DiscardOldStabilityStats(PrefService* local_state) {
424 local_state->SetBoolean(prefs::kStabilityExitedCleanly, true);
jar@chromium.orgc9abf242009-07-18 06:00:38425 local_state->SetBoolean(prefs::kStabilitySessionEndCompleted, true);
jar@chromium.org541f77922009-02-23 21:14:38426
427 local_state->SetInteger(prefs::kStabilityIncompleteSessionEndCount, 0);
428 local_state->SetInteger(prefs::kStabilityBreakpadRegistrationSuccess, 0);
429 local_state->SetInteger(prefs::kStabilityBreakpadRegistrationFail, 0);
430 local_state->SetInteger(prefs::kStabilityDebuggerPresent, 0);
431 local_state->SetInteger(prefs::kStabilityDebuggerNotPresent, 0);
432
433 local_state->SetInteger(prefs::kStabilityLaunchCount, 0);
434 local_state->SetInteger(prefs::kStabilityCrashCount, 0);
435
436 local_state->SetInteger(prefs::kStabilityPageLoadCount, 0);
437 local_state->SetInteger(prefs::kStabilityRendererCrashCount, 0);
438 local_state->SetInteger(prefs::kStabilityRendererHangCount, 0);
439
jar@chromium.org9165f742010-03-10 22:55:01440 local_state->SetInt64(prefs::kStabilityLaunchTimeSec, 0);
441 local_state->SetInt64(prefs::kStabilityLastTimestampSec, 0);
jar@chromium.org541f77922009-02-23 21:14:38442
443 local_state->ClearPref(prefs::kStabilityPluginStats);
jar@chromium.orgae155cb92009-06-19 06:10:37444
445 ListValue* unsent_initial_logs = local_state->GetMutableList(
446 prefs::kMetricsInitialLogs);
447 unsent_initial_logs->Clear();
448
449 ListValue* unsent_ongoing_logs = local_state->GetMutableList(
450 prefs::kMetricsOngoingLogs);
451 unsent_ongoing_logs->Clear();
jar@chromium.org541f77922009-02-23 21:14:38452}
453
initial.commit09911bf2008-07-26 23:55:29454MetricsService::MetricsService()
petersont@google.comd01b8732008-10-16 02:18:07455 : recording_active_(false),
456 reporting_active_(false),
457 user_permits_upload_(false),
458 server_permits_upload_(true),
459 state_(INITIALIZED),
initial.commit09911bf2008-07-26 23:55:29460 current_fetch_(NULL),
petersont@google.comd01b8732008-10-16 02:18:07461 idle_since_last_transmission_(false),
initial.commit09911bf2008-07-26 23:55:29462 next_window_id_(0),
maruel@chromium.org40bcc302009-03-02 20:50:39463 ALLOW_THIS_IN_INITIALIZER_LIST(log_sender_factory_(this)),
464 ALLOW_THIS_IN_INITIALIZER_LIST(state_saver_factory_(this)),
petersont@google.com252873ef2008-08-04 21:59:45465 interlog_duration_(TimeDelta::FromSeconds(kInitialInterlogDuration)),
petersont@google.comd01b8732008-10-16 02:18:07466 log_event_limit_(kInitialEventLimit),
initial.commit09911bf2008-07-26 23:55:29467 timer_pending_(false) {
468 DCHECK(IsSingleThreaded());
469 InitializeMetricsState();
470}
471
472MetricsService::~MetricsService() {
473 SetRecording(false);
474}
475
petersont@google.comd01b8732008-10-16 02:18:07476void MetricsService::SetUserPermitsUpload(bool enabled) {
477 HandleIdleSinceLastTransmission(false);
478 user_permits_upload_ = enabled;
479}
480
481void MetricsService::Start() {
482 SetRecording(true);
483 SetReporting(true);
484}
485
486void MetricsService::StartRecordingOnly() {
487 SetRecording(true);
488 SetReporting(false);
489}
490
491void MetricsService::Stop() {
492 SetReporting(false);
493 SetRecording(false);
494}
495
initial.commit09911bf2008-07-26 23:55:29496void MetricsService::SetRecording(bool enabled) {
497 DCHECK(IsSingleThreaded());
498
petersont@google.comd01b8732008-10-16 02:18:07499 if (enabled == recording_active_)
initial.commit09911bf2008-07-26 23:55:29500 return;
501
502 if (enabled) {
jar@chromium.orgb0c819f2009-03-08 04:52:15503 if (client_id_.empty()) {
504 PrefService* pref = g_browser_process->local_state();
505 DCHECK(pref);
estade@chromium.orgddd231e2010-06-29 20:35:19506 client_id_ = pref->GetString(prefs::kMetricsClientID);
jar@chromium.orgb0c819f2009-03-08 04:52:15507 if (client_id_.empty()) {
508 client_id_ = GenerateClientID();
estade@chromium.orgddd231e2010-06-29 20:35:19509 pref->SetString(prefs::kMetricsClientID, client_id_);
jar@chromium.orgb0c819f2009-03-08 04:52:15510
511 // Might as well make a note of how long this ID has existed
512 pref->SetString(prefs::kMetricsClientIDTimestamp,
brettw@chromium.org528c56d2010-07-30 19:28:44513 base::Int64ToString(Time::Now().ToTimeT()));
jar@chromium.orgb0c819f2009-03-08 04:52:15514 }
515 }
kuchhal@chromium.org157d5472009-11-05 22:31:03516 child_process_logging::SetClientId(client_id_);
initial.commit09911bf2008-07-26 23:55:29517 StartRecording();
pkasting@chromium.org005ef3e2009-05-22 20:55:46518
519 registrar_.Add(this, NotificationType::BROWSER_OPENED,
520 NotificationService::AllSources());
521 registrar_.Add(this, NotificationType::BROWSER_CLOSED,
522 NotificationService::AllSources());
523 registrar_.Add(this, NotificationType::USER_ACTION,
524 NotificationService::AllSources());
525 registrar_.Add(this, NotificationType::TAB_PARENTED,
526 NotificationService::AllSources());
527 registrar_.Add(this, NotificationType::TAB_CLOSING,
528 NotificationService::AllSources());
529 registrar_.Add(this, NotificationType::LOAD_START,
530 NotificationService::AllSources());
531 registrar_.Add(this, NotificationType::LOAD_STOP,
532 NotificationService::AllSources());
kkania@chromium.orgcd69619b2010-05-05 02:41:38533 registrar_.Add(this, NotificationType::RENDERER_PROCESS_CLOSED,
pkasting@chromium.org005ef3e2009-05-22 20:55:46534 NotificationService::AllSources());
535 registrar_.Add(this, NotificationType::RENDERER_PROCESS_HANG,
536 NotificationService::AllSources());
537 registrar_.Add(this, NotificationType::CHILD_PROCESS_HOST_CONNECTED,
538 NotificationService::AllSources());
539 registrar_.Add(this, NotificationType::CHILD_INSTANCE_CREATED,
540 NotificationService::AllSources());
541 registrar_.Add(this, NotificationType::CHILD_PROCESS_CRASHED,
542 NotificationService::AllSources());
543 registrar_.Add(this, NotificationType::TEMPLATE_URL_MODEL_LOADED,
544 NotificationService::AllSources());
545 registrar_.Add(this, NotificationType::OMNIBOX_OPENED_URL,
546 NotificationService::AllSources());
547 registrar_.Add(this, NotificationType::BOOKMARK_MODEL_LOADED,
548 NotificationService::AllSources());
initial.commit09911bf2008-07-26 23:55:29549 } else {
pkasting@chromium.org005ef3e2009-05-22 20:55:46550 registrar_.RemoveAll();
initial.commit09911bf2008-07-26 23:55:29551 PushPendingLogsToUnsentLists();
552 DCHECK(!pending_log());
553 if (state_ > INITIAL_LOG_READY && unsent_logs())
554 state_ = SEND_OLD_INITIAL_LOGS;
555 }
petersont@google.comd01b8732008-10-16 02:18:07556 recording_active_ = enabled;
initial.commit09911bf2008-07-26 23:55:29557}
558
petersont@google.comd01b8732008-10-16 02:18:07559bool MetricsService::recording_active() const {
initial.commit09911bf2008-07-26 23:55:29560 DCHECK(IsSingleThreaded());
petersont@google.comd01b8732008-10-16 02:18:07561 return recording_active_;
initial.commit09911bf2008-07-26 23:55:29562}
563
petersont@google.comd01b8732008-10-16 02:18:07564void MetricsService::SetReporting(bool enable) {
565 if (reporting_active_ != enable) {
566 reporting_active_ = enable;
567 if (reporting_active_)
initial.commit09911bf2008-07-26 23:55:29568 StartLogTransmissionTimer();
569 }
petersont@google.comd01b8732008-10-16 02:18:07570}
571
572bool MetricsService::reporting_active() const {
573 DCHECK(IsSingleThreaded());
574 return reporting_active_;
initial.commit09911bf2008-07-26 23:55:29575}
576
577void MetricsService::Observe(NotificationType type,
578 const NotificationSource& source,
579 const NotificationDetails& details) {
580 DCHECK(current_log_);
581 DCHECK(IsSingleThreaded());
582
583 if (!CanLogNotification(type, source, details))
584 return;
585
brettw@chromium.orgbfd04a62009-02-01 18:16:56586 switch (type.value) {
587 case NotificationType::USER_ACTION:
evan@chromium.orgafe3a1672009-11-17 19:04:12588 current_log_->RecordUserAction(*Details<const char*>(details).ptr());
initial.commit09911bf2008-07-26 23:55:29589 break;
590
brettw@chromium.orgbfd04a62009-02-01 18:16:56591 case NotificationType::BROWSER_OPENED:
592 case NotificationType::BROWSER_CLOSED:
initial.commit09911bf2008-07-26 23:55:29593 LogWindowChange(type, source, details);
594 break;
595
brettw@chromium.orgbfd04a62009-02-01 18:16:56596 case NotificationType::TAB_PARENTED:
597 case NotificationType::TAB_CLOSING:
initial.commit09911bf2008-07-26 23:55:29598 LogWindowChange(type, source, details);
599 break;
600
brettw@chromium.orgbfd04a62009-02-01 18:16:56601 case NotificationType::LOAD_STOP:
initial.commit09911bf2008-07-26 23:55:29602 LogLoadComplete(type, source, details);
603 break;
604
brettw@chromium.orgbfd04a62009-02-01 18:16:56605 case NotificationType::LOAD_START:
initial.commit09911bf2008-07-26 23:55:29606 LogLoadStarted();
607 break;
608
kkania@chromium.orgcd69619b2010-05-05 02:41:38609 case NotificationType::RENDERER_PROCESS_CLOSED:
asargent@chromium.org1f085622009-12-04 05:33:45610 {
kkania@chromium.orgcd69619b2010-05-05 02:41:38611 RenderProcessHost::RendererClosedDetails* process_details =
612 Details<RenderProcessHost::RendererClosedDetails>(details).ptr();
613 if (process_details->did_crash) {
614 if (process_details->was_extension_renderer) {
615 LogExtensionRendererCrash();
616 } else {
617 LogRendererCrash();
618 }
619 }
asargent@chromium.org1f085622009-12-04 05:33:45620 }
initial.commit09911bf2008-07-26 23:55:29621 break;
622
brettw@chromium.orgbfd04a62009-02-01 18:16:56623 case NotificationType::RENDERER_PROCESS_HANG:
initial.commit09911bf2008-07-26 23:55:29624 LogRendererHang();
625 break;
626
jam@chromium.orga27a9382009-02-11 23:55:10627 case NotificationType::CHILD_PROCESS_HOST_CONNECTED:
628 case NotificationType::CHILD_PROCESS_CRASHED:
629 case NotificationType::CHILD_INSTANCE_CREATED:
630 LogChildProcessChange(type, source, details);
initial.commit09911bf2008-07-26 23:55:29631 break;
632
brettw@chromium.orgbfd04a62009-02-01 18:16:56633 case NotificationType::TEMPLATE_URL_MODEL_LOADED:
initial.commit09911bf2008-07-26 23:55:29634 LogKeywords(Source<TemplateURLModel>(source).ptr());
635 break;
636
ananta@chromium.org1226abb2010-06-10 18:01:28637 case NotificationType::OMNIBOX_OPENED_URL: {
638 MetricsLog* current_log = current_log_->AsMetricsLog();
639 DCHECK(current_log);
640 current_log->RecordOmniboxOpenedURL(
initial.commit09911bf2008-07-26 23:55:29641 *Details<AutocompleteLog>(details).ptr());
642 break;
ananta@chromium.org1226abb2010-06-10 18:01:28643 }
initial.commit09911bf2008-07-26 23:55:29644
tim@chromium.orgb61236c62009-04-09 22:43:55645 case NotificationType::BOOKMARK_MODEL_LOADED: {
646 Profile* p = Source<Profile>(source).ptr();
647 if (p)
648 LogBookmarks(p->GetBookmarkModel());
initial.commit09911bf2008-07-26 23:55:29649 break;
tim@chromium.orgb61236c62009-04-09 22:43:55650 }
initial.commit09911bf2008-07-26 23:55:29651 default:
jar@chromium.orga063c102010-07-22 22:20:19652 NOTREACHED();
initial.commit09911bf2008-07-26 23:55:29653 break;
654 }
petersont@google.comd01b8732008-10-16 02:18:07655
656 HandleIdleSinceLastTransmission(false);
657
658 if (current_log_)
jar@chromium.org281d2882009-01-20 20:32:42659 DLOG(INFO) << "METRICS: NUMBER OF EVENTS = " << current_log_->num_events();
petersont@google.comd01b8732008-10-16 02:18:07660}
661
662void MetricsService::HandleIdleSinceLastTransmission(bool in_idle) {
663 // If there wasn't a lot of action, maybe the computer was asleep, in which
664 // case, the log transmissions should have stopped. Here we start them up
665 // again.
pkasting@chromium.orgcac78842008-11-27 01:02:20666 if (!in_idle && idle_since_last_transmission_)
667 StartLogTransmissionTimer();
668 idle_since_last_transmission_ = in_idle;
initial.commit09911bf2008-07-26 23:55:29669}
670
671void MetricsService::RecordCleanShutdown() {
672 RecordBooleanPrefValue(prefs::kStabilityExitedCleanly, true);
673}
674
675void MetricsService::RecordStartOfSessionEnd() {
676 RecordBooleanPrefValue(prefs::kStabilitySessionEndCompleted, false);
677}
678
679void MetricsService::RecordCompletedSessionEnd() {
680 RecordBooleanPrefValue(prefs::kStabilitySessionEndCompleted, true);
681}
682
cpu@google.come73c01972008-08-13 00:18:24683void MetricsService:: RecordBreakpadRegistration(bool success) {
jar@google.com68475e602008-08-22 03:21:15684 if (!success)
cpu@google.come73c01972008-08-13 00:18:24685 IncrementPrefValue(prefs::kStabilityBreakpadRegistrationFail);
686 else
687 IncrementPrefValue(prefs::kStabilityBreakpadRegistrationSuccess);
688}
689
690void MetricsService::RecordBreakpadHasDebugger(bool has_debugger) {
691 if (!has_debugger)
692 IncrementPrefValue(prefs::kStabilityDebuggerNotPresent);
693 else
jar@google.com68475e602008-08-22 03:21:15694 IncrementPrefValue(prefs::kStabilityDebuggerPresent);
cpu@google.come73c01972008-08-13 00:18:24695}
696
initial.commit09911bf2008-07-26 23:55:29697//------------------------------------------------------------------------------
698// private methods
699//------------------------------------------------------------------------------
700
701
702//------------------------------------------------------------------------------
703// Initialization methods
704
705void MetricsService::InitializeMetricsState() {
kuchhal@chromium.org79bf0b72009-04-27 21:30:55706#if defined(OS_POSIX)
707 server_url_ = L"https://clients4.google.com/firefox/metrics/collect";
708#else
709 BrowserDistribution* dist = BrowserDistribution::GetDistribution();
710 server_url_ = dist->GetStatsServerURL();
711#endif
712
initial.commit09911bf2008-07-26 23:55:29713 PrefService* pref = g_browser_process->local_state();
714 DCHECK(pref);
715
jar@chromium.org225c50842010-01-19 21:19:13716 if ((pref->GetInt64(prefs::kStabilityStatsBuildTime)
717 != MetricsLog::GetBuildTime()) ||
estade@chromium.orgddd231e2010-06-29 20:35:19718 (pref->GetString(prefs::kStabilityStatsVersion)
jar@chromium.org225c50842010-01-19 21:19:13719 != MetricsLog::GetVersionString())) {
jar@chromium.org541f77922009-02-23 21:14:38720 // This is a new version, so we don't want to confuse the stats about the
721 // old version with info that we upload.
722 DiscardOldStabilityStats(pref);
723 pref->SetString(prefs::kStabilityStatsVersion,
estade@chromium.orgddd231e2010-06-29 20:35:19724 MetricsLog::GetVersionString());
jar@chromium.org225c50842010-01-19 21:19:13725 pref->SetInt64(prefs::kStabilityStatsBuildTime,
726 MetricsLog::GetBuildTime());
jar@chromium.org541f77922009-02-23 21:14:38727 }
728
initial.commit09911bf2008-07-26 23:55:29729 // Update session ID
730 session_id_ = pref->GetInteger(prefs::kMetricsSessionID);
731 ++session_id_;
732 pref->SetInteger(prefs::kMetricsSessionID, session_id_);
733
initial.commit09911bf2008-07-26 23:55:29734 // Stability bookkeeping
cpu@google.come73c01972008-08-13 00:18:24735 IncrementPrefValue(prefs::kStabilityLaunchCount);
initial.commit09911bf2008-07-26 23:55:29736
cpu@google.come73c01972008-08-13 00:18:24737 if (!pref->GetBoolean(prefs::kStabilityExitedCleanly)) {
738 IncrementPrefValue(prefs::kStabilityCrashCount);
initial.commit09911bf2008-07-26 23:55:29739 }
cpu@google.come73c01972008-08-13 00:18:24740
741 // This will be set to 'true' if we exit cleanly.
initial.commit09911bf2008-07-26 23:55:29742 pref->SetBoolean(prefs::kStabilityExitedCleanly, false);
743
cpu@google.come73c01972008-08-13 00:18:24744 if (!pref->GetBoolean(prefs::kStabilitySessionEndCompleted)) {
745 IncrementPrefValue(prefs::kStabilityIncompleteSessionEndCount);
jar@chromium.orgc9abf242009-07-18 06:00:38746 // This is marked false when we get a WM_ENDSESSION.
747 pref->SetBoolean(prefs::kStabilitySessionEndCompleted, true);
initial.commit09911bf2008-07-26 23:55:29748 }
initial.commit09911bf2008-07-26 23:55:29749
jar@chromium.org9165f742010-03-10 22:55:01750 // Initialize uptime counters.
751 int64 startup_uptime = MetricsLog::GetIncrementalUptime(pref);
mad@google.comae393ec702010-06-27 16:23:14752 DCHECK_EQ(0, startup_uptime);
jar@chromium.org9165f742010-03-10 22:55:01753 // For backwards compatibility, leave this intact in case Omaha is checking
754 // them. prefs::kStabilityLastTimestampSec may also be useless now.
755 // TODO(jar): Delete these if they have no uses.
robertshield@google.com0bb1a622009-03-04 03:22:32756 pref->SetInt64(prefs::kStabilityLaunchTimeSec, Time::Now().ToTimeT());
757
758 // Bookkeeping for the uninstall metrics.
759 IncrementLongPrefsValue(prefs::kUninstallLaunchCount);
initial.commit09911bf2008-07-26 23:55:29760
761 // Save profile metrics.
762 PrefService* prefs = g_browser_process->local_state();
763 if (prefs) {
764 // Remove the current dictionary and store it for use when sending data to
765 // server. By removing the value we prune potentially dead profiles
766 // (and keys). All valid values are added back once services startup.
767 const DictionaryValue* profile_dictionary =
768 prefs->GetDictionary(prefs::kProfileMetrics);
769 if (profile_dictionary) {
770 // Do a deep copy of profile_dictionary since ClearPref will delete it.
771 profile_dictionary_.reset(static_cast<DictionaryValue*>(
772 profile_dictionary->DeepCopy()));
773 prefs->ClearPref(prefs::kProfileMetrics);
774 }
775 }
776
jar@chromium.org92745242009-06-12 16:52:21777 // Get stats on use of command line.
778 const CommandLine* command_line(CommandLine::ForCurrentProcess());
779 size_t common_commands = 0;
780 if (command_line->HasSwitch(switches::kUserDataDir)) {
781 ++common_commands;
782 UMA_HISTOGRAM_COUNTS_100("Chrome.CommandLineDatDirCount", 1);
783 }
784
785 if (command_line->HasSwitch(switches::kApp)) {
786 ++common_commands;
787 UMA_HISTOGRAM_COUNTS_100("Chrome.CommandLineAppModeCount", 1);
788 }
789
790 UMA_HISTOGRAM_COUNTS_100("Chrome.CommandLineFlagCount",
791 command_line->GetSwitchCount());
792 UMA_HISTOGRAM_COUNTS_100("Chrome.CommandLineUncommonFlagCount",
793 command_line->GetSwitchCount() - common_commands);
794
initial.commit09911bf2008-07-26 23:55:29795 // Kick off the process of saving the state (so the uptime numbers keep
796 // getting updated) every n minutes.
797 ScheduleNextStateSave();
798}
799
zelidrag@chromium.org85ed9d42010-06-08 22:37:44800void MetricsService::OnInitTaskComplete(
801 const std::string& hardware_class,
jam@chromium.org35fa6a22009-08-15 00:04:01802 const std::vector<WebPluginInfo>& plugins) {
zelidrag@chromium.org85ed9d42010-06-08 22:37:44803 DCHECK(state_ == INIT_TASK_SCHEDULED);
804 hardware_class_ = hardware_class;
jam@chromium.org35fa6a22009-08-15 00:04:01805 plugins_ = plugins;
zelidrag@chromium.org85ed9d42010-06-08 22:37:44806 if (state_ == INIT_TASK_SCHEDULED)
807 state_ = INIT_TASK_DONE;
initial.commit09911bf2008-07-26 23:55:29808}
809
810std::string MetricsService::GenerateClientID() {
dhollowa@chromium.org3469e7e2010-10-14 20:34:59811 return guid::GenerateGUID();
initial.commit09911bf2008-07-26 23:55:29812}
813
initial.commit09911bf2008-07-26 23:55:29814//------------------------------------------------------------------------------
815// State save methods
816
817void MetricsService::ScheduleNextStateSave() {
818 state_saver_factory_.RevokeAll();
819
820 MessageLoop::current()->PostDelayedTask(FROM_HERE,
821 state_saver_factory_.NewRunnableMethod(&MetricsService::SaveLocalState),
822 kSaveStateInterval * 1000);
823}
824
825void MetricsService::SaveLocalState() {
826 PrefService* pref = g_browser_process->local_state();
827 if (!pref) {
jar@chromium.orga063c102010-07-22 22:20:19828 NOTREACHED();
initial.commit09911bf2008-07-26 23:55:29829 return;
830 }
831
832 RecordCurrentState(pref);
phajdan.jr@chromium.org6faa0e0d2009-04-28 06:50:36833 pref->ScheduleSavePersistentPrefs();
initial.commit09911bf2008-07-26 23:55:29834
jar@chromium.org281d2882009-01-20 20:32:42835 // TODO(jar): Does this run down the batteries????
initial.commit09911bf2008-07-26 23:55:29836 ScheduleNextStateSave();
837}
838
839
840//------------------------------------------------------------------------------
841// Recording control methods
842
843void MetricsService::StartRecording() {
844 if (current_log_)
845 return;
846
847 current_log_ = new MetricsLog(client_id_, session_id_);
848 if (state_ == INITIALIZED) {
849 // We only need to schedule that run once.
zelidrag@chromium.org85ed9d42010-06-08 22:37:44850 state_ = INIT_TASK_SCHEDULED;
initial.commit09911bf2008-07-26 23:55:29851
zelidrag@chromium.org85ed9d42010-06-08 22:37:44852 // Schedules a task on the file thread for execution of slower
853 // initialization steps (such as plugin list generation) necessary
854 // for sending the initial log. This avoids blocking the main UI
855 // thread.
jamesr@chromium.org7f2e792e2009-11-30 23:18:29856 g_browser_process->file_thread()->message_loop()->PostDelayedTask(FROM_HERE,
zelidrag@chromium.org85ed9d42010-06-08 22:37:44857 new InitTask(MessageLoop::current()),
petersont@google.com252873ef2008-08-04 21:59:45858 kInitialInterlogDuration * 1000 / 2);
initial.commit09911bf2008-07-26 23:55:29859 }
860}
861
ananta@chromium.org1226abb2010-06-10 18:01:28862void MetricsService::StopRecording(MetricsLogBase** log) {
initial.commit09911bf2008-07-26 23:55:29863 if (!current_log_)
864 return;
865
ananta@chromium.org1226abb2010-06-10 18:01:28866 MetricsLog* current_log = current_log_->AsMetricsLog();
867 DCHECK(current_log);
868 current_log->set_hardware_class(hardware_class_); // Adds to ongoing logs.
zelidrag@chromium.org85ed9d42010-06-08 22:37:44869
jar@google.com68475e602008-08-22 03:21:15870 // TODO(jar): Integrate bounds on log recording more consistently, so that we
871 // can stop recording logs that are too big much sooner.
petersont@google.comd01b8732008-10-16 02:18:07872 if (current_log_->num_events() > log_event_limit_) {
dsh@google.com553dba62009-02-24 19:08:23873 UMA_HISTOGRAM_COUNTS("UMA.Discarded Log Events",
jar@google.com68475e602008-08-22 03:21:15874 current_log_->num_events());
875 current_log_->CloseLog();
876 delete current_log_;
jar@google.com294638782008-09-24 00:22:41877 current_log_ = NULL;
jar@google.com68475e602008-08-22 03:21:15878 StartRecording(); // Start trivial log to hold our histograms.
879 }
880
jar@google.com0b33f80b2008-12-17 21:34:36881 // Put incremental data (histogram deltas, and realtime stats deltas) at the
jar@google.com147bbc0b2009-01-06 19:37:40882 // end of all log transmissions (initial log handles this separately).
initial.commit09911bf2008-07-26 23:55:29883 // Don't bother if we're going to discard current_log_.
jar@google.com0b33f80b2008-12-17 21:34:36884 if (log) {
ananta@chromium.org1226abb2010-06-10 18:01:28885 current_log->RecordIncrementalStabilityElements();
initial.commit09911bf2008-07-26 23:55:29886 RecordCurrentHistograms();
jar@google.com0b33f80b2008-12-17 21:34:36887 }
initial.commit09911bf2008-07-26 23:55:29888
889 current_log_->CloseLog();
pkasting@chromium.orgcac78842008-11-27 01:02:20890 if (log)
ananta@chromium.org1226abb2010-06-10 18:01:28891 *log = current_log;
pkasting@chromium.orgcac78842008-11-27 01:02:20892 else
initial.commit09911bf2008-07-26 23:55:29893 delete current_log_;
initial.commit09911bf2008-07-26 23:55:29894 current_log_ = NULL;
895}
896
initial.commit09911bf2008-07-26 23:55:29897void MetricsService::PushPendingLogsToUnsentLists() {
898 if (state_ < INITIAL_LOG_READY)
avi@google.com28ab7f92009-01-06 21:39:04899 return; // We didn't and still don't have time to get plugin list etc.
initial.commit09911bf2008-07-26 23:55:29900
901 if (pending_log()) {
902 PreparePendingLogText();
903 if (state_ == INITIAL_LOG_READY) {
904 // We may race here, and send second copy of initial log later.
ziadh@chromium.org46f89e142010-07-19 08:00:42905 unsent_initial_logs_.push_back(compressed_log_);
petersont@google.comd01b8732008-10-16 02:18:07906 state_ = SEND_OLD_INITIAL_LOGS;
initial.commit09911bf2008-07-26 23:55:29907 } else {
jar@chromium.org281d2882009-01-20 20:32:42908 // TODO(jar): Verify correctness in other states, including sending unsent
jar@chromium.org541f77922009-02-23 21:14:38909 // initial logs.
jar@google.com68475e602008-08-22 03:21:15910 PushPendingLogTextToUnsentOngoingLogs();
initial.commit09911bf2008-07-26 23:55:29911 }
912 DiscardPendingLog();
913 }
914 DCHECK(!pending_log());
915 StopRecording(&pending_log_);
916 PreparePendingLogText();
jar@google.com68475e602008-08-22 03:21:15917 PushPendingLogTextToUnsentOngoingLogs();
initial.commit09911bf2008-07-26 23:55:29918 DiscardPendingLog();
919 StoreUnsentLogs();
920}
921
jar@google.com68475e602008-08-22 03:21:15922void MetricsService::PushPendingLogTextToUnsentOngoingLogs() {
petersont@google.comd01b8732008-10-16 02:18:07923 // If UMA response told us not to upload, there's no need to save the pending
924 // log. It wasn't supposed to be uploaded anyway.
925 if (!server_permits_upload_)
926 return;
ziadh@chromium.org46f89e142010-07-19 08:00:42927 if (compressed_log_.length() >
paul@chromium.orgdc6f4962009-02-13 01:25:50928 static_cast<size_t>(kUploadLogAvoidRetransmitSize)) {
dsh@google.com553dba62009-02-24 19:08:23929 UMA_HISTOGRAM_COUNTS("UMA.Large Accumulated Log Not Persisted",
ziadh@chromium.org46f89e142010-07-19 08:00:42930 static_cast<int>(compressed_log_.length()));
jar@google.com68475e602008-08-22 03:21:15931 return;
932 }
ziadh@chromium.org46f89e142010-07-19 08:00:42933 unsent_ongoing_logs_.push_back(compressed_log_);
jar@google.com68475e602008-08-22 03:21:15934}
935
initial.commit09911bf2008-07-26 23:55:29936//------------------------------------------------------------------------------
937// Transmission of logs methods
938
939void MetricsService::StartLogTransmissionTimer() {
petersont@google.comd01b8732008-10-16 02:18:07940 // If we're not reporting, there's no point in starting a log transmission
941 // timer.
942 if (!reporting_active())
943 return;
944
initial.commit09911bf2008-07-26 23:55:29945 if (!current_log_)
946 return; // Recorder is shutdown.
petersont@google.comd01b8732008-10-16 02:18:07947
948 // If there is already a timer running, we leave it running.
949 // If timer_pending is true because the fetch is waiting for a response,
950 // we return for now and let the response handler start the timer.
951 if (timer_pending_)
initial.commit09911bf2008-07-26 23:55:29952 return;
petersont@google.comd01b8732008-10-16 02:18:07953
petersont@google.comd01b8732008-10-16 02:18:07954 // Before starting the timer, set timer_pending_ to true.
initial.commit09911bf2008-07-26 23:55:29955 timer_pending_ = true;
petersont@google.comd01b8732008-10-16 02:18:07956
957 // Right before the UMA transmission gets started, there's one more thing we'd
958 // like to record: the histogram of memory usage, so we spawn a task to
jar@chromium.orgc9a3ef82009-05-28 22:02:46959 // collect the memory details and when that task is finished, it will call
960 // OnMemoryDetailCollectionDone, which will call HistogramSynchronization to
961 // collect histograms from all renderers and then we will call
962 // OnHistogramSynchronizationDone to continue processing.
initial.commit09911bf2008-07-26 23:55:29963 MessageLoop::current()->PostDelayedTask(FROM_HERE,
964 log_sender_factory_.
jar@chromium.orgc9a3ef82009-05-28 22:02:46965 NewRunnableMethod(&MetricsService::LogTransmissionTimerDone),
phajdan.jr@chromium.org743ace42009-06-17 17:23:51966 interlog_duration_.InMilliseconds());
initial.commit09911bf2008-07-26 23:55:29967}
968
jar@chromium.orgc9a3ef82009-05-28 22:02:46969void MetricsService::LogTransmissionTimerDone() {
970 Task* task = log_sender_factory_.
971 NewRunnableMethod(&MetricsService::OnMemoryDetailCollectionDone);
972
jam@chromium.orge9adedb2009-12-01 22:23:59973 scoped_refptr<MetricsMemoryDetails> details = new MetricsMemoryDetails(task);
jar@chromium.orgc9a3ef82009-05-28 22:02:46974 details->StartFetch();
975
976 // Collect WebCore cache information to put into a histogram.
pkasting@chromium.org019191a2009-10-02 20:37:27977 for (RenderProcessHost::iterator i(RenderProcessHost::AllHostsIterator());
978 !i.IsAtEnd(); i.Advance())
979 i.GetCurrentValue()->Send(new ViewMsg_GetCacheResourceStats());
jar@chromium.orgc9a3ef82009-05-28 22:02:46980}
981
982void MetricsService::OnMemoryDetailCollectionDone() {
983 DCHECK(IsSingleThreaded());
984
985 // HistogramSynchronizer will Collect histograms from all renderers and it
986 // will call OnHistogramSynchronizationDone (if wait time elapses before it
987 // heard from all renderers, then also it will call
988 // OnHistogramSynchronizationDone).
989
990 // Create a callback_task for OnHistogramSynchronizationDone.
991 Task* callback_task = log_sender_factory_.NewRunnableMethod(
992 &MetricsService::OnHistogramSynchronizationDone);
993
994 // Set up the callback to task to call after we receive histograms from all
995 // renderer processes. Wait time specifies how long to wait before absolutely
996 // calling us back on the task.
997 HistogramSynchronizer::FetchRendererHistogramsAsynchronously(
998 MessageLoop::current(), callback_task,
999 kMaxHistogramGatheringWaitDuration);
1000}
1001
1002void MetricsService::OnHistogramSynchronizationDone() {
initial.commit09911bf2008-07-26 23:55:291003 DCHECK(IsSingleThreaded());
1004
petersont@google.comd01b8732008-10-16 02:18:071005 // This function should only be called via timer, so timer_pending_
1006 // should be true.
1007 DCHECK(timer_pending_);
1008 timer_pending_ = false;
initial.commit09911bf2008-07-26 23:55:291009
1010 DCHECK(!current_fetch_.get());
initial.commit09911bf2008-07-26 23:55:291011
petersont@google.comd01b8732008-10-16 02:18:071012 // If we're getting no notifications, then the log won't have much in it, and
1013 // it's possible the computer is about to go to sleep, so don't upload and
1014 // don't restart the transmission timer.
1015 if (idle_since_last_transmission_)
1016 return;
1017
1018 // If somehow there is a fetch in progress, we return setting timer_pending_
1019 // to true and hope things work out.
1020 if (current_fetch_.get()) {
1021 timer_pending_ = true;
1022 return;
1023 }
1024
1025 // If uploads are forbidden by UMA response, there's no point in keeping
1026 // the current_log_, and the more often we delete it, the less likely it is
1027 // to expand forever.
1028 if (!server_permits_upload_ && current_log_) {
1029 StopRecording(NULL);
1030 StartRecording();
1031 }
initial.commit09911bf2008-07-26 23:55:291032
1033 if (!current_log_)
1034 return; // Logging was disabled.
petersont@google.comd01b8732008-10-16 02:18:071035 if (!reporting_active())
initial.commit09911bf2008-07-26 23:55:291036 return; // Don't do work if we're not going to send anything now.
1037
petersont@google.comd01b8732008-10-16 02:18:071038 MakePendingLog();
initial.commit09911bf2008-07-26 23:55:291039
petersont@google.comd01b8732008-10-16 02:18:071040 // MakePendingLog should have put something in the pending log, if it didn't,
1041 // we start the timer again, return and hope things work out.
1042 if (!pending_log()) {
1043 StartLogTransmissionTimer();
1044 return;
1045 }
initial.commit09911bf2008-07-26 23:55:291046
petersont@google.comd01b8732008-10-16 02:18:071047 // If we're not supposed to upload any UMA data because the response or the
1048 // user said so, cancel the upload at this point, but start the timer.
1049 if (!TransmissionPermitted()) {
1050 DiscardPendingLog();
1051 StartLogTransmissionTimer();
1052 return;
1053 }
initial.commit09911bf2008-07-26 23:55:291054
petersont@google.comd01b8732008-10-16 02:18:071055 PrepareFetchWithPendingLog();
1056
1057 if (!current_fetch_.get()) {
1058 // Compression failed, and log discarded :-/.
1059 DiscardPendingLog();
1060 StartLogTransmissionTimer(); // Maybe we'll do better next time
1061 // TODO(jar): If compression failed, we should have created a tiny log and
1062 // compressed that, so that we can signal that we're losing logs.
1063 return;
1064 }
1065
1066 DCHECK(!timer_pending_);
1067
1068 // The URL fetch is a like timer in that after a while we get called back
1069 // so we set timer_pending_ true just as we start the url fetch.
1070 timer_pending_ = true;
1071 current_fetch_->Start();
1072
1073 HandleIdleSinceLastTransmission(true);
1074}
1075
1076
1077void MetricsService::MakePendingLog() {
1078 if (pending_log())
1079 return;
1080
1081 switch (state_) {
1082 case INITIALIZED:
zelidrag@chromium.org85ed9d42010-06-08 22:37:441083 case INIT_TASK_SCHEDULED: // We should be further along by now.
petersont@google.comd01b8732008-10-16 02:18:071084 DCHECK(false);
1085 return;
1086
zelidrag@chromium.org85ed9d42010-06-08 22:37:441087 case INIT_TASK_DONE:
petersont@google.comd01b8732008-10-16 02:18:071088 // We need to wait for the initial log to be ready before sending
1089 // anything, because the server will tell us whether it wants to hear
1090 // from us.
1091 PrepareInitialLog();
zelidrag@chromium.org85ed9d42010-06-08 22:37:441092 DCHECK(state_ == INIT_TASK_DONE);
petersont@google.comd01b8732008-10-16 02:18:071093 RecallUnsentLogs();
1094 state_ = INITIAL_LOG_READY;
1095 break;
1096
1097 case SEND_OLD_INITIAL_LOGS:
pkasting@chromium.orgcac78842008-11-27 01:02:201098 if (!unsent_initial_logs_.empty()) {
ziadh@chromium.org46f89e142010-07-19 08:00:421099 compressed_log_ = unsent_initial_logs_.back();
pkasting@chromium.orgcac78842008-11-27 01:02:201100 break;
1101 }
petersont@google.comd01b8732008-10-16 02:18:071102 state_ = SENDING_OLD_LOGS;
1103 // Fall through.
initial.commit09911bf2008-07-26 23:55:291104
petersont@google.comd01b8732008-10-16 02:18:071105 case SENDING_OLD_LOGS:
1106 if (!unsent_ongoing_logs_.empty()) {
ziadh@chromium.org46f89e142010-07-19 08:00:421107 compressed_log_ = unsent_ongoing_logs_.back();
petersont@google.comd01b8732008-10-16 02:18:071108 break;
1109 }
1110 state_ = SENDING_CURRENT_LOGS;
1111 // Fall through.
1112
1113 case SENDING_CURRENT_LOGS:
1114 StopRecording(&pending_log_);
1115 StartRecording();
1116 break;
1117
1118 default:
jar@chromium.orga063c102010-07-22 22:20:191119 NOTREACHED();
petersont@google.comd01b8732008-10-16 02:18:071120 return;
1121 }
1122
1123 DCHECK(pending_log());
1124}
1125
1126bool MetricsService::TransmissionPermitted() const {
1127 // If the user forbids uploading that's they're business, and we don't upload
1128 // anything. If the server forbids uploading, that's our business, so we take
1129 // that to mean it forbids current logs, but we still send up the inital logs
1130 // and any old logs.
petersont@google.comd01b8732008-10-16 02:18:071131 if (!user_permits_upload_)
1132 return false;
pkasting@chromium.orgcac78842008-11-27 01:02:201133 if (server_permits_upload_)
petersont@google.comd01b8732008-10-16 02:18:071134 return true;
initial.commit09911bf2008-07-26 23:55:291135
pkasting@chromium.orgcac78842008-11-27 01:02:201136 switch (state_) {
1137 case INITIAL_LOG_READY:
1138 case SEND_OLD_INITIAL_LOGS:
1139 case SENDING_OLD_LOGS:
1140 return true;
1141
1142 case SENDING_CURRENT_LOGS:
1143 default:
1144 return false;
nsylvain@chromium.org8c8824b2008-09-20 01:55:501145 }
initial.commit09911bf2008-07-26 23:55:291146}
1147
initial.commit09911bf2008-07-26 23:55:291148void MetricsService::PrepareInitialLog() {
zelidrag@chromium.org85ed9d42010-06-08 22:37:441149 DCHECK(state_ == INIT_TASK_DONE);
initial.commit09911bf2008-07-26 23:55:291150
1151 MetricsLog* log = new MetricsLog(client_id_, session_id_);
zelidrag@chromium.org85ed9d42010-06-08 22:37:441152 log->set_hardware_class(hardware_class_); // Adds to initial log.
jam@chromium.org35fa6a22009-08-15 00:04:011153 log->RecordEnvironment(plugins_, profile_dictionary_.get());
initial.commit09911bf2008-07-26 23:55:291154
1155 // Histograms only get written to current_log_, so setup for the write.
ananta@chromium.org1226abb2010-06-10 18:01:281156 MetricsLogBase* save_log = current_log_;
initial.commit09911bf2008-07-26 23:55:291157 current_log_ = log;
1158 RecordCurrentHistograms(); // Into current_log_... which is really log.
1159 current_log_ = save_log;
1160
1161 log->CloseLog();
1162 DCHECK(!pending_log());
1163 pending_log_ = log;
1164}
1165
ziadh@chromium.org46f89e142010-07-19 08:00:421166// static
1167MetricsService::LogRecallStatus MetricsService::RecallUnsentLogsHelper(
1168 const ListValue& list,
1169 std::vector<std::string>* local_list) {
1170 DCHECK(local_list->empty());
1171 if (list.GetSize() == 0)
1172 return MakeRecallStatusHistogram(LIST_EMPTY);
1173 if (list.GetSize() < 3)
1174 return MakeRecallStatusHistogram(LIST_SIZE_TOO_SMALL);
initial.commit09911bf2008-07-26 23:55:291175
ziadh@chromium.org46f89e142010-07-19 08:00:421176 // The size is stored at the beginning of the list.
1177 int size;
1178 bool valid = (*list.begin())->GetAsInteger(&size);
1179 if (!valid)
1180 return MakeRecallStatusHistogram(LIST_SIZE_MISSING);
1181
1182 // Account for checksum and size included in the list.
1183 if (static_cast<unsigned int>(size) !=
1184 list.GetSize() - kChecksumEntryCount)
1185 return MakeRecallStatusHistogram(LIST_SIZE_CORRUPTION);
1186
1187 MD5Context ctx;
1188 MD5Init(&ctx);
1189 std::string encoded_log;
1190 std::string decoded_log;
1191 for (ListValue::const_iterator it = list.begin() + 1;
1192 it != list.end() - 1; ++it) { // Last element is the checksum.
1193 valid = (*it)->GetAsString(&encoded_log);
1194 if (!valid) {
1195 local_list->clear();
1196 return MakeRecallStatusHistogram(LOG_STRING_CORRUPTION);
1197 }
1198
1199 MD5Update(&ctx, encoded_log.data(), encoded_log.length());
1200
1201 if (!base::Base64Decode(encoded_log, &decoded_log)) {
1202 local_list->clear();
1203 return MakeRecallStatusHistogram(DECODE_FAIL);
1204 }
1205 local_list->push_back(decoded_log);
1206 }
1207
1208 // Verify checksum.
1209 MD5Digest digest;
1210 MD5Final(&digest, &ctx);
1211 std::string recovered_md5;
1212 // We store the hash at the end of the list.
1213 valid = (*(list.end() - 1))->GetAsString(&recovered_md5);
1214 if (!valid) {
1215 local_list->clear();
1216 return MakeRecallStatusHistogram(CHECKSUM_STRING_CORRUPTION);
1217 }
1218 if (recovered_md5 != MD5DigestToBase16(digest)) {
1219 local_list->clear();
1220 return MakeRecallStatusHistogram(CHECKSUM_CORRUPTION);
1221 }
1222 return MakeRecallStatusHistogram(RECALL_SUCCESS);
1223}
1224void MetricsService::RecallUnsentLogs() {
initial.commit09911bf2008-07-26 23:55:291225 PrefService* local_state = g_browser_process->local_state();
1226 DCHECK(local_state);
1227
1228 ListValue* unsent_initial_logs = local_state->GetMutableList(
1229 prefs::kMetricsInitialLogs);
ziadh@chromium.org46f89e142010-07-19 08:00:421230 RecallUnsentLogsHelper(*unsent_initial_logs, &unsent_initial_logs_);
initial.commit09911bf2008-07-26 23:55:291231
1232 ListValue* unsent_ongoing_logs = local_state->GetMutableList(
1233 prefs::kMetricsOngoingLogs);
ziadh@chromium.org46f89e142010-07-19 08:00:421234 RecallUnsentLogsHelper(*unsent_ongoing_logs, &unsent_ongoing_logs_);
1235}
1236
1237// static
1238void MetricsService::StoreUnsentLogsHelper(
1239 const std::vector<std::string>& local_list,
1240 const size_t kMaxLocalListSize,
1241 ListValue* list) {
1242 list->Clear();
1243 size_t start = 0;
1244 if (local_list.size() > kMaxLocalListSize)
1245 start = local_list.size() - kMaxLocalListSize;
1246 DCHECK(start <= local_list.size());
1247 if (local_list.size() == start)
1248 return;
1249
1250 // Store size at the beginning of the list.
1251 list->Append(Value::CreateIntegerValue(local_list.size() - start));
1252
1253 MD5Context ctx;
1254 MD5Init(&ctx);
1255 std::string encoded_log;
1256 for (std::vector<std::string>::const_iterator it = local_list.begin() + start;
1257 it != local_list.end(); ++it) {
1258 // We encode the compressed log as Value::CreateStringValue() expects to
1259 // take a valid UTF8 string.
1260 if (!base::Base64Encode(*it, &encoded_log)) {
1261 MakeStoreStatusHistogram(ENCODE_FAIL);
1262 list->Clear();
1263 return;
1264 }
1265 MD5Update(&ctx, encoded_log.data(), encoded_log.length());
1266 list->Append(Value::CreateStringValue(encoded_log));
initial.commit09911bf2008-07-26 23:55:291267 }
ziadh@chromium.org46f89e142010-07-19 08:00:421268
1269 // Append hash to the end of the list.
1270 MD5Digest digest;
1271 MD5Final(&digest, &ctx);
1272 list->Append(Value::CreateStringValue(MD5DigestToBase16(digest)));
1273 DCHECK(list->GetSize() >= 3); // Minimum of 3 elements (size, data, hash).
ziadh@chromium.org4e95d202010-07-24 01:47:561274 MakeStoreStatusHistogram(STORE_SUCCESS);
initial.commit09911bf2008-07-26 23:55:291275}
1276
1277void MetricsService::StoreUnsentLogs() {
1278 if (state_ < INITIAL_LOG_READY)
1279 return; // We never Recalled the prior unsent logs.
1280
1281 PrefService* local_state = g_browser_process->local_state();
1282 DCHECK(local_state);
1283
1284 ListValue* unsent_initial_logs = local_state->GetMutableList(
1285 prefs::kMetricsInitialLogs);
ziadh@chromium.org46f89e142010-07-19 08:00:421286 StoreUnsentLogsHelper(unsent_initial_logs_, kMaxInitialLogsPersisted,
1287 unsent_initial_logs);
initial.commit09911bf2008-07-26 23:55:291288
1289 ListValue* unsent_ongoing_logs = local_state->GetMutableList(
1290 prefs::kMetricsOngoingLogs);
ziadh@chromium.org46f89e142010-07-19 08:00:421291 StoreUnsentLogsHelper(unsent_ongoing_logs_, kMaxOngoingLogsPersisted,
1292 unsent_ongoing_logs);
initial.commit09911bf2008-07-26 23:55:291293}
1294
1295void MetricsService::PreparePendingLogText() {
1296 DCHECK(pending_log());
ziadh@chromium.org46f89e142010-07-19 08:00:421297 if (!compressed_log_.empty())
initial.commit09911bf2008-07-26 23:55:291298 return;
mark@chromium.org9ffcccf42009-09-15 22:19:181299 int text_size = pending_log_->GetEncodedLogSize();
1300
ziadh@chromium.org46f89e142010-07-19 08:00:421301 std::string pending_log_text;
1302 // Leave room for the NULL terminator.
1303 pending_log_->GetEncodedLog(WriteInto(&pending_log_text, text_size + 1),
mark@chromium.org9ffcccf42009-09-15 22:19:181304 text_size);
ziadh@chromium.org46f89e142010-07-19 08:00:421305
1306 if (Bzip2Compress(pending_log_text, &compressed_log_)) {
1307 // Allow security conscious users to see all metrics logs that we send.
1308 LOG(INFO) << "COMPRESSED FOLLOWING METRICS LOG: " << pending_log_text;
1309 } else {
1310 LOG(DFATAL) << "Failed to compress log for transmission.";
1311 // We can't discard the logs as other caller functions expect that
1312 // |compressed_log_| not be empty. We can detect this failure at the server
1313 // after we transmit.
1314 compressed_log_ = "Unable to compress!";
1315 MakeStoreStatusHistogram(COMPRESS_FAIL);
1316 return;
1317 }
initial.commit09911bf2008-07-26 23:55:291318}
1319
petersont@google.comd01b8732008-10-16 02:18:071320void MetricsService::PrepareFetchWithPendingLog() {
initial.commit09911bf2008-07-26 23:55:291321 DCHECK(pending_log());
1322 DCHECK(!current_fetch_.get());
1323 PreparePendingLogText();
ziadh@chromium.org46f89e142010-07-19 08:00:421324 DCHECK(!compressed_log_.empty());
pkasting@chromium.orgcac78842008-11-27 01:02:201325
kuchhal@chromium.org79bf0b72009-04-27 21:30:551326 current_fetch_.reset(new URLFetcher(GURL(WideToUTF16(server_url_)),
1327 URLFetcher::POST,
initial.commit09911bf2008-07-26 23:55:291328 this));
1329 current_fetch_->set_request_context(Profile::GetDefaultRequestContext());
ziadh@chromium.org46f89e142010-07-19 08:00:421330 current_fetch_->set_upload_data(kMetricsType, compressed_log_);
initial.commit09911bf2008-07-26 23:55:291331}
1332
initial.commit09911bf2008-07-26 23:55:291333static const char* StatusToString(const URLRequestStatus& status) {
1334 switch (status.status()) {
1335 case URLRequestStatus::SUCCESS:
1336 return "SUCCESS";
1337
1338 case URLRequestStatus::IO_PENDING:
1339 return "IO_PENDING";
1340
1341 case URLRequestStatus::HANDLED_EXTERNALLY:
1342 return "HANDLED_EXTERNALLY";
1343
1344 case URLRequestStatus::CANCELED:
1345 return "CANCELED";
1346
1347 case URLRequestStatus::FAILED:
1348 return "FAILED";
1349
1350 default:
jar@chromium.orga063c102010-07-22 22:20:191351 NOTREACHED();
initial.commit09911bf2008-07-26 23:55:291352 return "Unknown";
1353 }
1354}
1355
1356void MetricsService::OnURLFetchComplete(const URLFetcher* source,
1357 const GURL& url,
1358 const URLRequestStatus& status,
1359 int response_code,
1360 const ResponseCookies& cookies,
1361 const std::string& data) {
1362 DCHECK(timer_pending_);
1363 timer_pending_ = false;
1364 DCHECK(current_fetch_.get());
1365 current_fetch_.reset(NULL); // We're not allowed to re-use it.
1366
1367 // Confirm send so that we can move on.
jar@chromium.org281d2882009-01-20 20:32:421368 LOG(INFO) << "METRICS RESPONSE CODE: " << response_code << " status=" <<
pkasting@chromium.orgcac78842008-11-27 01:02:201369 StatusToString(status);
petersont@google.com252873ef2008-08-04 21:59:451370
jar@chromium.org0eb34fee2009-01-21 08:04:381371 // Provide boolean for error recovery (allow us to ignore response_code).
paul@chromium.orgdc6f4962009-02-13 01:25:501372 bool discard_log = false;
jar@chromium.org0eb34fee2009-01-21 08:04:381373
jar@google.com68475e602008-08-22 03:21:151374 if (response_code != 200 &&
ziadh@chromium.org46f89e142010-07-19 08:00:421375 (compressed_log_.length() >
1376 static_cast<size_t>(kUploadLogAvoidRetransmitSize))) {
dsh@google.com553dba62009-02-24 19:08:231377 UMA_HISTOGRAM_COUNTS("UMA.Large Rejected Log was Discarded",
ziadh@chromium.org46f89e142010-07-19 08:00:421378 static_cast<int>(compressed_log_.length()));
jar@chromium.org0eb34fee2009-01-21 08:04:381379 discard_log = true;
1380 } else if (response_code == 400) {
1381 // Bad syntax. Retransmission won't work.
dsh@google.com553dba62009-02-24 19:08:231382 UMA_HISTOGRAM_COUNTS("UMA.Unacceptable_Log_Discarded", state_);
jar@chromium.org0eb34fee2009-01-21 08:04:381383 discard_log = true;
jar@google.com68475e602008-08-22 03:21:151384 }
1385
jar@chromium.org0eb34fee2009-01-21 08:04:381386 if (response_code != 200 && !discard_log) {
jar@chromium.org281d2882009-01-20 20:32:421387 LOG(INFO) << "METRICS: transmission attempt returned a failure code: "
1388 << response_code << ". Verify network connectivity";
petersont@google.com252873ef2008-08-04 21:59:451389 HandleBadResponseCode();
jar@chromium.org0eb34fee2009-01-21 08:04:381390 } else { // Successful receipt (or we are discarding log).
jar@chromium.org281d2882009-01-20 20:32:421391 LOG(INFO) << "METRICS RESPONSE DATA: " << data;
initial.commit09911bf2008-07-26 23:55:291392 switch (state_) {
1393 case INITIAL_LOG_READY:
1394 state_ = SEND_OLD_INITIAL_LOGS;
1395 break;
1396
1397 case SEND_OLD_INITIAL_LOGS:
1398 DCHECK(!unsent_initial_logs_.empty());
1399 unsent_initial_logs_.pop_back();
1400 StoreUnsentLogs();
1401 break;
1402
1403 case SENDING_OLD_LOGS:
1404 DCHECK(!unsent_ongoing_logs_.empty());
1405 unsent_ongoing_logs_.pop_back();
1406 StoreUnsentLogs();
1407 break;
1408
1409 case SENDING_CURRENT_LOGS:
1410 break;
1411
1412 default:
jar@chromium.orga063c102010-07-22 22:20:191413 NOTREACHED();
initial.commit09911bf2008-07-26 23:55:291414 break;
1415 }
petersont@google.comd01b8732008-10-16 02:18:071416
initial.commit09911bf2008-07-26 23:55:291417 DiscardPendingLog();
jar@google.com29be92552008-08-07 22:49:271418 // Since we sent a log, make sure our in-memory state is recorded to disk.
1419 PrefService* local_state = g_browser_process->local_state();
1420 DCHECK(local_state);
1421 if (local_state)
phajdan.jr@chromium.org6faa0e0d2009-04-28 06:50:361422 local_state->ScheduleSavePersistentPrefs();
petersont@google.com252873ef2008-08-04 21:59:451423
jar@google.com147bbc0b2009-01-06 19:37:401424 // Provide a default (free of exponetial backoff, other varances) in case
1425 // the server does not specify a value.
1426 interlog_duration_ = TimeDelta::FromSeconds(kMinSecondsPerLog);
1427
petersont@google.com252873ef2008-08-04 21:59:451428 GetSettingsFromResponseData(data);
petersont@google.com252873ef2008-08-04 21:59:451429 // Override server specified interlog delay if there are unsent logs to
jar@google.com29be92552008-08-07 22:49:271430 // transmit.
initial.commit09911bf2008-07-26 23:55:291431 if (unsent_logs()) {
1432 DCHECK(state_ < SENDING_CURRENT_LOGS);
1433 interlog_duration_ = TimeDelta::FromSeconds(kUnsentLogDelay);
initial.commit09911bf2008-07-26 23:55:291434 }
1435 }
petersont@google.com252873ef2008-08-04 21:59:451436
initial.commit09911bf2008-07-26 23:55:291437 StartLogTransmissionTimer();
1438}
1439
petersont@google.com252873ef2008-08-04 21:59:451440void MetricsService::HandleBadResponseCode() {
jar@chromium.org281d2882009-01-20 20:32:421441 LOG(INFO) << "Verify your metrics logs are formatted correctly. "
kuchhal@chromium.org79bf0b72009-04-27 21:30:551442 "Verify server is active at " << server_url_;
petersont@google.com252873ef2008-08-04 21:59:451443 if (!pending_log()) {
jar@chromium.org281d2882009-01-20 20:32:421444 LOG(INFO) << "METRICS: Recorder shutdown during log transmission.";
petersont@google.com252873ef2008-08-04 21:59:451445 } else {
1446 // Send progressively less frequently.
1447 DCHECK(kBackoff > 1.0);
1448 interlog_duration_ = TimeDelta::FromMicroseconds(
1449 static_cast<int64>(kBackoff * interlog_duration_.InMicroseconds()));
1450
1451 if (kMaxBackoff * TimeDelta::FromSeconds(kMinSecondsPerLog) <
pkasting@chromium.orgcac78842008-11-27 01:02:201452 interlog_duration_) {
petersont@google.com252873ef2008-08-04 21:59:451453 interlog_duration_ = kMaxBackoff *
1454 TimeDelta::FromSeconds(kMinSecondsPerLog);
pkasting@chromium.orgcac78842008-11-27 01:02:201455 }
petersont@google.com252873ef2008-08-04 21:59:451456
jar@chromium.org281d2882009-01-20 20:32:421457 LOG(INFO) << "METRICS: transmission retry being scheduled in " <<
petersont@google.com252873ef2008-08-04 21:59:451458 interlog_duration_.InSeconds() << " seconds for " <<
ziadh@chromium.org46f89e142010-07-19 08:00:421459 compressed_log_;
initial.commit09911bf2008-07-26 23:55:291460 }
initial.commit09911bf2008-07-26 23:55:291461}
1462
petersont@google.com252873ef2008-08-04 21:59:451463void MetricsService::GetSettingsFromResponseData(const std::string& data) {
1464 // We assume that the file is structured as a block opened by <response>
petersont@google.comd01b8732008-10-16 02:18:071465 // and that inside response, there is a block opened by tag <chrome_config>
1466 // other tags are ignored for now except the content of <chrome_config>.
jar@chromium.org281d2882009-01-20 20:32:421467 LOG(INFO) << "METRICS: getting settings from response data: " << data;
petersont@google.comd01b8732008-10-16 02:18:071468
petersont@google.com252873ef2008-08-04 21:59:451469 int data_size = static_cast<int>(data.size());
1470 if (data_size < 0) {
jar@chromium.org281d2882009-01-20 20:32:421471 LOG(INFO) << "METRICS: server response data bad size: " << data_size <<
pkasting@chromium.orgcac78842008-11-27 01:02:201472 "; aborting extraction of settings";
petersont@google.com252873ef2008-08-04 21:59:451473 return;
1474 }
pkasting@chromium.orgcac78842008-11-27 01:02:201475 xmlDocPtr doc = xmlReadMemory(data.c_str(), data_size, "", NULL, 0);
petersont@google.comd01b8732008-10-16 02:18:071476 // If the document is malformed, we just use the settings that were there.
1477 if (!doc) {
jar@chromium.org281d2882009-01-20 20:32:421478 LOG(INFO) << "METRICS: reading xml from server response data failed";
petersont@google.com252873ef2008-08-04 21:59:451479 return;
petersont@google.comd01b8732008-10-16 02:18:071480 }
petersont@google.com252873ef2008-08-04 21:59:451481
petersont@google.comd01b8732008-10-16 02:18:071482 xmlNodePtr top_node = xmlDocGetRootElement(doc), chrome_config_node = NULL;
1483 // Here, we find the chrome_config node by name.
petersont@google.com252873ef2008-08-04 21:59:451484 for (xmlNodePtr p = top_node->children; p; p = p->next) {
petersont@google.comd01b8732008-10-16 02:18:071485 if (xmlStrEqual(p->name, BAD_CAST "chrome_config")) {
1486 chrome_config_node = p;
petersont@google.com252873ef2008-08-04 21:59:451487 break;
1488 }
1489 }
1490 // If the server data is formatted wrong and there is no
1491 // config node where we expect, we just drop out.
petersont@google.comd01b8732008-10-16 02:18:071492 if (chrome_config_node != NULL)
1493 GetSettingsFromChromeConfigNode(chrome_config_node);
petersont@google.com252873ef2008-08-04 21:59:451494 xmlFreeDoc(doc);
1495}
1496
petersont@google.comd01b8732008-10-16 02:18:071497void MetricsService::GetSettingsFromChromeConfigNode(
1498 xmlNodePtr chrome_config_node) {
1499 // Iterate through all children of the config node.
1500 for (xmlNodePtr current_node = chrome_config_node->children;
1501 current_node;
1502 current_node = current_node->next) {
1503 // If we find the upload tag, we appeal to another function
1504 // GetSettingsFromUploadNode to read all the data in it.
petersont@google.com252873ef2008-08-04 21:59:451505 if (xmlStrEqual(current_node->name, BAD_CAST "upload")) {
petersont@google.comd01b8732008-10-16 02:18:071506 GetSettingsFromUploadNode(current_node);
petersont@google.com252873ef2008-08-04 21:59:451507 continue;
1508 }
1509 }
1510}
initial.commit09911bf2008-07-26 23:55:291511
petersont@google.comd01b8732008-10-16 02:18:071512void MetricsService::InheritedProperties::OverwriteWhereNeeded(
1513 xmlNodePtr node) {
1514 xmlChar* salt_value = xmlGetProp(node, BAD_CAST "salt");
1515 if (salt_value) // If the property isn't there, xmlGetProp returns NULL.
1516 salt = atoi(reinterpret_cast<char*>(salt_value));
1517 // If the property isn't there, we keep the value the property had before
1518
1519 xmlChar* denominator_value = xmlGetProp(node, BAD_CAST "denominator");
1520 if (denominator_value)
1521 denominator = atoi(reinterpret_cast<char*>(denominator_value));
1522}
1523
1524void MetricsService::GetSettingsFromUploadNode(xmlNodePtr upload_node) {
1525 InheritedProperties props;
1526 GetSettingsFromUploadNodeRecursive(upload_node, props, "", true);
1527}
1528
pkasting@chromium.orgcac78842008-11-27 01:02:201529void MetricsService::GetSettingsFromUploadNodeRecursive(
1530 xmlNodePtr node,
1531 InheritedProperties props,
1532 std::string path_prefix,
1533 bool uploadOn) {
petersont@google.comd01b8732008-10-16 02:18:071534 props.OverwriteWhereNeeded(node);
1535
1536 // The bool uploadOn is set to true if the data represented by current
1537 // node should be uploaded. This gets inherited in the tree; the children
1538 // of a node that has already been rejected for upload get rejected for
1539 // upload.
1540 uploadOn = uploadOn && NodeProbabilityTest(node, props);
1541
1542 // The path is a / separated list of the node names ancestral to the current
1543 // one. So, if you want to check if the current node has a certain name,
1544 // compare to name. If you want to check if it is a certan tag at a certain
1545 // place in the tree, compare to the whole path.
1546 std::string name = std::string(reinterpret_cast<const char*>(node->name));
1547 std::string path = path_prefix + "/" + name;
1548
1549 if (path == "/upload") {
1550 xmlChar* upload_interval_val = xmlGetProp(node, BAD_CAST "interval");
1551 if (upload_interval_val) {
1552 interlog_duration_ = TimeDelta::FromSeconds(
1553 atoi(reinterpret_cast<char*>(upload_interval_val)));
1554 }
1555
1556 server_permits_upload_ = uploadOn;
ziadh@chromium.org24d07e32010-07-10 00:31:271557 } else if (path == "/upload/logs") {
petersont@google.comd01b8732008-10-16 02:18:071558 xmlChar* log_event_limit_val = xmlGetProp(node, BAD_CAST "event_limit");
1559 if (log_event_limit_val)
1560 log_event_limit_ = atoi(reinterpret_cast<char*>(log_event_limit_val));
1561 }
petersont@google.comd01b8732008-10-16 02:18:071562
1563 // Recursive call. If the node is a leaf i.e. if it ends in a "/>", then it
1564 // doesn't have children, so node->children is NULL, and this loop doesn't
1565 // call (that's how the recursion ends).
1566 for (xmlNodePtr child_node = node->children;
pkasting@chromium.orgcac78842008-11-27 01:02:201567 child_node;
1568 child_node = child_node->next) {
petersont@google.comd01b8732008-10-16 02:18:071569 GetSettingsFromUploadNodeRecursive(child_node, props, path, uploadOn);
1570 }
1571}
1572
1573bool MetricsService::NodeProbabilityTest(xmlNodePtr node,
pkasting@chromium.orgcac78842008-11-27 01:02:201574 InheritedProperties props) const {
petersont@google.comd01b8732008-10-16 02:18:071575 // Default value of probability on any node is 1, but recall that
1576 // its parents can already have been rejected for upload.
1577 double probability = 1;
1578
1579 // If a probability is specified in the node, we use it instead.
1580 xmlChar* probability_value = xmlGetProp(node, BAD_CAST "probability");
1581 if (probability_value)
jar@google.com0b33f80b2008-12-17 21:34:361582 probability = atoi(reinterpret_cast<char*>(probability_value));
petersont@google.comd01b8732008-10-16 02:18:071583
1584 return ProbabilityTest(probability, props.salt, props.denominator);
1585}
1586
1587bool MetricsService::ProbabilityTest(double probability,
1588 int salt,
1589 int denominator) const {
1590 // Okay, first we figure out how many of the digits of the
1591 // client_id_ we need in order to make a nice pseudorandomish
1592 // number in the range [0,denominator). Too many digits is
1593 // fine.
petersont@google.comd01b8732008-10-16 02:18:071594
1595 // n is the length of the client_id_ string
1596 size_t n = client_id_.size();
1597
1598 // idnumber is a positive integer generated from the client_id_.
1599 // It plus salt is going to give us our pseudorandom number.
1600 int idnumber = 0;
1601 const char* client_id_c_str = client_id_.c_str();
1602
1603 // Here we hash the relevant digits of the client_id_
1604 // string somehow to get a big integer idnumber (could be negative
1605 // from wraparound)
1606 int big = 1;
robertshield@google.com5ed73342009-03-18 17:39:431607 int last_pos = n - 1;
1608 for (size_t j = 0; j < n; ++j) {
1609 idnumber += static_cast<int>(client_id_c_str[last_pos - j]) * big;
petersont@google.comd01b8732008-10-16 02:18:071610 big *= 10;
1611 }
1612
1613 // Mod id number by denominator making sure to get a non-negative
1614 // answer.
pkasting@chromium.orgcac78842008-11-27 01:02:201615 idnumber = ((idnumber % denominator) + denominator) % denominator;
petersont@google.comd01b8732008-10-16 02:18:071616
pkasting@chromium.orgcac78842008-11-27 01:02:201617 // ((idnumber + salt) % denominator) / denominator is in the range [0,1]
petersont@google.comd01b8732008-10-16 02:18:071618 // if it's less than probability we call that an affirmative coin
1619 // toss.
pkasting@chromium.orgcac78842008-11-27 01:02:201620 return static_cast<double>((idnumber + salt) % denominator) <
1621 probability * denominator;
petersont@google.comd01b8732008-10-16 02:18:071622}
1623
initial.commit09911bf2008-07-26 23:55:291624void MetricsService::LogWindowChange(NotificationType type,
1625 const NotificationSource& source,
1626 const NotificationDetails& details) {
brettw@google.com534e54b2008-08-13 15:40:091627 int controller_id = -1;
1628 uintptr_t window_or_tab = source.map_key();
initial.commit09911bf2008-07-26 23:55:291629 MetricsLog::WindowEventType window_type;
1630
1631 // Note: since we stop all logging when a single OTR session is active, it is
1632 // possible that we start getting notifications about a window that we don't
1633 // know about.
brettw@google.com534e54b2008-08-13 15:40:091634 if (window_map_.find(window_or_tab) == window_map_.end()) {
1635 controller_id = next_window_id_++;
1636 window_map_[window_or_tab] = controller_id;
initial.commit09911bf2008-07-26 23:55:291637 } else {
brettw@google.com534e54b2008-08-13 15:40:091638 controller_id = window_map_[window_or_tab];
initial.commit09911bf2008-07-26 23:55:291639 }
jar@chromium.org92745242009-06-12 16:52:211640 DCHECK_NE(controller_id, -1);
initial.commit09911bf2008-07-26 23:55:291641
brettw@chromium.orgbfd04a62009-02-01 18:16:561642 switch (type.value) {
1643 case NotificationType::TAB_PARENTED:
1644 case NotificationType::BROWSER_OPENED:
initial.commit09911bf2008-07-26 23:55:291645 window_type = MetricsLog::WINDOW_CREATE;
1646 break;
1647
brettw@chromium.orgbfd04a62009-02-01 18:16:561648 case NotificationType::TAB_CLOSING:
1649 case NotificationType::BROWSER_CLOSED:
brettw@google.com534e54b2008-08-13 15:40:091650 window_map_.erase(window_map_.find(window_or_tab));
initial.commit09911bf2008-07-26 23:55:291651 window_type = MetricsLog::WINDOW_DESTROY;
1652 break;
1653
1654 default:
jar@chromium.orga063c102010-07-22 22:20:191655 NOTREACHED();
paul@chromium.org68d74f02009-02-13 01:36:501656 return;
initial.commit09911bf2008-07-26 23:55:291657 }
1658
brettw@google.com534e54b2008-08-13 15:40:091659 // TODO(brettw) we should have some kind of ID for the parent.
1660 current_log_->RecordWindowEvent(window_type, controller_id, 0);
initial.commit09911bf2008-07-26 23:55:291661}
1662
1663void MetricsService::LogLoadComplete(NotificationType type,
1664 const NotificationSource& source,
1665 const NotificationDetails& details) {
1666 if (details == NotificationService::NoDetails())
1667 return;
1668
jar@google.com68475e602008-08-22 03:21:151669 // TODO(jar): There is a bug causing this to be called too many times, and
1670 // the log overflows. For now, we won't record these events.
dsh@google.com553dba62009-02-24 19:08:231671 UMA_HISTOGRAM_COUNTS("UMA.LogLoadComplete called", 1);
jar@google.com68475e602008-08-22 03:21:151672 return;
1673
initial.commit09911bf2008-07-26 23:55:291674 const Details<LoadNotificationDetails> load_details(details);
brettw@google.com534e54b2008-08-13 15:40:091675 int controller_id = window_map_[details.map_key()];
1676 current_log_->RecordLoadEvent(controller_id,
initial.commit09911bf2008-07-26 23:55:291677 load_details->url(),
1678 load_details->origin(),
1679 load_details->session_index(),
1680 load_details->load_time());
1681}
1682
viettrungluu@chromium.org57ecc4b2010-08-11 03:02:511683void MetricsService::IncrementPrefValue(const char* path) {
cpu@google.come73c01972008-08-13 00:18:241684 PrefService* pref = g_browser_process->local_state();
1685 DCHECK(pref);
1686 int value = pref->GetInteger(path);
1687 pref->SetInteger(path, value + 1);
1688}
1689
viettrungluu@chromium.org57ecc4b2010-08-11 03:02:511690void MetricsService::IncrementLongPrefsValue(const char* path) {
robertshield@google.com0bb1a622009-03-04 03:22:321691 PrefService* pref = g_browser_process->local_state();
1692 DCHECK(pref);
1693 int64 value = pref->GetInt64(path);
jar@chromium.orgb42c5e42010-06-03 20:43:251694 pref->SetInt64(path, value + 1);
robertshield@google.com0bb1a622009-03-04 03:22:321695}
1696
initial.commit09911bf2008-07-26 23:55:291697void MetricsService::LogLoadStarted() {
cpu@google.come73c01972008-08-13 00:18:241698 IncrementPrefValue(prefs::kStabilityPageLoadCount);
robertshield@google.com0bb1a622009-03-04 03:22:321699 IncrementLongPrefsValue(prefs::kUninstallMetricsPageLoadCount);
jar@google.com0b33f80b2008-12-17 21:34:361700 // We need to save the prefs, as page load count is a critical stat, and it
1701 // might be lost due to a crash :-(.
initial.commit09911bf2008-07-26 23:55:291702}
1703
initial.commit09911bf2008-07-26 23:55:291704void MetricsService::LogRendererCrash() {
cpu@google.come73c01972008-08-13 00:18:241705 IncrementPrefValue(prefs::kStabilityRendererCrashCount);
initial.commit09911bf2008-07-26 23:55:291706}
1707
asargent@chromium.org1f085622009-12-04 05:33:451708void MetricsService::LogExtensionRendererCrash() {
1709 IncrementPrefValue(prefs::kStabilityExtensionRendererCrashCount);
1710}
1711
initial.commit09911bf2008-07-26 23:55:291712void MetricsService::LogRendererHang() {
cpu@google.come73c01972008-08-13 00:18:241713 IncrementPrefValue(prefs::kStabilityRendererHangCount);
initial.commit09911bf2008-07-26 23:55:291714}
1715
jam@chromium.orga27a9382009-02-11 23:55:101716void MetricsService::LogChildProcessChange(
1717 NotificationType type,
1718 const NotificationSource& source,
1719 const NotificationDetails& details) {
gregoryd@google.com0d84c5d2009-10-09 01:10:421720 Details<ChildProcessInfo> child_details(details);
1721 const std::wstring& child_name = child_details->name();
1722
jam@chromium.orga27a9382009-02-11 23:55:101723 if (child_process_stats_buffer_.find(child_name) ==
1724 child_process_stats_buffer_.end()) {
gregoryd@google.com0d84c5d2009-10-09 01:10:421725 child_process_stats_buffer_[child_name] =
1726 ChildProcessStats(child_details->type());
initial.commit09911bf2008-07-26 23:55:291727 }
1728
jam@chromium.orga27a9382009-02-11 23:55:101729 ChildProcessStats& stats = child_process_stats_buffer_[child_name];
brettw@chromium.orgbfd04a62009-02-01 18:16:561730 switch (type.value) {
jam@chromium.orga27a9382009-02-11 23:55:101731 case NotificationType::CHILD_PROCESS_HOST_CONNECTED:
initial.commit09911bf2008-07-26 23:55:291732 stats.process_launches++;
1733 break;
1734
jam@chromium.orga27a9382009-02-11 23:55:101735 case NotificationType::CHILD_INSTANCE_CREATED:
initial.commit09911bf2008-07-26 23:55:291736 stats.instances++;
1737 break;
1738
jam@chromium.orga27a9382009-02-11 23:55:101739 case NotificationType::CHILD_PROCESS_CRASHED:
initial.commit09911bf2008-07-26 23:55:291740 stats.process_crashes++;
asargent@chromium.org1f085622009-12-04 05:33:451741 // Exclude plugin crashes from the count below because we report them via
1742 // a separate UMA metric.
1743 if (child_details->type() != ChildProcessInfo::PLUGIN_PROCESS) {
1744 IncrementPrefValue(prefs::kStabilityChildProcessCrashCount);
1745 }
initial.commit09911bf2008-07-26 23:55:291746 break;
1747
1748 default:
jar@chromium.orga063c102010-07-22 22:20:191749 NOTREACHED() << "Unexpected notification type " << type.value;
initial.commit09911bf2008-07-26 23:55:291750 return;
1751 }
1752}
1753
1754// Recursively counts the number of bookmarks and folders in node.
munjal@chromium.orgb3c33d462009-06-26 22:29:201755static void CountBookmarks(const BookmarkNode* node,
1756 int* bookmarks,
1757 int* folders) {
sky@chromium.org037db002009-10-19 20:06:081758 if (node->type() == BookmarkNode::URL)
initial.commit09911bf2008-07-26 23:55:291759 (*bookmarks)++;
1760 else
1761 (*folders)++;
1762 for (int i = 0; i < node->GetChildCount(); ++i)
1763 CountBookmarks(node->GetChild(i), bookmarks, folders);
1764}
1765
munjal@chromium.orgb3c33d462009-06-26 22:29:201766void MetricsService::LogBookmarks(const BookmarkNode* node,
viettrungluu@chromium.org57ecc4b2010-08-11 03:02:511767 const char* num_bookmarks_key,
1768 const char* num_folders_key) {
initial.commit09911bf2008-07-26 23:55:291769 DCHECK(node);
1770 int num_bookmarks = 0;
1771 int num_folders = 0;
1772 CountBookmarks(node, &num_bookmarks, &num_folders);
1773 num_folders--; // Don't include the root folder in the count.
1774
1775 PrefService* pref = g_browser_process->local_state();
1776 DCHECK(pref);
1777 pref->SetInteger(num_bookmarks_key, num_bookmarks);
1778 pref->SetInteger(num_folders_key, num_folders);
1779}
1780
sky@google.comd8e41ed2008-09-11 15:22:321781void MetricsService::LogBookmarks(BookmarkModel* model) {
initial.commit09911bf2008-07-26 23:55:291782 DCHECK(model);
1783 LogBookmarks(model->GetBookmarkBarNode(),
1784 prefs::kNumBookmarksOnBookmarkBar,
1785 prefs::kNumFoldersOnBookmarkBar);
1786 LogBookmarks(model->other_node(),
1787 prefs::kNumBookmarksInOtherBookmarkFolder,
1788 prefs::kNumFoldersInOtherBookmarkFolder);
1789 ScheduleNextStateSave();
1790}
1791
1792void MetricsService::LogKeywords(const TemplateURLModel* url_model) {
1793 DCHECK(url_model);
1794
1795 PrefService* pref = g_browser_process->local_state();
1796 DCHECK(pref);
1797 pref->SetInteger(prefs::kNumKeywords,
1798 static_cast<int>(url_model->GetTemplateURLs().size()));
1799 ScheduleNextStateSave();
1800}
1801
1802void MetricsService::RecordPluginChanges(PrefService* pref) {
1803 ListValue* plugins = pref->GetMutableList(prefs::kStabilityPluginStats);
1804 DCHECK(plugins);
1805
1806 for (ListValue::iterator value_iter = plugins->begin();
1807 value_iter != plugins->end(); ++value_iter) {
1808 if (!(*value_iter)->IsType(Value::TYPE_DICTIONARY)) {
jar@chromium.orga063c102010-07-22 22:20:191809 NOTREACHED();
initial.commit09911bf2008-07-26 23:55:291810 continue;
1811 }
1812
1813 DictionaryValue* plugin_dict = static_cast<DictionaryValue*>(*value_iter);
viettrungluu@chromium.org57ecc4b2010-08-11 03:02:511814 std::string plugin_name;
nsylvain@chromium.org8e50b602009-03-03 22:59:431815 plugin_dict->GetString(prefs::kStabilityPluginName, &plugin_name);
nsylvain@chromium.org6470ee8f2009-03-03 20:46:401816 if (plugin_name.empty()) {
jar@chromium.orga063c102010-07-22 22:20:191817 NOTREACHED();
initial.commit09911bf2008-07-26 23:55:291818 continue;
1819 }
1820
viettrungluu@chromium.org57ecc4b2010-08-11 03:02:511821 // TODO(viettrungluu): remove conversions
1822 if (child_process_stats_buffer_.find(UTF8ToWide(plugin_name)) ==
jam@chromium.orga27a9382009-02-11 23:55:101823 child_process_stats_buffer_.end())
initial.commit09911bf2008-07-26 23:55:291824 continue;
1825
viettrungluu@chromium.org57ecc4b2010-08-11 03:02:511826 ChildProcessStats stats =
1827 child_process_stats_buffer_[UTF8ToWide(plugin_name)];
initial.commit09911bf2008-07-26 23:55:291828 if (stats.process_launches) {
1829 int launches = 0;
nsylvain@chromium.org8e50b602009-03-03 22:59:431830 plugin_dict->GetInteger(prefs::kStabilityPluginLaunches, &launches);
initial.commit09911bf2008-07-26 23:55:291831 launches += stats.process_launches;
nsylvain@chromium.org8e50b602009-03-03 22:59:431832 plugin_dict->SetInteger(prefs::kStabilityPluginLaunches, launches);
initial.commit09911bf2008-07-26 23:55:291833 }
1834 if (stats.process_crashes) {
1835 int crashes = 0;
nsylvain@chromium.org8e50b602009-03-03 22:59:431836 plugin_dict->GetInteger(prefs::kStabilityPluginCrashes, &crashes);
initial.commit09911bf2008-07-26 23:55:291837 crashes += stats.process_crashes;
nsylvain@chromium.org8e50b602009-03-03 22:59:431838 plugin_dict->SetInteger(prefs::kStabilityPluginCrashes, crashes);
initial.commit09911bf2008-07-26 23:55:291839 }
1840 if (stats.instances) {
1841 int instances = 0;
nsylvain@chromium.org8e50b602009-03-03 22:59:431842 plugin_dict->GetInteger(prefs::kStabilityPluginInstances, &instances);
initial.commit09911bf2008-07-26 23:55:291843 instances += stats.instances;
nsylvain@chromium.org8e50b602009-03-03 22:59:431844 plugin_dict->SetInteger(prefs::kStabilityPluginInstances, instances);
initial.commit09911bf2008-07-26 23:55:291845 }
1846
viettrungluu@chromium.org57ecc4b2010-08-11 03:02:511847 child_process_stats_buffer_.erase(UTF8ToWide(plugin_name));
initial.commit09911bf2008-07-26 23:55:291848 }
1849
1850 // Now go through and add dictionaries for plugins that didn't already have
1851 // reports in Local State.
jam@chromium.orga27a9382009-02-11 23:55:101852 for (std::map<std::wstring, ChildProcessStats>::iterator cache_iter =
1853 child_process_stats_buffer_.begin();
1854 cache_iter != child_process_stats_buffer_.end(); ++cache_iter) {
jam@chromium.orga27a9382009-02-11 23:55:101855 ChildProcessStats stats = cache_iter->second;
gregoryd@google.com0d84c5d2009-10-09 01:10:421856
1857 // Insert only plugins information into the plugins list.
1858 if (ChildProcessInfo::PLUGIN_PROCESS != stats.process_type)
1859 continue;
1860
viettrungluu@chromium.org57ecc4b2010-08-11 03:02:511861 // TODO(viettrungluu): remove conversion
1862 std::string plugin_name = WideToUTF8(cache_iter->first);
gregoryd@google.com0d84c5d2009-10-09 01:10:421863
initial.commit09911bf2008-07-26 23:55:291864 DictionaryValue* plugin_dict = new DictionaryValue;
1865
nsylvain@chromium.org8e50b602009-03-03 22:59:431866 plugin_dict->SetString(prefs::kStabilityPluginName, plugin_name);
1867 plugin_dict->SetInteger(prefs::kStabilityPluginLaunches,
initial.commit09911bf2008-07-26 23:55:291868 stats.process_launches);
nsylvain@chromium.org8e50b602009-03-03 22:59:431869 plugin_dict->SetInteger(prefs::kStabilityPluginCrashes,
initial.commit09911bf2008-07-26 23:55:291870 stats.process_crashes);
nsylvain@chromium.org8e50b602009-03-03 22:59:431871 plugin_dict->SetInteger(prefs::kStabilityPluginInstances,
initial.commit09911bf2008-07-26 23:55:291872 stats.instances);
1873 plugins->Append(plugin_dict);
1874 }
jam@chromium.orga27a9382009-02-11 23:55:101875 child_process_stats_buffer_.clear();
initial.commit09911bf2008-07-26 23:55:291876}
1877
1878bool MetricsService::CanLogNotification(NotificationType type,
1879 const NotificationSource& source,
1880 const NotificationDetails& details) {
1881 // We simply don't log anything to UMA if there is a single off the record
1882 // session visible. The problem is that we always notify using the orginal
1883 // profile in order to simplify notification processing.
1884 return !BrowserList::IsOffTheRecordSessionActive();
1885}
1886
viettrungluu@chromium.org57ecc4b2010-08-11 03:02:511887void MetricsService::RecordBooleanPrefValue(const char* path, bool value) {
initial.commit09911bf2008-07-26 23:55:291888 DCHECK(IsSingleThreaded());
1889
1890 PrefService* pref = g_browser_process->local_state();
1891 DCHECK(pref);
1892
1893 pref->SetBoolean(path, value);
1894 RecordCurrentState(pref);
1895}
1896
1897void MetricsService::RecordCurrentState(PrefService* pref) {
robertshield@google.com0bb1a622009-03-04 03:22:321898 pref->SetInt64(prefs::kStabilityLastTimestampSec, Time::Now().ToTimeT());
initial.commit09911bf2008-07-26 23:55:291899
1900 RecordPluginChanges(pref);
1901}
1902
initial.commit09911bf2008-07-26 23:55:291903static bool IsSingleThreaded() {
paul@chromium.orgdc6f4962009-02-13 01:25:501904 static PlatformThreadId thread_id = 0;
initial.commit09911bf2008-07-26 23:55:291905 if (!thread_id)
paul@chromium.orgdc6f4962009-02-13 01:25:501906 thread_id = PlatformThread::CurrentId();
1907 return PlatformThread::CurrentId() == thread_id;
initial.commit09911bf2008-07-26 23:55:291908}
rvargas@google.com5ccaa412009-11-13 22:00:161909
1910#if defined(OS_CHROMEOS)
sky@chromium.org29cf16772010-04-21 15:13:471911void MetricsService::StartExternalMetrics() {
rvargas@google.com5ccaa412009-11-13 22:00:161912 external_metrics_ = new chromeos::ExternalMetrics;
sky@chromium.org29cf16772010-04-21 15:13:471913 external_metrics_->Start();
rvargas@google.com5ccaa412009-11-13 22:00:161914}
1915#endif