blob: 442306f609e15fc7769704dfedba0ef44b09c156 [file] [log] [blame]
[email protected]4d818fee2010-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
[email protected]281d2882009-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
[email protected]46f89e142010-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//
[email protected]281d2882009-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
[email protected]281d2882009-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)
[email protected]0b33f80b2008-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
[email protected]281d2882009-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
[email protected]281d2882009-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.
[email protected]85ed9d42010-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//
[email protected]85ed9d42010-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
[email protected]85ed9d42010-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//
[email protected]85ed9d42010-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
[email protected]85ed9d42010-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.
[email protected]0b33f80b2008-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
[email protected]281d2882009-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
[email protected]281d2882009-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
[email protected]40bcc302009-03-02 20:50:39159#include "chrome/browser/metrics/metrics_service.h"
160
[email protected]dc6f4962009-02-13 01:25:50161#if defined(OS_WIN)
initial.commit09911bf2008-07-26 23:55:29162#include <windows.h>
[email protected]40bcc302009-03-02 20:50:39163#include <objbase.h>
[email protected]dc6f4962009-02-13 01:25:50164#endif
initial.commit09911bf2008-07-26 23:55:29165
[email protected]46f89e142010-07-19 08:00:42166#include "base/base64.h"
[email protected]5d91c9e2010-07-28 17:25:28167#include "base/command_line.h"
[email protected]679082052010-07-21 21:30:13168#include "base/histogram.h"
[email protected]46f89e142010-07-19 08:00:42169#include "base/md5.h"
[email protected]528c56d2010-07-30 19:28:44170#include "base/string_number_conversions.h"
[email protected]4d022ff2009-10-23 18:47:09171#include "base/thread.h"
[email protected]679082052010-07-21 21:30:13172#include "base/values.h"
[email protected]d8e41ed2008-09-11 15:22:32173#include "chrome/browser/bookmarks/bookmark_model.h"
initial.commit09911bf2008-07-26 23:55:29174#include "chrome/browser/browser_list.h"
175#include "chrome/browser/browser_process.h"
176#include "chrome/browser/load_notification_details.h"
177#include "chrome/browser/memory_details.h"
[email protected]7c927b62010-02-24 09:54:13178#include "chrome/browser/metrics/histogram_synchronizer.h"
[email protected]679082052010-07-21 21:30:13179#include "chrome/browser/metrics/metrics_log.h"
[email protected]052313b2010-02-19 09:43:08180#include "chrome/browser/pref_service.h"
initial.commit09911bf2008-07-26 23:55:29181#include "chrome/browser/profile.h"
[email protected]8c8657d62009-01-16 18:31:26182#include "chrome/browser/renderer_host/render_process_host.h"
[email protected]d54e03a52009-01-16 00:31:04183#include "chrome/browser/search_engines/template_url_model.h"
[email protected]679082052010-07-21 21:30:13184#include "chrome/common/child_process_info.h"
[email protected]157d5472009-11-05 22:31:03185#include "chrome/common/child_process_logging.h"
[email protected]92745242009-06-12 16:52:21186#include "chrome/common/chrome_switches.h"
[email protected]bfd04a62009-02-01 18:16:56187#include "chrome/common/notification_service.h"
initial.commit09911bf2008-07-26 23:55:29188#include "chrome/common/pref_names.h"
[email protected]e09ba552009-02-05 03:26:29189#include "chrome/common/render_messages.h"
[email protected]35fa6a22009-08-15 00:04:01190#include "webkit/glue/plugins/plugin_list.h"
[email protected]679082052010-07-21 21:30:13191#include "webkit/glue/plugins/webplugininfo.h"
[email protected]ae393ec702010-06-27 16:23:14192#include "libxml/xmlwriter.h"
initial.commit09911bf2008-07-26 23:55:29193
[email protected]4d022ff2009-10-23 18:47:09194#if !defined(OS_WIN)
195#include "base/rand_util.h"
196#endif
197
[email protected]e06131d2010-02-10 18:40:33198// TODO(port): port browser_distribution.h.
199#if !defined(OS_POSIX)
[email protected]79bf0b72009-04-27 21:30:55200#include "chrome/installer/util/browser_distribution.h"
[email protected]dc6f4962009-02-13 01:25:50201#endif
202
[email protected]5ccaa412009-11-13 22:00:16203#if defined(OS_CHROMEOS)
204#include "chrome/browser/chromeos/external_metrics.h"
[email protected]85ed9d42010-06-08 22:37:44205
206static const char kHardwareClassTool[] = "/usr/bin/hardware_class";
207static const char kUnknownHardwareClass[] = "unknown";
[email protected]5ccaa412009-11-13 22:00:16208#endif
209
[email protected]46f89e142010-07-19 08:00:42210namespace {
211MetricsService::LogRecallStatus MakeRecallStatusHistogram(
212 MetricsService::LogRecallStatus status) {
213 UMA_HISTOGRAM_ENUMERATION("PrefService.PersistentLogRecall", status,
214 MetricsService::END_RECALL_STATUS);
215 return status;
216}
217
218// TODO(ziadh): Remove this when done with experiment.
219void MakeStoreStatusHistogram(MetricsService::LogStoreStatus status) {
[email protected]4e95d202010-07-24 01:47:56220 UMA_HISTOGRAM_ENUMERATION("PrefService.PersistentLogStore2", status,
[email protected]46f89e142010-07-19 08:00:42221 MetricsService::END_STORE_STATUS);
222}
223} // namespace
224
[email protected]e1acf6f2008-10-27 20:43:33225using base::Time;
226using base::TimeDelta;
227
initial.commit09911bf2008-07-26 23:55:29228// Check to see that we're being called on only one thread.
229static bool IsSingleThreaded();
230
initial.commit09911bf2008-07-26 23:55:29231static const char kMetricsType[] = "application/vnd.mozilla.metrics.bz2";
232
233// The delay, in seconds, after startup before sending the first log message.
[email protected]252873ef2008-08-04 21:59:45234static const int kInitialInterlogDuration = 60; // one minute
235
[email protected]c9a3ef82009-05-28 22:02:46236// This specifies the amount of time to wait for all renderers to send their
237// data.
238static const int kMaxHistogramGatheringWaitDuration = 60000; // 60 seconds.
239
[email protected]252873ef2008-08-04 21:59:45240// The default maximum number of events in a log uploaded to the UMA server.
[email protected]0b33f80b2008-12-17 21:34:36241static const int kInitialEventLimit = 2400;
[email protected]68475e602008-08-22 03:21:15242
243// If an upload fails, and the transmission was over this byte count, then we
244// will discard the log, and not try to retransmit it. We also don't persist
245// the log to the prefs for transmission during the next chrome session if this
246// limit is exceeded.
247static const int kUploadLogAvoidRetransmitSize = 50000;
initial.commit09911bf2008-07-26 23:55:29248
249// When we have logs from previous Chrome sessions to send, how long should we
250// delay (in seconds) between each log transmission.
251static const int kUnsentLogDelay = 15; // 15 seconds
252
253// Minimum time a log typically exists before sending, in seconds.
254// This number is supplied by the server, but until we parse it out of a server
255// response, we use this duration to specify how long we should wait before
256// sending the next log. If the channel is busy, such as when there is a
257// failure during an attempt to transmit a previous log, then a log may wait
[email protected]2fe42fe2010-05-07 19:22:39258// (and continue to accrue new log entries) for a much greater period of time.
259static const int kMinSecondsPerLog = 30 * 60; // Thirty minutes.
initial.commit09911bf2008-07-26 23:55:29260
initial.commit09911bf2008-07-26 23:55:29261// When we don't succeed at transmitting a log to a server, we progressively
262// wait longer and longer before sending the next log. This backoff process
263// help reduce load on the server, and makes the amount of backoff vary between
264// clients so that a collision (server overload?) on retransmit is less likely.
265// The following is the constant we use to expand that inter-log duration.
266static const double kBackoff = 1.1;
267// We limit the maximum backoff to be no greater than some multiple of the
268// default kMinSecondsPerLog. The following is that maximum ratio.
269static const int kMaxBackoff = 10;
270
271// Interval, in seconds, between state saves.
272static const int kSaveStateInterval = 5 * 60; // five minutes
273
274// The number of "initial" logs we're willing to save, and hope to send during
275// a future Chrome session. Initial logs contain crash stats, and are pretty
276// small.
277static const size_t kMaxInitialLogsPersisted = 20;
278
279// The number of ongoing logs we're willing to save persistently, and hope to
[email protected]281d2882009-01-20 20:32:42280// send during a this or future sessions. Note that each log may be pretty
initial.commit09911bf2008-07-26 23:55:29281// large, as presumably the related "initial" log wasn't sent (probably nothing
282// was, as the user was probably off-line). As a result, the log probably kept
283// accumulating while the "initial" log was stalled (pending_), and couldn't be
284// sent. As a result, we don't want to save too many of these mega-logs.
285// A "standard shutdown" will create a small log, including just the data that
286// was not yet been transmitted, and that is normal (to have exactly one
287// ongoing_log_ at startup).
[email protected]281d2882009-01-20 20:32:42288static const size_t kMaxOngoingLogsPersisted = 8;
initial.commit09911bf2008-07-26 23:55:29289
[email protected]46f89e142010-07-19 08:00:42290// We append (2) more elements to persisted lists: the size of the list and a
291// checksum of the elements.
292static const size_t kChecksumEntryCount = 2;
293
[email protected]679082052010-07-21 21:30:13294// This is used to quickly log stats from child process related notifications in
295// MetricsService::child_stats_buffer_. The buffer's contents are transferred
296// out when Local State is periodically saved. The information is then
297// reported to the UMA server on next launch.
298struct MetricsService::ChildProcessStats {
299 public:
300 explicit ChildProcessStats(ChildProcessInfo::ProcessType type)
301 : process_launches(0),
302 process_crashes(0),
303 instances(0),
304 process_type(type) {}
305
306 // This constructor is only used by the map to return some default value for
307 // an index for which no value has been assigned.
308 ChildProcessStats()
309 : process_launches(0),
310 process_crashes(0),
311 instances(0),
312 process_type(ChildProcessInfo::UNKNOWN_PROCESS) {}
313
314 // The number of times that the given child process has been launched
315 int process_launches;
316
317 // The number of times that the given child process has crashed
318 int process_crashes;
319
320 // The number of instances of this child process that have been created.
321 // An instance is a DOM object rendered by this child process during a page
322 // load.
323 int instances;
324
325 ChildProcessInfo::ProcessType process_type;
326};
initial.commit09911bf2008-07-26 23:55:29327
328// Handles asynchronous fetching of memory details.
329// Will run the provided task after finished.
330class MetricsMemoryDetails : public MemoryDetails {
331 public:
332 explicit MetricsMemoryDetails(Task* completion) : completion_(completion) {}
333
334 virtual void OnDetailsAvailable() {
335 MessageLoop::current()->PostTask(FROM_HERE, completion_);
336 }
337
338 private:
[email protected]e6e6ba42009-11-07 01:56:19339 ~MetricsMemoryDetails() {}
340
initial.commit09911bf2008-07-26 23:55:29341 Task* completion_;
[email protected]4d818fee2010-06-06 13:32:27342 DISALLOW_COPY_AND_ASSIGN(MetricsMemoryDetails);
initial.commit09911bf2008-07-26 23:55:29343};
344
[email protected]85ed9d42010-06-08 22:37:44345class MetricsService::InitTaskComplete : public Task {
[email protected]35fa6a22009-08-15 00:04:01346 public:
[email protected]85ed9d42010-06-08 22:37:44347 explicit InitTaskComplete(const std::string& hardware_class,
348 const std::vector<WebPluginInfo>& plugins)
349 : hardware_class_(hardware_class), plugins_(plugins) {}
350
[email protected]7f2e792e2009-11-30 23:18:29351 virtual void Run() {
[email protected]85ed9d42010-06-08 22:37:44352 g_browser_process->metrics_service()->OnInitTaskComplete(
353 hardware_class_, plugins_);
initial.commit09911bf2008-07-26 23:55:29354 }
[email protected]35fa6a22009-08-15 00:04:01355
[email protected]7f2e792e2009-11-30 23:18:29356 private:
[email protected]85ed9d42010-06-08 22:37:44357 std::string hardware_class_;
[email protected]7f2e792e2009-11-30 23:18:29358 std::vector<WebPluginInfo> plugins_;
initial.commit09911bf2008-07-26 23:55:29359};
360
[email protected]85ed9d42010-06-08 22:37:44361class MetricsService::InitTask : public Task {
[email protected]7f2e792e2009-11-30 23:18:29362 public:
[email protected]85ed9d42010-06-08 22:37:44363 explicit InitTask(MessageLoop* callback_loop)
[email protected]7f2e792e2009-11-30 23:18:29364 : callback_loop_(callback_loop) {}
365
366 virtual void Run() {
367 std::vector<WebPluginInfo> plugins;
368 NPAPI::PluginList::Singleton()->GetPlugins(false, &plugins);
[email protected]85ed9d42010-06-08 22:37:44369 std::string hardware_class; // Empty string by default.
370#if defined(OS_CHROMEOS)
371 hardware_class = MetricsService::GetHardwareClass();
372#endif // OS_CHROMEOS
373 callback_loop_->PostTask(FROM_HERE, new InitTaskComplete(
374 hardware_class, plugins));
[email protected]7f2e792e2009-11-30 23:18:29375 }
376
377 private:
378 MessageLoop* callback_loop_;
379};
[email protected]90d41372009-11-30 21:52:32380
initial.commit09911bf2008-07-26 23:55:29381// static
382void MetricsService::RegisterPrefs(PrefService* local_state) {
383 DCHECK(IsSingleThreaded());
[email protected]20ce516d2010-06-18 02:20:04384 local_state->RegisterStringPref(prefs::kMetricsClientID, "");
[email protected]0bb1a622009-03-04 03:22:32385 local_state->RegisterInt64Pref(prefs::kMetricsClientIDTimestamp, 0);
386 local_state->RegisterInt64Pref(prefs::kStabilityLaunchTimeSec, 0);
387 local_state->RegisterInt64Pref(prefs::kStabilityLastTimestampSec, 0);
[email protected]20ce516d2010-06-18 02:20:04388 local_state->RegisterStringPref(prefs::kStabilityStatsVersion, "");
[email protected]225c50842010-01-19 21:19:13389 local_state->RegisterInt64Pref(prefs::kStabilityStatsBuildTime, 0);
initial.commit09911bf2008-07-26 23:55:29390 local_state->RegisterBooleanPref(prefs::kStabilityExitedCleanly, true);
391 local_state->RegisterBooleanPref(prefs::kStabilitySessionEndCompleted, true);
392 local_state->RegisterIntegerPref(prefs::kMetricsSessionID, -1);
393 local_state->RegisterIntegerPref(prefs::kStabilityLaunchCount, 0);
394 local_state->RegisterIntegerPref(prefs::kStabilityCrashCount, 0);
395 local_state->RegisterIntegerPref(prefs::kStabilityIncompleteSessionEndCount,
396 0);
397 local_state->RegisterIntegerPref(prefs::kStabilityPageLoadCount, 0);
initial.commit09911bf2008-07-26 23:55:29398 local_state->RegisterIntegerPref(prefs::kStabilityRendererCrashCount, 0);
[email protected]1f085622009-12-04 05:33:45399 local_state->RegisterIntegerPref(prefs::kStabilityExtensionRendererCrashCount,
400 0);
initial.commit09911bf2008-07-26 23:55:29401 local_state->RegisterIntegerPref(prefs::kStabilityRendererHangCount, 0);
[email protected]1f085622009-12-04 05:33:45402 local_state->RegisterIntegerPref(prefs::kStabilityChildProcessCrashCount, 0);
[email protected]e73c01972008-08-13 00:18:24403 local_state->RegisterIntegerPref(prefs::kStabilityBreakpadRegistrationFail,
404 0);
405 local_state->RegisterIntegerPref(prefs::kStabilityBreakpadRegistrationSuccess,
406 0);
407 local_state->RegisterIntegerPref(prefs::kStabilityDebuggerPresent, 0);
408 local_state->RegisterIntegerPref(prefs::kStabilityDebuggerNotPresent, 0);
409
initial.commit09911bf2008-07-26 23:55:29410 local_state->RegisterDictionaryPref(prefs::kProfileMetrics);
411 local_state->RegisterIntegerPref(prefs::kNumBookmarksOnBookmarkBar, 0);
412 local_state->RegisterIntegerPref(prefs::kNumFoldersOnBookmarkBar, 0);
413 local_state->RegisterIntegerPref(prefs::kNumBookmarksInOtherBookmarkFolder,
414 0);
415 local_state->RegisterIntegerPref(prefs::kNumFoldersInOtherBookmarkFolder, 0);
416 local_state->RegisterIntegerPref(prefs::kNumKeywords, 0);
417 local_state->RegisterListPref(prefs::kMetricsInitialLogs);
418 local_state->RegisterListPref(prefs::kMetricsOngoingLogs);
[email protected]0bb1a622009-03-04 03:22:32419
420 local_state->RegisterInt64Pref(prefs::kUninstallMetricsPageLoadCount, 0);
421 local_state->RegisterInt64Pref(prefs::kUninstallLaunchCount, 0);
[email protected]6b5f21d2009-04-13 17:01:35422 local_state->RegisterInt64Pref(prefs::kUninstallMetricsInstallDate, 0);
[email protected]0bb1a622009-03-04 03:22:32423 local_state->RegisterInt64Pref(prefs::kUninstallMetricsUptimeSec, 0);
424 local_state->RegisterInt64Pref(prefs::kUninstallLastLaunchTimeSec, 0);
425 local_state->RegisterInt64Pref(prefs::kUninstallLastObservedRunTimeSec, 0);
initial.commit09911bf2008-07-26 23:55:29426}
427
[email protected]541f77922009-02-23 21:14:38428// static
429void MetricsService::DiscardOldStabilityStats(PrefService* local_state) {
430 local_state->SetBoolean(prefs::kStabilityExitedCleanly, true);
[email protected]c9abf242009-07-18 06:00:38431 local_state->SetBoolean(prefs::kStabilitySessionEndCompleted, true);
[email protected]541f77922009-02-23 21:14:38432
433 local_state->SetInteger(prefs::kStabilityIncompleteSessionEndCount, 0);
434 local_state->SetInteger(prefs::kStabilityBreakpadRegistrationSuccess, 0);
435 local_state->SetInteger(prefs::kStabilityBreakpadRegistrationFail, 0);
436 local_state->SetInteger(prefs::kStabilityDebuggerPresent, 0);
437 local_state->SetInteger(prefs::kStabilityDebuggerNotPresent, 0);
438
439 local_state->SetInteger(prefs::kStabilityLaunchCount, 0);
440 local_state->SetInteger(prefs::kStabilityCrashCount, 0);
441
442 local_state->SetInteger(prefs::kStabilityPageLoadCount, 0);
443 local_state->SetInteger(prefs::kStabilityRendererCrashCount, 0);
444 local_state->SetInteger(prefs::kStabilityRendererHangCount, 0);
445
[email protected]9165f742010-03-10 22:55:01446 local_state->SetInt64(prefs::kStabilityLaunchTimeSec, 0);
447 local_state->SetInt64(prefs::kStabilityLastTimestampSec, 0);
[email protected]541f77922009-02-23 21:14:38448
449 local_state->ClearPref(prefs::kStabilityPluginStats);
[email protected]ae155cb92009-06-19 06:10:37450
451 ListValue* unsent_initial_logs = local_state->GetMutableList(
452 prefs::kMetricsInitialLogs);
453 unsent_initial_logs->Clear();
454
455 ListValue* unsent_ongoing_logs = local_state->GetMutableList(
456 prefs::kMetricsOngoingLogs);
457 unsent_ongoing_logs->Clear();
[email protected]541f77922009-02-23 21:14:38458}
459
initial.commit09911bf2008-07-26 23:55:29460MetricsService::MetricsService()
[email protected]d01b8732008-10-16 02:18:07461 : recording_active_(false),
462 reporting_active_(false),
463 user_permits_upload_(false),
464 server_permits_upload_(true),
465 state_(INITIALIZED),
initial.commit09911bf2008-07-26 23:55:29466 current_fetch_(NULL),
[email protected]d01b8732008-10-16 02:18:07467 idle_since_last_transmission_(false),
initial.commit09911bf2008-07-26 23:55:29468 next_window_id_(0),
[email protected]40bcc302009-03-02 20:50:39469 ALLOW_THIS_IN_INITIALIZER_LIST(log_sender_factory_(this)),
470 ALLOW_THIS_IN_INITIALIZER_LIST(state_saver_factory_(this)),
[email protected]252873ef2008-08-04 21:59:45471 interlog_duration_(TimeDelta::FromSeconds(kInitialInterlogDuration)),
[email protected]d01b8732008-10-16 02:18:07472 log_event_limit_(kInitialEventLimit),
initial.commit09911bf2008-07-26 23:55:29473 timer_pending_(false) {
474 DCHECK(IsSingleThreaded());
475 InitializeMetricsState();
476}
477
478MetricsService::~MetricsService() {
479 SetRecording(false);
480}
481
[email protected]d01b8732008-10-16 02:18:07482void MetricsService::SetUserPermitsUpload(bool enabled) {
483 HandleIdleSinceLastTransmission(false);
484 user_permits_upload_ = enabled;
485}
486
487void MetricsService::Start() {
488 SetRecording(true);
489 SetReporting(true);
490}
491
492void MetricsService::StartRecordingOnly() {
493 SetRecording(true);
494 SetReporting(false);
495}
496
497void MetricsService::Stop() {
498 SetReporting(false);
499 SetRecording(false);
500}
501
initial.commit09911bf2008-07-26 23:55:29502void MetricsService::SetRecording(bool enabled) {
503 DCHECK(IsSingleThreaded());
504
[email protected]d01b8732008-10-16 02:18:07505 if (enabled == recording_active_)
initial.commit09911bf2008-07-26 23:55:29506 return;
507
508 if (enabled) {
[email protected]b0c819f2009-03-08 04:52:15509 if (client_id_.empty()) {
510 PrefService* pref = g_browser_process->local_state();
511 DCHECK(pref);
[email protected]ddd231e2010-06-29 20:35:19512 client_id_ = pref->GetString(prefs::kMetricsClientID);
[email protected]b0c819f2009-03-08 04:52:15513 if (client_id_.empty()) {
514 client_id_ = GenerateClientID();
[email protected]ddd231e2010-06-29 20:35:19515 pref->SetString(prefs::kMetricsClientID, client_id_);
[email protected]b0c819f2009-03-08 04:52:15516
517 // Might as well make a note of how long this ID has existed
518 pref->SetString(prefs::kMetricsClientIDTimestamp,
[email protected]528c56d2010-07-30 19:28:44519 base::Int64ToString(Time::Now().ToTimeT()));
[email protected]b0c819f2009-03-08 04:52:15520 }
521 }
[email protected]157d5472009-11-05 22:31:03522 child_process_logging::SetClientId(client_id_);
initial.commit09911bf2008-07-26 23:55:29523 StartRecording();
[email protected]005ef3e2009-05-22 20:55:46524
525 registrar_.Add(this, NotificationType::BROWSER_OPENED,
526 NotificationService::AllSources());
527 registrar_.Add(this, NotificationType::BROWSER_CLOSED,
528 NotificationService::AllSources());
529 registrar_.Add(this, NotificationType::USER_ACTION,
530 NotificationService::AllSources());
531 registrar_.Add(this, NotificationType::TAB_PARENTED,
532 NotificationService::AllSources());
533 registrar_.Add(this, NotificationType::TAB_CLOSING,
534 NotificationService::AllSources());
535 registrar_.Add(this, NotificationType::LOAD_START,
536 NotificationService::AllSources());
537 registrar_.Add(this, NotificationType::LOAD_STOP,
538 NotificationService::AllSources());
[email protected]cd69619b2010-05-05 02:41:38539 registrar_.Add(this, NotificationType::RENDERER_PROCESS_CLOSED,
[email protected]005ef3e2009-05-22 20:55:46540 NotificationService::AllSources());
541 registrar_.Add(this, NotificationType::RENDERER_PROCESS_HANG,
542 NotificationService::AllSources());
543 registrar_.Add(this, NotificationType::CHILD_PROCESS_HOST_CONNECTED,
544 NotificationService::AllSources());
545 registrar_.Add(this, NotificationType::CHILD_INSTANCE_CREATED,
546 NotificationService::AllSources());
547 registrar_.Add(this, NotificationType::CHILD_PROCESS_CRASHED,
548 NotificationService::AllSources());
549 registrar_.Add(this, NotificationType::TEMPLATE_URL_MODEL_LOADED,
550 NotificationService::AllSources());
551 registrar_.Add(this, NotificationType::OMNIBOX_OPENED_URL,
552 NotificationService::AllSources());
553 registrar_.Add(this, NotificationType::BOOKMARK_MODEL_LOADED,
554 NotificationService::AllSources());
initial.commit09911bf2008-07-26 23:55:29555 } else {
[email protected]005ef3e2009-05-22 20:55:46556 registrar_.RemoveAll();
initial.commit09911bf2008-07-26 23:55:29557 PushPendingLogsToUnsentLists();
558 DCHECK(!pending_log());
559 if (state_ > INITIAL_LOG_READY && unsent_logs())
560 state_ = SEND_OLD_INITIAL_LOGS;
561 }
[email protected]d01b8732008-10-16 02:18:07562 recording_active_ = enabled;
initial.commit09911bf2008-07-26 23:55:29563}
564
[email protected]d01b8732008-10-16 02:18:07565bool MetricsService::recording_active() const {
initial.commit09911bf2008-07-26 23:55:29566 DCHECK(IsSingleThreaded());
[email protected]d01b8732008-10-16 02:18:07567 return recording_active_;
initial.commit09911bf2008-07-26 23:55:29568}
569
[email protected]d01b8732008-10-16 02:18:07570void MetricsService::SetReporting(bool enable) {
571 if (reporting_active_ != enable) {
572 reporting_active_ = enable;
573 if (reporting_active_)
initial.commit09911bf2008-07-26 23:55:29574 StartLogTransmissionTimer();
575 }
[email protected]d01b8732008-10-16 02:18:07576}
577
578bool MetricsService::reporting_active() const {
579 DCHECK(IsSingleThreaded());
580 return reporting_active_;
initial.commit09911bf2008-07-26 23:55:29581}
582
583void MetricsService::Observe(NotificationType type,
584 const NotificationSource& source,
585 const NotificationDetails& details) {
586 DCHECK(current_log_);
587 DCHECK(IsSingleThreaded());
588
589 if (!CanLogNotification(type, source, details))
590 return;
591
[email protected]bfd04a62009-02-01 18:16:56592 switch (type.value) {
593 case NotificationType::USER_ACTION:
[email protected]afe3a1672009-11-17 19:04:12594 current_log_->RecordUserAction(*Details<const char*>(details).ptr());
initial.commit09911bf2008-07-26 23:55:29595 break;
596
[email protected]bfd04a62009-02-01 18:16:56597 case NotificationType::BROWSER_OPENED:
598 case NotificationType::BROWSER_CLOSED:
initial.commit09911bf2008-07-26 23:55:29599 LogWindowChange(type, source, details);
600 break;
601
[email protected]bfd04a62009-02-01 18:16:56602 case NotificationType::TAB_PARENTED:
603 case NotificationType::TAB_CLOSING:
initial.commit09911bf2008-07-26 23:55:29604 LogWindowChange(type, source, details);
605 break;
606
[email protected]bfd04a62009-02-01 18:16:56607 case NotificationType::LOAD_STOP:
initial.commit09911bf2008-07-26 23:55:29608 LogLoadComplete(type, source, details);
609 break;
610
[email protected]bfd04a62009-02-01 18:16:56611 case NotificationType::LOAD_START:
initial.commit09911bf2008-07-26 23:55:29612 LogLoadStarted();
613 break;
614
[email protected]cd69619b2010-05-05 02:41:38615 case NotificationType::RENDERER_PROCESS_CLOSED:
[email protected]1f085622009-12-04 05:33:45616 {
[email protected]cd69619b2010-05-05 02:41:38617 RenderProcessHost::RendererClosedDetails* process_details =
618 Details<RenderProcessHost::RendererClosedDetails>(details).ptr();
619 if (process_details->did_crash) {
620 if (process_details->was_extension_renderer) {
621 LogExtensionRendererCrash();
622 } else {
623 LogRendererCrash();
624 }
625 }
[email protected]1f085622009-12-04 05:33:45626 }
initial.commit09911bf2008-07-26 23:55:29627 break;
628
[email protected]bfd04a62009-02-01 18:16:56629 case NotificationType::RENDERER_PROCESS_HANG:
initial.commit09911bf2008-07-26 23:55:29630 LogRendererHang();
631 break;
632
[email protected]a27a9382009-02-11 23:55:10633 case NotificationType::CHILD_PROCESS_HOST_CONNECTED:
634 case NotificationType::CHILD_PROCESS_CRASHED:
635 case NotificationType::CHILD_INSTANCE_CREATED:
636 LogChildProcessChange(type, source, details);
initial.commit09911bf2008-07-26 23:55:29637 break;
638
[email protected]bfd04a62009-02-01 18:16:56639 case NotificationType::TEMPLATE_URL_MODEL_LOADED:
initial.commit09911bf2008-07-26 23:55:29640 LogKeywords(Source<TemplateURLModel>(source).ptr());
641 break;
642
[email protected]1226abb2010-06-10 18:01:28643 case NotificationType::OMNIBOX_OPENED_URL: {
644 MetricsLog* current_log = current_log_->AsMetricsLog();
645 DCHECK(current_log);
646 current_log->RecordOmniboxOpenedURL(
initial.commit09911bf2008-07-26 23:55:29647 *Details<AutocompleteLog>(details).ptr());
648 break;
[email protected]1226abb2010-06-10 18:01:28649 }
initial.commit09911bf2008-07-26 23:55:29650
[email protected]b61236c62009-04-09 22:43:55651 case NotificationType::BOOKMARK_MODEL_LOADED: {
652 Profile* p = Source<Profile>(source).ptr();
653 if (p)
654 LogBookmarks(p->GetBookmarkModel());
initial.commit09911bf2008-07-26 23:55:29655 break;
[email protected]b61236c62009-04-09 22:43:55656 }
initial.commit09911bf2008-07-26 23:55:29657 default:
[email protected]a063c102010-07-22 22:20:19658 NOTREACHED();
initial.commit09911bf2008-07-26 23:55:29659 break;
660 }
[email protected]d01b8732008-10-16 02:18:07661
662 HandleIdleSinceLastTransmission(false);
663
664 if (current_log_)
[email protected]281d2882009-01-20 20:32:42665 DLOG(INFO) << "METRICS: NUMBER OF EVENTS = " << current_log_->num_events();
[email protected]d01b8732008-10-16 02:18:07666}
667
668void MetricsService::HandleIdleSinceLastTransmission(bool in_idle) {
669 // If there wasn't a lot of action, maybe the computer was asleep, in which
670 // case, the log transmissions should have stopped. Here we start them up
671 // again.
[email protected]cac78842008-11-27 01:02:20672 if (!in_idle && idle_since_last_transmission_)
673 StartLogTransmissionTimer();
674 idle_since_last_transmission_ = in_idle;
initial.commit09911bf2008-07-26 23:55:29675}
676
677void MetricsService::RecordCleanShutdown() {
678 RecordBooleanPrefValue(prefs::kStabilityExitedCleanly, true);
679}
680
681void MetricsService::RecordStartOfSessionEnd() {
682 RecordBooleanPrefValue(prefs::kStabilitySessionEndCompleted, false);
683}
684
685void MetricsService::RecordCompletedSessionEnd() {
686 RecordBooleanPrefValue(prefs::kStabilitySessionEndCompleted, true);
687}
688
[email protected]e73c01972008-08-13 00:18:24689void MetricsService:: RecordBreakpadRegistration(bool success) {
[email protected]68475e602008-08-22 03:21:15690 if (!success)
[email protected]e73c01972008-08-13 00:18:24691 IncrementPrefValue(prefs::kStabilityBreakpadRegistrationFail);
692 else
693 IncrementPrefValue(prefs::kStabilityBreakpadRegistrationSuccess);
694}
695
696void MetricsService::RecordBreakpadHasDebugger(bool has_debugger) {
697 if (!has_debugger)
698 IncrementPrefValue(prefs::kStabilityDebuggerNotPresent);
699 else
[email protected]68475e602008-08-22 03:21:15700 IncrementPrefValue(prefs::kStabilityDebuggerPresent);
[email protected]e73c01972008-08-13 00:18:24701}
702
initial.commit09911bf2008-07-26 23:55:29703//------------------------------------------------------------------------------
704// private methods
705//------------------------------------------------------------------------------
706
707
708//------------------------------------------------------------------------------
709// Initialization methods
710
711void MetricsService::InitializeMetricsState() {
[email protected]79bf0b72009-04-27 21:30:55712#if defined(OS_POSIX)
713 server_url_ = L"https://clients4.google.com/firefox/metrics/collect";
714#else
715 BrowserDistribution* dist = BrowserDistribution::GetDistribution();
716 server_url_ = dist->GetStatsServerURL();
717#endif
718
initial.commit09911bf2008-07-26 23:55:29719 PrefService* pref = g_browser_process->local_state();
720 DCHECK(pref);
721
[email protected]225c50842010-01-19 21:19:13722 if ((pref->GetInt64(prefs::kStabilityStatsBuildTime)
723 != MetricsLog::GetBuildTime()) ||
[email protected]ddd231e2010-06-29 20:35:19724 (pref->GetString(prefs::kStabilityStatsVersion)
[email protected]225c50842010-01-19 21:19:13725 != MetricsLog::GetVersionString())) {
[email protected]541f77922009-02-23 21:14:38726 // This is a new version, so we don't want to confuse the stats about the
727 // old version with info that we upload.
728 DiscardOldStabilityStats(pref);
729 pref->SetString(prefs::kStabilityStatsVersion,
[email protected]ddd231e2010-06-29 20:35:19730 MetricsLog::GetVersionString());
[email protected]225c50842010-01-19 21:19:13731 pref->SetInt64(prefs::kStabilityStatsBuildTime,
732 MetricsLog::GetBuildTime());
[email protected]541f77922009-02-23 21:14:38733 }
734
initial.commit09911bf2008-07-26 23:55:29735 // Update session ID
736 session_id_ = pref->GetInteger(prefs::kMetricsSessionID);
737 ++session_id_;
738 pref->SetInteger(prefs::kMetricsSessionID, session_id_);
739
initial.commit09911bf2008-07-26 23:55:29740 // Stability bookkeeping
[email protected]e73c01972008-08-13 00:18:24741 IncrementPrefValue(prefs::kStabilityLaunchCount);
initial.commit09911bf2008-07-26 23:55:29742
[email protected]e73c01972008-08-13 00:18:24743 if (!pref->GetBoolean(prefs::kStabilityExitedCleanly)) {
744 IncrementPrefValue(prefs::kStabilityCrashCount);
initial.commit09911bf2008-07-26 23:55:29745 }
[email protected]e73c01972008-08-13 00:18:24746
747 // This will be set to 'true' if we exit cleanly.
initial.commit09911bf2008-07-26 23:55:29748 pref->SetBoolean(prefs::kStabilityExitedCleanly, false);
749
[email protected]e73c01972008-08-13 00:18:24750 if (!pref->GetBoolean(prefs::kStabilitySessionEndCompleted)) {
751 IncrementPrefValue(prefs::kStabilityIncompleteSessionEndCount);
[email protected]c9abf242009-07-18 06:00:38752 // This is marked false when we get a WM_ENDSESSION.
753 pref->SetBoolean(prefs::kStabilitySessionEndCompleted, true);
initial.commit09911bf2008-07-26 23:55:29754 }
initial.commit09911bf2008-07-26 23:55:29755
[email protected]9165f742010-03-10 22:55:01756 // Initialize uptime counters.
757 int64 startup_uptime = MetricsLog::GetIncrementalUptime(pref);
[email protected]ae393ec702010-06-27 16:23:14758 DCHECK_EQ(0, startup_uptime);
[email protected]9165f742010-03-10 22:55:01759 // For backwards compatibility, leave this intact in case Omaha is checking
760 // them. prefs::kStabilityLastTimestampSec may also be useless now.
761 // TODO(jar): Delete these if they have no uses.
[email protected]0bb1a622009-03-04 03:22:32762 pref->SetInt64(prefs::kStabilityLaunchTimeSec, Time::Now().ToTimeT());
763
764 // Bookkeeping for the uninstall metrics.
765 IncrementLongPrefsValue(prefs::kUninstallLaunchCount);
initial.commit09911bf2008-07-26 23:55:29766
767 // Save profile metrics.
768 PrefService* prefs = g_browser_process->local_state();
769 if (prefs) {
770 // Remove the current dictionary and store it for use when sending data to
771 // server. By removing the value we prune potentially dead profiles
772 // (and keys). All valid values are added back once services startup.
773 const DictionaryValue* profile_dictionary =
774 prefs->GetDictionary(prefs::kProfileMetrics);
775 if (profile_dictionary) {
776 // Do a deep copy of profile_dictionary since ClearPref will delete it.
777 profile_dictionary_.reset(static_cast<DictionaryValue*>(
778 profile_dictionary->DeepCopy()));
779 prefs->ClearPref(prefs::kProfileMetrics);
780 }
781 }
782
[email protected]92745242009-06-12 16:52:21783 // Get stats on use of command line.
784 const CommandLine* command_line(CommandLine::ForCurrentProcess());
785 size_t common_commands = 0;
786 if (command_line->HasSwitch(switches::kUserDataDir)) {
787 ++common_commands;
788 UMA_HISTOGRAM_COUNTS_100("Chrome.CommandLineDatDirCount", 1);
789 }
790
791 if (command_line->HasSwitch(switches::kApp)) {
792 ++common_commands;
793 UMA_HISTOGRAM_COUNTS_100("Chrome.CommandLineAppModeCount", 1);
794 }
795
796 UMA_HISTOGRAM_COUNTS_100("Chrome.CommandLineFlagCount",
797 command_line->GetSwitchCount());
798 UMA_HISTOGRAM_COUNTS_100("Chrome.CommandLineUncommonFlagCount",
799 command_line->GetSwitchCount() - common_commands);
800
initial.commit09911bf2008-07-26 23:55:29801 // Kick off the process of saving the state (so the uptime numbers keep
802 // getting updated) every n minutes.
803 ScheduleNextStateSave();
804}
805
[email protected]85ed9d42010-06-08 22:37:44806void MetricsService::OnInitTaskComplete(
807 const std::string& hardware_class,
[email protected]35fa6a22009-08-15 00:04:01808 const std::vector<WebPluginInfo>& plugins) {
[email protected]85ed9d42010-06-08 22:37:44809 DCHECK(state_ == INIT_TASK_SCHEDULED);
810 hardware_class_ = hardware_class;
[email protected]35fa6a22009-08-15 00:04:01811 plugins_ = plugins;
[email protected]85ed9d42010-06-08 22:37:44812 if (state_ == INIT_TASK_SCHEDULED)
813 state_ = INIT_TASK_DONE;
initial.commit09911bf2008-07-26 23:55:29814}
815
816std::string MetricsService::GenerateClientID() {
[email protected]dc6f4962009-02-13 01:25:50817#if defined(OS_WIN)
initial.commit09911bf2008-07-26 23:55:29818 const int kGUIDSize = 39;
819
820 GUID guid;
821 HRESULT guid_result = CoCreateGuid(&guid);
822 DCHECK(SUCCEEDED(guid_result));
823
824 std::wstring guid_string;
825 int result = StringFromGUID2(guid,
826 WriteInto(&guid_string, kGUIDSize), kGUIDSize);
827 DCHECK(result == kGUIDSize);
828
829 return WideToUTF8(guid_string.substr(1, guid_string.length() - 2));
[email protected]271b24f2009-07-28 16:05:51830#else
[email protected]06aaac22009-07-08 20:54:13831 uint64 sixteen_bytes[2] = { base::RandUint64(), base::RandUint64() };
832 return RandomBytesToGUIDString(sixteen_bytes);
[email protected]dc6f4962009-02-13 01:25:50833#endif
initial.commit09911bf2008-07-26 23:55:29834}
835
[email protected]06aaac22009-07-08 20:54:13836#if defined(OS_POSIX)
837// TODO(cmasone): Once we're comfortable this works, migrate Windows code to
838// use this as well.
839std::string MetricsService::RandomBytesToGUIDString(const uint64 bytes[2]) {
[email protected]34b2b002009-11-20 06:53:28840 return StringPrintf("%08X-%04X-%04X-%04X-%012llX",
841 static_cast<unsigned int>(bytes[0] >> 32),
842 static_cast<unsigned int>((bytes[0] >> 16) & 0x0000ffff),
843 static_cast<unsigned int>(bytes[0] & 0x0000ffff),
844 static_cast<unsigned int>(bytes[1] >> 48),
[email protected]06aaac22009-07-08 20:54:13845 bytes[1] & 0x0000ffffffffffffULL);
846}
847#endif
initial.commit09911bf2008-07-26 23:55:29848
849//------------------------------------------------------------------------------
850// State save methods
851
852void MetricsService::ScheduleNextStateSave() {
853 state_saver_factory_.RevokeAll();
854
855 MessageLoop::current()->PostDelayedTask(FROM_HERE,
856 state_saver_factory_.NewRunnableMethod(&MetricsService::SaveLocalState),
857 kSaveStateInterval * 1000);
858}
859
860void MetricsService::SaveLocalState() {
861 PrefService* pref = g_browser_process->local_state();
862 if (!pref) {
[email protected]a063c102010-07-22 22:20:19863 NOTREACHED();
initial.commit09911bf2008-07-26 23:55:29864 return;
865 }
866
867 RecordCurrentState(pref);
[email protected]6faa0e0d2009-04-28 06:50:36868 pref->ScheduleSavePersistentPrefs();
initial.commit09911bf2008-07-26 23:55:29869
[email protected]281d2882009-01-20 20:32:42870 // TODO(jar): Does this run down the batteries????
initial.commit09911bf2008-07-26 23:55:29871 ScheduleNextStateSave();
872}
873
874
875//------------------------------------------------------------------------------
876// Recording control methods
877
878void MetricsService::StartRecording() {
879 if (current_log_)
880 return;
881
882 current_log_ = new MetricsLog(client_id_, session_id_);
883 if (state_ == INITIALIZED) {
884 // We only need to schedule that run once.
[email protected]85ed9d42010-06-08 22:37:44885 state_ = INIT_TASK_SCHEDULED;
initial.commit09911bf2008-07-26 23:55:29886
[email protected]85ed9d42010-06-08 22:37:44887 // Schedules a task on the file thread for execution of slower
888 // initialization steps (such as plugin list generation) necessary
889 // for sending the initial log. This avoids blocking the main UI
890 // thread.
[email protected]7f2e792e2009-11-30 23:18:29891 g_browser_process->file_thread()->message_loop()->PostDelayedTask(FROM_HERE,
[email protected]85ed9d42010-06-08 22:37:44892 new InitTask(MessageLoop::current()),
[email protected]252873ef2008-08-04 21:59:45893 kInitialInterlogDuration * 1000 / 2);
initial.commit09911bf2008-07-26 23:55:29894 }
895}
896
[email protected]1226abb2010-06-10 18:01:28897void MetricsService::StopRecording(MetricsLogBase** log) {
initial.commit09911bf2008-07-26 23:55:29898 if (!current_log_)
899 return;
900
[email protected]1226abb2010-06-10 18:01:28901 MetricsLog* current_log = current_log_->AsMetricsLog();
902 DCHECK(current_log);
903 current_log->set_hardware_class(hardware_class_); // Adds to ongoing logs.
[email protected]85ed9d42010-06-08 22:37:44904
[email protected]68475e602008-08-22 03:21:15905 // TODO(jar): Integrate bounds on log recording more consistently, so that we
906 // can stop recording logs that are too big much sooner.
[email protected]d01b8732008-10-16 02:18:07907 if (current_log_->num_events() > log_event_limit_) {
[email protected]553dba62009-02-24 19:08:23908 UMA_HISTOGRAM_COUNTS("UMA.Discarded Log Events",
[email protected]68475e602008-08-22 03:21:15909 current_log_->num_events());
910 current_log_->CloseLog();
911 delete current_log_;
[email protected]294638782008-09-24 00:22:41912 current_log_ = NULL;
[email protected]68475e602008-08-22 03:21:15913 StartRecording(); // Start trivial log to hold our histograms.
914 }
915
[email protected]0b33f80b2008-12-17 21:34:36916 // Put incremental data (histogram deltas, and realtime stats deltas) at the
[email protected]147bbc0b2009-01-06 19:37:40917 // end of all log transmissions (initial log handles this separately).
initial.commit09911bf2008-07-26 23:55:29918 // Don't bother if we're going to discard current_log_.
[email protected]0b33f80b2008-12-17 21:34:36919 if (log) {
[email protected]1226abb2010-06-10 18:01:28920 current_log->RecordIncrementalStabilityElements();
initial.commit09911bf2008-07-26 23:55:29921 RecordCurrentHistograms();
[email protected]0b33f80b2008-12-17 21:34:36922 }
initial.commit09911bf2008-07-26 23:55:29923
924 current_log_->CloseLog();
[email protected]cac78842008-11-27 01:02:20925 if (log)
[email protected]1226abb2010-06-10 18:01:28926 *log = current_log;
[email protected]cac78842008-11-27 01:02:20927 else
initial.commit09911bf2008-07-26 23:55:29928 delete current_log_;
initial.commit09911bf2008-07-26 23:55:29929 current_log_ = NULL;
930}
931
initial.commit09911bf2008-07-26 23:55:29932void MetricsService::PushPendingLogsToUnsentLists() {
933 if (state_ < INITIAL_LOG_READY)
[email protected]28ab7f92009-01-06 21:39:04934 return; // We didn't and still don't have time to get plugin list etc.
initial.commit09911bf2008-07-26 23:55:29935
936 if (pending_log()) {
937 PreparePendingLogText();
938 if (state_ == INITIAL_LOG_READY) {
939 // We may race here, and send second copy of initial log later.
[email protected]46f89e142010-07-19 08:00:42940 unsent_initial_logs_.push_back(compressed_log_);
[email protected]d01b8732008-10-16 02:18:07941 state_ = SEND_OLD_INITIAL_LOGS;
initial.commit09911bf2008-07-26 23:55:29942 } else {
[email protected]281d2882009-01-20 20:32:42943 // TODO(jar): Verify correctness in other states, including sending unsent
[email protected]541f77922009-02-23 21:14:38944 // initial logs.
[email protected]68475e602008-08-22 03:21:15945 PushPendingLogTextToUnsentOngoingLogs();
initial.commit09911bf2008-07-26 23:55:29946 }
947 DiscardPendingLog();
948 }
949 DCHECK(!pending_log());
950 StopRecording(&pending_log_);
951 PreparePendingLogText();
[email protected]68475e602008-08-22 03:21:15952 PushPendingLogTextToUnsentOngoingLogs();
initial.commit09911bf2008-07-26 23:55:29953 DiscardPendingLog();
954 StoreUnsentLogs();
955}
956
[email protected]68475e602008-08-22 03:21:15957void MetricsService::PushPendingLogTextToUnsentOngoingLogs() {
[email protected]d01b8732008-10-16 02:18:07958 // If UMA response told us not to upload, there's no need to save the pending
959 // log. It wasn't supposed to be uploaded anyway.
960 if (!server_permits_upload_)
961 return;
[email protected]46f89e142010-07-19 08:00:42962 if (compressed_log_.length() >
[email protected]dc6f4962009-02-13 01:25:50963 static_cast<size_t>(kUploadLogAvoidRetransmitSize)) {
[email protected]553dba62009-02-24 19:08:23964 UMA_HISTOGRAM_COUNTS("UMA.Large Accumulated Log Not Persisted",
[email protected]46f89e142010-07-19 08:00:42965 static_cast<int>(compressed_log_.length()));
[email protected]68475e602008-08-22 03:21:15966 return;
967 }
[email protected]46f89e142010-07-19 08:00:42968 unsent_ongoing_logs_.push_back(compressed_log_);
[email protected]68475e602008-08-22 03:21:15969}
970
initial.commit09911bf2008-07-26 23:55:29971//------------------------------------------------------------------------------
972// Transmission of logs methods
973
974void MetricsService::StartLogTransmissionTimer() {
[email protected]d01b8732008-10-16 02:18:07975 // If we're not reporting, there's no point in starting a log transmission
976 // timer.
977 if (!reporting_active())
978 return;
979
initial.commit09911bf2008-07-26 23:55:29980 if (!current_log_)
981 return; // Recorder is shutdown.
[email protected]d01b8732008-10-16 02:18:07982
983 // If there is already a timer running, we leave it running.
984 // If timer_pending is true because the fetch is waiting for a response,
985 // we return for now and let the response handler start the timer.
986 if (timer_pending_)
initial.commit09911bf2008-07-26 23:55:29987 return;
[email protected]d01b8732008-10-16 02:18:07988
[email protected]d01b8732008-10-16 02:18:07989 // Before starting the timer, set timer_pending_ to true.
initial.commit09911bf2008-07-26 23:55:29990 timer_pending_ = true;
[email protected]d01b8732008-10-16 02:18:07991
992 // Right before the UMA transmission gets started, there's one more thing we'd
993 // like to record: the histogram of memory usage, so we spawn a task to
[email protected]c9a3ef82009-05-28 22:02:46994 // collect the memory details and when that task is finished, it will call
995 // OnMemoryDetailCollectionDone, which will call HistogramSynchronization to
996 // collect histograms from all renderers and then we will call
997 // OnHistogramSynchronizationDone to continue processing.
initial.commit09911bf2008-07-26 23:55:29998 MessageLoop::current()->PostDelayedTask(FROM_HERE,
999 log_sender_factory_.
[email protected]c9a3ef82009-05-28 22:02:461000 NewRunnableMethod(&MetricsService::LogTransmissionTimerDone),
[email protected]743ace42009-06-17 17:23:511001 interlog_duration_.InMilliseconds());
initial.commit09911bf2008-07-26 23:55:291002}
1003
[email protected]c9a3ef82009-05-28 22:02:461004void MetricsService::LogTransmissionTimerDone() {
1005 Task* task = log_sender_factory_.
1006 NewRunnableMethod(&MetricsService::OnMemoryDetailCollectionDone);
1007
[email protected]e9adedb2009-12-01 22:23:591008 scoped_refptr<MetricsMemoryDetails> details = new MetricsMemoryDetails(task);
[email protected]c9a3ef82009-05-28 22:02:461009 details->StartFetch();
1010
1011 // Collect WebCore cache information to put into a histogram.
[email protected]019191a2009-10-02 20:37:271012 for (RenderProcessHost::iterator i(RenderProcessHost::AllHostsIterator());
1013 !i.IsAtEnd(); i.Advance())
1014 i.GetCurrentValue()->Send(new ViewMsg_GetCacheResourceStats());
[email protected]c9a3ef82009-05-28 22:02:461015}
1016
1017void MetricsService::OnMemoryDetailCollectionDone() {
1018 DCHECK(IsSingleThreaded());
1019
1020 // HistogramSynchronizer will Collect histograms from all renderers and it
1021 // will call OnHistogramSynchronizationDone (if wait time elapses before it
1022 // heard from all renderers, then also it will call
1023 // OnHistogramSynchronizationDone).
1024
1025 // Create a callback_task for OnHistogramSynchronizationDone.
1026 Task* callback_task = log_sender_factory_.NewRunnableMethod(
1027 &MetricsService::OnHistogramSynchronizationDone);
1028
1029 // Set up the callback to task to call after we receive histograms from all
1030 // renderer processes. Wait time specifies how long to wait before absolutely
1031 // calling us back on the task.
1032 HistogramSynchronizer::FetchRendererHistogramsAsynchronously(
1033 MessageLoop::current(), callback_task,
1034 kMaxHistogramGatheringWaitDuration);
1035}
1036
1037void MetricsService::OnHistogramSynchronizationDone() {
initial.commit09911bf2008-07-26 23:55:291038 DCHECK(IsSingleThreaded());
1039
[email protected]d01b8732008-10-16 02:18:071040 // This function should only be called via timer, so timer_pending_
1041 // should be true.
1042 DCHECK(timer_pending_);
1043 timer_pending_ = false;
initial.commit09911bf2008-07-26 23:55:291044
1045 DCHECK(!current_fetch_.get());
initial.commit09911bf2008-07-26 23:55:291046
[email protected]d01b8732008-10-16 02:18:071047 // If we're getting no notifications, then the log won't have much in it, and
1048 // it's possible the computer is about to go to sleep, so don't upload and
1049 // don't restart the transmission timer.
1050 if (idle_since_last_transmission_)
1051 return;
1052
1053 // If somehow there is a fetch in progress, we return setting timer_pending_
1054 // to true and hope things work out.
1055 if (current_fetch_.get()) {
1056 timer_pending_ = true;
1057 return;
1058 }
1059
1060 // If uploads are forbidden by UMA response, there's no point in keeping
1061 // the current_log_, and the more often we delete it, the less likely it is
1062 // to expand forever.
1063 if (!server_permits_upload_ && current_log_) {
1064 StopRecording(NULL);
1065 StartRecording();
1066 }
initial.commit09911bf2008-07-26 23:55:291067
1068 if (!current_log_)
1069 return; // Logging was disabled.
[email protected]d01b8732008-10-16 02:18:071070 if (!reporting_active())
initial.commit09911bf2008-07-26 23:55:291071 return; // Don't do work if we're not going to send anything now.
1072
[email protected]d01b8732008-10-16 02:18:071073 MakePendingLog();
initial.commit09911bf2008-07-26 23:55:291074
[email protected]d01b8732008-10-16 02:18:071075 // MakePendingLog should have put something in the pending log, if it didn't,
1076 // we start the timer again, return and hope things work out.
1077 if (!pending_log()) {
1078 StartLogTransmissionTimer();
1079 return;
1080 }
initial.commit09911bf2008-07-26 23:55:291081
[email protected]d01b8732008-10-16 02:18:071082 // If we're not supposed to upload any UMA data because the response or the
1083 // user said so, cancel the upload at this point, but start the timer.
1084 if (!TransmissionPermitted()) {
1085 DiscardPendingLog();
1086 StartLogTransmissionTimer();
1087 return;
1088 }
initial.commit09911bf2008-07-26 23:55:291089
[email protected]d01b8732008-10-16 02:18:071090 PrepareFetchWithPendingLog();
1091
1092 if (!current_fetch_.get()) {
1093 // Compression failed, and log discarded :-/.
1094 DiscardPendingLog();
1095 StartLogTransmissionTimer(); // Maybe we'll do better next time
1096 // TODO(jar): If compression failed, we should have created a tiny log and
1097 // compressed that, so that we can signal that we're losing logs.
1098 return;
1099 }
1100
1101 DCHECK(!timer_pending_);
1102
1103 // The URL fetch is a like timer in that after a while we get called back
1104 // so we set timer_pending_ true just as we start the url fetch.
1105 timer_pending_ = true;
1106 current_fetch_->Start();
1107
1108 HandleIdleSinceLastTransmission(true);
1109}
1110
1111
1112void MetricsService::MakePendingLog() {
1113 if (pending_log())
1114 return;
1115
1116 switch (state_) {
1117 case INITIALIZED:
[email protected]85ed9d42010-06-08 22:37:441118 case INIT_TASK_SCHEDULED: // We should be further along by now.
[email protected]d01b8732008-10-16 02:18:071119 DCHECK(false);
1120 return;
1121
[email protected]85ed9d42010-06-08 22:37:441122 case INIT_TASK_DONE:
[email protected]d01b8732008-10-16 02:18:071123 // We need to wait for the initial log to be ready before sending
1124 // anything, because the server will tell us whether it wants to hear
1125 // from us.
1126 PrepareInitialLog();
[email protected]85ed9d42010-06-08 22:37:441127 DCHECK(state_ == INIT_TASK_DONE);
[email protected]d01b8732008-10-16 02:18:071128 RecallUnsentLogs();
1129 state_ = INITIAL_LOG_READY;
1130 break;
1131
1132 case SEND_OLD_INITIAL_LOGS:
[email protected]cac78842008-11-27 01:02:201133 if (!unsent_initial_logs_.empty()) {
[email protected]46f89e142010-07-19 08:00:421134 compressed_log_ = unsent_initial_logs_.back();
[email protected]cac78842008-11-27 01:02:201135 break;
1136 }
[email protected]d01b8732008-10-16 02:18:071137 state_ = SENDING_OLD_LOGS;
1138 // Fall through.
initial.commit09911bf2008-07-26 23:55:291139
[email protected]d01b8732008-10-16 02:18:071140 case SENDING_OLD_LOGS:
1141 if (!unsent_ongoing_logs_.empty()) {
[email protected]46f89e142010-07-19 08:00:421142 compressed_log_ = unsent_ongoing_logs_.back();
[email protected]d01b8732008-10-16 02:18:071143 break;
1144 }
1145 state_ = SENDING_CURRENT_LOGS;
1146 // Fall through.
1147
1148 case SENDING_CURRENT_LOGS:
1149 StopRecording(&pending_log_);
1150 StartRecording();
1151 break;
1152
1153 default:
[email protected]a063c102010-07-22 22:20:191154 NOTREACHED();
[email protected]d01b8732008-10-16 02:18:071155 return;
1156 }
1157
1158 DCHECK(pending_log());
1159}
1160
1161bool MetricsService::TransmissionPermitted() const {
1162 // If the user forbids uploading that's they're business, and we don't upload
1163 // anything. If the server forbids uploading, that's our business, so we take
1164 // that to mean it forbids current logs, but we still send up the inital logs
1165 // and any old logs.
[email protected]d01b8732008-10-16 02:18:071166 if (!user_permits_upload_)
1167 return false;
[email protected]cac78842008-11-27 01:02:201168 if (server_permits_upload_)
[email protected]d01b8732008-10-16 02:18:071169 return true;
initial.commit09911bf2008-07-26 23:55:291170
[email protected]cac78842008-11-27 01:02:201171 switch (state_) {
1172 case INITIAL_LOG_READY:
1173 case SEND_OLD_INITIAL_LOGS:
1174 case SENDING_OLD_LOGS:
1175 return true;
1176
1177 case SENDING_CURRENT_LOGS:
1178 default:
1179 return false;
[email protected]8c8824b2008-09-20 01:55:501180 }
initial.commit09911bf2008-07-26 23:55:291181}
1182
initial.commit09911bf2008-07-26 23:55:291183void MetricsService::PrepareInitialLog() {
[email protected]85ed9d42010-06-08 22:37:441184 DCHECK(state_ == INIT_TASK_DONE);
initial.commit09911bf2008-07-26 23:55:291185
1186 MetricsLog* log = new MetricsLog(client_id_, session_id_);
[email protected]85ed9d42010-06-08 22:37:441187 log->set_hardware_class(hardware_class_); // Adds to initial log.
[email protected]35fa6a22009-08-15 00:04:011188 log->RecordEnvironment(plugins_, profile_dictionary_.get());
initial.commit09911bf2008-07-26 23:55:291189
1190 // Histograms only get written to current_log_, so setup for the write.
[email protected]1226abb2010-06-10 18:01:281191 MetricsLogBase* save_log = current_log_;
initial.commit09911bf2008-07-26 23:55:291192 current_log_ = log;
1193 RecordCurrentHistograms(); // Into current_log_... which is really log.
1194 current_log_ = save_log;
1195
1196 log->CloseLog();
1197 DCHECK(!pending_log());
1198 pending_log_ = log;
1199}
1200
[email protected]46f89e142010-07-19 08:00:421201// static
1202MetricsService::LogRecallStatus MetricsService::RecallUnsentLogsHelper(
1203 const ListValue& list,
1204 std::vector<std::string>* local_list) {
1205 DCHECK(local_list->empty());
1206 if (list.GetSize() == 0)
1207 return MakeRecallStatusHistogram(LIST_EMPTY);
1208 if (list.GetSize() < 3)
1209 return MakeRecallStatusHistogram(LIST_SIZE_TOO_SMALL);
initial.commit09911bf2008-07-26 23:55:291210
[email protected]46f89e142010-07-19 08:00:421211 // The size is stored at the beginning of the list.
1212 int size;
1213 bool valid = (*list.begin())->GetAsInteger(&size);
1214 if (!valid)
1215 return MakeRecallStatusHistogram(LIST_SIZE_MISSING);
1216
1217 // Account for checksum and size included in the list.
1218 if (static_cast<unsigned int>(size) !=
1219 list.GetSize() - kChecksumEntryCount)
1220 return MakeRecallStatusHistogram(LIST_SIZE_CORRUPTION);
1221
1222 MD5Context ctx;
1223 MD5Init(&ctx);
1224 std::string encoded_log;
1225 std::string decoded_log;
1226 for (ListValue::const_iterator it = list.begin() + 1;
1227 it != list.end() - 1; ++it) { // Last element is the checksum.
1228 valid = (*it)->GetAsString(&encoded_log);
1229 if (!valid) {
1230 local_list->clear();
1231 return MakeRecallStatusHistogram(LOG_STRING_CORRUPTION);
1232 }
1233
1234 MD5Update(&ctx, encoded_log.data(), encoded_log.length());
1235
1236 if (!base::Base64Decode(encoded_log, &decoded_log)) {
1237 local_list->clear();
1238 return MakeRecallStatusHistogram(DECODE_FAIL);
1239 }
1240 local_list->push_back(decoded_log);
1241 }
1242
1243 // Verify checksum.
1244 MD5Digest digest;
1245 MD5Final(&digest, &ctx);
1246 std::string recovered_md5;
1247 // We store the hash at the end of the list.
1248 valid = (*(list.end() - 1))->GetAsString(&recovered_md5);
1249 if (!valid) {
1250 local_list->clear();
1251 return MakeRecallStatusHistogram(CHECKSUM_STRING_CORRUPTION);
1252 }
1253 if (recovered_md5 != MD5DigestToBase16(digest)) {
1254 local_list->clear();
1255 return MakeRecallStatusHistogram(CHECKSUM_CORRUPTION);
1256 }
1257 return MakeRecallStatusHistogram(RECALL_SUCCESS);
1258}
1259void MetricsService::RecallUnsentLogs() {
initial.commit09911bf2008-07-26 23:55:291260 PrefService* local_state = g_browser_process->local_state();
1261 DCHECK(local_state);
1262
1263 ListValue* unsent_initial_logs = local_state->GetMutableList(
1264 prefs::kMetricsInitialLogs);
[email protected]46f89e142010-07-19 08:00:421265 RecallUnsentLogsHelper(*unsent_initial_logs, &unsent_initial_logs_);
initial.commit09911bf2008-07-26 23:55:291266
1267 ListValue* unsent_ongoing_logs = local_state->GetMutableList(
1268 prefs::kMetricsOngoingLogs);
[email protected]46f89e142010-07-19 08:00:421269 RecallUnsentLogsHelper(*unsent_ongoing_logs, &unsent_ongoing_logs_);
1270}
1271
1272// static
1273void MetricsService::StoreUnsentLogsHelper(
1274 const std::vector<std::string>& local_list,
1275 const size_t kMaxLocalListSize,
1276 ListValue* list) {
1277 list->Clear();
1278 size_t start = 0;
1279 if (local_list.size() > kMaxLocalListSize)
1280 start = local_list.size() - kMaxLocalListSize;
1281 DCHECK(start <= local_list.size());
1282 if (local_list.size() == start)
1283 return;
1284
1285 // Store size at the beginning of the list.
1286 list->Append(Value::CreateIntegerValue(local_list.size() - start));
1287
1288 MD5Context ctx;
1289 MD5Init(&ctx);
1290 std::string encoded_log;
1291 for (std::vector<std::string>::const_iterator it = local_list.begin() + start;
1292 it != local_list.end(); ++it) {
1293 // We encode the compressed log as Value::CreateStringValue() expects to
1294 // take a valid UTF8 string.
1295 if (!base::Base64Encode(*it, &encoded_log)) {
1296 MakeStoreStatusHistogram(ENCODE_FAIL);
1297 list->Clear();
1298 return;
1299 }
1300 MD5Update(&ctx, encoded_log.data(), encoded_log.length());
1301 list->Append(Value::CreateStringValue(encoded_log));
initial.commit09911bf2008-07-26 23:55:291302 }
[email protected]46f89e142010-07-19 08:00:421303
1304 // Append hash to the end of the list.
1305 MD5Digest digest;
1306 MD5Final(&digest, &ctx);
1307 list->Append(Value::CreateStringValue(MD5DigestToBase16(digest)));
1308 DCHECK(list->GetSize() >= 3); // Minimum of 3 elements (size, data, hash).
[email protected]4e95d202010-07-24 01:47:561309 MakeStoreStatusHistogram(STORE_SUCCESS);
initial.commit09911bf2008-07-26 23:55:291310}
1311
1312void MetricsService::StoreUnsentLogs() {
1313 if (state_ < INITIAL_LOG_READY)
1314 return; // We never Recalled the prior unsent logs.
1315
1316 PrefService* local_state = g_browser_process->local_state();
1317 DCHECK(local_state);
1318
1319 ListValue* unsent_initial_logs = local_state->GetMutableList(
1320 prefs::kMetricsInitialLogs);
[email protected]46f89e142010-07-19 08:00:421321 StoreUnsentLogsHelper(unsent_initial_logs_, kMaxInitialLogsPersisted,
1322 unsent_initial_logs);
initial.commit09911bf2008-07-26 23:55:291323
1324 ListValue* unsent_ongoing_logs = local_state->GetMutableList(
1325 prefs::kMetricsOngoingLogs);
[email protected]46f89e142010-07-19 08:00:421326 StoreUnsentLogsHelper(unsent_ongoing_logs_, kMaxOngoingLogsPersisted,
1327 unsent_ongoing_logs);
initial.commit09911bf2008-07-26 23:55:291328}
1329
1330void MetricsService::PreparePendingLogText() {
1331 DCHECK(pending_log());
[email protected]46f89e142010-07-19 08:00:421332 if (!compressed_log_.empty())
initial.commit09911bf2008-07-26 23:55:291333 return;
[email protected]9ffcccf42009-09-15 22:19:181334 int text_size = pending_log_->GetEncodedLogSize();
1335
[email protected]46f89e142010-07-19 08:00:421336 std::string pending_log_text;
1337 // Leave room for the NULL terminator.
1338 pending_log_->GetEncodedLog(WriteInto(&pending_log_text, text_size + 1),
[email protected]9ffcccf42009-09-15 22:19:181339 text_size);
[email protected]46f89e142010-07-19 08:00:421340
1341 if (Bzip2Compress(pending_log_text, &compressed_log_)) {
1342 // Allow security conscious users to see all metrics logs that we send.
1343 LOG(INFO) << "COMPRESSED FOLLOWING METRICS LOG: " << pending_log_text;
1344 } else {
1345 LOG(DFATAL) << "Failed to compress log for transmission.";
1346 // We can't discard the logs as other caller functions expect that
1347 // |compressed_log_| not be empty. We can detect this failure at the server
1348 // after we transmit.
1349 compressed_log_ = "Unable to compress!";
1350 MakeStoreStatusHistogram(COMPRESS_FAIL);
1351 return;
1352 }
initial.commit09911bf2008-07-26 23:55:291353}
1354
[email protected]d01b8732008-10-16 02:18:071355void MetricsService::PrepareFetchWithPendingLog() {
initial.commit09911bf2008-07-26 23:55:291356 DCHECK(pending_log());
1357 DCHECK(!current_fetch_.get());
1358 PreparePendingLogText();
[email protected]46f89e142010-07-19 08:00:421359 DCHECK(!compressed_log_.empty());
[email protected]cac78842008-11-27 01:02:201360
[email protected]79bf0b72009-04-27 21:30:551361 current_fetch_.reset(new URLFetcher(GURL(WideToUTF16(server_url_)),
1362 URLFetcher::POST,
initial.commit09911bf2008-07-26 23:55:291363 this));
1364 current_fetch_->set_request_context(Profile::GetDefaultRequestContext());
[email protected]46f89e142010-07-19 08:00:421365 current_fetch_->set_upload_data(kMetricsType, compressed_log_);
initial.commit09911bf2008-07-26 23:55:291366}
1367
initial.commit09911bf2008-07-26 23:55:291368static const char* StatusToString(const URLRequestStatus& status) {
1369 switch (status.status()) {
1370 case URLRequestStatus::SUCCESS:
1371 return "SUCCESS";
1372
1373 case URLRequestStatus::IO_PENDING:
1374 return "IO_PENDING";
1375
1376 case URLRequestStatus::HANDLED_EXTERNALLY:
1377 return "HANDLED_EXTERNALLY";
1378
1379 case URLRequestStatus::CANCELED:
1380 return "CANCELED";
1381
1382 case URLRequestStatus::FAILED:
1383 return "FAILED";
1384
1385 default:
[email protected]a063c102010-07-22 22:20:191386 NOTREACHED();
initial.commit09911bf2008-07-26 23:55:291387 return "Unknown";
1388 }
1389}
1390
1391void MetricsService::OnURLFetchComplete(const URLFetcher* source,
1392 const GURL& url,
1393 const URLRequestStatus& status,
1394 int response_code,
1395 const ResponseCookies& cookies,
1396 const std::string& data) {
1397 DCHECK(timer_pending_);
1398 timer_pending_ = false;
1399 DCHECK(current_fetch_.get());
1400 current_fetch_.reset(NULL); // We're not allowed to re-use it.
1401
1402 // Confirm send so that we can move on.
[email protected]281d2882009-01-20 20:32:421403 LOG(INFO) << "METRICS RESPONSE CODE: " << response_code << " status=" <<
[email protected]cac78842008-11-27 01:02:201404 StatusToString(status);
[email protected]252873ef2008-08-04 21:59:451405
[email protected]0eb34fee2009-01-21 08:04:381406 // Provide boolean for error recovery (allow us to ignore response_code).
[email protected]dc6f4962009-02-13 01:25:501407 bool discard_log = false;
[email protected]0eb34fee2009-01-21 08:04:381408
[email protected]68475e602008-08-22 03:21:151409 if (response_code != 200 &&
[email protected]46f89e142010-07-19 08:00:421410 (compressed_log_.length() >
1411 static_cast<size_t>(kUploadLogAvoidRetransmitSize))) {
[email protected]553dba62009-02-24 19:08:231412 UMA_HISTOGRAM_COUNTS("UMA.Large Rejected Log was Discarded",
[email protected]46f89e142010-07-19 08:00:421413 static_cast<int>(compressed_log_.length()));
[email protected]0eb34fee2009-01-21 08:04:381414 discard_log = true;
1415 } else if (response_code == 400) {
1416 // Bad syntax. Retransmission won't work.
[email protected]553dba62009-02-24 19:08:231417 UMA_HISTOGRAM_COUNTS("UMA.Unacceptable_Log_Discarded", state_);
[email protected]0eb34fee2009-01-21 08:04:381418 discard_log = true;
[email protected]68475e602008-08-22 03:21:151419 }
1420
[email protected]0eb34fee2009-01-21 08:04:381421 if (response_code != 200 && !discard_log) {
[email protected]281d2882009-01-20 20:32:421422 LOG(INFO) << "METRICS: transmission attempt returned a failure code: "
1423 << response_code << ". Verify network connectivity";
[email protected]252873ef2008-08-04 21:59:451424 HandleBadResponseCode();
[email protected]0eb34fee2009-01-21 08:04:381425 } else { // Successful receipt (or we are discarding log).
[email protected]281d2882009-01-20 20:32:421426 LOG(INFO) << "METRICS RESPONSE DATA: " << data;
initial.commit09911bf2008-07-26 23:55:291427 switch (state_) {
1428 case INITIAL_LOG_READY:
1429 state_ = SEND_OLD_INITIAL_LOGS;
1430 break;
1431
1432 case SEND_OLD_INITIAL_LOGS:
1433 DCHECK(!unsent_initial_logs_.empty());
1434 unsent_initial_logs_.pop_back();
1435 StoreUnsentLogs();
1436 break;
1437
1438 case SENDING_OLD_LOGS:
1439 DCHECK(!unsent_ongoing_logs_.empty());
1440 unsent_ongoing_logs_.pop_back();
1441 StoreUnsentLogs();
1442 break;
1443
1444 case SENDING_CURRENT_LOGS:
1445 break;
1446
1447 default:
[email protected]a063c102010-07-22 22:20:191448 NOTREACHED();
initial.commit09911bf2008-07-26 23:55:291449 break;
1450 }
[email protected]d01b8732008-10-16 02:18:071451
initial.commit09911bf2008-07-26 23:55:291452 DiscardPendingLog();
[email protected]29be92552008-08-07 22:49:271453 // Since we sent a log, make sure our in-memory state is recorded to disk.
1454 PrefService* local_state = g_browser_process->local_state();
1455 DCHECK(local_state);
1456 if (local_state)
[email protected]6faa0e0d2009-04-28 06:50:361457 local_state->ScheduleSavePersistentPrefs();
[email protected]252873ef2008-08-04 21:59:451458
[email protected]147bbc0b2009-01-06 19:37:401459 // Provide a default (free of exponetial backoff, other varances) in case
1460 // the server does not specify a value.
1461 interlog_duration_ = TimeDelta::FromSeconds(kMinSecondsPerLog);
1462
[email protected]252873ef2008-08-04 21:59:451463 GetSettingsFromResponseData(data);
[email protected]252873ef2008-08-04 21:59:451464 // Override server specified interlog delay if there are unsent logs to
[email protected]29be92552008-08-07 22:49:271465 // transmit.
initial.commit09911bf2008-07-26 23:55:291466 if (unsent_logs()) {
1467 DCHECK(state_ < SENDING_CURRENT_LOGS);
1468 interlog_duration_ = TimeDelta::FromSeconds(kUnsentLogDelay);
initial.commit09911bf2008-07-26 23:55:291469 }
1470 }
[email protected]252873ef2008-08-04 21:59:451471
initial.commit09911bf2008-07-26 23:55:291472 StartLogTransmissionTimer();
1473}
1474
[email protected]252873ef2008-08-04 21:59:451475void MetricsService::HandleBadResponseCode() {
[email protected]281d2882009-01-20 20:32:421476 LOG(INFO) << "Verify your metrics logs are formatted correctly. "
[email protected]79bf0b72009-04-27 21:30:551477 "Verify server is active at " << server_url_;
[email protected]252873ef2008-08-04 21:59:451478 if (!pending_log()) {
[email protected]281d2882009-01-20 20:32:421479 LOG(INFO) << "METRICS: Recorder shutdown during log transmission.";
[email protected]252873ef2008-08-04 21:59:451480 } else {
1481 // Send progressively less frequently.
1482 DCHECK(kBackoff > 1.0);
1483 interlog_duration_ = TimeDelta::FromMicroseconds(
1484 static_cast<int64>(kBackoff * interlog_duration_.InMicroseconds()));
1485
1486 if (kMaxBackoff * TimeDelta::FromSeconds(kMinSecondsPerLog) <
[email protected]cac78842008-11-27 01:02:201487 interlog_duration_) {
[email protected]252873ef2008-08-04 21:59:451488 interlog_duration_ = kMaxBackoff *
1489 TimeDelta::FromSeconds(kMinSecondsPerLog);
[email protected]cac78842008-11-27 01:02:201490 }
[email protected]252873ef2008-08-04 21:59:451491
[email protected]281d2882009-01-20 20:32:421492 LOG(INFO) << "METRICS: transmission retry being scheduled in " <<
[email protected]252873ef2008-08-04 21:59:451493 interlog_duration_.InSeconds() << " seconds for " <<
[email protected]46f89e142010-07-19 08:00:421494 compressed_log_;
initial.commit09911bf2008-07-26 23:55:291495 }
initial.commit09911bf2008-07-26 23:55:291496}
1497
[email protected]252873ef2008-08-04 21:59:451498void MetricsService::GetSettingsFromResponseData(const std::string& data) {
1499 // We assume that the file is structured as a block opened by <response>
[email protected]d01b8732008-10-16 02:18:071500 // and that inside response, there is a block opened by tag <chrome_config>
1501 // other tags are ignored for now except the content of <chrome_config>.
[email protected]281d2882009-01-20 20:32:421502 LOG(INFO) << "METRICS: getting settings from response data: " << data;
[email protected]d01b8732008-10-16 02:18:071503
[email protected]252873ef2008-08-04 21:59:451504 int data_size = static_cast<int>(data.size());
1505 if (data_size < 0) {
[email protected]281d2882009-01-20 20:32:421506 LOG(INFO) << "METRICS: server response data bad size: " << data_size <<
[email protected]cac78842008-11-27 01:02:201507 "; aborting extraction of settings";
[email protected]252873ef2008-08-04 21:59:451508 return;
1509 }
[email protected]cac78842008-11-27 01:02:201510 xmlDocPtr doc = xmlReadMemory(data.c_str(), data_size, "", NULL, 0);
[email protected]d01b8732008-10-16 02:18:071511 // If the document is malformed, we just use the settings that were there.
1512 if (!doc) {
[email protected]281d2882009-01-20 20:32:421513 LOG(INFO) << "METRICS: reading xml from server response data failed";
[email protected]252873ef2008-08-04 21:59:451514 return;
[email protected]d01b8732008-10-16 02:18:071515 }
[email protected]252873ef2008-08-04 21:59:451516
[email protected]d01b8732008-10-16 02:18:071517 xmlNodePtr top_node = xmlDocGetRootElement(doc), chrome_config_node = NULL;
1518 // Here, we find the chrome_config node by name.
[email protected]252873ef2008-08-04 21:59:451519 for (xmlNodePtr p = top_node->children; p; p = p->next) {
[email protected]d01b8732008-10-16 02:18:071520 if (xmlStrEqual(p->name, BAD_CAST "chrome_config")) {
1521 chrome_config_node = p;
[email protected]252873ef2008-08-04 21:59:451522 break;
1523 }
1524 }
1525 // If the server data is formatted wrong and there is no
1526 // config node where we expect, we just drop out.
[email protected]d01b8732008-10-16 02:18:071527 if (chrome_config_node != NULL)
1528 GetSettingsFromChromeConfigNode(chrome_config_node);
[email protected]252873ef2008-08-04 21:59:451529 xmlFreeDoc(doc);
1530}
1531
[email protected]d01b8732008-10-16 02:18:071532void MetricsService::GetSettingsFromChromeConfigNode(
1533 xmlNodePtr chrome_config_node) {
1534 // Iterate through all children of the config node.
1535 for (xmlNodePtr current_node = chrome_config_node->children;
1536 current_node;
1537 current_node = current_node->next) {
1538 // If we find the upload tag, we appeal to another function
1539 // GetSettingsFromUploadNode to read all the data in it.
[email protected]252873ef2008-08-04 21:59:451540 if (xmlStrEqual(current_node->name, BAD_CAST "upload")) {
[email protected]d01b8732008-10-16 02:18:071541 GetSettingsFromUploadNode(current_node);
[email protected]252873ef2008-08-04 21:59:451542 continue;
1543 }
1544 }
1545}
initial.commit09911bf2008-07-26 23:55:291546
[email protected]d01b8732008-10-16 02:18:071547void MetricsService::InheritedProperties::OverwriteWhereNeeded(
1548 xmlNodePtr node) {
1549 xmlChar* salt_value = xmlGetProp(node, BAD_CAST "salt");
1550 if (salt_value) // If the property isn't there, xmlGetProp returns NULL.
1551 salt = atoi(reinterpret_cast<char*>(salt_value));
1552 // If the property isn't there, we keep the value the property had before
1553
1554 xmlChar* denominator_value = xmlGetProp(node, BAD_CAST "denominator");
1555 if (denominator_value)
1556 denominator = atoi(reinterpret_cast<char*>(denominator_value));
1557}
1558
1559void MetricsService::GetSettingsFromUploadNode(xmlNodePtr upload_node) {
1560 InheritedProperties props;
1561 GetSettingsFromUploadNodeRecursive(upload_node, props, "", true);
1562}
1563
[email protected]cac78842008-11-27 01:02:201564void MetricsService::GetSettingsFromUploadNodeRecursive(
1565 xmlNodePtr node,
1566 InheritedProperties props,
1567 std::string path_prefix,
1568 bool uploadOn) {
[email protected]d01b8732008-10-16 02:18:071569 props.OverwriteWhereNeeded(node);
1570
1571 // The bool uploadOn is set to true if the data represented by current
1572 // node should be uploaded. This gets inherited in the tree; the children
1573 // of a node that has already been rejected for upload get rejected for
1574 // upload.
1575 uploadOn = uploadOn && NodeProbabilityTest(node, props);
1576
1577 // The path is a / separated list of the node names ancestral to the current
1578 // one. So, if you want to check if the current node has a certain name,
1579 // compare to name. If you want to check if it is a certan tag at a certain
1580 // place in the tree, compare to the whole path.
1581 std::string name = std::string(reinterpret_cast<const char*>(node->name));
1582 std::string path = path_prefix + "/" + name;
1583
1584 if (path == "/upload") {
1585 xmlChar* upload_interval_val = xmlGetProp(node, BAD_CAST "interval");
1586 if (upload_interval_val) {
1587 interlog_duration_ = TimeDelta::FromSeconds(
1588 atoi(reinterpret_cast<char*>(upload_interval_val)));
1589 }
1590
1591 server_permits_upload_ = uploadOn;
[email protected]24d07e32010-07-10 00:31:271592 } else if (path == "/upload/logs") {
[email protected]d01b8732008-10-16 02:18:071593 xmlChar* log_event_limit_val = xmlGetProp(node, BAD_CAST "event_limit");
1594 if (log_event_limit_val)
1595 log_event_limit_ = atoi(reinterpret_cast<char*>(log_event_limit_val));
1596 }
[email protected]d01b8732008-10-16 02:18:071597
1598 // Recursive call. If the node is a leaf i.e. if it ends in a "/>", then it
1599 // doesn't have children, so node->children is NULL, and this loop doesn't
1600 // call (that's how the recursion ends).
1601 for (xmlNodePtr child_node = node->children;
[email protected]cac78842008-11-27 01:02:201602 child_node;
1603 child_node = child_node->next) {
[email protected]d01b8732008-10-16 02:18:071604 GetSettingsFromUploadNodeRecursive(child_node, props, path, uploadOn);
1605 }
1606}
1607
1608bool MetricsService::NodeProbabilityTest(xmlNodePtr node,
[email protected]cac78842008-11-27 01:02:201609 InheritedProperties props) const {
[email protected]d01b8732008-10-16 02:18:071610 // Default value of probability on any node is 1, but recall that
1611 // its parents can already have been rejected for upload.
1612 double probability = 1;
1613
1614 // If a probability is specified in the node, we use it instead.
1615 xmlChar* probability_value = xmlGetProp(node, BAD_CAST "probability");
1616 if (probability_value)
[email protected]0b33f80b2008-12-17 21:34:361617 probability = atoi(reinterpret_cast<char*>(probability_value));
[email protected]d01b8732008-10-16 02:18:071618
1619 return ProbabilityTest(probability, props.salt, props.denominator);
1620}
1621
1622bool MetricsService::ProbabilityTest(double probability,
1623 int salt,
1624 int denominator) const {
1625 // Okay, first we figure out how many of the digits of the
1626 // client_id_ we need in order to make a nice pseudorandomish
1627 // number in the range [0,denominator). Too many digits is
1628 // fine.
[email protected]d01b8732008-10-16 02:18:071629
1630 // n is the length of the client_id_ string
1631 size_t n = client_id_.size();
1632
1633 // idnumber is a positive integer generated from the client_id_.
1634 // It plus salt is going to give us our pseudorandom number.
1635 int idnumber = 0;
1636 const char* client_id_c_str = client_id_.c_str();
1637
1638 // Here we hash the relevant digits of the client_id_
1639 // string somehow to get a big integer idnumber (could be negative
1640 // from wraparound)
1641 int big = 1;
[email protected]5ed73342009-03-18 17:39:431642 int last_pos = n - 1;
1643 for (size_t j = 0; j < n; ++j) {
1644 idnumber += static_cast<int>(client_id_c_str[last_pos - j]) * big;
[email protected]d01b8732008-10-16 02:18:071645 big *= 10;
1646 }
1647
1648 // Mod id number by denominator making sure to get a non-negative
1649 // answer.
[email protected]cac78842008-11-27 01:02:201650 idnumber = ((idnumber % denominator) + denominator) % denominator;
[email protected]d01b8732008-10-16 02:18:071651
[email protected]cac78842008-11-27 01:02:201652 // ((idnumber + salt) % denominator) / denominator is in the range [0,1]
[email protected]d01b8732008-10-16 02:18:071653 // if it's less than probability we call that an affirmative coin
1654 // toss.
[email protected]cac78842008-11-27 01:02:201655 return static_cast<double>((idnumber + salt) % denominator) <
1656 probability * denominator;
[email protected]d01b8732008-10-16 02:18:071657}
1658
initial.commit09911bf2008-07-26 23:55:291659void MetricsService::LogWindowChange(NotificationType type,
1660 const NotificationSource& source,
1661 const NotificationDetails& details) {
[email protected]534e54b2008-08-13 15:40:091662 int controller_id = -1;
1663 uintptr_t window_or_tab = source.map_key();
initial.commit09911bf2008-07-26 23:55:291664 MetricsLog::WindowEventType window_type;
1665
1666 // Note: since we stop all logging when a single OTR session is active, it is
1667 // possible that we start getting notifications about a window that we don't
1668 // know about.
[email protected]534e54b2008-08-13 15:40:091669 if (window_map_.find(window_or_tab) == window_map_.end()) {
1670 controller_id = next_window_id_++;
1671 window_map_[window_or_tab] = controller_id;
initial.commit09911bf2008-07-26 23:55:291672 } else {
[email protected]534e54b2008-08-13 15:40:091673 controller_id = window_map_[window_or_tab];
initial.commit09911bf2008-07-26 23:55:291674 }
[email protected]92745242009-06-12 16:52:211675 DCHECK_NE(controller_id, -1);
initial.commit09911bf2008-07-26 23:55:291676
[email protected]bfd04a62009-02-01 18:16:561677 switch (type.value) {
1678 case NotificationType::TAB_PARENTED:
1679 case NotificationType::BROWSER_OPENED:
initial.commit09911bf2008-07-26 23:55:291680 window_type = MetricsLog::WINDOW_CREATE;
1681 break;
1682
[email protected]bfd04a62009-02-01 18:16:561683 case NotificationType::TAB_CLOSING:
1684 case NotificationType::BROWSER_CLOSED:
[email protected]534e54b2008-08-13 15:40:091685 window_map_.erase(window_map_.find(window_or_tab));
initial.commit09911bf2008-07-26 23:55:291686 window_type = MetricsLog::WINDOW_DESTROY;
1687 break;
1688
1689 default:
[email protected]a063c102010-07-22 22:20:191690 NOTREACHED();
[email protected]68d74f02009-02-13 01:36:501691 return;
initial.commit09911bf2008-07-26 23:55:291692 }
1693
[email protected]534e54b2008-08-13 15:40:091694 // TODO(brettw) we should have some kind of ID for the parent.
1695 current_log_->RecordWindowEvent(window_type, controller_id, 0);
initial.commit09911bf2008-07-26 23:55:291696}
1697
1698void MetricsService::LogLoadComplete(NotificationType type,
1699 const NotificationSource& source,
1700 const NotificationDetails& details) {
1701 if (details == NotificationService::NoDetails())
1702 return;
1703
[email protected]68475e602008-08-22 03:21:151704 // TODO(jar): There is a bug causing this to be called too many times, and
1705 // the log overflows. For now, we won't record these events.
[email protected]553dba62009-02-24 19:08:231706 UMA_HISTOGRAM_COUNTS("UMA.LogLoadComplete called", 1);
[email protected]68475e602008-08-22 03:21:151707 return;
1708
initial.commit09911bf2008-07-26 23:55:291709 const Details<LoadNotificationDetails> load_details(details);
[email protected]534e54b2008-08-13 15:40:091710 int controller_id = window_map_[details.map_key()];
1711 current_log_->RecordLoadEvent(controller_id,
initial.commit09911bf2008-07-26 23:55:291712 load_details->url(),
1713 load_details->origin(),
1714 load_details->session_index(),
1715 load_details->load_time());
1716}
1717
[email protected]e73c01972008-08-13 00:18:241718void MetricsService::IncrementPrefValue(const wchar_t* path) {
1719 PrefService* pref = g_browser_process->local_state();
1720 DCHECK(pref);
1721 int value = pref->GetInteger(path);
1722 pref->SetInteger(path, value + 1);
1723}
1724
[email protected]0bb1a622009-03-04 03:22:321725void MetricsService::IncrementLongPrefsValue(const wchar_t* path) {
1726 PrefService* pref = g_browser_process->local_state();
1727 DCHECK(pref);
1728 int64 value = pref->GetInt64(path);
[email protected]b42c5e42010-06-03 20:43:251729 pref->SetInt64(path, value + 1);
[email protected]0bb1a622009-03-04 03:22:321730}
1731
initial.commit09911bf2008-07-26 23:55:291732void MetricsService::LogLoadStarted() {
[email protected]e73c01972008-08-13 00:18:241733 IncrementPrefValue(prefs::kStabilityPageLoadCount);
[email protected]0bb1a622009-03-04 03:22:321734 IncrementLongPrefsValue(prefs::kUninstallMetricsPageLoadCount);
[email protected]0b33f80b2008-12-17 21:34:361735 // We need to save the prefs, as page load count is a critical stat, and it
1736 // might be lost due to a crash :-(.
initial.commit09911bf2008-07-26 23:55:291737}
1738
initial.commit09911bf2008-07-26 23:55:291739void MetricsService::LogRendererCrash() {
[email protected]e73c01972008-08-13 00:18:241740 IncrementPrefValue(prefs::kStabilityRendererCrashCount);
initial.commit09911bf2008-07-26 23:55:291741}
1742
[email protected]1f085622009-12-04 05:33:451743void MetricsService::LogExtensionRendererCrash() {
1744 IncrementPrefValue(prefs::kStabilityExtensionRendererCrashCount);
1745}
1746
initial.commit09911bf2008-07-26 23:55:291747void MetricsService::LogRendererHang() {
[email protected]e73c01972008-08-13 00:18:241748 IncrementPrefValue(prefs::kStabilityRendererHangCount);
initial.commit09911bf2008-07-26 23:55:291749}
1750
[email protected]a27a9382009-02-11 23:55:101751void MetricsService::LogChildProcessChange(
1752 NotificationType type,
1753 const NotificationSource& source,
1754 const NotificationDetails& details) {
[email protected]0d84c5d2009-10-09 01:10:421755 Details<ChildProcessInfo> child_details(details);
1756 const std::wstring& child_name = child_details->name();
1757
[email protected]a27a9382009-02-11 23:55:101758 if (child_process_stats_buffer_.find(child_name) ==
1759 child_process_stats_buffer_.end()) {
[email protected]0d84c5d2009-10-09 01:10:421760 child_process_stats_buffer_[child_name] =
1761 ChildProcessStats(child_details->type());
initial.commit09911bf2008-07-26 23:55:291762 }
1763
[email protected]a27a9382009-02-11 23:55:101764 ChildProcessStats& stats = child_process_stats_buffer_[child_name];
[email protected]bfd04a62009-02-01 18:16:561765 switch (type.value) {
[email protected]a27a9382009-02-11 23:55:101766 case NotificationType::CHILD_PROCESS_HOST_CONNECTED:
initial.commit09911bf2008-07-26 23:55:291767 stats.process_launches++;
1768 break;
1769
[email protected]a27a9382009-02-11 23:55:101770 case NotificationType::CHILD_INSTANCE_CREATED:
initial.commit09911bf2008-07-26 23:55:291771 stats.instances++;
1772 break;
1773
[email protected]a27a9382009-02-11 23:55:101774 case NotificationType::CHILD_PROCESS_CRASHED:
initial.commit09911bf2008-07-26 23:55:291775 stats.process_crashes++;
[email protected]1f085622009-12-04 05:33:451776 // Exclude plugin crashes from the count below because we report them via
1777 // a separate UMA metric.
1778 if (child_details->type() != ChildProcessInfo::PLUGIN_PROCESS) {
1779 IncrementPrefValue(prefs::kStabilityChildProcessCrashCount);
1780 }
initial.commit09911bf2008-07-26 23:55:291781 break;
1782
1783 default:
[email protected]a063c102010-07-22 22:20:191784 NOTREACHED() << "Unexpected notification type " << type.value;
initial.commit09911bf2008-07-26 23:55:291785 return;
1786 }
1787}
1788
1789// Recursively counts the number of bookmarks and folders in node.
[email protected]b3c33d462009-06-26 22:29:201790static void CountBookmarks(const BookmarkNode* node,
1791 int* bookmarks,
1792 int* folders) {
[email protected]037db002009-10-19 20:06:081793 if (node->type() == BookmarkNode::URL)
initial.commit09911bf2008-07-26 23:55:291794 (*bookmarks)++;
1795 else
1796 (*folders)++;
1797 for (int i = 0; i < node->GetChildCount(); ++i)
1798 CountBookmarks(node->GetChild(i), bookmarks, folders);
1799}
1800
[email protected]b3c33d462009-06-26 22:29:201801void MetricsService::LogBookmarks(const BookmarkNode* node,
initial.commit09911bf2008-07-26 23:55:291802 const wchar_t* num_bookmarks_key,
1803 const wchar_t* num_folders_key) {
1804 DCHECK(node);
1805 int num_bookmarks = 0;
1806 int num_folders = 0;
1807 CountBookmarks(node, &num_bookmarks, &num_folders);
1808 num_folders--; // Don't include the root folder in the count.
1809
1810 PrefService* pref = g_browser_process->local_state();
1811 DCHECK(pref);
1812 pref->SetInteger(num_bookmarks_key, num_bookmarks);
1813 pref->SetInteger(num_folders_key, num_folders);
1814}
1815
[email protected]d8e41ed2008-09-11 15:22:321816void MetricsService::LogBookmarks(BookmarkModel* model) {
initial.commit09911bf2008-07-26 23:55:291817 DCHECK(model);
1818 LogBookmarks(model->GetBookmarkBarNode(),
1819 prefs::kNumBookmarksOnBookmarkBar,
1820 prefs::kNumFoldersOnBookmarkBar);
1821 LogBookmarks(model->other_node(),
1822 prefs::kNumBookmarksInOtherBookmarkFolder,
1823 prefs::kNumFoldersInOtherBookmarkFolder);
1824 ScheduleNextStateSave();
1825}
1826
1827void MetricsService::LogKeywords(const TemplateURLModel* url_model) {
1828 DCHECK(url_model);
1829
1830 PrefService* pref = g_browser_process->local_state();
1831 DCHECK(pref);
1832 pref->SetInteger(prefs::kNumKeywords,
1833 static_cast<int>(url_model->GetTemplateURLs().size()));
1834 ScheduleNextStateSave();
1835}
1836
1837void MetricsService::RecordPluginChanges(PrefService* pref) {
1838 ListValue* plugins = pref->GetMutableList(prefs::kStabilityPluginStats);
1839 DCHECK(plugins);
1840
1841 for (ListValue::iterator value_iter = plugins->begin();
1842 value_iter != plugins->end(); ++value_iter) {
1843 if (!(*value_iter)->IsType(Value::TYPE_DICTIONARY)) {
[email protected]a063c102010-07-22 22:20:191844 NOTREACHED();
initial.commit09911bf2008-07-26 23:55:291845 continue;
1846 }
1847
1848 DictionaryValue* plugin_dict = static_cast<DictionaryValue*>(*value_iter);
[email protected]8e50b602009-03-03 22:59:431849 std::wstring plugin_name;
1850 plugin_dict->GetString(prefs::kStabilityPluginName, &plugin_name);
[email protected]6470ee8f2009-03-03 20:46:401851 if (plugin_name.empty()) {
[email protected]a063c102010-07-22 22:20:191852 NOTREACHED();
initial.commit09911bf2008-07-26 23:55:291853 continue;
1854 }
1855
[email protected]8e50b602009-03-03 22:59:431856 if (child_process_stats_buffer_.find(plugin_name) ==
[email protected]a27a9382009-02-11 23:55:101857 child_process_stats_buffer_.end())
initial.commit09911bf2008-07-26 23:55:291858 continue;
1859
[email protected]8e50b602009-03-03 22:59:431860 ChildProcessStats stats = child_process_stats_buffer_[plugin_name];
initial.commit09911bf2008-07-26 23:55:291861 if (stats.process_launches) {
1862 int launches = 0;
[email protected]8e50b602009-03-03 22:59:431863 plugin_dict->GetInteger(prefs::kStabilityPluginLaunches, &launches);
initial.commit09911bf2008-07-26 23:55:291864 launches += stats.process_launches;
[email protected]8e50b602009-03-03 22:59:431865 plugin_dict->SetInteger(prefs::kStabilityPluginLaunches, launches);
initial.commit09911bf2008-07-26 23:55:291866 }
1867 if (stats.process_crashes) {
1868 int crashes = 0;
[email protected]8e50b602009-03-03 22:59:431869 plugin_dict->GetInteger(prefs::kStabilityPluginCrashes, &crashes);
initial.commit09911bf2008-07-26 23:55:291870 crashes += stats.process_crashes;
[email protected]8e50b602009-03-03 22:59:431871 plugin_dict->SetInteger(prefs::kStabilityPluginCrashes, crashes);
initial.commit09911bf2008-07-26 23:55:291872 }
1873 if (stats.instances) {
1874 int instances = 0;
[email protected]8e50b602009-03-03 22:59:431875 plugin_dict->GetInteger(prefs::kStabilityPluginInstances, &instances);
initial.commit09911bf2008-07-26 23:55:291876 instances += stats.instances;
[email protected]8e50b602009-03-03 22:59:431877 plugin_dict->SetInteger(prefs::kStabilityPluginInstances, instances);
initial.commit09911bf2008-07-26 23:55:291878 }
1879
[email protected]8e50b602009-03-03 22:59:431880 child_process_stats_buffer_.erase(plugin_name);
initial.commit09911bf2008-07-26 23:55:291881 }
1882
1883 // Now go through and add dictionaries for plugins that didn't already have
1884 // reports in Local State.
[email protected]a27a9382009-02-11 23:55:101885 for (std::map<std::wstring, ChildProcessStats>::iterator cache_iter =
1886 child_process_stats_buffer_.begin();
1887 cache_iter != child_process_stats_buffer_.end(); ++cache_iter) {
[email protected]a27a9382009-02-11 23:55:101888 ChildProcessStats stats = cache_iter->second;
[email protected]0d84c5d2009-10-09 01:10:421889
1890 // Insert only plugins information into the plugins list.
1891 if (ChildProcessInfo::PLUGIN_PROCESS != stats.process_type)
1892 continue;
1893
1894 std::wstring plugin_name = cache_iter->first;
1895
initial.commit09911bf2008-07-26 23:55:291896 DictionaryValue* plugin_dict = new DictionaryValue;
1897
[email protected]8e50b602009-03-03 22:59:431898 plugin_dict->SetString(prefs::kStabilityPluginName, plugin_name);
1899 plugin_dict->SetInteger(prefs::kStabilityPluginLaunches,
initial.commit09911bf2008-07-26 23:55:291900 stats.process_launches);
[email protected]8e50b602009-03-03 22:59:431901 plugin_dict->SetInteger(prefs::kStabilityPluginCrashes,
initial.commit09911bf2008-07-26 23:55:291902 stats.process_crashes);
[email protected]8e50b602009-03-03 22:59:431903 plugin_dict->SetInteger(prefs::kStabilityPluginInstances,
initial.commit09911bf2008-07-26 23:55:291904 stats.instances);
1905 plugins->Append(plugin_dict);
1906 }
[email protected]a27a9382009-02-11 23:55:101907 child_process_stats_buffer_.clear();
initial.commit09911bf2008-07-26 23:55:291908}
1909
1910bool MetricsService::CanLogNotification(NotificationType type,
1911 const NotificationSource& source,
1912 const NotificationDetails& details) {
1913 // We simply don't log anything to UMA if there is a single off the record
1914 // session visible. The problem is that we always notify using the orginal
1915 // profile in order to simplify notification processing.
1916 return !BrowserList::IsOffTheRecordSessionActive();
1917}
1918
1919void MetricsService::RecordBooleanPrefValue(const wchar_t* path, bool value) {
1920 DCHECK(IsSingleThreaded());
1921
1922 PrefService* pref = g_browser_process->local_state();
1923 DCHECK(pref);
1924
1925 pref->SetBoolean(path, value);
1926 RecordCurrentState(pref);
1927}
1928
1929void MetricsService::RecordCurrentState(PrefService* pref) {
[email protected]0bb1a622009-03-04 03:22:321930 pref->SetInt64(prefs::kStabilityLastTimestampSec, Time::Now().ToTimeT());
initial.commit09911bf2008-07-26 23:55:291931
1932 RecordPluginChanges(pref);
1933}
1934
initial.commit09911bf2008-07-26 23:55:291935static bool IsSingleThreaded() {
[email protected]dc6f4962009-02-13 01:25:501936 static PlatformThreadId thread_id = 0;
initial.commit09911bf2008-07-26 23:55:291937 if (!thread_id)
[email protected]dc6f4962009-02-13 01:25:501938 thread_id = PlatformThread::CurrentId();
1939 return PlatformThread::CurrentId() == thread_id;
initial.commit09911bf2008-07-26 23:55:291940}
[email protected]5ccaa412009-11-13 22:00:161941
1942#if defined(OS_CHROMEOS)
[email protected]85ed9d42010-06-08 22:37:441943// static
1944std::string MetricsService::GetHardwareClass() {
1945 DCHECK(!ChromeThread::CurrentlyOn(ChromeThread::UI));
1946 std::string hardware_class;
1947 FilePath tool(kHardwareClassTool);
1948 CommandLine command(tool);
1949 if (base::GetAppOutput(command, &hardware_class)) {
1950 TrimWhitespaceASCII(hardware_class, TRIM_ALL, &hardware_class);
1951 } else {
1952 hardware_class = kUnknownHardwareClass;
1953 }
1954 return hardware_class;
1955}
1956
[email protected]29cf16772010-04-21 15:13:471957void MetricsService::StartExternalMetrics() {
[email protected]5ccaa412009-11-13 22:00:161958 external_metrics_ = new chromeos::ExternalMetrics;
[email protected]29cf16772010-04-21 15:13:471959 external_metrics_->Start();
[email protected]5ccaa412009-11-13 22:00:161960}
1961#endif