blob: a27d2cf10501384c6c9f1c78f36897d7bd96a379 [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]37858e52010-08-26 00:22:02180#include "chrome/browser/prefs/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)
[email protected]db342d52010-08-09 21:19:37204#include "chrome/browser/chromeos/cros/cros_library.h"
205#include "chrome/browser/chromeos/cros/system_library.h"
[email protected]5ccaa412009-11-13 22:00:16206#include "chrome/browser/chromeos/external_metrics.h"
[email protected]5ccaa412009-11-13 22:00:16207#endif
208
[email protected]46f89e142010-07-19 08:00:42209namespace {
210MetricsService::LogRecallStatus MakeRecallStatusHistogram(
211 MetricsService::LogRecallStatus status) {
212 UMA_HISTOGRAM_ENUMERATION("PrefService.PersistentLogRecall", status,
213 MetricsService::END_RECALL_STATUS);
214 return status;
215}
216
217// TODO(ziadh): Remove this when done with experiment.
218void MakeStoreStatusHistogram(MetricsService::LogStoreStatus status) {
[email protected]4e95d202010-07-24 01:47:56219 UMA_HISTOGRAM_ENUMERATION("PrefService.PersistentLogStore2", status,
[email protected]46f89e142010-07-19 08:00:42220 MetricsService::END_STORE_STATUS);
221}
222} // namespace
223
[email protected]e1acf6f2008-10-27 20:43:33224using base::Time;
225using base::TimeDelta;
226
initial.commit09911bf2008-07-26 23:55:29227// Check to see that we're being called on only one thread.
228static bool IsSingleThreaded();
229
initial.commit09911bf2008-07-26 23:55:29230static const char kMetricsType[] = "application/vnd.mozilla.metrics.bz2";
231
232// The delay, in seconds, after startup before sending the first log message.
[email protected]252873ef2008-08-04 21:59:45233static const int kInitialInterlogDuration = 60; // one minute
234
[email protected]c9a3ef82009-05-28 22:02:46235// This specifies the amount of time to wait for all renderers to send their
236// data.
237static const int kMaxHistogramGatheringWaitDuration = 60000; // 60 seconds.
238
[email protected]252873ef2008-08-04 21:59:45239// The default maximum number of events in a log uploaded to the UMA server.
[email protected]0b33f80b2008-12-17 21:34:36240static const int kInitialEventLimit = 2400;
[email protected]68475e602008-08-22 03:21:15241
242// If an upload fails, and the transmission was over this byte count, then we
243// will discard the log, and not try to retransmit it. We also don't persist
244// the log to the prefs for transmission during the next chrome session if this
245// limit is exceeded.
246static const int kUploadLogAvoidRetransmitSize = 50000;
initial.commit09911bf2008-07-26 23:55:29247
248// When we have logs from previous Chrome sessions to send, how long should we
249// delay (in seconds) between each log transmission.
250static const int kUnsentLogDelay = 15; // 15 seconds
251
252// Minimum time a log typically exists before sending, in seconds.
253// This number is supplied by the server, but until we parse it out of a server
254// response, we use this duration to specify how long we should wait before
255// sending the next log. If the channel is busy, such as when there is a
256// failure during an attempt to transmit a previous log, then a log may wait
[email protected]2fe42fe2010-05-07 19:22:39257// (and continue to accrue new log entries) for a much greater period of time.
258static const int kMinSecondsPerLog = 30 * 60; // Thirty minutes.
initial.commit09911bf2008-07-26 23:55:29259
initial.commit09911bf2008-07-26 23:55:29260// When we don't succeed at transmitting a log to a server, we progressively
261// wait longer and longer before sending the next log. This backoff process
262// help reduce load on the server, and makes the amount of backoff vary between
263// clients so that a collision (server overload?) on retransmit is less likely.
264// The following is the constant we use to expand that inter-log duration.
265static const double kBackoff = 1.1;
266// We limit the maximum backoff to be no greater than some multiple of the
267// default kMinSecondsPerLog. The following is that maximum ratio.
268static const int kMaxBackoff = 10;
269
270// Interval, in seconds, between state saves.
271static const int kSaveStateInterval = 5 * 60; // five minutes
272
273// The number of "initial" logs we're willing to save, and hope to send during
274// a future Chrome session. Initial logs contain crash stats, and are pretty
275// small.
276static const size_t kMaxInitialLogsPersisted = 20;
277
278// The number of ongoing logs we're willing to save persistently, and hope to
[email protected]281d2882009-01-20 20:32:42279// send during a this or future sessions. Note that each log may be pretty
initial.commit09911bf2008-07-26 23:55:29280// large, as presumably the related "initial" log wasn't sent (probably nothing
281// was, as the user was probably off-line). As a result, the log probably kept
282// accumulating while the "initial" log was stalled (pending_), and couldn't be
283// sent. As a result, we don't want to save too many of these mega-logs.
284// A "standard shutdown" will create a small log, including just the data that
285// was not yet been transmitted, and that is normal (to have exactly one
286// ongoing_log_ at startup).
[email protected]281d2882009-01-20 20:32:42287static const size_t kMaxOngoingLogsPersisted = 8;
initial.commit09911bf2008-07-26 23:55:29288
[email protected]46f89e142010-07-19 08:00:42289// We append (2) more elements to persisted lists: the size of the list and a
290// checksum of the elements.
291static const size_t kChecksumEntryCount = 2;
292
[email protected]679082052010-07-21 21:30:13293// This is used to quickly log stats from child process related notifications in
294// MetricsService::child_stats_buffer_. The buffer's contents are transferred
295// out when Local State is periodically saved. The information is then
296// reported to the UMA server on next launch.
297struct MetricsService::ChildProcessStats {
298 public:
299 explicit ChildProcessStats(ChildProcessInfo::ProcessType type)
300 : process_launches(0),
301 process_crashes(0),
302 instances(0),
303 process_type(type) {}
304
305 // This constructor is only used by the map to return some default value for
306 // an index for which no value has been assigned.
307 ChildProcessStats()
308 : process_launches(0),
309 process_crashes(0),
310 instances(0),
311 process_type(ChildProcessInfo::UNKNOWN_PROCESS) {}
312
313 // The number of times that the given child process has been launched
314 int process_launches;
315
316 // The number of times that the given child process has crashed
317 int process_crashes;
318
319 // The number of instances of this child process that have been created.
320 // An instance is a DOM object rendered by this child process during a page
321 // load.
322 int instances;
323
324 ChildProcessInfo::ProcessType process_type;
325};
initial.commit09911bf2008-07-26 23:55:29326
327// Handles asynchronous fetching of memory details.
328// Will run the provided task after finished.
329class MetricsMemoryDetails : public MemoryDetails {
330 public:
331 explicit MetricsMemoryDetails(Task* completion) : completion_(completion) {}
332
333 virtual void OnDetailsAvailable() {
334 MessageLoop::current()->PostTask(FROM_HERE, completion_);
335 }
336
337 private:
[email protected]e6e6ba42009-11-07 01:56:19338 ~MetricsMemoryDetails() {}
339
initial.commit09911bf2008-07-26 23:55:29340 Task* completion_;
[email protected]4d818fee2010-06-06 13:32:27341 DISALLOW_COPY_AND_ASSIGN(MetricsMemoryDetails);
initial.commit09911bf2008-07-26 23:55:29342};
343
[email protected]85ed9d42010-06-08 22:37:44344class MetricsService::InitTaskComplete : public Task {
[email protected]35fa6a22009-08-15 00:04:01345 public:
[email protected]85ed9d42010-06-08 22:37:44346 explicit InitTaskComplete(const std::string& hardware_class,
347 const std::vector<WebPluginInfo>& plugins)
348 : hardware_class_(hardware_class), plugins_(plugins) {}
349
[email protected]7f2e792e2009-11-30 23:18:29350 virtual void Run() {
[email protected]85ed9d42010-06-08 22:37:44351 g_browser_process->metrics_service()->OnInitTaskComplete(
352 hardware_class_, plugins_);
initial.commit09911bf2008-07-26 23:55:29353 }
[email protected]35fa6a22009-08-15 00:04:01354
[email protected]7f2e792e2009-11-30 23:18:29355 private:
[email protected]85ed9d42010-06-08 22:37:44356 std::string hardware_class_;
[email protected]7f2e792e2009-11-30 23:18:29357 std::vector<WebPluginInfo> plugins_;
initial.commit09911bf2008-07-26 23:55:29358};
359
[email protected]85ed9d42010-06-08 22:37:44360class MetricsService::InitTask : public Task {
[email protected]7f2e792e2009-11-30 23:18:29361 public:
[email protected]85ed9d42010-06-08 22:37:44362 explicit InitTask(MessageLoop* callback_loop)
[email protected]7f2e792e2009-11-30 23:18:29363 : callback_loop_(callback_loop) {}
364
365 virtual void Run() {
366 std::vector<WebPluginInfo> plugins;
367 NPAPI::PluginList::Singleton()->GetPlugins(false, &plugins);
[email protected]85ed9d42010-06-08 22:37:44368 std::string hardware_class; // Empty string by default.
369#if defined(OS_CHROMEOS)
[email protected]db342d52010-08-09 21:19:37370 chromeos::SystemLibrary* system_library =
371 chromeos::CrosLibrary::Get()->GetSystemLibrary();
372 system_library->GetMachineStatistic("hardware_class", &hardware_class);
[email protected]85ed9d42010-06-08 22:37:44373#endif // OS_CHROMEOS
374 callback_loop_->PostTask(FROM_HERE, new InitTaskComplete(
375 hardware_class, plugins));
[email protected]7f2e792e2009-11-30 23:18:29376 }
377
378 private:
379 MessageLoop* callback_loop_;
380};
[email protected]90d41372009-11-30 21:52:32381
initial.commit09911bf2008-07-26 23:55:29382// static
383void MetricsService::RegisterPrefs(PrefService* local_state) {
384 DCHECK(IsSingleThreaded());
[email protected]20ce516d2010-06-18 02:20:04385 local_state->RegisterStringPref(prefs::kMetricsClientID, "");
[email protected]0bb1a622009-03-04 03:22:32386 local_state->RegisterInt64Pref(prefs::kMetricsClientIDTimestamp, 0);
387 local_state->RegisterInt64Pref(prefs::kStabilityLaunchTimeSec, 0);
388 local_state->RegisterInt64Pref(prefs::kStabilityLastTimestampSec, 0);
[email protected]20ce516d2010-06-18 02:20:04389 local_state->RegisterStringPref(prefs::kStabilityStatsVersion, "");
[email protected]225c50842010-01-19 21:19:13390 local_state->RegisterInt64Pref(prefs::kStabilityStatsBuildTime, 0);
initial.commit09911bf2008-07-26 23:55:29391 local_state->RegisterBooleanPref(prefs::kStabilityExitedCleanly, true);
392 local_state->RegisterBooleanPref(prefs::kStabilitySessionEndCompleted, true);
393 local_state->RegisterIntegerPref(prefs::kMetricsSessionID, -1);
394 local_state->RegisterIntegerPref(prefs::kStabilityLaunchCount, 0);
395 local_state->RegisterIntegerPref(prefs::kStabilityCrashCount, 0);
396 local_state->RegisterIntegerPref(prefs::kStabilityIncompleteSessionEndCount,
397 0);
398 local_state->RegisterIntegerPref(prefs::kStabilityPageLoadCount, 0);
initial.commit09911bf2008-07-26 23:55:29399 local_state->RegisterIntegerPref(prefs::kStabilityRendererCrashCount, 0);
[email protected]1f085622009-12-04 05:33:45400 local_state->RegisterIntegerPref(prefs::kStabilityExtensionRendererCrashCount,
401 0);
initial.commit09911bf2008-07-26 23:55:29402 local_state->RegisterIntegerPref(prefs::kStabilityRendererHangCount, 0);
[email protected]1f085622009-12-04 05:33:45403 local_state->RegisterIntegerPref(prefs::kStabilityChildProcessCrashCount, 0);
[email protected]e73c01972008-08-13 00:18:24404 local_state->RegisterIntegerPref(prefs::kStabilityBreakpadRegistrationFail,
405 0);
406 local_state->RegisterIntegerPref(prefs::kStabilityBreakpadRegistrationSuccess,
407 0);
408 local_state->RegisterIntegerPref(prefs::kStabilityDebuggerPresent, 0);
409 local_state->RegisterIntegerPref(prefs::kStabilityDebuggerNotPresent, 0);
410
initial.commit09911bf2008-07-26 23:55:29411 local_state->RegisterDictionaryPref(prefs::kProfileMetrics);
412 local_state->RegisterIntegerPref(prefs::kNumBookmarksOnBookmarkBar, 0);
413 local_state->RegisterIntegerPref(prefs::kNumFoldersOnBookmarkBar, 0);
414 local_state->RegisterIntegerPref(prefs::kNumBookmarksInOtherBookmarkFolder,
415 0);
416 local_state->RegisterIntegerPref(prefs::kNumFoldersInOtherBookmarkFolder, 0);
417 local_state->RegisterIntegerPref(prefs::kNumKeywords, 0);
418 local_state->RegisterListPref(prefs::kMetricsInitialLogs);
419 local_state->RegisterListPref(prefs::kMetricsOngoingLogs);
[email protected]0bb1a622009-03-04 03:22:32420
421 local_state->RegisterInt64Pref(prefs::kUninstallMetricsPageLoadCount, 0);
422 local_state->RegisterInt64Pref(prefs::kUninstallLaunchCount, 0);
[email protected]6b5f21d2009-04-13 17:01:35423 local_state->RegisterInt64Pref(prefs::kUninstallMetricsInstallDate, 0);
[email protected]0bb1a622009-03-04 03:22:32424 local_state->RegisterInt64Pref(prefs::kUninstallMetricsUptimeSec, 0);
425 local_state->RegisterInt64Pref(prefs::kUninstallLastLaunchTimeSec, 0);
426 local_state->RegisterInt64Pref(prefs::kUninstallLastObservedRunTimeSec, 0);
initial.commit09911bf2008-07-26 23:55:29427}
428
[email protected]541f77922009-02-23 21:14:38429// static
430void MetricsService::DiscardOldStabilityStats(PrefService* local_state) {
431 local_state->SetBoolean(prefs::kStabilityExitedCleanly, true);
[email protected]c9abf242009-07-18 06:00:38432 local_state->SetBoolean(prefs::kStabilitySessionEndCompleted, true);
[email protected]541f77922009-02-23 21:14:38433
434 local_state->SetInteger(prefs::kStabilityIncompleteSessionEndCount, 0);
435 local_state->SetInteger(prefs::kStabilityBreakpadRegistrationSuccess, 0);
436 local_state->SetInteger(prefs::kStabilityBreakpadRegistrationFail, 0);
437 local_state->SetInteger(prefs::kStabilityDebuggerPresent, 0);
438 local_state->SetInteger(prefs::kStabilityDebuggerNotPresent, 0);
439
440 local_state->SetInteger(prefs::kStabilityLaunchCount, 0);
441 local_state->SetInteger(prefs::kStabilityCrashCount, 0);
442
443 local_state->SetInteger(prefs::kStabilityPageLoadCount, 0);
444 local_state->SetInteger(prefs::kStabilityRendererCrashCount, 0);
445 local_state->SetInteger(prefs::kStabilityRendererHangCount, 0);
446
[email protected]9165f742010-03-10 22:55:01447 local_state->SetInt64(prefs::kStabilityLaunchTimeSec, 0);
448 local_state->SetInt64(prefs::kStabilityLastTimestampSec, 0);
[email protected]541f77922009-02-23 21:14:38449
450 local_state->ClearPref(prefs::kStabilityPluginStats);
[email protected]ae155cb92009-06-19 06:10:37451
452 ListValue* unsent_initial_logs = local_state->GetMutableList(
453 prefs::kMetricsInitialLogs);
454 unsent_initial_logs->Clear();
455
456 ListValue* unsent_ongoing_logs = local_state->GetMutableList(
457 prefs::kMetricsOngoingLogs);
458 unsent_ongoing_logs->Clear();
[email protected]541f77922009-02-23 21:14:38459}
460
initial.commit09911bf2008-07-26 23:55:29461MetricsService::MetricsService()
[email protected]d01b8732008-10-16 02:18:07462 : recording_active_(false),
463 reporting_active_(false),
464 user_permits_upload_(false),
465 server_permits_upload_(true),
466 state_(INITIALIZED),
initial.commit09911bf2008-07-26 23:55:29467 current_fetch_(NULL),
[email protected]d01b8732008-10-16 02:18:07468 idle_since_last_transmission_(false),
initial.commit09911bf2008-07-26 23:55:29469 next_window_id_(0),
[email protected]40bcc302009-03-02 20:50:39470 ALLOW_THIS_IN_INITIALIZER_LIST(log_sender_factory_(this)),
471 ALLOW_THIS_IN_INITIALIZER_LIST(state_saver_factory_(this)),
[email protected]252873ef2008-08-04 21:59:45472 interlog_duration_(TimeDelta::FromSeconds(kInitialInterlogDuration)),
[email protected]d01b8732008-10-16 02:18:07473 log_event_limit_(kInitialEventLimit),
initial.commit09911bf2008-07-26 23:55:29474 timer_pending_(false) {
475 DCHECK(IsSingleThreaded());
476 InitializeMetricsState();
477}
478
479MetricsService::~MetricsService() {
480 SetRecording(false);
481}
482
[email protected]d01b8732008-10-16 02:18:07483void MetricsService::SetUserPermitsUpload(bool enabled) {
484 HandleIdleSinceLastTransmission(false);
485 user_permits_upload_ = enabled;
486}
487
488void MetricsService::Start() {
489 SetRecording(true);
490 SetReporting(true);
491}
492
493void MetricsService::StartRecordingOnly() {
494 SetRecording(true);
495 SetReporting(false);
496}
497
498void MetricsService::Stop() {
499 SetReporting(false);
500 SetRecording(false);
501}
502
initial.commit09911bf2008-07-26 23:55:29503void MetricsService::SetRecording(bool enabled) {
504 DCHECK(IsSingleThreaded());
505
[email protected]d01b8732008-10-16 02:18:07506 if (enabled == recording_active_)
initial.commit09911bf2008-07-26 23:55:29507 return;
508
509 if (enabled) {
[email protected]b0c819f2009-03-08 04:52:15510 if (client_id_.empty()) {
511 PrefService* pref = g_browser_process->local_state();
512 DCHECK(pref);
[email protected]ddd231e2010-06-29 20:35:19513 client_id_ = pref->GetString(prefs::kMetricsClientID);
[email protected]b0c819f2009-03-08 04:52:15514 if (client_id_.empty()) {
515 client_id_ = GenerateClientID();
[email protected]ddd231e2010-06-29 20:35:19516 pref->SetString(prefs::kMetricsClientID, client_id_);
[email protected]b0c819f2009-03-08 04:52:15517
518 // Might as well make a note of how long this ID has existed
519 pref->SetString(prefs::kMetricsClientIDTimestamp,
[email protected]528c56d2010-07-30 19:28:44520 base::Int64ToString(Time::Now().ToTimeT()));
[email protected]b0c819f2009-03-08 04:52:15521 }
522 }
[email protected]157d5472009-11-05 22:31:03523 child_process_logging::SetClientId(client_id_);
initial.commit09911bf2008-07-26 23:55:29524 StartRecording();
[email protected]005ef3e2009-05-22 20:55:46525
526 registrar_.Add(this, NotificationType::BROWSER_OPENED,
527 NotificationService::AllSources());
528 registrar_.Add(this, NotificationType::BROWSER_CLOSED,
529 NotificationService::AllSources());
530 registrar_.Add(this, NotificationType::USER_ACTION,
531 NotificationService::AllSources());
532 registrar_.Add(this, NotificationType::TAB_PARENTED,
533 NotificationService::AllSources());
534 registrar_.Add(this, NotificationType::TAB_CLOSING,
535 NotificationService::AllSources());
536 registrar_.Add(this, NotificationType::LOAD_START,
537 NotificationService::AllSources());
538 registrar_.Add(this, NotificationType::LOAD_STOP,
539 NotificationService::AllSources());
[email protected]cd69619b2010-05-05 02:41:38540 registrar_.Add(this, NotificationType::RENDERER_PROCESS_CLOSED,
[email protected]005ef3e2009-05-22 20:55:46541 NotificationService::AllSources());
542 registrar_.Add(this, NotificationType::RENDERER_PROCESS_HANG,
543 NotificationService::AllSources());
544 registrar_.Add(this, NotificationType::CHILD_PROCESS_HOST_CONNECTED,
545 NotificationService::AllSources());
546 registrar_.Add(this, NotificationType::CHILD_INSTANCE_CREATED,
547 NotificationService::AllSources());
548 registrar_.Add(this, NotificationType::CHILD_PROCESS_CRASHED,
549 NotificationService::AllSources());
550 registrar_.Add(this, NotificationType::TEMPLATE_URL_MODEL_LOADED,
551 NotificationService::AllSources());
552 registrar_.Add(this, NotificationType::OMNIBOX_OPENED_URL,
553 NotificationService::AllSources());
554 registrar_.Add(this, NotificationType::BOOKMARK_MODEL_LOADED,
555 NotificationService::AllSources());
initial.commit09911bf2008-07-26 23:55:29556 } else {
[email protected]005ef3e2009-05-22 20:55:46557 registrar_.RemoveAll();
initial.commit09911bf2008-07-26 23:55:29558 PushPendingLogsToUnsentLists();
559 DCHECK(!pending_log());
560 if (state_ > INITIAL_LOG_READY && unsent_logs())
561 state_ = SEND_OLD_INITIAL_LOGS;
562 }
[email protected]d01b8732008-10-16 02:18:07563 recording_active_ = enabled;
initial.commit09911bf2008-07-26 23:55:29564}
565
[email protected]d01b8732008-10-16 02:18:07566bool MetricsService::recording_active() const {
initial.commit09911bf2008-07-26 23:55:29567 DCHECK(IsSingleThreaded());
[email protected]d01b8732008-10-16 02:18:07568 return recording_active_;
initial.commit09911bf2008-07-26 23:55:29569}
570
[email protected]d01b8732008-10-16 02:18:07571void MetricsService::SetReporting(bool enable) {
572 if (reporting_active_ != enable) {
573 reporting_active_ = enable;
574 if (reporting_active_)
initial.commit09911bf2008-07-26 23:55:29575 StartLogTransmissionTimer();
576 }
[email protected]d01b8732008-10-16 02:18:07577}
578
579bool MetricsService::reporting_active() const {
580 DCHECK(IsSingleThreaded());
581 return reporting_active_;
initial.commit09911bf2008-07-26 23:55:29582}
583
584void MetricsService::Observe(NotificationType type,
585 const NotificationSource& source,
586 const NotificationDetails& details) {
587 DCHECK(current_log_);
588 DCHECK(IsSingleThreaded());
589
590 if (!CanLogNotification(type, source, details))
591 return;
592
[email protected]bfd04a62009-02-01 18:16:56593 switch (type.value) {
594 case NotificationType::USER_ACTION:
[email protected]afe3a1672009-11-17 19:04:12595 current_log_->RecordUserAction(*Details<const char*>(details).ptr());
initial.commit09911bf2008-07-26 23:55:29596 break;
597
[email protected]bfd04a62009-02-01 18:16:56598 case NotificationType::BROWSER_OPENED:
599 case NotificationType::BROWSER_CLOSED:
initial.commit09911bf2008-07-26 23:55:29600 LogWindowChange(type, source, details);
601 break;
602
[email protected]bfd04a62009-02-01 18:16:56603 case NotificationType::TAB_PARENTED:
604 case NotificationType::TAB_CLOSING:
initial.commit09911bf2008-07-26 23:55:29605 LogWindowChange(type, source, details);
606 break;
607
[email protected]bfd04a62009-02-01 18:16:56608 case NotificationType::LOAD_STOP:
initial.commit09911bf2008-07-26 23:55:29609 LogLoadComplete(type, source, details);
610 break;
611
[email protected]bfd04a62009-02-01 18:16:56612 case NotificationType::LOAD_START:
initial.commit09911bf2008-07-26 23:55:29613 LogLoadStarted();
614 break;
615
[email protected]cd69619b2010-05-05 02:41:38616 case NotificationType::RENDERER_PROCESS_CLOSED:
[email protected]1f085622009-12-04 05:33:45617 {
[email protected]cd69619b2010-05-05 02:41:38618 RenderProcessHost::RendererClosedDetails* process_details =
619 Details<RenderProcessHost::RendererClosedDetails>(details).ptr();
620 if (process_details->did_crash) {
621 if (process_details->was_extension_renderer) {
622 LogExtensionRendererCrash();
623 } else {
624 LogRendererCrash();
625 }
626 }
[email protected]1f085622009-12-04 05:33:45627 }
initial.commit09911bf2008-07-26 23:55:29628 break;
629
[email protected]bfd04a62009-02-01 18:16:56630 case NotificationType::RENDERER_PROCESS_HANG:
initial.commit09911bf2008-07-26 23:55:29631 LogRendererHang();
632 break;
633
[email protected]a27a9382009-02-11 23:55:10634 case NotificationType::CHILD_PROCESS_HOST_CONNECTED:
635 case NotificationType::CHILD_PROCESS_CRASHED:
636 case NotificationType::CHILD_INSTANCE_CREATED:
637 LogChildProcessChange(type, source, details);
initial.commit09911bf2008-07-26 23:55:29638 break;
639
[email protected]bfd04a62009-02-01 18:16:56640 case NotificationType::TEMPLATE_URL_MODEL_LOADED:
initial.commit09911bf2008-07-26 23:55:29641 LogKeywords(Source<TemplateURLModel>(source).ptr());
642 break;
643
[email protected]1226abb2010-06-10 18:01:28644 case NotificationType::OMNIBOX_OPENED_URL: {
645 MetricsLog* current_log = current_log_->AsMetricsLog();
646 DCHECK(current_log);
647 current_log->RecordOmniboxOpenedURL(
initial.commit09911bf2008-07-26 23:55:29648 *Details<AutocompleteLog>(details).ptr());
649 break;
[email protected]1226abb2010-06-10 18:01:28650 }
initial.commit09911bf2008-07-26 23:55:29651
[email protected]b61236c62009-04-09 22:43:55652 case NotificationType::BOOKMARK_MODEL_LOADED: {
653 Profile* p = Source<Profile>(source).ptr();
654 if (p)
655 LogBookmarks(p->GetBookmarkModel());
initial.commit09911bf2008-07-26 23:55:29656 break;
[email protected]b61236c62009-04-09 22:43:55657 }
initial.commit09911bf2008-07-26 23:55:29658 default:
[email protected]a063c102010-07-22 22:20:19659 NOTREACHED();
initial.commit09911bf2008-07-26 23:55:29660 break;
661 }
[email protected]d01b8732008-10-16 02:18:07662
663 HandleIdleSinceLastTransmission(false);
664
665 if (current_log_)
[email protected]281d2882009-01-20 20:32:42666 DLOG(INFO) << "METRICS: NUMBER OF EVENTS = " << current_log_->num_events();
[email protected]d01b8732008-10-16 02:18:07667}
668
669void MetricsService::HandleIdleSinceLastTransmission(bool in_idle) {
670 // If there wasn't a lot of action, maybe the computer was asleep, in which
671 // case, the log transmissions should have stopped. Here we start them up
672 // again.
[email protected]cac78842008-11-27 01:02:20673 if (!in_idle && idle_since_last_transmission_)
674 StartLogTransmissionTimer();
675 idle_since_last_transmission_ = in_idle;
initial.commit09911bf2008-07-26 23:55:29676}
677
678void MetricsService::RecordCleanShutdown() {
679 RecordBooleanPrefValue(prefs::kStabilityExitedCleanly, true);
680}
681
682void MetricsService::RecordStartOfSessionEnd() {
683 RecordBooleanPrefValue(prefs::kStabilitySessionEndCompleted, false);
684}
685
686void MetricsService::RecordCompletedSessionEnd() {
687 RecordBooleanPrefValue(prefs::kStabilitySessionEndCompleted, true);
688}
689
[email protected]e73c01972008-08-13 00:18:24690void MetricsService:: RecordBreakpadRegistration(bool success) {
[email protected]68475e602008-08-22 03:21:15691 if (!success)
[email protected]e73c01972008-08-13 00:18:24692 IncrementPrefValue(prefs::kStabilityBreakpadRegistrationFail);
693 else
694 IncrementPrefValue(prefs::kStabilityBreakpadRegistrationSuccess);
695}
696
697void MetricsService::RecordBreakpadHasDebugger(bool has_debugger) {
698 if (!has_debugger)
699 IncrementPrefValue(prefs::kStabilityDebuggerNotPresent);
700 else
[email protected]68475e602008-08-22 03:21:15701 IncrementPrefValue(prefs::kStabilityDebuggerPresent);
[email protected]e73c01972008-08-13 00:18:24702}
703
initial.commit09911bf2008-07-26 23:55:29704//------------------------------------------------------------------------------
705// private methods
706//------------------------------------------------------------------------------
707
708
709//------------------------------------------------------------------------------
710// Initialization methods
711
712void MetricsService::InitializeMetricsState() {
[email protected]79bf0b72009-04-27 21:30:55713#if defined(OS_POSIX)
714 server_url_ = L"https://clients4.google.com/firefox/metrics/collect";
715#else
716 BrowserDistribution* dist = BrowserDistribution::GetDistribution();
717 server_url_ = dist->GetStatsServerURL();
718#endif
719
initial.commit09911bf2008-07-26 23:55:29720 PrefService* pref = g_browser_process->local_state();
721 DCHECK(pref);
722
[email protected]225c50842010-01-19 21:19:13723 if ((pref->GetInt64(prefs::kStabilityStatsBuildTime)
724 != MetricsLog::GetBuildTime()) ||
[email protected]ddd231e2010-06-29 20:35:19725 (pref->GetString(prefs::kStabilityStatsVersion)
[email protected]225c50842010-01-19 21:19:13726 != MetricsLog::GetVersionString())) {
[email protected]541f77922009-02-23 21:14:38727 // This is a new version, so we don't want to confuse the stats about the
728 // old version with info that we upload.
729 DiscardOldStabilityStats(pref);
730 pref->SetString(prefs::kStabilityStatsVersion,
[email protected]ddd231e2010-06-29 20:35:19731 MetricsLog::GetVersionString());
[email protected]225c50842010-01-19 21:19:13732 pref->SetInt64(prefs::kStabilityStatsBuildTime,
733 MetricsLog::GetBuildTime());
[email protected]541f77922009-02-23 21:14:38734 }
735
initial.commit09911bf2008-07-26 23:55:29736 // Update session ID
737 session_id_ = pref->GetInteger(prefs::kMetricsSessionID);
738 ++session_id_;
739 pref->SetInteger(prefs::kMetricsSessionID, session_id_);
740
initial.commit09911bf2008-07-26 23:55:29741 // Stability bookkeeping
[email protected]e73c01972008-08-13 00:18:24742 IncrementPrefValue(prefs::kStabilityLaunchCount);
initial.commit09911bf2008-07-26 23:55:29743
[email protected]e73c01972008-08-13 00:18:24744 if (!pref->GetBoolean(prefs::kStabilityExitedCleanly)) {
745 IncrementPrefValue(prefs::kStabilityCrashCount);
initial.commit09911bf2008-07-26 23:55:29746 }
[email protected]e73c01972008-08-13 00:18:24747
748 // This will be set to 'true' if we exit cleanly.
initial.commit09911bf2008-07-26 23:55:29749 pref->SetBoolean(prefs::kStabilityExitedCleanly, false);
750
[email protected]e73c01972008-08-13 00:18:24751 if (!pref->GetBoolean(prefs::kStabilitySessionEndCompleted)) {
752 IncrementPrefValue(prefs::kStabilityIncompleteSessionEndCount);
[email protected]c9abf242009-07-18 06:00:38753 // This is marked false when we get a WM_ENDSESSION.
754 pref->SetBoolean(prefs::kStabilitySessionEndCompleted, true);
initial.commit09911bf2008-07-26 23:55:29755 }
initial.commit09911bf2008-07-26 23:55:29756
[email protected]9165f742010-03-10 22:55:01757 // Initialize uptime counters.
758 int64 startup_uptime = MetricsLog::GetIncrementalUptime(pref);
[email protected]ae393ec702010-06-27 16:23:14759 DCHECK_EQ(0, startup_uptime);
[email protected]9165f742010-03-10 22:55:01760 // For backwards compatibility, leave this intact in case Omaha is checking
761 // them. prefs::kStabilityLastTimestampSec may also be useless now.
762 // TODO(jar): Delete these if they have no uses.
[email protected]0bb1a622009-03-04 03:22:32763 pref->SetInt64(prefs::kStabilityLaunchTimeSec, Time::Now().ToTimeT());
764
765 // Bookkeeping for the uninstall metrics.
766 IncrementLongPrefsValue(prefs::kUninstallLaunchCount);
initial.commit09911bf2008-07-26 23:55:29767
768 // Save profile metrics.
769 PrefService* prefs = g_browser_process->local_state();
770 if (prefs) {
771 // Remove the current dictionary and store it for use when sending data to
772 // server. By removing the value we prune potentially dead profiles
773 // (and keys). All valid values are added back once services startup.
774 const DictionaryValue* profile_dictionary =
775 prefs->GetDictionary(prefs::kProfileMetrics);
776 if (profile_dictionary) {
777 // Do a deep copy of profile_dictionary since ClearPref will delete it.
778 profile_dictionary_.reset(static_cast<DictionaryValue*>(
779 profile_dictionary->DeepCopy()));
780 prefs->ClearPref(prefs::kProfileMetrics);
781 }
782 }
783
[email protected]92745242009-06-12 16:52:21784 // Get stats on use of command line.
785 const CommandLine* command_line(CommandLine::ForCurrentProcess());
786 size_t common_commands = 0;
787 if (command_line->HasSwitch(switches::kUserDataDir)) {
788 ++common_commands;
789 UMA_HISTOGRAM_COUNTS_100("Chrome.CommandLineDatDirCount", 1);
790 }
791
792 if (command_line->HasSwitch(switches::kApp)) {
793 ++common_commands;
794 UMA_HISTOGRAM_COUNTS_100("Chrome.CommandLineAppModeCount", 1);
795 }
796
797 UMA_HISTOGRAM_COUNTS_100("Chrome.CommandLineFlagCount",
798 command_line->GetSwitchCount());
799 UMA_HISTOGRAM_COUNTS_100("Chrome.CommandLineUncommonFlagCount",
800 command_line->GetSwitchCount() - common_commands);
801
initial.commit09911bf2008-07-26 23:55:29802 // Kick off the process of saving the state (so the uptime numbers keep
803 // getting updated) every n minutes.
804 ScheduleNextStateSave();
805}
806
[email protected]85ed9d42010-06-08 22:37:44807void MetricsService::OnInitTaskComplete(
808 const std::string& hardware_class,
[email protected]35fa6a22009-08-15 00:04:01809 const std::vector<WebPluginInfo>& plugins) {
[email protected]85ed9d42010-06-08 22:37:44810 DCHECK(state_ == INIT_TASK_SCHEDULED);
811 hardware_class_ = hardware_class;
[email protected]35fa6a22009-08-15 00:04:01812 plugins_ = plugins;
[email protected]85ed9d42010-06-08 22:37:44813 if (state_ == INIT_TASK_SCHEDULED)
814 state_ = INIT_TASK_DONE;
initial.commit09911bf2008-07-26 23:55:29815}
816
817std::string MetricsService::GenerateClientID() {
[email protected]dc6f4962009-02-13 01:25:50818#if defined(OS_WIN)
initial.commit09911bf2008-07-26 23:55:29819 const int kGUIDSize = 39;
820
821 GUID guid;
822 HRESULT guid_result = CoCreateGuid(&guid);
823 DCHECK(SUCCEEDED(guid_result));
824
825 std::wstring guid_string;
826 int result = StringFromGUID2(guid,
827 WriteInto(&guid_string, kGUIDSize), kGUIDSize);
828 DCHECK(result == kGUIDSize);
829
830 return WideToUTF8(guid_string.substr(1, guid_string.length() - 2));
[email protected]271b24f2009-07-28 16:05:51831#else
[email protected]06aaac22009-07-08 20:54:13832 uint64 sixteen_bytes[2] = { base::RandUint64(), base::RandUint64() };
833 return RandomBytesToGUIDString(sixteen_bytes);
[email protected]dc6f4962009-02-13 01:25:50834#endif
initial.commit09911bf2008-07-26 23:55:29835}
836
[email protected]06aaac22009-07-08 20:54:13837#if defined(OS_POSIX)
838// TODO(cmasone): Once we're comfortable this works, migrate Windows code to
839// use this as well.
840std::string MetricsService::RandomBytesToGUIDString(const uint64 bytes[2]) {
[email protected]34b2b002009-11-20 06:53:28841 return StringPrintf("%08X-%04X-%04X-%04X-%012llX",
842 static_cast<unsigned int>(bytes[0] >> 32),
843 static_cast<unsigned int>((bytes[0] >> 16) & 0x0000ffff),
844 static_cast<unsigned int>(bytes[0] & 0x0000ffff),
845 static_cast<unsigned int>(bytes[1] >> 48),
[email protected]06aaac22009-07-08 20:54:13846 bytes[1] & 0x0000ffffffffffffULL);
847}
848#endif
initial.commit09911bf2008-07-26 23:55:29849
850//------------------------------------------------------------------------------
851// State save methods
852
853void MetricsService::ScheduleNextStateSave() {
854 state_saver_factory_.RevokeAll();
855
856 MessageLoop::current()->PostDelayedTask(FROM_HERE,
857 state_saver_factory_.NewRunnableMethod(&MetricsService::SaveLocalState),
858 kSaveStateInterval * 1000);
859}
860
861void MetricsService::SaveLocalState() {
862 PrefService* pref = g_browser_process->local_state();
863 if (!pref) {
[email protected]a063c102010-07-22 22:20:19864 NOTREACHED();
initial.commit09911bf2008-07-26 23:55:29865 return;
866 }
867
868 RecordCurrentState(pref);
[email protected]6faa0e0d2009-04-28 06:50:36869 pref->ScheduleSavePersistentPrefs();
initial.commit09911bf2008-07-26 23:55:29870
[email protected]281d2882009-01-20 20:32:42871 // TODO(jar): Does this run down the batteries????
initial.commit09911bf2008-07-26 23:55:29872 ScheduleNextStateSave();
873}
874
875
876//------------------------------------------------------------------------------
877// Recording control methods
878
879void MetricsService::StartRecording() {
880 if (current_log_)
881 return;
882
883 current_log_ = new MetricsLog(client_id_, session_id_);
884 if (state_ == INITIALIZED) {
885 // We only need to schedule that run once.
[email protected]85ed9d42010-06-08 22:37:44886 state_ = INIT_TASK_SCHEDULED;
initial.commit09911bf2008-07-26 23:55:29887
[email protected]85ed9d42010-06-08 22:37:44888 // Schedules a task on the file thread for execution of slower
889 // initialization steps (such as plugin list generation) necessary
890 // for sending the initial log. This avoids blocking the main UI
891 // thread.
[email protected]7f2e792e2009-11-30 23:18:29892 g_browser_process->file_thread()->message_loop()->PostDelayedTask(FROM_HERE,
[email protected]85ed9d42010-06-08 22:37:44893 new InitTask(MessageLoop::current()),
[email protected]252873ef2008-08-04 21:59:45894 kInitialInterlogDuration * 1000 / 2);
initial.commit09911bf2008-07-26 23:55:29895 }
896}
897
[email protected]1226abb2010-06-10 18:01:28898void MetricsService::StopRecording(MetricsLogBase** log) {
initial.commit09911bf2008-07-26 23:55:29899 if (!current_log_)
900 return;
901
[email protected]1226abb2010-06-10 18:01:28902 MetricsLog* current_log = current_log_->AsMetricsLog();
903 DCHECK(current_log);
904 current_log->set_hardware_class(hardware_class_); // Adds to ongoing logs.
[email protected]85ed9d42010-06-08 22:37:44905
[email protected]68475e602008-08-22 03:21:15906 // TODO(jar): Integrate bounds on log recording more consistently, so that we
907 // can stop recording logs that are too big much sooner.
[email protected]d01b8732008-10-16 02:18:07908 if (current_log_->num_events() > log_event_limit_) {
[email protected]553dba62009-02-24 19:08:23909 UMA_HISTOGRAM_COUNTS("UMA.Discarded Log Events",
[email protected]68475e602008-08-22 03:21:15910 current_log_->num_events());
911 current_log_->CloseLog();
912 delete current_log_;
[email protected]294638782008-09-24 00:22:41913 current_log_ = NULL;
[email protected]68475e602008-08-22 03:21:15914 StartRecording(); // Start trivial log to hold our histograms.
915 }
916
[email protected]0b33f80b2008-12-17 21:34:36917 // Put incremental data (histogram deltas, and realtime stats deltas) at the
[email protected]147bbc0b2009-01-06 19:37:40918 // end of all log transmissions (initial log handles this separately).
initial.commit09911bf2008-07-26 23:55:29919 // Don't bother if we're going to discard current_log_.
[email protected]0b33f80b2008-12-17 21:34:36920 if (log) {
[email protected]1226abb2010-06-10 18:01:28921 current_log->RecordIncrementalStabilityElements();
initial.commit09911bf2008-07-26 23:55:29922 RecordCurrentHistograms();
[email protected]0b33f80b2008-12-17 21:34:36923 }
initial.commit09911bf2008-07-26 23:55:29924
925 current_log_->CloseLog();
[email protected]cac78842008-11-27 01:02:20926 if (log)
[email protected]1226abb2010-06-10 18:01:28927 *log = current_log;
[email protected]cac78842008-11-27 01:02:20928 else
initial.commit09911bf2008-07-26 23:55:29929 delete current_log_;
initial.commit09911bf2008-07-26 23:55:29930 current_log_ = NULL;
931}
932
initial.commit09911bf2008-07-26 23:55:29933void MetricsService::PushPendingLogsToUnsentLists() {
934 if (state_ < INITIAL_LOG_READY)
[email protected]28ab7f92009-01-06 21:39:04935 return; // We didn't and still don't have time to get plugin list etc.
initial.commit09911bf2008-07-26 23:55:29936
937 if (pending_log()) {
938 PreparePendingLogText();
939 if (state_ == INITIAL_LOG_READY) {
940 // We may race here, and send second copy of initial log later.
[email protected]46f89e142010-07-19 08:00:42941 unsent_initial_logs_.push_back(compressed_log_);
[email protected]d01b8732008-10-16 02:18:07942 state_ = SEND_OLD_INITIAL_LOGS;
initial.commit09911bf2008-07-26 23:55:29943 } else {
[email protected]281d2882009-01-20 20:32:42944 // TODO(jar): Verify correctness in other states, including sending unsent
[email protected]541f77922009-02-23 21:14:38945 // initial logs.
[email protected]68475e602008-08-22 03:21:15946 PushPendingLogTextToUnsentOngoingLogs();
initial.commit09911bf2008-07-26 23:55:29947 }
948 DiscardPendingLog();
949 }
950 DCHECK(!pending_log());
951 StopRecording(&pending_log_);
952 PreparePendingLogText();
[email protected]68475e602008-08-22 03:21:15953 PushPendingLogTextToUnsentOngoingLogs();
initial.commit09911bf2008-07-26 23:55:29954 DiscardPendingLog();
955 StoreUnsentLogs();
956}
957
[email protected]68475e602008-08-22 03:21:15958void MetricsService::PushPendingLogTextToUnsentOngoingLogs() {
[email protected]d01b8732008-10-16 02:18:07959 // If UMA response told us not to upload, there's no need to save the pending
960 // log. It wasn't supposed to be uploaded anyway.
961 if (!server_permits_upload_)
962 return;
[email protected]46f89e142010-07-19 08:00:42963 if (compressed_log_.length() >
[email protected]dc6f4962009-02-13 01:25:50964 static_cast<size_t>(kUploadLogAvoidRetransmitSize)) {
[email protected]553dba62009-02-24 19:08:23965 UMA_HISTOGRAM_COUNTS("UMA.Large Accumulated Log Not Persisted",
[email protected]46f89e142010-07-19 08:00:42966 static_cast<int>(compressed_log_.length()));
[email protected]68475e602008-08-22 03:21:15967 return;
968 }
[email protected]46f89e142010-07-19 08:00:42969 unsent_ongoing_logs_.push_back(compressed_log_);
[email protected]68475e602008-08-22 03:21:15970}
971
initial.commit09911bf2008-07-26 23:55:29972//------------------------------------------------------------------------------
973// Transmission of logs methods
974
975void MetricsService::StartLogTransmissionTimer() {
[email protected]d01b8732008-10-16 02:18:07976 // If we're not reporting, there's no point in starting a log transmission
977 // timer.
978 if (!reporting_active())
979 return;
980
initial.commit09911bf2008-07-26 23:55:29981 if (!current_log_)
982 return; // Recorder is shutdown.
[email protected]d01b8732008-10-16 02:18:07983
984 // If there is already a timer running, we leave it running.
985 // If timer_pending is true because the fetch is waiting for a response,
986 // we return for now and let the response handler start the timer.
987 if (timer_pending_)
initial.commit09911bf2008-07-26 23:55:29988 return;
[email protected]d01b8732008-10-16 02:18:07989
[email protected]d01b8732008-10-16 02:18:07990 // Before starting the timer, set timer_pending_ to true.
initial.commit09911bf2008-07-26 23:55:29991 timer_pending_ = true;
[email protected]d01b8732008-10-16 02:18:07992
993 // Right before the UMA transmission gets started, there's one more thing we'd
994 // like to record: the histogram of memory usage, so we spawn a task to
[email protected]c9a3ef82009-05-28 22:02:46995 // collect the memory details and when that task is finished, it will call
996 // OnMemoryDetailCollectionDone, which will call HistogramSynchronization to
997 // collect histograms from all renderers and then we will call
998 // OnHistogramSynchronizationDone to continue processing.
initial.commit09911bf2008-07-26 23:55:29999 MessageLoop::current()->PostDelayedTask(FROM_HERE,
1000 log_sender_factory_.
[email protected]c9a3ef82009-05-28 22:02:461001 NewRunnableMethod(&MetricsService::LogTransmissionTimerDone),
[email protected]743ace42009-06-17 17:23:511002 interlog_duration_.InMilliseconds());
initial.commit09911bf2008-07-26 23:55:291003}
1004
[email protected]c9a3ef82009-05-28 22:02:461005void MetricsService::LogTransmissionTimerDone() {
1006 Task* task = log_sender_factory_.
1007 NewRunnableMethod(&MetricsService::OnMemoryDetailCollectionDone);
1008
[email protected]e9adedb2009-12-01 22:23:591009 scoped_refptr<MetricsMemoryDetails> details = new MetricsMemoryDetails(task);
[email protected]c9a3ef82009-05-28 22:02:461010 details->StartFetch();
1011
1012 // Collect WebCore cache information to put into a histogram.
[email protected]019191a2009-10-02 20:37:271013 for (RenderProcessHost::iterator i(RenderProcessHost::AllHostsIterator());
1014 !i.IsAtEnd(); i.Advance())
1015 i.GetCurrentValue()->Send(new ViewMsg_GetCacheResourceStats());
[email protected]c9a3ef82009-05-28 22:02:461016}
1017
1018void MetricsService::OnMemoryDetailCollectionDone() {
1019 DCHECK(IsSingleThreaded());
1020
1021 // HistogramSynchronizer will Collect histograms from all renderers and it
1022 // will call OnHistogramSynchronizationDone (if wait time elapses before it
1023 // heard from all renderers, then also it will call
1024 // OnHistogramSynchronizationDone).
1025
1026 // Create a callback_task for OnHistogramSynchronizationDone.
1027 Task* callback_task = log_sender_factory_.NewRunnableMethod(
1028 &MetricsService::OnHistogramSynchronizationDone);
1029
1030 // Set up the callback to task to call after we receive histograms from all
1031 // renderer processes. Wait time specifies how long to wait before absolutely
1032 // calling us back on the task.
1033 HistogramSynchronizer::FetchRendererHistogramsAsynchronously(
1034 MessageLoop::current(), callback_task,
1035 kMaxHistogramGatheringWaitDuration);
1036}
1037
1038void MetricsService::OnHistogramSynchronizationDone() {
initial.commit09911bf2008-07-26 23:55:291039 DCHECK(IsSingleThreaded());
1040
[email protected]d01b8732008-10-16 02:18:071041 // This function should only be called via timer, so timer_pending_
1042 // should be true.
1043 DCHECK(timer_pending_);
1044 timer_pending_ = false;
initial.commit09911bf2008-07-26 23:55:291045
1046 DCHECK(!current_fetch_.get());
initial.commit09911bf2008-07-26 23:55:291047
[email protected]d01b8732008-10-16 02:18:071048 // If we're getting no notifications, then the log won't have much in it, and
1049 // it's possible the computer is about to go to sleep, so don't upload and
1050 // don't restart the transmission timer.
1051 if (idle_since_last_transmission_)
1052 return;
1053
1054 // If somehow there is a fetch in progress, we return setting timer_pending_
1055 // to true and hope things work out.
1056 if (current_fetch_.get()) {
1057 timer_pending_ = true;
1058 return;
1059 }
1060
1061 // If uploads are forbidden by UMA response, there's no point in keeping
1062 // the current_log_, and the more often we delete it, the less likely it is
1063 // to expand forever.
1064 if (!server_permits_upload_ && current_log_) {
1065 StopRecording(NULL);
1066 StartRecording();
1067 }
initial.commit09911bf2008-07-26 23:55:291068
1069 if (!current_log_)
1070 return; // Logging was disabled.
[email protected]d01b8732008-10-16 02:18:071071 if (!reporting_active())
initial.commit09911bf2008-07-26 23:55:291072 return; // Don't do work if we're not going to send anything now.
1073
[email protected]d01b8732008-10-16 02:18:071074 MakePendingLog();
initial.commit09911bf2008-07-26 23:55:291075
[email protected]d01b8732008-10-16 02:18:071076 // MakePendingLog should have put something in the pending log, if it didn't,
1077 // we start the timer again, return and hope things work out.
1078 if (!pending_log()) {
1079 StartLogTransmissionTimer();
1080 return;
1081 }
initial.commit09911bf2008-07-26 23:55:291082
[email protected]d01b8732008-10-16 02:18:071083 // If we're not supposed to upload any UMA data because the response or the
1084 // user said so, cancel the upload at this point, but start the timer.
1085 if (!TransmissionPermitted()) {
1086 DiscardPendingLog();
1087 StartLogTransmissionTimer();
1088 return;
1089 }
initial.commit09911bf2008-07-26 23:55:291090
[email protected]d01b8732008-10-16 02:18:071091 PrepareFetchWithPendingLog();
1092
1093 if (!current_fetch_.get()) {
1094 // Compression failed, and log discarded :-/.
1095 DiscardPendingLog();
1096 StartLogTransmissionTimer(); // Maybe we'll do better next time
1097 // TODO(jar): If compression failed, we should have created a tiny log and
1098 // compressed that, so that we can signal that we're losing logs.
1099 return;
1100 }
1101
1102 DCHECK(!timer_pending_);
1103
1104 // The URL fetch is a like timer in that after a while we get called back
1105 // so we set timer_pending_ true just as we start the url fetch.
1106 timer_pending_ = true;
1107 current_fetch_->Start();
1108
1109 HandleIdleSinceLastTransmission(true);
1110}
1111
1112
1113void MetricsService::MakePendingLog() {
1114 if (pending_log())
1115 return;
1116
1117 switch (state_) {
1118 case INITIALIZED:
[email protected]85ed9d42010-06-08 22:37:441119 case INIT_TASK_SCHEDULED: // We should be further along by now.
[email protected]d01b8732008-10-16 02:18:071120 DCHECK(false);
1121 return;
1122
[email protected]85ed9d42010-06-08 22:37:441123 case INIT_TASK_DONE:
[email protected]d01b8732008-10-16 02:18:071124 // We need to wait for the initial log to be ready before sending
1125 // anything, because the server will tell us whether it wants to hear
1126 // from us.
1127 PrepareInitialLog();
[email protected]85ed9d42010-06-08 22:37:441128 DCHECK(state_ == INIT_TASK_DONE);
[email protected]d01b8732008-10-16 02:18:071129 RecallUnsentLogs();
1130 state_ = INITIAL_LOG_READY;
1131 break;
1132
1133 case SEND_OLD_INITIAL_LOGS:
[email protected]cac78842008-11-27 01:02:201134 if (!unsent_initial_logs_.empty()) {
[email protected]46f89e142010-07-19 08:00:421135 compressed_log_ = unsent_initial_logs_.back();
[email protected]cac78842008-11-27 01:02:201136 break;
1137 }
[email protected]d01b8732008-10-16 02:18:071138 state_ = SENDING_OLD_LOGS;
1139 // Fall through.
initial.commit09911bf2008-07-26 23:55:291140
[email protected]d01b8732008-10-16 02:18:071141 case SENDING_OLD_LOGS:
1142 if (!unsent_ongoing_logs_.empty()) {
[email protected]46f89e142010-07-19 08:00:421143 compressed_log_ = unsent_ongoing_logs_.back();
[email protected]d01b8732008-10-16 02:18:071144 break;
1145 }
1146 state_ = SENDING_CURRENT_LOGS;
1147 // Fall through.
1148
1149 case SENDING_CURRENT_LOGS:
1150 StopRecording(&pending_log_);
1151 StartRecording();
1152 break;
1153
1154 default:
[email protected]a063c102010-07-22 22:20:191155 NOTREACHED();
[email protected]d01b8732008-10-16 02:18:071156 return;
1157 }
1158
1159 DCHECK(pending_log());
1160}
1161
1162bool MetricsService::TransmissionPermitted() const {
1163 // If the user forbids uploading that's they're business, and we don't upload
1164 // anything. If the server forbids uploading, that's our business, so we take
1165 // that to mean it forbids current logs, but we still send up the inital logs
1166 // and any old logs.
[email protected]d01b8732008-10-16 02:18:071167 if (!user_permits_upload_)
1168 return false;
[email protected]cac78842008-11-27 01:02:201169 if (server_permits_upload_)
[email protected]d01b8732008-10-16 02:18:071170 return true;
initial.commit09911bf2008-07-26 23:55:291171
[email protected]cac78842008-11-27 01:02:201172 switch (state_) {
1173 case INITIAL_LOG_READY:
1174 case SEND_OLD_INITIAL_LOGS:
1175 case SENDING_OLD_LOGS:
1176 return true;
1177
1178 case SENDING_CURRENT_LOGS:
1179 default:
1180 return false;
[email protected]8c8824b2008-09-20 01:55:501181 }
initial.commit09911bf2008-07-26 23:55:291182}
1183
initial.commit09911bf2008-07-26 23:55:291184void MetricsService::PrepareInitialLog() {
[email protected]85ed9d42010-06-08 22:37:441185 DCHECK(state_ == INIT_TASK_DONE);
initial.commit09911bf2008-07-26 23:55:291186
1187 MetricsLog* log = new MetricsLog(client_id_, session_id_);
[email protected]85ed9d42010-06-08 22:37:441188 log->set_hardware_class(hardware_class_); // Adds to initial log.
[email protected]35fa6a22009-08-15 00:04:011189 log->RecordEnvironment(plugins_, profile_dictionary_.get());
initial.commit09911bf2008-07-26 23:55:291190
1191 // Histograms only get written to current_log_, so setup for the write.
[email protected]1226abb2010-06-10 18:01:281192 MetricsLogBase* save_log = current_log_;
initial.commit09911bf2008-07-26 23:55:291193 current_log_ = log;
1194 RecordCurrentHistograms(); // Into current_log_... which is really log.
1195 current_log_ = save_log;
1196
1197 log->CloseLog();
1198 DCHECK(!pending_log());
1199 pending_log_ = log;
1200}
1201
[email protected]46f89e142010-07-19 08:00:421202// static
1203MetricsService::LogRecallStatus MetricsService::RecallUnsentLogsHelper(
1204 const ListValue& list,
1205 std::vector<std::string>* local_list) {
1206 DCHECK(local_list->empty());
1207 if (list.GetSize() == 0)
1208 return MakeRecallStatusHistogram(LIST_EMPTY);
1209 if (list.GetSize() < 3)
1210 return MakeRecallStatusHistogram(LIST_SIZE_TOO_SMALL);
initial.commit09911bf2008-07-26 23:55:291211
[email protected]46f89e142010-07-19 08:00:421212 // The size is stored at the beginning of the list.
1213 int size;
1214 bool valid = (*list.begin())->GetAsInteger(&size);
1215 if (!valid)
1216 return MakeRecallStatusHistogram(LIST_SIZE_MISSING);
1217
1218 // Account for checksum and size included in the list.
1219 if (static_cast<unsigned int>(size) !=
1220 list.GetSize() - kChecksumEntryCount)
1221 return MakeRecallStatusHistogram(LIST_SIZE_CORRUPTION);
1222
1223 MD5Context ctx;
1224 MD5Init(&ctx);
1225 std::string encoded_log;
1226 std::string decoded_log;
1227 for (ListValue::const_iterator it = list.begin() + 1;
1228 it != list.end() - 1; ++it) { // Last element is the checksum.
1229 valid = (*it)->GetAsString(&encoded_log);
1230 if (!valid) {
1231 local_list->clear();
1232 return MakeRecallStatusHistogram(LOG_STRING_CORRUPTION);
1233 }
1234
1235 MD5Update(&ctx, encoded_log.data(), encoded_log.length());
1236
1237 if (!base::Base64Decode(encoded_log, &decoded_log)) {
1238 local_list->clear();
1239 return MakeRecallStatusHistogram(DECODE_FAIL);
1240 }
1241 local_list->push_back(decoded_log);
1242 }
1243
1244 // Verify checksum.
1245 MD5Digest digest;
1246 MD5Final(&digest, &ctx);
1247 std::string recovered_md5;
1248 // We store the hash at the end of the list.
1249 valid = (*(list.end() - 1))->GetAsString(&recovered_md5);
1250 if (!valid) {
1251 local_list->clear();
1252 return MakeRecallStatusHistogram(CHECKSUM_STRING_CORRUPTION);
1253 }
1254 if (recovered_md5 != MD5DigestToBase16(digest)) {
1255 local_list->clear();
1256 return MakeRecallStatusHistogram(CHECKSUM_CORRUPTION);
1257 }
1258 return MakeRecallStatusHistogram(RECALL_SUCCESS);
1259}
1260void MetricsService::RecallUnsentLogs() {
initial.commit09911bf2008-07-26 23:55:291261 PrefService* local_state = g_browser_process->local_state();
1262 DCHECK(local_state);
1263
1264 ListValue* unsent_initial_logs = local_state->GetMutableList(
1265 prefs::kMetricsInitialLogs);
[email protected]46f89e142010-07-19 08:00:421266 RecallUnsentLogsHelper(*unsent_initial_logs, &unsent_initial_logs_);
initial.commit09911bf2008-07-26 23:55:291267
1268 ListValue* unsent_ongoing_logs = local_state->GetMutableList(
1269 prefs::kMetricsOngoingLogs);
[email protected]46f89e142010-07-19 08:00:421270 RecallUnsentLogsHelper(*unsent_ongoing_logs, &unsent_ongoing_logs_);
1271}
1272
1273// static
1274void MetricsService::StoreUnsentLogsHelper(
1275 const std::vector<std::string>& local_list,
1276 const size_t kMaxLocalListSize,
1277 ListValue* list) {
1278 list->Clear();
1279 size_t start = 0;
1280 if (local_list.size() > kMaxLocalListSize)
1281 start = local_list.size() - kMaxLocalListSize;
1282 DCHECK(start <= local_list.size());
1283 if (local_list.size() == start)
1284 return;
1285
1286 // Store size at the beginning of the list.
1287 list->Append(Value::CreateIntegerValue(local_list.size() - start));
1288
1289 MD5Context ctx;
1290 MD5Init(&ctx);
1291 std::string encoded_log;
1292 for (std::vector<std::string>::const_iterator it = local_list.begin() + start;
1293 it != local_list.end(); ++it) {
1294 // We encode the compressed log as Value::CreateStringValue() expects to
1295 // take a valid UTF8 string.
1296 if (!base::Base64Encode(*it, &encoded_log)) {
1297 MakeStoreStatusHistogram(ENCODE_FAIL);
1298 list->Clear();
1299 return;
1300 }
1301 MD5Update(&ctx, encoded_log.data(), encoded_log.length());
1302 list->Append(Value::CreateStringValue(encoded_log));
initial.commit09911bf2008-07-26 23:55:291303 }
[email protected]46f89e142010-07-19 08:00:421304
1305 // Append hash to the end of the list.
1306 MD5Digest digest;
1307 MD5Final(&digest, &ctx);
1308 list->Append(Value::CreateStringValue(MD5DigestToBase16(digest)));
1309 DCHECK(list->GetSize() >= 3); // Minimum of 3 elements (size, data, hash).
[email protected]4e95d202010-07-24 01:47:561310 MakeStoreStatusHistogram(STORE_SUCCESS);
initial.commit09911bf2008-07-26 23:55:291311}
1312
1313void MetricsService::StoreUnsentLogs() {
1314 if (state_ < INITIAL_LOG_READY)
1315 return; // We never Recalled the prior unsent logs.
1316
1317 PrefService* local_state = g_browser_process->local_state();
1318 DCHECK(local_state);
1319
1320 ListValue* unsent_initial_logs = local_state->GetMutableList(
1321 prefs::kMetricsInitialLogs);
[email protected]46f89e142010-07-19 08:00:421322 StoreUnsentLogsHelper(unsent_initial_logs_, kMaxInitialLogsPersisted,
1323 unsent_initial_logs);
initial.commit09911bf2008-07-26 23:55:291324
1325 ListValue* unsent_ongoing_logs = local_state->GetMutableList(
1326 prefs::kMetricsOngoingLogs);
[email protected]46f89e142010-07-19 08:00:421327 StoreUnsentLogsHelper(unsent_ongoing_logs_, kMaxOngoingLogsPersisted,
1328 unsent_ongoing_logs);
initial.commit09911bf2008-07-26 23:55:291329}
1330
1331void MetricsService::PreparePendingLogText() {
1332 DCHECK(pending_log());
[email protected]46f89e142010-07-19 08:00:421333 if (!compressed_log_.empty())
initial.commit09911bf2008-07-26 23:55:291334 return;
[email protected]9ffcccf42009-09-15 22:19:181335 int text_size = pending_log_->GetEncodedLogSize();
1336
[email protected]46f89e142010-07-19 08:00:421337 std::string pending_log_text;
1338 // Leave room for the NULL terminator.
1339 pending_log_->GetEncodedLog(WriteInto(&pending_log_text, text_size + 1),
[email protected]9ffcccf42009-09-15 22:19:181340 text_size);
[email protected]46f89e142010-07-19 08:00:421341
1342 if (Bzip2Compress(pending_log_text, &compressed_log_)) {
1343 // Allow security conscious users to see all metrics logs that we send.
1344 LOG(INFO) << "COMPRESSED FOLLOWING METRICS LOG: " << pending_log_text;
1345 } else {
1346 LOG(DFATAL) << "Failed to compress log for transmission.";
1347 // We can't discard the logs as other caller functions expect that
1348 // |compressed_log_| not be empty. We can detect this failure at the server
1349 // after we transmit.
1350 compressed_log_ = "Unable to compress!";
1351 MakeStoreStatusHistogram(COMPRESS_FAIL);
1352 return;
1353 }
initial.commit09911bf2008-07-26 23:55:291354}
1355
[email protected]d01b8732008-10-16 02:18:071356void MetricsService::PrepareFetchWithPendingLog() {
initial.commit09911bf2008-07-26 23:55:291357 DCHECK(pending_log());
1358 DCHECK(!current_fetch_.get());
1359 PreparePendingLogText();
[email protected]46f89e142010-07-19 08:00:421360 DCHECK(!compressed_log_.empty());
[email protected]cac78842008-11-27 01:02:201361
[email protected]79bf0b72009-04-27 21:30:551362 current_fetch_.reset(new URLFetcher(GURL(WideToUTF16(server_url_)),
1363 URLFetcher::POST,
initial.commit09911bf2008-07-26 23:55:291364 this));
1365 current_fetch_->set_request_context(Profile::GetDefaultRequestContext());
[email protected]46f89e142010-07-19 08:00:421366 current_fetch_->set_upload_data(kMetricsType, compressed_log_);
initial.commit09911bf2008-07-26 23:55:291367}
1368
initial.commit09911bf2008-07-26 23:55:291369static const char* StatusToString(const URLRequestStatus& status) {
1370 switch (status.status()) {
1371 case URLRequestStatus::SUCCESS:
1372 return "SUCCESS";
1373
1374 case URLRequestStatus::IO_PENDING:
1375 return "IO_PENDING";
1376
1377 case URLRequestStatus::HANDLED_EXTERNALLY:
1378 return "HANDLED_EXTERNALLY";
1379
1380 case URLRequestStatus::CANCELED:
1381 return "CANCELED";
1382
1383 case URLRequestStatus::FAILED:
1384 return "FAILED";
1385
1386 default:
[email protected]a063c102010-07-22 22:20:191387 NOTREACHED();
initial.commit09911bf2008-07-26 23:55:291388 return "Unknown";
1389 }
1390}
1391
1392void MetricsService::OnURLFetchComplete(const URLFetcher* source,
1393 const GURL& url,
1394 const URLRequestStatus& status,
1395 int response_code,
1396 const ResponseCookies& cookies,
1397 const std::string& data) {
1398 DCHECK(timer_pending_);
1399 timer_pending_ = false;
1400 DCHECK(current_fetch_.get());
1401 current_fetch_.reset(NULL); // We're not allowed to re-use it.
1402
1403 // Confirm send so that we can move on.
[email protected]281d2882009-01-20 20:32:421404 LOG(INFO) << "METRICS RESPONSE CODE: " << response_code << " status=" <<
[email protected]cac78842008-11-27 01:02:201405 StatusToString(status);
[email protected]252873ef2008-08-04 21:59:451406
[email protected]0eb34fee2009-01-21 08:04:381407 // Provide boolean for error recovery (allow us to ignore response_code).
[email protected]dc6f4962009-02-13 01:25:501408 bool discard_log = false;
[email protected]0eb34fee2009-01-21 08:04:381409
[email protected]68475e602008-08-22 03:21:151410 if (response_code != 200 &&
[email protected]46f89e142010-07-19 08:00:421411 (compressed_log_.length() >
1412 static_cast<size_t>(kUploadLogAvoidRetransmitSize))) {
[email protected]553dba62009-02-24 19:08:231413 UMA_HISTOGRAM_COUNTS("UMA.Large Rejected Log was Discarded",
[email protected]46f89e142010-07-19 08:00:421414 static_cast<int>(compressed_log_.length()));
[email protected]0eb34fee2009-01-21 08:04:381415 discard_log = true;
1416 } else if (response_code == 400) {
1417 // Bad syntax. Retransmission won't work.
[email protected]553dba62009-02-24 19:08:231418 UMA_HISTOGRAM_COUNTS("UMA.Unacceptable_Log_Discarded", state_);
[email protected]0eb34fee2009-01-21 08:04:381419 discard_log = true;
[email protected]68475e602008-08-22 03:21:151420 }
1421
[email protected]0eb34fee2009-01-21 08:04:381422 if (response_code != 200 && !discard_log) {
[email protected]281d2882009-01-20 20:32:421423 LOG(INFO) << "METRICS: transmission attempt returned a failure code: "
1424 << response_code << ". Verify network connectivity";
[email protected]252873ef2008-08-04 21:59:451425 HandleBadResponseCode();
[email protected]0eb34fee2009-01-21 08:04:381426 } else { // Successful receipt (or we are discarding log).
[email protected]281d2882009-01-20 20:32:421427 LOG(INFO) << "METRICS RESPONSE DATA: " << data;
initial.commit09911bf2008-07-26 23:55:291428 switch (state_) {
1429 case INITIAL_LOG_READY:
1430 state_ = SEND_OLD_INITIAL_LOGS;
1431 break;
1432
1433 case SEND_OLD_INITIAL_LOGS:
1434 DCHECK(!unsent_initial_logs_.empty());
1435 unsent_initial_logs_.pop_back();
1436 StoreUnsentLogs();
1437 break;
1438
1439 case SENDING_OLD_LOGS:
1440 DCHECK(!unsent_ongoing_logs_.empty());
1441 unsent_ongoing_logs_.pop_back();
1442 StoreUnsentLogs();
1443 break;
1444
1445 case SENDING_CURRENT_LOGS:
1446 break;
1447
1448 default:
[email protected]a063c102010-07-22 22:20:191449 NOTREACHED();
initial.commit09911bf2008-07-26 23:55:291450 break;
1451 }
[email protected]d01b8732008-10-16 02:18:071452
initial.commit09911bf2008-07-26 23:55:291453 DiscardPendingLog();
[email protected]29be92552008-08-07 22:49:271454 // Since we sent a log, make sure our in-memory state is recorded to disk.
1455 PrefService* local_state = g_browser_process->local_state();
1456 DCHECK(local_state);
1457 if (local_state)
[email protected]6faa0e0d2009-04-28 06:50:361458 local_state->ScheduleSavePersistentPrefs();
[email protected]252873ef2008-08-04 21:59:451459
[email protected]147bbc0b2009-01-06 19:37:401460 // Provide a default (free of exponetial backoff, other varances) in case
1461 // the server does not specify a value.
1462 interlog_duration_ = TimeDelta::FromSeconds(kMinSecondsPerLog);
1463
[email protected]252873ef2008-08-04 21:59:451464 GetSettingsFromResponseData(data);
[email protected]252873ef2008-08-04 21:59:451465 // Override server specified interlog delay if there are unsent logs to
[email protected]29be92552008-08-07 22:49:271466 // transmit.
initial.commit09911bf2008-07-26 23:55:291467 if (unsent_logs()) {
1468 DCHECK(state_ < SENDING_CURRENT_LOGS);
1469 interlog_duration_ = TimeDelta::FromSeconds(kUnsentLogDelay);
initial.commit09911bf2008-07-26 23:55:291470 }
1471 }
[email protected]252873ef2008-08-04 21:59:451472
initial.commit09911bf2008-07-26 23:55:291473 StartLogTransmissionTimer();
1474}
1475
[email protected]252873ef2008-08-04 21:59:451476void MetricsService::HandleBadResponseCode() {
[email protected]281d2882009-01-20 20:32:421477 LOG(INFO) << "Verify your metrics logs are formatted correctly. "
[email protected]79bf0b72009-04-27 21:30:551478 "Verify server is active at " << server_url_;
[email protected]252873ef2008-08-04 21:59:451479 if (!pending_log()) {
[email protected]281d2882009-01-20 20:32:421480 LOG(INFO) << "METRICS: Recorder shutdown during log transmission.";
[email protected]252873ef2008-08-04 21:59:451481 } else {
1482 // Send progressively less frequently.
1483 DCHECK(kBackoff > 1.0);
1484 interlog_duration_ = TimeDelta::FromMicroseconds(
1485 static_cast<int64>(kBackoff * interlog_duration_.InMicroseconds()));
1486
1487 if (kMaxBackoff * TimeDelta::FromSeconds(kMinSecondsPerLog) <
[email protected]cac78842008-11-27 01:02:201488 interlog_duration_) {
[email protected]252873ef2008-08-04 21:59:451489 interlog_duration_ = kMaxBackoff *
1490 TimeDelta::FromSeconds(kMinSecondsPerLog);
[email protected]cac78842008-11-27 01:02:201491 }
[email protected]252873ef2008-08-04 21:59:451492
[email protected]281d2882009-01-20 20:32:421493 LOG(INFO) << "METRICS: transmission retry being scheduled in " <<
[email protected]252873ef2008-08-04 21:59:451494 interlog_duration_.InSeconds() << " seconds for " <<
[email protected]46f89e142010-07-19 08:00:421495 compressed_log_;
initial.commit09911bf2008-07-26 23:55:291496 }
initial.commit09911bf2008-07-26 23:55:291497}
1498
[email protected]252873ef2008-08-04 21:59:451499void MetricsService::GetSettingsFromResponseData(const std::string& data) {
1500 // We assume that the file is structured as a block opened by <response>
[email protected]d01b8732008-10-16 02:18:071501 // and that inside response, there is a block opened by tag <chrome_config>
1502 // other tags are ignored for now except the content of <chrome_config>.
[email protected]281d2882009-01-20 20:32:421503 LOG(INFO) << "METRICS: getting settings from response data: " << data;
[email protected]d01b8732008-10-16 02:18:071504
[email protected]252873ef2008-08-04 21:59:451505 int data_size = static_cast<int>(data.size());
1506 if (data_size < 0) {
[email protected]281d2882009-01-20 20:32:421507 LOG(INFO) << "METRICS: server response data bad size: " << data_size <<
[email protected]cac78842008-11-27 01:02:201508 "; aborting extraction of settings";
[email protected]252873ef2008-08-04 21:59:451509 return;
1510 }
[email protected]cac78842008-11-27 01:02:201511 xmlDocPtr doc = xmlReadMemory(data.c_str(), data_size, "", NULL, 0);
[email protected]d01b8732008-10-16 02:18:071512 // If the document is malformed, we just use the settings that were there.
1513 if (!doc) {
[email protected]281d2882009-01-20 20:32:421514 LOG(INFO) << "METRICS: reading xml from server response data failed";
[email protected]252873ef2008-08-04 21:59:451515 return;
[email protected]d01b8732008-10-16 02:18:071516 }
[email protected]252873ef2008-08-04 21:59:451517
[email protected]d01b8732008-10-16 02:18:071518 xmlNodePtr top_node = xmlDocGetRootElement(doc), chrome_config_node = NULL;
1519 // Here, we find the chrome_config node by name.
[email protected]252873ef2008-08-04 21:59:451520 for (xmlNodePtr p = top_node->children; p; p = p->next) {
[email protected]d01b8732008-10-16 02:18:071521 if (xmlStrEqual(p->name, BAD_CAST "chrome_config")) {
1522 chrome_config_node = p;
[email protected]252873ef2008-08-04 21:59:451523 break;
1524 }
1525 }
1526 // If the server data is formatted wrong and there is no
1527 // config node where we expect, we just drop out.
[email protected]d01b8732008-10-16 02:18:071528 if (chrome_config_node != NULL)
1529 GetSettingsFromChromeConfigNode(chrome_config_node);
[email protected]252873ef2008-08-04 21:59:451530 xmlFreeDoc(doc);
1531}
1532
[email protected]d01b8732008-10-16 02:18:071533void MetricsService::GetSettingsFromChromeConfigNode(
1534 xmlNodePtr chrome_config_node) {
1535 // Iterate through all children of the config node.
1536 for (xmlNodePtr current_node = chrome_config_node->children;
1537 current_node;
1538 current_node = current_node->next) {
1539 // If we find the upload tag, we appeal to another function
1540 // GetSettingsFromUploadNode to read all the data in it.
[email protected]252873ef2008-08-04 21:59:451541 if (xmlStrEqual(current_node->name, BAD_CAST "upload")) {
[email protected]d01b8732008-10-16 02:18:071542 GetSettingsFromUploadNode(current_node);
[email protected]252873ef2008-08-04 21:59:451543 continue;
1544 }
1545 }
1546}
initial.commit09911bf2008-07-26 23:55:291547
[email protected]d01b8732008-10-16 02:18:071548void MetricsService::InheritedProperties::OverwriteWhereNeeded(
1549 xmlNodePtr node) {
1550 xmlChar* salt_value = xmlGetProp(node, BAD_CAST "salt");
1551 if (salt_value) // If the property isn't there, xmlGetProp returns NULL.
1552 salt = atoi(reinterpret_cast<char*>(salt_value));
1553 // If the property isn't there, we keep the value the property had before
1554
1555 xmlChar* denominator_value = xmlGetProp(node, BAD_CAST "denominator");
1556 if (denominator_value)
1557 denominator = atoi(reinterpret_cast<char*>(denominator_value));
1558}
1559
1560void MetricsService::GetSettingsFromUploadNode(xmlNodePtr upload_node) {
1561 InheritedProperties props;
1562 GetSettingsFromUploadNodeRecursive(upload_node, props, "", true);
1563}
1564
[email protected]cac78842008-11-27 01:02:201565void MetricsService::GetSettingsFromUploadNodeRecursive(
1566 xmlNodePtr node,
1567 InheritedProperties props,
1568 std::string path_prefix,
1569 bool uploadOn) {
[email protected]d01b8732008-10-16 02:18:071570 props.OverwriteWhereNeeded(node);
1571
1572 // The bool uploadOn is set to true if the data represented by current
1573 // node should be uploaded. This gets inherited in the tree; the children
1574 // of a node that has already been rejected for upload get rejected for
1575 // upload.
1576 uploadOn = uploadOn && NodeProbabilityTest(node, props);
1577
1578 // The path is a / separated list of the node names ancestral to the current
1579 // one. So, if you want to check if the current node has a certain name,
1580 // compare to name. If you want to check if it is a certan tag at a certain
1581 // place in the tree, compare to the whole path.
1582 std::string name = std::string(reinterpret_cast<const char*>(node->name));
1583 std::string path = path_prefix + "/" + name;
1584
1585 if (path == "/upload") {
1586 xmlChar* upload_interval_val = xmlGetProp(node, BAD_CAST "interval");
1587 if (upload_interval_val) {
1588 interlog_duration_ = TimeDelta::FromSeconds(
1589 atoi(reinterpret_cast<char*>(upload_interval_val)));
1590 }
1591
1592 server_permits_upload_ = uploadOn;
[email protected]24d07e32010-07-10 00:31:271593 } else if (path == "/upload/logs") {
[email protected]d01b8732008-10-16 02:18:071594 xmlChar* log_event_limit_val = xmlGetProp(node, BAD_CAST "event_limit");
1595 if (log_event_limit_val)
1596 log_event_limit_ = atoi(reinterpret_cast<char*>(log_event_limit_val));
1597 }
[email protected]d01b8732008-10-16 02:18:071598
1599 // Recursive call. If the node is a leaf i.e. if it ends in a "/>", then it
1600 // doesn't have children, so node->children is NULL, and this loop doesn't
1601 // call (that's how the recursion ends).
1602 for (xmlNodePtr child_node = node->children;
[email protected]cac78842008-11-27 01:02:201603 child_node;
1604 child_node = child_node->next) {
[email protected]d01b8732008-10-16 02:18:071605 GetSettingsFromUploadNodeRecursive(child_node, props, path, uploadOn);
1606 }
1607}
1608
1609bool MetricsService::NodeProbabilityTest(xmlNodePtr node,
[email protected]cac78842008-11-27 01:02:201610 InheritedProperties props) const {
[email protected]d01b8732008-10-16 02:18:071611 // Default value of probability on any node is 1, but recall that
1612 // its parents can already have been rejected for upload.
1613 double probability = 1;
1614
1615 // If a probability is specified in the node, we use it instead.
1616 xmlChar* probability_value = xmlGetProp(node, BAD_CAST "probability");
1617 if (probability_value)
[email protected]0b33f80b2008-12-17 21:34:361618 probability = atoi(reinterpret_cast<char*>(probability_value));
[email protected]d01b8732008-10-16 02:18:071619
1620 return ProbabilityTest(probability, props.salt, props.denominator);
1621}
1622
1623bool MetricsService::ProbabilityTest(double probability,
1624 int salt,
1625 int denominator) const {
1626 // Okay, first we figure out how many of the digits of the
1627 // client_id_ we need in order to make a nice pseudorandomish
1628 // number in the range [0,denominator). Too many digits is
1629 // fine.
[email protected]d01b8732008-10-16 02:18:071630
1631 // n is the length of the client_id_ string
1632 size_t n = client_id_.size();
1633
1634 // idnumber is a positive integer generated from the client_id_.
1635 // It plus salt is going to give us our pseudorandom number.
1636 int idnumber = 0;
1637 const char* client_id_c_str = client_id_.c_str();
1638
1639 // Here we hash the relevant digits of the client_id_
1640 // string somehow to get a big integer idnumber (could be negative
1641 // from wraparound)
1642 int big = 1;
[email protected]5ed73342009-03-18 17:39:431643 int last_pos = n - 1;
1644 for (size_t j = 0; j < n; ++j) {
1645 idnumber += static_cast<int>(client_id_c_str[last_pos - j]) * big;
[email protected]d01b8732008-10-16 02:18:071646 big *= 10;
1647 }
1648
1649 // Mod id number by denominator making sure to get a non-negative
1650 // answer.
[email protected]cac78842008-11-27 01:02:201651 idnumber = ((idnumber % denominator) + denominator) % denominator;
[email protected]d01b8732008-10-16 02:18:071652
[email protected]cac78842008-11-27 01:02:201653 // ((idnumber + salt) % denominator) / denominator is in the range [0,1]
[email protected]d01b8732008-10-16 02:18:071654 // if it's less than probability we call that an affirmative coin
1655 // toss.
[email protected]cac78842008-11-27 01:02:201656 return static_cast<double>((idnumber + salt) % denominator) <
1657 probability * denominator;
[email protected]d01b8732008-10-16 02:18:071658}
1659
initial.commit09911bf2008-07-26 23:55:291660void MetricsService::LogWindowChange(NotificationType type,
1661 const NotificationSource& source,
1662 const NotificationDetails& details) {
[email protected]534e54b2008-08-13 15:40:091663 int controller_id = -1;
1664 uintptr_t window_or_tab = source.map_key();
initial.commit09911bf2008-07-26 23:55:291665 MetricsLog::WindowEventType window_type;
1666
1667 // Note: since we stop all logging when a single OTR session is active, it is
1668 // possible that we start getting notifications about a window that we don't
1669 // know about.
[email protected]534e54b2008-08-13 15:40:091670 if (window_map_.find(window_or_tab) == window_map_.end()) {
1671 controller_id = next_window_id_++;
1672 window_map_[window_or_tab] = controller_id;
initial.commit09911bf2008-07-26 23:55:291673 } else {
[email protected]534e54b2008-08-13 15:40:091674 controller_id = window_map_[window_or_tab];
initial.commit09911bf2008-07-26 23:55:291675 }
[email protected]92745242009-06-12 16:52:211676 DCHECK_NE(controller_id, -1);
initial.commit09911bf2008-07-26 23:55:291677
[email protected]bfd04a62009-02-01 18:16:561678 switch (type.value) {
1679 case NotificationType::TAB_PARENTED:
1680 case NotificationType::BROWSER_OPENED:
initial.commit09911bf2008-07-26 23:55:291681 window_type = MetricsLog::WINDOW_CREATE;
1682 break;
1683
[email protected]bfd04a62009-02-01 18:16:561684 case NotificationType::TAB_CLOSING:
1685 case NotificationType::BROWSER_CLOSED:
[email protected]534e54b2008-08-13 15:40:091686 window_map_.erase(window_map_.find(window_or_tab));
initial.commit09911bf2008-07-26 23:55:291687 window_type = MetricsLog::WINDOW_DESTROY;
1688 break;
1689
1690 default:
[email protected]a063c102010-07-22 22:20:191691 NOTREACHED();
[email protected]68d74f02009-02-13 01:36:501692 return;
initial.commit09911bf2008-07-26 23:55:291693 }
1694
[email protected]534e54b2008-08-13 15:40:091695 // TODO(brettw) we should have some kind of ID for the parent.
1696 current_log_->RecordWindowEvent(window_type, controller_id, 0);
initial.commit09911bf2008-07-26 23:55:291697}
1698
1699void MetricsService::LogLoadComplete(NotificationType type,
1700 const NotificationSource& source,
1701 const NotificationDetails& details) {
1702 if (details == NotificationService::NoDetails())
1703 return;
1704
[email protected]68475e602008-08-22 03:21:151705 // TODO(jar): There is a bug causing this to be called too many times, and
1706 // the log overflows. For now, we won't record these events.
[email protected]553dba62009-02-24 19:08:231707 UMA_HISTOGRAM_COUNTS("UMA.LogLoadComplete called", 1);
[email protected]68475e602008-08-22 03:21:151708 return;
1709
initial.commit09911bf2008-07-26 23:55:291710 const Details<LoadNotificationDetails> load_details(details);
[email protected]534e54b2008-08-13 15:40:091711 int controller_id = window_map_[details.map_key()];
1712 current_log_->RecordLoadEvent(controller_id,
initial.commit09911bf2008-07-26 23:55:291713 load_details->url(),
1714 load_details->origin(),
1715 load_details->session_index(),
1716 load_details->load_time());
1717}
1718
[email protected]57ecc4b2010-08-11 03:02:511719void MetricsService::IncrementPrefValue(const char* path) {
[email protected]e73c01972008-08-13 00:18:241720 PrefService* pref = g_browser_process->local_state();
1721 DCHECK(pref);
1722 int value = pref->GetInteger(path);
1723 pref->SetInteger(path, value + 1);
1724}
1725
[email protected]57ecc4b2010-08-11 03:02:511726void MetricsService::IncrementLongPrefsValue(const char* path) {
[email protected]0bb1a622009-03-04 03:22:321727 PrefService* pref = g_browser_process->local_state();
1728 DCHECK(pref);
1729 int64 value = pref->GetInt64(path);
[email protected]b42c5e42010-06-03 20:43:251730 pref->SetInt64(path, value + 1);
[email protected]0bb1a622009-03-04 03:22:321731}
1732
initial.commit09911bf2008-07-26 23:55:291733void MetricsService::LogLoadStarted() {
[email protected]e73c01972008-08-13 00:18:241734 IncrementPrefValue(prefs::kStabilityPageLoadCount);
[email protected]0bb1a622009-03-04 03:22:321735 IncrementLongPrefsValue(prefs::kUninstallMetricsPageLoadCount);
[email protected]0b33f80b2008-12-17 21:34:361736 // We need to save the prefs, as page load count is a critical stat, and it
1737 // might be lost due to a crash :-(.
initial.commit09911bf2008-07-26 23:55:291738}
1739
initial.commit09911bf2008-07-26 23:55:291740void MetricsService::LogRendererCrash() {
[email protected]e73c01972008-08-13 00:18:241741 IncrementPrefValue(prefs::kStabilityRendererCrashCount);
initial.commit09911bf2008-07-26 23:55:291742}
1743
[email protected]1f085622009-12-04 05:33:451744void MetricsService::LogExtensionRendererCrash() {
1745 IncrementPrefValue(prefs::kStabilityExtensionRendererCrashCount);
1746}
1747
initial.commit09911bf2008-07-26 23:55:291748void MetricsService::LogRendererHang() {
[email protected]e73c01972008-08-13 00:18:241749 IncrementPrefValue(prefs::kStabilityRendererHangCount);
initial.commit09911bf2008-07-26 23:55:291750}
1751
[email protected]a27a9382009-02-11 23:55:101752void MetricsService::LogChildProcessChange(
1753 NotificationType type,
1754 const NotificationSource& source,
1755 const NotificationDetails& details) {
[email protected]0d84c5d2009-10-09 01:10:421756 Details<ChildProcessInfo> child_details(details);
1757 const std::wstring& child_name = child_details->name();
1758
[email protected]a27a9382009-02-11 23:55:101759 if (child_process_stats_buffer_.find(child_name) ==
1760 child_process_stats_buffer_.end()) {
[email protected]0d84c5d2009-10-09 01:10:421761 child_process_stats_buffer_[child_name] =
1762 ChildProcessStats(child_details->type());
initial.commit09911bf2008-07-26 23:55:291763 }
1764
[email protected]a27a9382009-02-11 23:55:101765 ChildProcessStats& stats = child_process_stats_buffer_[child_name];
[email protected]bfd04a62009-02-01 18:16:561766 switch (type.value) {
[email protected]a27a9382009-02-11 23:55:101767 case NotificationType::CHILD_PROCESS_HOST_CONNECTED:
initial.commit09911bf2008-07-26 23:55:291768 stats.process_launches++;
1769 break;
1770
[email protected]a27a9382009-02-11 23:55:101771 case NotificationType::CHILD_INSTANCE_CREATED:
initial.commit09911bf2008-07-26 23:55:291772 stats.instances++;
1773 break;
1774
[email protected]a27a9382009-02-11 23:55:101775 case NotificationType::CHILD_PROCESS_CRASHED:
initial.commit09911bf2008-07-26 23:55:291776 stats.process_crashes++;
[email protected]1f085622009-12-04 05:33:451777 // Exclude plugin crashes from the count below because we report them via
1778 // a separate UMA metric.
1779 if (child_details->type() != ChildProcessInfo::PLUGIN_PROCESS) {
1780 IncrementPrefValue(prefs::kStabilityChildProcessCrashCount);
1781 }
initial.commit09911bf2008-07-26 23:55:291782 break;
1783
1784 default:
[email protected]a063c102010-07-22 22:20:191785 NOTREACHED() << "Unexpected notification type " << type.value;
initial.commit09911bf2008-07-26 23:55:291786 return;
1787 }
1788}
1789
1790// Recursively counts the number of bookmarks and folders in node.
[email protected]b3c33d462009-06-26 22:29:201791static void CountBookmarks(const BookmarkNode* node,
1792 int* bookmarks,
1793 int* folders) {
[email protected]037db002009-10-19 20:06:081794 if (node->type() == BookmarkNode::URL)
initial.commit09911bf2008-07-26 23:55:291795 (*bookmarks)++;
1796 else
1797 (*folders)++;
1798 for (int i = 0; i < node->GetChildCount(); ++i)
1799 CountBookmarks(node->GetChild(i), bookmarks, folders);
1800}
1801
[email protected]b3c33d462009-06-26 22:29:201802void MetricsService::LogBookmarks(const BookmarkNode* node,
[email protected]57ecc4b2010-08-11 03:02:511803 const char* num_bookmarks_key,
1804 const char* num_folders_key) {
initial.commit09911bf2008-07-26 23:55:291805 DCHECK(node);
1806 int num_bookmarks = 0;
1807 int num_folders = 0;
1808 CountBookmarks(node, &num_bookmarks, &num_folders);
1809 num_folders--; // Don't include the root folder in the count.
1810
1811 PrefService* pref = g_browser_process->local_state();
1812 DCHECK(pref);
1813 pref->SetInteger(num_bookmarks_key, num_bookmarks);
1814 pref->SetInteger(num_folders_key, num_folders);
1815}
1816
[email protected]d8e41ed2008-09-11 15:22:321817void MetricsService::LogBookmarks(BookmarkModel* model) {
initial.commit09911bf2008-07-26 23:55:291818 DCHECK(model);
1819 LogBookmarks(model->GetBookmarkBarNode(),
1820 prefs::kNumBookmarksOnBookmarkBar,
1821 prefs::kNumFoldersOnBookmarkBar);
1822 LogBookmarks(model->other_node(),
1823 prefs::kNumBookmarksInOtherBookmarkFolder,
1824 prefs::kNumFoldersInOtherBookmarkFolder);
1825 ScheduleNextStateSave();
1826}
1827
1828void MetricsService::LogKeywords(const TemplateURLModel* url_model) {
1829 DCHECK(url_model);
1830
1831 PrefService* pref = g_browser_process->local_state();
1832 DCHECK(pref);
1833 pref->SetInteger(prefs::kNumKeywords,
1834 static_cast<int>(url_model->GetTemplateURLs().size()));
1835 ScheduleNextStateSave();
1836}
1837
1838void MetricsService::RecordPluginChanges(PrefService* pref) {
1839 ListValue* plugins = pref->GetMutableList(prefs::kStabilityPluginStats);
1840 DCHECK(plugins);
1841
1842 for (ListValue::iterator value_iter = plugins->begin();
1843 value_iter != plugins->end(); ++value_iter) {
1844 if (!(*value_iter)->IsType(Value::TYPE_DICTIONARY)) {
[email protected]a063c102010-07-22 22:20:191845 NOTREACHED();
initial.commit09911bf2008-07-26 23:55:291846 continue;
1847 }
1848
1849 DictionaryValue* plugin_dict = static_cast<DictionaryValue*>(*value_iter);
[email protected]57ecc4b2010-08-11 03:02:511850 std::string plugin_name;
[email protected]8e50b602009-03-03 22:59:431851 plugin_dict->GetString(prefs::kStabilityPluginName, &plugin_name);
[email protected]6470ee8f2009-03-03 20:46:401852 if (plugin_name.empty()) {
[email protected]a063c102010-07-22 22:20:191853 NOTREACHED();
initial.commit09911bf2008-07-26 23:55:291854 continue;
1855 }
1856
[email protected]57ecc4b2010-08-11 03:02:511857 // TODO(viettrungluu): remove conversions
1858 if (child_process_stats_buffer_.find(UTF8ToWide(plugin_name)) ==
[email protected]a27a9382009-02-11 23:55:101859 child_process_stats_buffer_.end())
initial.commit09911bf2008-07-26 23:55:291860 continue;
1861
[email protected]57ecc4b2010-08-11 03:02:511862 ChildProcessStats stats =
1863 child_process_stats_buffer_[UTF8ToWide(plugin_name)];
initial.commit09911bf2008-07-26 23:55:291864 if (stats.process_launches) {
1865 int launches = 0;
[email protected]8e50b602009-03-03 22:59:431866 plugin_dict->GetInteger(prefs::kStabilityPluginLaunches, &launches);
initial.commit09911bf2008-07-26 23:55:291867 launches += stats.process_launches;
[email protected]8e50b602009-03-03 22:59:431868 plugin_dict->SetInteger(prefs::kStabilityPluginLaunches, launches);
initial.commit09911bf2008-07-26 23:55:291869 }
1870 if (stats.process_crashes) {
1871 int crashes = 0;
[email protected]8e50b602009-03-03 22:59:431872 plugin_dict->GetInteger(prefs::kStabilityPluginCrashes, &crashes);
initial.commit09911bf2008-07-26 23:55:291873 crashes += stats.process_crashes;
[email protected]8e50b602009-03-03 22:59:431874 plugin_dict->SetInteger(prefs::kStabilityPluginCrashes, crashes);
initial.commit09911bf2008-07-26 23:55:291875 }
1876 if (stats.instances) {
1877 int instances = 0;
[email protected]8e50b602009-03-03 22:59:431878 plugin_dict->GetInteger(prefs::kStabilityPluginInstances, &instances);
initial.commit09911bf2008-07-26 23:55:291879 instances += stats.instances;
[email protected]8e50b602009-03-03 22:59:431880 plugin_dict->SetInteger(prefs::kStabilityPluginInstances, instances);
initial.commit09911bf2008-07-26 23:55:291881 }
1882
[email protected]57ecc4b2010-08-11 03:02:511883 child_process_stats_buffer_.erase(UTF8ToWide(plugin_name));
initial.commit09911bf2008-07-26 23:55:291884 }
1885
1886 // Now go through and add dictionaries for plugins that didn't already have
1887 // reports in Local State.
[email protected]a27a9382009-02-11 23:55:101888 for (std::map<std::wstring, ChildProcessStats>::iterator cache_iter =
1889 child_process_stats_buffer_.begin();
1890 cache_iter != child_process_stats_buffer_.end(); ++cache_iter) {
[email protected]a27a9382009-02-11 23:55:101891 ChildProcessStats stats = cache_iter->second;
[email protected]0d84c5d2009-10-09 01:10:421892
1893 // Insert only plugins information into the plugins list.
1894 if (ChildProcessInfo::PLUGIN_PROCESS != stats.process_type)
1895 continue;
1896
[email protected]57ecc4b2010-08-11 03:02:511897 // TODO(viettrungluu): remove conversion
1898 std::string plugin_name = WideToUTF8(cache_iter->first);
[email protected]0d84c5d2009-10-09 01:10:421899
initial.commit09911bf2008-07-26 23:55:291900 DictionaryValue* plugin_dict = new DictionaryValue;
1901
[email protected]8e50b602009-03-03 22:59:431902 plugin_dict->SetString(prefs::kStabilityPluginName, plugin_name);
1903 plugin_dict->SetInteger(prefs::kStabilityPluginLaunches,
initial.commit09911bf2008-07-26 23:55:291904 stats.process_launches);
[email protected]8e50b602009-03-03 22:59:431905 plugin_dict->SetInteger(prefs::kStabilityPluginCrashes,
initial.commit09911bf2008-07-26 23:55:291906 stats.process_crashes);
[email protected]8e50b602009-03-03 22:59:431907 plugin_dict->SetInteger(prefs::kStabilityPluginInstances,
initial.commit09911bf2008-07-26 23:55:291908 stats.instances);
1909 plugins->Append(plugin_dict);
1910 }
[email protected]a27a9382009-02-11 23:55:101911 child_process_stats_buffer_.clear();
initial.commit09911bf2008-07-26 23:55:291912}
1913
1914bool MetricsService::CanLogNotification(NotificationType type,
1915 const NotificationSource& source,
1916 const NotificationDetails& details) {
1917 // We simply don't log anything to UMA if there is a single off the record
1918 // session visible. The problem is that we always notify using the orginal
1919 // profile in order to simplify notification processing.
1920 return !BrowserList::IsOffTheRecordSessionActive();
1921}
1922
[email protected]57ecc4b2010-08-11 03:02:511923void MetricsService::RecordBooleanPrefValue(const char* path, bool value) {
initial.commit09911bf2008-07-26 23:55:291924 DCHECK(IsSingleThreaded());
1925
1926 PrefService* pref = g_browser_process->local_state();
1927 DCHECK(pref);
1928
1929 pref->SetBoolean(path, value);
1930 RecordCurrentState(pref);
1931}
1932
1933void MetricsService::RecordCurrentState(PrefService* pref) {
[email protected]0bb1a622009-03-04 03:22:321934 pref->SetInt64(prefs::kStabilityLastTimestampSec, Time::Now().ToTimeT());
initial.commit09911bf2008-07-26 23:55:291935
1936 RecordPluginChanges(pref);
1937}
1938
initial.commit09911bf2008-07-26 23:55:291939static bool IsSingleThreaded() {
[email protected]dc6f4962009-02-13 01:25:501940 static PlatformThreadId thread_id = 0;
initial.commit09911bf2008-07-26 23:55:291941 if (!thread_id)
[email protected]dc6f4962009-02-13 01:25:501942 thread_id = PlatformThread::CurrentId();
1943 return PlatformThread::CurrentId() == thread_id;
initial.commit09911bf2008-07-26 23:55:291944}
[email protected]5ccaa412009-11-13 22:00:161945
1946#if defined(OS_CHROMEOS)
[email protected]29cf16772010-04-21 15:13:471947void MetricsService::StartExternalMetrics() {
[email protected]5ccaa412009-11-13 22:00:161948 external_metrics_ = new chromeos::ExternalMetrics;
[email protected]29cf16772010-04-21 15:13:471949 external_metrics_->Start();
[email protected]5ccaa412009-11-13 22:00:161950}
1951#endif