blob: 3669f5b4f232e27733a4988b37131ab49f234cd0 [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
initial.commit09911bf2008-07-26 23:55:295//------------------------------------------------------------------------------
6// Description of the life cycle of a instance of MetricsService.
7//
8// OVERVIEW
9//
10// A MetricsService instance is typically created at application startup. It
11// is the central controller for the acquisition of log data, and the automatic
12// transmission of that log data to an external server. Its major job is to
13// manage logs, grouping them for transmission, and transmitting them. As part
14// of its grouping, MS finalizes logs by including some just-in-time gathered
15// memory statistics, snapshotting the current stats of numerous histograms,
16// closing the logs, translating to XML text, and compressing the results for
17// transmission. Transmission includes submitting a compressed log as data in a
[email protected]281d2882009-01-20 20:32:4218// URL-post, and retransmitting (or retaining at process termination) if the
initial.commit09911bf2008-07-26 23:55:2919// attempted transmission failed. Retention across process terminations is done
[email protected]46f89e142010-07-19 08:00:4220// using the the PrefServices facilities. The retained logs (the ones that never
21// got transmitted) are compressed and base64-encoded before being persisted.
initial.commit09911bf2008-07-26 23:55:2922//
[email protected]281d2882009-01-20 20:32:4223// Logs fall into one of two categories: "initial logs," and "ongoing logs."
24// There is at most one initial log sent for each complete run of the chromium
initial.commit09911bf2008-07-26 23:55:2925// product (from startup, to browser shutdown). An initial log is generally
26// transmitted some short time (1 minute?) after startup, and includes stats
27// such as recent crash info, the number and types of plugins, etc. The
[email protected]281d2882009-01-20 20:32:4228// external server's response to the initial log conceptually tells this MS if
29// it should continue transmitting logs (during this session). The server
30// response can actually be much more detailed, and always includes (at a
31// minimum) how often additional ongoing logs should be sent.
initial.commit09911bf2008-07-26 23:55:2932//
33// After the above initial log, a series of ongoing logs will be transmitted.
34// The first ongoing log actually begins to accumulate information stating when
35// the MS was first constructed. Note that even though the initial log is
36// commonly sent a full minute after startup, the initial log does not include
37// much in the way of user stats. The most common interlog period (delay)
[email protected]0b33f80b2008-12-17 21:34:3638// is 20 minutes. That time period starts when the first user action causes a
initial.commit09911bf2008-07-26 23:55:2939// logging event. This means that if there is no user action, there may be long
[email protected]281d2882009-01-20 20:32:4240// periods without any (ongoing) log transmissions. Ongoing logs typically
initial.commit09911bf2008-07-26 23:55:2941// contain very detailed records of user activities (ex: opened tab, closed
42// tab, fetched URL, maximized window, etc.) In addition, just before an
43// ongoing log is closed out, a call is made to gather memory statistics. Those
44// memory statistics are deposited into a histogram, and the log finalization
45// code is then called. In the finalization, a call to a Histogram server
46// acquires a list of all local histograms that have been flagged for upload
[email protected]281d2882009-01-20 20:32:4247// to the UMA server. The finalization also acquires a the most recent number
48// of page loads, along with any counts of renderer or plugin crashes.
initial.commit09911bf2008-07-26 23:55:2949//
50// When the browser shuts down, there will typically be a fragment of an ongoing
51// log that has not yet been transmitted. At shutdown time, that fragment
52// is closed (including snapshotting histograms), and converted to text. Note
53// that memory stats are not gathered during shutdown, as gathering *might* be
54// too time consuming. The textual representation of the fragment of the
55// ongoing log is then stored persistently as a string in the PrefServices, for
56// potential transmission during a future run of the product.
57//
58// There are two slightly abnormal shutdown conditions. There is a
59// "disconnected scenario," and a "really fast startup and shutdown" scenario.
60// In the "never connected" situation, the user has (during the running of the
61// process) never established an internet connection. As a result, attempts to
62// transmit the initial log have failed, and a lot(?) of data has accumulated in
63// the ongoing log (which didn't yet get closed, because there was never even a
64// contemplation of sending it). There is also a kindred "lost connection"
65// situation, where a loss of connection prevented an ongoing log from being
66// transmitted, and a (still open) log was stuck accumulating a lot(?) of data,
67// while the earlier log retried its transmission. In both of these
68// disconnected situations, two logs need to be, and are, persistently stored
69// for future transmission.
70//
71// The other unusual shutdown condition, termed "really fast startup and
72// shutdown," involves the deliberate user termination of the process before
73// the initial log is even formed or transmitted. In that situation, no logging
74// is done, but the historical crash statistics remain (unlogged) for inclusion
75// in a future run's initial log. (i.e., we don't lose crash stats).
76//
77// With the above overview, we can now describe the state machine's various
78// stats, based on the State enum specified in the state_ member. Those states
79// are:
80//
81// INITIALIZED, // Constructor was called.
[email protected]85ed9d42010-06-08 22:37:4482// INIT_TASK_SCHEDULED, // Waiting for deferred init tasks to complete.
83// INIT_TASK_DONE, // Waiting for timer to send initial log.
initial.commit09911bf2008-07-26 23:55:2984// INITIAL_LOG_READY, // Initial log generated, and waiting for reply.
85// SEND_OLD_INITIAL_LOGS, // Sending unsent logs from previous session.
86// SENDING_OLD_LOGS, // Sending unsent logs from previous session.
87// SENDING_CURRENT_LOGS, // Sending standard current logs as they accrue.
88//
89// In more detail, we have:
90//
91// INITIALIZED, // Constructor was called.
92// The MS has been constructed, but has taken no actions to compose the
93// initial log.
94//
[email protected]85ed9d42010-06-08 22:37:4495// INIT_TASK_SCHEDULED, // Waiting for deferred init tasks to complete.
initial.commit09911bf2008-07-26 23:55:2996// Typically about 30 seconds after startup, a task is sent to a second thread
[email protected]85ed9d42010-06-08 22:37:4497// (the file thread) to perform deferred (lower priority and slower)
98// initialization steps such as getting the list of plugins. That task will
99// (when complete) make an async callback (via a Task) to indicate the
100// completion.
initial.commit09911bf2008-07-26 23:55:29101//
[email protected]85ed9d42010-06-08 22:37:44102// INIT_TASK_DONE, // Waiting for timer to send initial log.
initial.commit09911bf2008-07-26 23:55:29103// The callback has arrived, and it is now possible for an initial log to be
104// created. This callback typically arrives back less than one second after
[email protected]85ed9d42010-06-08 22:37:44105// the deferred init task is dispatched.
initial.commit09911bf2008-07-26 23:55:29106//
107// INITIAL_LOG_READY, // Initial log generated, and waiting for reply.
108// This state is entered only after an initial log has been composed, and
109// prepared for transmission. It is also the case that any previously unsent
110// logs have been loaded into instance variables for possible transmission.
111//
112// SEND_OLD_INITIAL_LOGS, // Sending unsent logs from previous session.
113// This state indicates that the initial log for this session has been
114// successfully sent and it is now time to send any "initial logs" that were
115// saved from previous sessions. Most commonly, there are none, but all old
116// logs that were "initial logs" must be sent before this state is exited.
117//
118// SENDING_OLD_LOGS, // Sending unsent logs from previous session.
119// This state indicates that there are no more unsent initial logs, and now any
120// ongoing logs from previous sessions should be transmitted. All such logs
121// will be transmitted before exiting this state, and proceeding with ongoing
122// logs from the current session (see next state).
123//
124// SENDING_CURRENT_LOGS, // Sending standard current logs as they accrue.
[email protected]0b33f80b2008-12-17 21:34:36125// Current logs are being accumulated. Typically every 20 minutes a log is
initial.commit09911bf2008-07-26 23:55:29126// closed and finalized for transmission, at the same time as a new log is
127// started.
128//
129// The progression through the above states is simple, and sequential, in the
130// most common use cases. States proceed from INITIAL to SENDING_CURRENT_LOGS,
131// and remain in the latter until shutdown.
132//
133// The one unusual case is when the user asks that we stop logging. When that
134// happens, any pending (transmission in progress) log is pushed into the list
135// of old unsent logs (the appropriate list, depending on whether it is an
136// initial log, or an ongoing log). An addition, any log that is currently
137// accumulating is also finalized, and pushed into the unsent log list. With
[email protected]281d2882009-01-20 20:32:42138// those pushes performed, we regress back to the SEND_OLD_INITIAL_LOGS state in
initial.commit09911bf2008-07-26 23:55:29139// case the user enables log recording again during this session. This way
140// anything we have "pushed back" will be sent automatically if/when we progress
141// back to SENDING_CURRENT_LOG state.
142//
143// Also note that whenever the member variables containing unsent logs are
144// modified (i.e., when we send an old log), we mirror the list of logs into
145// the PrefServices. This ensures that IF we crash, we won't start up and
146// retransmit our old logs again.
147//
148// Due to race conditions, it is always possible that a log file could be sent
149// twice. For example, if a log file is sent, but not yet acknowledged by
150// the external server, and the user shuts down, then a copy of the log may be
151// saved for re-transmission. These duplicates could be filtered out server
[email protected]281d2882009-01-20 20:32:42152// side, but are not expected to be a significant problem.
initial.commit09911bf2008-07-26 23:55:29153//
154//
155//------------------------------------------------------------------------------
156
[email protected]40bcc302009-03-02 20:50:39157#include "chrome/browser/metrics/metrics_service.h"
158
[email protected]46f89e142010-07-19 08:00:42159#include "base/base64.h"
[email protected]5d91c9e2010-07-28 17:25:28160#include "base/command_line.h"
[email protected]46f89e142010-07-19 08:00:42161#include "base/md5.h"
[email protected]835d7c82010-10-14 04:38:38162#include "base/metrics/histogram.h"
[email protected]528c56d2010-07-30 19:28:44163#include "base/string_number_conversions.h"
[email protected]4d022ff2009-10-23 18:47:09164#include "base/thread.h"
[email protected]ce072a72010-12-31 20:02:16165#include "base/threading/platform_thread.h"
[email protected]440b37b22010-08-30 05:31:40166#include "base/utf_string_conversions.h"
[email protected]679082052010-07-21 21:30:13167#include "base/values.h"
[email protected]d8e41ed2008-09-11 15:22:32168#include "chrome/browser/bookmarks/bookmark_model.h"
initial.commit09911bf2008-07-26 23:55:29169#include "chrome/browser/browser_list.h"
170#include "chrome/browser/browser_process.h"
initial.commit09911bf2008-07-26 23:55:29171#include "chrome/browser/load_notification_details.h"
172#include "chrome/browser/memory_details.h"
[email protected]7c927b62010-02-24 09:54:13173#include "chrome/browser/metrics/histogram_synchronizer.h"
[email protected]679082052010-07-21 21:30:13174#include "chrome/browser/metrics/metrics_log.h"
[email protected]37858e52010-08-26 00:22:02175#include "chrome/browser/prefs/pref_service.h"
[email protected]8ecad5e2010-12-02 21:18:33176#include "chrome/browser/profiles/profile.h"
[email protected]8c8657d62009-01-16 18:31:26177#include "chrome/browser/renderer_host/render_process_host.h"
[email protected]d54e03a52009-01-16 00:31:04178#include "chrome/browser/search_engines/template_url_model.h"
[email protected]679082052010-07-21 21:30:13179#include "chrome/common/child_process_info.h"
[email protected]157d5472009-11-05 22:31:03180#include "chrome/common/child_process_logging.h"
[email protected]92745242009-06-12 16:52:21181#include "chrome/common/chrome_switches.h"
[email protected]3eb0d8f72010-12-15 23:38:25182#include "chrome/common/guid.h"
[email protected]bfd04a62009-02-01 18:16:56183#include "chrome/common/notification_service.h"
initial.commit09911bf2008-07-26 23:55:29184#include "chrome/common/pref_names.h"
[email protected]e09ba552009-02-05 03:26:29185#include "chrome/common/render_messages.h"
[email protected]191eb3f72010-12-21 06:27:50186#include "webkit/plugins/npapi/plugin_list.h"
187#include "webkit/plugins/npapi/webplugininfo.h"
[email protected]ae393ec702010-06-27 16:23:14188#include "libxml/xmlwriter.h"
initial.commit09911bf2008-07-26 23:55:29189
[email protected]e06131d2010-02-10 18:40:33190// TODO(port): port browser_distribution.h.
191#if !defined(OS_POSIX)
[email protected]79bf0b72009-04-27 21:30:55192#include "chrome/installer/util/browser_distribution.h"
[email protected]dc6f4962009-02-13 01:25:50193#endif
194
[email protected]5ccaa412009-11-13 22:00:16195#if defined(OS_CHROMEOS)
[email protected]db342d52010-08-09 21:19:37196#include "chrome/browser/chromeos/cros/cros_library.h"
197#include "chrome/browser/chromeos/cros/system_library.h"
[email protected]5ccaa412009-11-13 22:00:16198#include "chrome/browser/chromeos/external_metrics.h"
199#endif
200
[email protected]46f89e142010-07-19 08:00:42201namespace {
202MetricsService::LogRecallStatus MakeRecallStatusHistogram(
203 MetricsService::LogRecallStatus status) {
204 UMA_HISTOGRAM_ENUMERATION("PrefService.PersistentLogRecall", status,
205 MetricsService::END_RECALL_STATUS);
206 return status;
207}
208
209// TODO(ziadh): Remove this when done with experiment.
210void MakeStoreStatusHistogram(MetricsService::LogStoreStatus status) {
[email protected]4e95d202010-07-24 01:47:56211 UMA_HISTOGRAM_ENUMERATION("PrefService.PersistentLogStore2", status,
[email protected]46f89e142010-07-19 08:00:42212 MetricsService::END_STORE_STATUS);
213}
214} // namespace
215
[email protected]e1acf6f2008-10-27 20:43:33216using base::Time;
217using base::TimeDelta;
218
initial.commit09911bf2008-07-26 23:55:29219// Check to see that we're being called on only one thread.
220static bool IsSingleThreaded();
221
initial.commit09911bf2008-07-26 23:55:29222static const char kMetricsType[] = "application/vnd.mozilla.metrics.bz2";
223
224// The delay, in seconds, after startup before sending the first log message.
[email protected]252873ef2008-08-04 21:59:45225static const int kInitialInterlogDuration = 60; // one minute
226
[email protected]c9a3ef82009-05-28 22:02:46227// This specifies the amount of time to wait for all renderers to send their
228// data.
229static const int kMaxHistogramGatheringWaitDuration = 60000; // 60 seconds.
230
[email protected]252873ef2008-08-04 21:59:45231// The default maximum number of events in a log uploaded to the UMA server.
[email protected]0b33f80b2008-12-17 21:34:36232static const int kInitialEventLimit = 2400;
[email protected]68475e602008-08-22 03:21:15233
234// If an upload fails, and the transmission was over this byte count, then we
235// will discard the log, and not try to retransmit it. We also don't persist
236// the log to the prefs for transmission during the next chrome session if this
237// limit is exceeded.
238static const int kUploadLogAvoidRetransmitSize = 50000;
initial.commit09911bf2008-07-26 23:55:29239
240// When we have logs from previous Chrome sessions to send, how long should we
241// delay (in seconds) between each log transmission.
242static const int kUnsentLogDelay = 15; // 15 seconds
243
244// Minimum time a log typically exists before sending, in seconds.
245// This number is supplied by the server, but until we parse it out of a server
246// response, we use this duration to specify how long we should wait before
247// sending the next log. If the channel is busy, such as when there is a
248// failure during an attempt to transmit a previous log, then a log may wait
[email protected]2fe42fe2010-05-07 19:22:39249// (and continue to accrue new log entries) for a much greater period of time.
250static const int kMinSecondsPerLog = 30 * 60; // Thirty minutes.
initial.commit09911bf2008-07-26 23:55:29251
initial.commit09911bf2008-07-26 23:55:29252// When we don't succeed at transmitting a log to a server, we progressively
253// wait longer and longer before sending the next log. This backoff process
254// help reduce load on the server, and makes the amount of backoff vary between
255// clients so that a collision (server overload?) on retransmit is less likely.
256// The following is the constant we use to expand that inter-log duration.
257static const double kBackoff = 1.1;
258// We limit the maximum backoff to be no greater than some multiple of the
259// default kMinSecondsPerLog. The following is that maximum ratio.
260static const int kMaxBackoff = 10;
261
262// Interval, in seconds, between state saves.
263static const int kSaveStateInterval = 5 * 60; // five minutes
264
265// The number of "initial" logs we're willing to save, and hope to send during
266// a future Chrome session. Initial logs contain crash stats, and are pretty
267// small.
268static const size_t kMaxInitialLogsPersisted = 20;
269
270// The number of ongoing logs we're willing to save persistently, and hope to
[email protected]281d2882009-01-20 20:32:42271// send during a this or future sessions. Note that each log may be pretty
initial.commit09911bf2008-07-26 23:55:29272// large, as presumably the related "initial" log wasn't sent (probably nothing
273// was, as the user was probably off-line). As a result, the log probably kept
274// accumulating while the "initial" log was stalled (pending_), and couldn't be
275// sent. As a result, we don't want to save too many of these mega-logs.
276// A "standard shutdown" will create a small log, including just the data that
277// was not yet been transmitted, and that is normal (to have exactly one
278// ongoing_log_ at startup).
[email protected]281d2882009-01-20 20:32:42279static const size_t kMaxOngoingLogsPersisted = 8;
initial.commit09911bf2008-07-26 23:55:29280
[email protected]46f89e142010-07-19 08:00:42281// We append (2) more elements to persisted lists: the size of the list and a
282// checksum of the elements.
283static const size_t kChecksumEntryCount = 2;
284
[email protected]679082052010-07-21 21:30:13285// This is used to quickly log stats from child process related notifications in
286// MetricsService::child_stats_buffer_. The buffer's contents are transferred
287// out when Local State is periodically saved. The information is then
288// reported to the UMA server on next launch.
289struct MetricsService::ChildProcessStats {
290 public:
291 explicit ChildProcessStats(ChildProcessInfo::ProcessType type)
292 : process_launches(0),
293 process_crashes(0),
294 instances(0),
295 process_type(type) {}
296
297 // This constructor is only used by the map to return some default value for
298 // an index for which no value has been assigned.
299 ChildProcessStats()
300 : process_launches(0),
301 process_crashes(0),
302 instances(0),
303 process_type(ChildProcessInfo::UNKNOWN_PROCESS) {}
304
305 // The number of times that the given child process has been launched
306 int process_launches;
307
308 // The number of times that the given child process has crashed
309 int process_crashes;
310
311 // The number of instances of this child process that have been created.
312 // An instance is a DOM object rendered by this child process during a page
313 // load.
314 int instances;
315
316 ChildProcessInfo::ProcessType process_type;
317};
initial.commit09911bf2008-07-26 23:55:29318
319// Handles asynchronous fetching of memory details.
320// Will run the provided task after finished.
321class MetricsMemoryDetails : public MemoryDetails {
322 public:
323 explicit MetricsMemoryDetails(Task* completion) : completion_(completion) {}
324
325 virtual void OnDetailsAvailable() {
326 MessageLoop::current()->PostTask(FROM_HERE, completion_);
327 }
328
329 private:
[email protected]e6e6ba42009-11-07 01:56:19330 ~MetricsMemoryDetails() {}
331
initial.commit09911bf2008-07-26 23:55:29332 Task* completion_;
[email protected]4d818fee2010-06-06 13:32:27333 DISALLOW_COPY_AND_ASSIGN(MetricsMemoryDetails);
initial.commit09911bf2008-07-26 23:55:29334};
335
[email protected]85ed9d42010-06-08 22:37:44336class MetricsService::InitTaskComplete : public Task {
[email protected]35fa6a22009-08-15 00:04:01337 public:
[email protected]191eb3f72010-12-21 06:27:50338 explicit InitTaskComplete(
339 const std::string& hardware_class,
340 const std::vector<webkit::npapi::WebPluginInfo>& plugins)
[email protected]85ed9d42010-06-08 22:37:44341 : hardware_class_(hardware_class), plugins_(plugins) {}
342
[email protected]7f2e792e2009-11-30 23:18:29343 virtual void Run() {
[email protected]85ed9d42010-06-08 22:37:44344 g_browser_process->metrics_service()->OnInitTaskComplete(
345 hardware_class_, plugins_);
initial.commit09911bf2008-07-26 23:55:29346 }
[email protected]35fa6a22009-08-15 00:04:01347
[email protected]7f2e792e2009-11-30 23:18:29348 private:
[email protected]85ed9d42010-06-08 22:37:44349 std::string hardware_class_;
[email protected]191eb3f72010-12-21 06:27:50350 std::vector<webkit::npapi::WebPluginInfo> plugins_;
initial.commit09911bf2008-07-26 23:55:29351};
352
[email protected]85ed9d42010-06-08 22:37:44353class MetricsService::InitTask : public Task {
[email protected]7f2e792e2009-11-30 23:18:29354 public:
[email protected]85ed9d42010-06-08 22:37:44355 explicit InitTask(MessageLoop* callback_loop)
[email protected]7f2e792e2009-11-30 23:18:29356 : callback_loop_(callback_loop) {}
357
358 virtual void Run() {
[email protected]191eb3f72010-12-21 06:27:50359 std::vector<webkit::npapi::WebPluginInfo> plugins;
360 webkit::npapi::PluginList::Singleton()->GetPlugins(false, &plugins);
[email protected]85ed9d42010-06-08 22:37:44361 std::string hardware_class; // Empty string by default.
362#if defined(OS_CHROMEOS)
[email protected]db342d52010-08-09 21:19:37363 chromeos::SystemLibrary* system_library =
[email protected]191eb3f72010-12-21 06:27:50364 chromeos::CrosLibrary::Get()->GetSystemLibrary();
[email protected]db342d52010-08-09 21:19:37365 system_library->GetMachineStatistic("hardware_class", &hardware_class);
[email protected]85ed9d42010-06-08 22:37:44366#endif // OS_CHROMEOS
367 callback_loop_->PostTask(FROM_HERE, new InitTaskComplete(
368 hardware_class, plugins));
[email protected]7f2e792e2009-11-30 23:18:29369 }
370
371 private:
372 MessageLoop* callback_loop_;
373};
[email protected]90d41372009-11-30 21:52:32374
initial.commit09911bf2008-07-26 23:55:29375// static
376void MetricsService::RegisterPrefs(PrefService* local_state) {
377 DCHECK(IsSingleThreaded());
[email protected]20ce516d2010-06-18 02:20:04378 local_state->RegisterStringPref(prefs::kMetricsClientID, "");
[email protected]0bb1a622009-03-04 03:22:32379 local_state->RegisterInt64Pref(prefs::kMetricsClientIDTimestamp, 0);
380 local_state->RegisterInt64Pref(prefs::kStabilityLaunchTimeSec, 0);
381 local_state->RegisterInt64Pref(prefs::kStabilityLastTimestampSec, 0);
[email protected]20ce516d2010-06-18 02:20:04382 local_state->RegisterStringPref(prefs::kStabilityStatsVersion, "");
[email protected]225c50842010-01-19 21:19:13383 local_state->RegisterInt64Pref(prefs::kStabilityStatsBuildTime, 0);
initial.commit09911bf2008-07-26 23:55:29384 local_state->RegisterBooleanPref(prefs::kStabilityExitedCleanly, true);
385 local_state->RegisterBooleanPref(prefs::kStabilitySessionEndCompleted, true);
386 local_state->RegisterIntegerPref(prefs::kMetricsSessionID, -1);
387 local_state->RegisterIntegerPref(prefs::kStabilityLaunchCount, 0);
388 local_state->RegisterIntegerPref(prefs::kStabilityCrashCount, 0);
389 local_state->RegisterIntegerPref(prefs::kStabilityIncompleteSessionEndCount,
390 0);
391 local_state->RegisterIntegerPref(prefs::kStabilityPageLoadCount, 0);
initial.commit09911bf2008-07-26 23:55:29392 local_state->RegisterIntegerPref(prefs::kStabilityRendererCrashCount, 0);
[email protected]1f085622009-12-04 05:33:45393 local_state->RegisterIntegerPref(prefs::kStabilityExtensionRendererCrashCount,
394 0);
initial.commit09911bf2008-07-26 23:55:29395 local_state->RegisterIntegerPref(prefs::kStabilityRendererHangCount, 0);
[email protected]1f085622009-12-04 05:33:45396 local_state->RegisterIntegerPref(prefs::kStabilityChildProcessCrashCount, 0);
[email protected]e73c01972008-08-13 00:18:24397 local_state->RegisterIntegerPref(prefs::kStabilityBreakpadRegistrationFail,
398 0);
399 local_state->RegisterIntegerPref(prefs::kStabilityBreakpadRegistrationSuccess,
400 0);
401 local_state->RegisterIntegerPref(prefs::kStabilityDebuggerPresent, 0);
402 local_state->RegisterIntegerPref(prefs::kStabilityDebuggerNotPresent, 0);
403
initial.commit09911bf2008-07-26 23:55:29404 local_state->RegisterDictionaryPref(prefs::kProfileMetrics);
405 local_state->RegisterIntegerPref(prefs::kNumBookmarksOnBookmarkBar, 0);
406 local_state->RegisterIntegerPref(prefs::kNumFoldersOnBookmarkBar, 0);
407 local_state->RegisterIntegerPref(prefs::kNumBookmarksInOtherBookmarkFolder,
408 0);
409 local_state->RegisterIntegerPref(prefs::kNumFoldersInOtherBookmarkFolder, 0);
410 local_state->RegisterIntegerPref(prefs::kNumKeywords, 0);
411 local_state->RegisterListPref(prefs::kMetricsInitialLogs);
412 local_state->RegisterListPref(prefs::kMetricsOngoingLogs);
[email protected]0bb1a622009-03-04 03:22:32413
414 local_state->RegisterInt64Pref(prefs::kUninstallMetricsPageLoadCount, 0);
415 local_state->RegisterInt64Pref(prefs::kUninstallLaunchCount, 0);
[email protected]6b5f21d2009-04-13 17:01:35416 local_state->RegisterInt64Pref(prefs::kUninstallMetricsInstallDate, 0);
[email protected]0bb1a622009-03-04 03:22:32417 local_state->RegisterInt64Pref(prefs::kUninstallMetricsUptimeSec, 0);
418 local_state->RegisterInt64Pref(prefs::kUninstallLastLaunchTimeSec, 0);
419 local_state->RegisterInt64Pref(prefs::kUninstallLastObservedRunTimeSec, 0);
initial.commit09911bf2008-07-26 23:55:29420}
421
[email protected]541f77922009-02-23 21:14:38422// static
423void MetricsService::DiscardOldStabilityStats(PrefService* local_state) {
424 local_state->SetBoolean(prefs::kStabilityExitedCleanly, true);
[email protected]c9abf242009-07-18 06:00:38425 local_state->SetBoolean(prefs::kStabilitySessionEndCompleted, true);
[email protected]541f77922009-02-23 21:14:38426
427 local_state->SetInteger(prefs::kStabilityIncompleteSessionEndCount, 0);
428 local_state->SetInteger(prefs::kStabilityBreakpadRegistrationSuccess, 0);
429 local_state->SetInteger(prefs::kStabilityBreakpadRegistrationFail, 0);
430 local_state->SetInteger(prefs::kStabilityDebuggerPresent, 0);
431 local_state->SetInteger(prefs::kStabilityDebuggerNotPresent, 0);
432
433 local_state->SetInteger(prefs::kStabilityLaunchCount, 0);
434 local_state->SetInteger(prefs::kStabilityCrashCount, 0);
435
436 local_state->SetInteger(prefs::kStabilityPageLoadCount, 0);
437 local_state->SetInteger(prefs::kStabilityRendererCrashCount, 0);
438 local_state->SetInteger(prefs::kStabilityRendererHangCount, 0);
439
[email protected]9165f742010-03-10 22:55:01440 local_state->SetInt64(prefs::kStabilityLaunchTimeSec, 0);
441 local_state->SetInt64(prefs::kStabilityLastTimestampSec, 0);
[email protected]541f77922009-02-23 21:14:38442
443 local_state->ClearPref(prefs::kStabilityPluginStats);
[email protected]ae155cb92009-06-19 06:10:37444
445 ListValue* unsent_initial_logs = local_state->GetMutableList(
446 prefs::kMetricsInitialLogs);
447 unsent_initial_logs->Clear();
448
449 ListValue* unsent_ongoing_logs = local_state->GetMutableList(
450 prefs::kMetricsOngoingLogs);
451 unsent_ongoing_logs->Clear();
[email protected]541f77922009-02-23 21:14:38452}
453
initial.commit09911bf2008-07-26 23:55:29454MetricsService::MetricsService()
[email protected]d01b8732008-10-16 02:18:07455 : recording_active_(false),
456 reporting_active_(false),
457 user_permits_upload_(false),
458 server_permits_upload_(true),
459 state_(INITIALIZED),
initial.commit09911bf2008-07-26 23:55:29460 current_fetch_(NULL),
[email protected]d01b8732008-10-16 02:18:07461 idle_since_last_transmission_(false),
initial.commit09911bf2008-07-26 23:55:29462 next_window_id_(0),
[email protected]40bcc302009-03-02 20:50:39463 ALLOW_THIS_IN_INITIALIZER_LIST(log_sender_factory_(this)),
464 ALLOW_THIS_IN_INITIALIZER_LIST(state_saver_factory_(this)),
[email protected]252873ef2008-08-04 21:59:45465 interlog_duration_(TimeDelta::FromSeconds(kInitialInterlogDuration)),
[email protected]d01b8732008-10-16 02:18:07466 log_event_limit_(kInitialEventLimit),
initial.commit09911bf2008-07-26 23:55:29467 timer_pending_(false) {
468 DCHECK(IsSingleThreaded());
469 InitializeMetricsState();
470}
471
472MetricsService::~MetricsService() {
473 SetRecording(false);
474}
475
[email protected]d01b8732008-10-16 02:18:07476void MetricsService::SetUserPermitsUpload(bool enabled) {
477 HandleIdleSinceLastTransmission(false);
478 user_permits_upload_ = enabled;
479}
480
481void MetricsService::Start() {
482 SetRecording(true);
483 SetReporting(true);
484}
485
486void MetricsService::StartRecordingOnly() {
487 SetRecording(true);
488 SetReporting(false);
489}
490
491void MetricsService::Stop() {
492 SetReporting(false);
493 SetRecording(false);
494}
495
initial.commit09911bf2008-07-26 23:55:29496void MetricsService::SetRecording(bool enabled) {
497 DCHECK(IsSingleThreaded());
498
[email protected]d01b8732008-10-16 02:18:07499 if (enabled == recording_active_)
initial.commit09911bf2008-07-26 23:55:29500 return;
501
502 if (enabled) {
[email protected]b0c819f2009-03-08 04:52:15503 if (client_id_.empty()) {
504 PrefService* pref = g_browser_process->local_state();
505 DCHECK(pref);
[email protected]ddd231e2010-06-29 20:35:19506 client_id_ = pref->GetString(prefs::kMetricsClientID);
[email protected]b0c819f2009-03-08 04:52:15507 if (client_id_.empty()) {
508 client_id_ = GenerateClientID();
[email protected]ddd231e2010-06-29 20:35:19509 pref->SetString(prefs::kMetricsClientID, client_id_);
[email protected]b0c819f2009-03-08 04:52:15510
511 // Might as well make a note of how long this ID has existed
512 pref->SetString(prefs::kMetricsClientIDTimestamp,
[email protected]528c56d2010-07-30 19:28:44513 base::Int64ToString(Time::Now().ToTimeT()));
[email protected]b0c819f2009-03-08 04:52:15514 }
515 }
[email protected]157d5472009-11-05 22:31:03516 child_process_logging::SetClientId(client_id_);
initial.commit09911bf2008-07-26 23:55:29517 StartRecording();
[email protected]005ef3e2009-05-22 20:55:46518
519 registrar_.Add(this, NotificationType::BROWSER_OPENED,
520 NotificationService::AllSources());
521 registrar_.Add(this, NotificationType::BROWSER_CLOSED,
522 NotificationService::AllSources());
523 registrar_.Add(this, NotificationType::USER_ACTION,
524 NotificationService::AllSources());
525 registrar_.Add(this, NotificationType::TAB_PARENTED,
526 NotificationService::AllSources());
527 registrar_.Add(this, NotificationType::TAB_CLOSING,
528 NotificationService::AllSources());
529 registrar_.Add(this, NotificationType::LOAD_START,
530 NotificationService::AllSources());
531 registrar_.Add(this, NotificationType::LOAD_STOP,
532 NotificationService::AllSources());
[email protected]cd69619b2010-05-05 02:41:38533 registrar_.Add(this, NotificationType::RENDERER_PROCESS_CLOSED,
[email protected]005ef3e2009-05-22 20:55:46534 NotificationService::AllSources());
535 registrar_.Add(this, NotificationType::RENDERER_PROCESS_HANG,
536 NotificationService::AllSources());
537 registrar_.Add(this, NotificationType::CHILD_PROCESS_HOST_CONNECTED,
538 NotificationService::AllSources());
539 registrar_.Add(this, NotificationType::CHILD_INSTANCE_CREATED,
540 NotificationService::AllSources());
541 registrar_.Add(this, NotificationType::CHILD_PROCESS_CRASHED,
542 NotificationService::AllSources());
543 registrar_.Add(this, NotificationType::TEMPLATE_URL_MODEL_LOADED,
544 NotificationService::AllSources());
545 registrar_.Add(this, NotificationType::OMNIBOX_OPENED_URL,
546 NotificationService::AllSources());
547 registrar_.Add(this, NotificationType::BOOKMARK_MODEL_LOADED,
548 NotificationService::AllSources());
initial.commit09911bf2008-07-26 23:55:29549 } else {
[email protected]005ef3e2009-05-22 20:55:46550 registrar_.RemoveAll();
initial.commit09911bf2008-07-26 23:55:29551 PushPendingLogsToUnsentLists();
552 DCHECK(!pending_log());
553 if (state_ > INITIAL_LOG_READY && unsent_logs())
554 state_ = SEND_OLD_INITIAL_LOGS;
555 }
[email protected]d01b8732008-10-16 02:18:07556 recording_active_ = enabled;
initial.commit09911bf2008-07-26 23:55:29557}
558
[email protected]d01b8732008-10-16 02:18:07559bool MetricsService::recording_active() const {
initial.commit09911bf2008-07-26 23:55:29560 DCHECK(IsSingleThreaded());
[email protected]d01b8732008-10-16 02:18:07561 return recording_active_;
initial.commit09911bf2008-07-26 23:55:29562}
563
[email protected]d01b8732008-10-16 02:18:07564void MetricsService::SetReporting(bool enable) {
565 if (reporting_active_ != enable) {
566 reporting_active_ = enable;
567 if (reporting_active_)
initial.commit09911bf2008-07-26 23:55:29568 StartLogTransmissionTimer();
569 }
[email protected]d01b8732008-10-16 02:18:07570}
571
572bool MetricsService::reporting_active() const {
573 DCHECK(IsSingleThreaded());
574 return reporting_active_;
initial.commit09911bf2008-07-26 23:55:29575}
576
577void MetricsService::Observe(NotificationType type,
578 const NotificationSource& source,
579 const NotificationDetails& details) {
580 DCHECK(current_log_);
581 DCHECK(IsSingleThreaded());
582
583 if (!CanLogNotification(type, source, details))
584 return;
585
[email protected]bfd04a62009-02-01 18:16:56586 switch (type.value) {
587 case NotificationType::USER_ACTION:
[email protected]afe3a1672009-11-17 19:04:12588 current_log_->RecordUserAction(*Details<const char*>(details).ptr());
initial.commit09911bf2008-07-26 23:55:29589 break;
590
[email protected]bfd04a62009-02-01 18:16:56591 case NotificationType::BROWSER_OPENED:
592 case NotificationType::BROWSER_CLOSED:
initial.commit09911bf2008-07-26 23:55:29593 LogWindowChange(type, source, details);
594 break;
595
[email protected]bfd04a62009-02-01 18:16:56596 case NotificationType::TAB_PARENTED:
597 case NotificationType::TAB_CLOSING:
initial.commit09911bf2008-07-26 23:55:29598 LogWindowChange(type, source, details);
599 break;
600
[email protected]bfd04a62009-02-01 18:16:56601 case NotificationType::LOAD_STOP:
initial.commit09911bf2008-07-26 23:55:29602 LogLoadComplete(type, source, details);
603 break;
604
[email protected]bfd04a62009-02-01 18:16:56605 case NotificationType::LOAD_START:
initial.commit09911bf2008-07-26 23:55:29606 LogLoadStarted();
607 break;
608
[email protected]443b80e2010-12-14 00:42:23609 case NotificationType::RENDERER_PROCESS_CLOSED: {
[email protected]cd69619b2010-05-05 02:41:38610 RenderProcessHost::RendererClosedDetails* process_details =
611 Details<RenderProcessHost::RendererClosedDetails>(details).ptr();
[email protected]443b80e2010-12-14 00:42:23612 if (process_details->status ==
613 base::TERMINATION_STATUS_PROCESS_CRASHED ||
614 process_details->status ==
615 base::TERMINATION_STATUS_ABNORMAL_TERMINATION) {
[email protected]cd69619b2010-05-05 02:41:38616 if (process_details->was_extension_renderer) {
617 LogExtensionRendererCrash();
618 } else {
619 LogRendererCrash();
620 }
621 }
[email protected]1f085622009-12-04 05:33:45622 }
initial.commit09911bf2008-07-26 23:55:29623 break;
624
[email protected]bfd04a62009-02-01 18:16:56625 case NotificationType::RENDERER_PROCESS_HANG:
initial.commit09911bf2008-07-26 23:55:29626 LogRendererHang();
627 break;
628
[email protected]a27a9382009-02-11 23:55:10629 case NotificationType::CHILD_PROCESS_HOST_CONNECTED:
630 case NotificationType::CHILD_PROCESS_CRASHED:
631 case NotificationType::CHILD_INSTANCE_CREATED:
632 LogChildProcessChange(type, source, details);
initial.commit09911bf2008-07-26 23:55:29633 break;
634
[email protected]bfd04a62009-02-01 18:16:56635 case NotificationType::TEMPLATE_URL_MODEL_LOADED:
initial.commit09911bf2008-07-26 23:55:29636 LogKeywords(Source<TemplateURLModel>(source).ptr());
637 break;
638
[email protected]1226abb2010-06-10 18:01:28639 case NotificationType::OMNIBOX_OPENED_URL: {
640 MetricsLog* current_log = current_log_->AsMetricsLog();
641 DCHECK(current_log);
642 current_log->RecordOmniboxOpenedURL(
initial.commit09911bf2008-07-26 23:55:29643 *Details<AutocompleteLog>(details).ptr());
644 break;
[email protected]1226abb2010-06-10 18:01:28645 }
initial.commit09911bf2008-07-26 23:55:29646
[email protected]b61236c62009-04-09 22:43:55647 case NotificationType::BOOKMARK_MODEL_LOADED: {
648 Profile* p = Source<Profile>(source).ptr();
649 if (p)
650 LogBookmarks(p->GetBookmarkModel());
initial.commit09911bf2008-07-26 23:55:29651 break;
[email protected]b61236c62009-04-09 22:43:55652 }
initial.commit09911bf2008-07-26 23:55:29653 default:
[email protected]a063c102010-07-22 22:20:19654 NOTREACHED();
initial.commit09911bf2008-07-26 23:55:29655 break;
656 }
[email protected]d01b8732008-10-16 02:18:07657
658 HandleIdleSinceLastTransmission(false);
659
660 if (current_log_)
[email protected]666205032010-10-21 20:56:58661 DVLOG(1) << "METRICS: NUMBER OF EVENTS = " << current_log_->num_events();
[email protected]d01b8732008-10-16 02:18:07662}
663
664void MetricsService::HandleIdleSinceLastTransmission(bool in_idle) {
665 // If there wasn't a lot of action, maybe the computer was asleep, in which
666 // case, the log transmissions should have stopped. Here we start them up
667 // again.
[email protected]cac78842008-11-27 01:02:20668 if (!in_idle && idle_since_last_transmission_)
669 StartLogTransmissionTimer();
670 idle_since_last_transmission_ = in_idle;
initial.commit09911bf2008-07-26 23:55:29671}
672
673void MetricsService::RecordCleanShutdown() {
674 RecordBooleanPrefValue(prefs::kStabilityExitedCleanly, true);
675}
676
677void MetricsService::RecordStartOfSessionEnd() {
678 RecordBooleanPrefValue(prefs::kStabilitySessionEndCompleted, false);
679}
680
681void MetricsService::RecordCompletedSessionEnd() {
682 RecordBooleanPrefValue(prefs::kStabilitySessionEndCompleted, true);
683}
684
[email protected]e73c01972008-08-13 00:18:24685void MetricsService:: RecordBreakpadRegistration(bool success) {
[email protected]68475e602008-08-22 03:21:15686 if (!success)
[email protected]e73c01972008-08-13 00:18:24687 IncrementPrefValue(prefs::kStabilityBreakpadRegistrationFail);
688 else
689 IncrementPrefValue(prefs::kStabilityBreakpadRegistrationSuccess);
690}
691
692void MetricsService::RecordBreakpadHasDebugger(bool has_debugger) {
693 if (!has_debugger)
694 IncrementPrefValue(prefs::kStabilityDebuggerNotPresent);
695 else
[email protected]68475e602008-08-22 03:21:15696 IncrementPrefValue(prefs::kStabilityDebuggerPresent);
[email protected]e73c01972008-08-13 00:18:24697}
698
initial.commit09911bf2008-07-26 23:55:29699//------------------------------------------------------------------------------
700// private methods
701//------------------------------------------------------------------------------
702
703
704//------------------------------------------------------------------------------
705// Initialization methods
706
707void MetricsService::InitializeMetricsState() {
[email protected]79bf0b72009-04-27 21:30:55708#if defined(OS_POSIX)
709 server_url_ = L"https://clients4.google.com/firefox/metrics/collect";
710#else
711 BrowserDistribution* dist = BrowserDistribution::GetDistribution();
712 server_url_ = dist->GetStatsServerURL();
713#endif
714
initial.commit09911bf2008-07-26 23:55:29715 PrefService* pref = g_browser_process->local_state();
716 DCHECK(pref);
717
[email protected]225c50842010-01-19 21:19:13718 if ((pref->GetInt64(prefs::kStabilityStatsBuildTime)
719 != MetricsLog::GetBuildTime()) ||
[email protected]ddd231e2010-06-29 20:35:19720 (pref->GetString(prefs::kStabilityStatsVersion)
[email protected]225c50842010-01-19 21:19:13721 != MetricsLog::GetVersionString())) {
[email protected]541f77922009-02-23 21:14:38722 // This is a new version, so we don't want to confuse the stats about the
723 // old version with info that we upload.
724 DiscardOldStabilityStats(pref);
725 pref->SetString(prefs::kStabilityStatsVersion,
[email protected]ddd231e2010-06-29 20:35:19726 MetricsLog::GetVersionString());
[email protected]225c50842010-01-19 21:19:13727 pref->SetInt64(prefs::kStabilityStatsBuildTime,
728 MetricsLog::GetBuildTime());
[email protected]541f77922009-02-23 21:14:38729 }
730
initial.commit09911bf2008-07-26 23:55:29731 // Update session ID
732 session_id_ = pref->GetInteger(prefs::kMetricsSessionID);
733 ++session_id_;
734 pref->SetInteger(prefs::kMetricsSessionID, session_id_);
735
initial.commit09911bf2008-07-26 23:55:29736 // Stability bookkeeping
[email protected]e73c01972008-08-13 00:18:24737 IncrementPrefValue(prefs::kStabilityLaunchCount);
initial.commit09911bf2008-07-26 23:55:29738
[email protected]e73c01972008-08-13 00:18:24739 if (!pref->GetBoolean(prefs::kStabilityExitedCleanly)) {
740 IncrementPrefValue(prefs::kStabilityCrashCount);
initial.commit09911bf2008-07-26 23:55:29741 }
[email protected]e73c01972008-08-13 00:18:24742
743 // This will be set to 'true' if we exit cleanly.
initial.commit09911bf2008-07-26 23:55:29744 pref->SetBoolean(prefs::kStabilityExitedCleanly, false);
745
[email protected]e73c01972008-08-13 00:18:24746 if (!pref->GetBoolean(prefs::kStabilitySessionEndCompleted)) {
747 IncrementPrefValue(prefs::kStabilityIncompleteSessionEndCount);
[email protected]c9abf242009-07-18 06:00:38748 // This is marked false when we get a WM_ENDSESSION.
749 pref->SetBoolean(prefs::kStabilitySessionEndCompleted, true);
initial.commit09911bf2008-07-26 23:55:29750 }
initial.commit09911bf2008-07-26 23:55:29751
[email protected]9165f742010-03-10 22:55:01752 // Initialize uptime counters.
753 int64 startup_uptime = MetricsLog::GetIncrementalUptime(pref);
[email protected]ae393ec702010-06-27 16:23:14754 DCHECK_EQ(0, startup_uptime);
[email protected]9165f742010-03-10 22:55:01755 // For backwards compatibility, leave this intact in case Omaha is checking
756 // them. prefs::kStabilityLastTimestampSec may also be useless now.
757 // TODO(jar): Delete these if they have no uses.
[email protected]0bb1a622009-03-04 03:22:32758 pref->SetInt64(prefs::kStabilityLaunchTimeSec, Time::Now().ToTimeT());
759
760 // Bookkeeping for the uninstall metrics.
761 IncrementLongPrefsValue(prefs::kUninstallLaunchCount);
initial.commit09911bf2008-07-26 23:55:29762
763 // Save profile metrics.
764 PrefService* prefs = g_browser_process->local_state();
765 if (prefs) {
766 // Remove the current dictionary and store it for use when sending data to
767 // server. By removing the value we prune potentially dead profiles
768 // (and keys). All valid values are added back once services startup.
769 const DictionaryValue* profile_dictionary =
770 prefs->GetDictionary(prefs::kProfileMetrics);
771 if (profile_dictionary) {
772 // Do a deep copy of profile_dictionary since ClearPref will delete it.
773 profile_dictionary_.reset(static_cast<DictionaryValue*>(
774 profile_dictionary->DeepCopy()));
775 prefs->ClearPref(prefs::kProfileMetrics);
776 }
777 }
778
[email protected]92745242009-06-12 16:52:21779 // Get stats on use of command line.
780 const CommandLine* command_line(CommandLine::ForCurrentProcess());
781 size_t common_commands = 0;
782 if (command_line->HasSwitch(switches::kUserDataDir)) {
783 ++common_commands;
784 UMA_HISTOGRAM_COUNTS_100("Chrome.CommandLineDatDirCount", 1);
785 }
786
787 if (command_line->HasSwitch(switches::kApp)) {
788 ++common_commands;
789 UMA_HISTOGRAM_COUNTS_100("Chrome.CommandLineAppModeCount", 1);
790 }
791
792 UMA_HISTOGRAM_COUNTS_100("Chrome.CommandLineFlagCount",
793 command_line->GetSwitchCount());
794 UMA_HISTOGRAM_COUNTS_100("Chrome.CommandLineUncommonFlagCount",
795 command_line->GetSwitchCount() - common_commands);
796
initial.commit09911bf2008-07-26 23:55:29797 // Kick off the process of saving the state (so the uptime numbers keep
798 // getting updated) every n minutes.
799 ScheduleNextStateSave();
800}
801
[email protected]85ed9d42010-06-08 22:37:44802void MetricsService::OnInitTaskComplete(
803 const std::string& hardware_class,
[email protected]191eb3f72010-12-21 06:27:50804 const std::vector<webkit::npapi::WebPluginInfo>& plugins) {
[email protected]85ed9d42010-06-08 22:37:44805 DCHECK(state_ == INIT_TASK_SCHEDULED);
806 hardware_class_ = hardware_class;
[email protected]35fa6a22009-08-15 00:04:01807 plugins_ = plugins;
[email protected]85ed9d42010-06-08 22:37:44808 if (state_ == INIT_TASK_SCHEDULED)
809 state_ = INIT_TASK_DONE;
initial.commit09911bf2008-07-26 23:55:29810}
811
812std::string MetricsService::GenerateClientID() {
[email protected]3469e7e2010-10-14 20:34:59813 return guid::GenerateGUID();
initial.commit09911bf2008-07-26 23:55:29814}
815
initial.commit09911bf2008-07-26 23:55:29816//------------------------------------------------------------------------------
817// State save methods
818
819void MetricsService::ScheduleNextStateSave() {
820 state_saver_factory_.RevokeAll();
821
822 MessageLoop::current()->PostDelayedTask(FROM_HERE,
823 state_saver_factory_.NewRunnableMethod(&MetricsService::SaveLocalState),
824 kSaveStateInterval * 1000);
825}
826
827void MetricsService::SaveLocalState() {
828 PrefService* pref = g_browser_process->local_state();
829 if (!pref) {
[email protected]a063c102010-07-22 22:20:19830 NOTREACHED();
initial.commit09911bf2008-07-26 23:55:29831 return;
832 }
833
834 RecordCurrentState(pref);
[email protected]6faa0e0d2009-04-28 06:50:36835 pref->ScheduleSavePersistentPrefs();
initial.commit09911bf2008-07-26 23:55:29836
[email protected]281d2882009-01-20 20:32:42837 // TODO(jar): Does this run down the batteries????
initial.commit09911bf2008-07-26 23:55:29838 ScheduleNextStateSave();
839}
840
841
842//------------------------------------------------------------------------------
843// Recording control methods
844
845void MetricsService::StartRecording() {
846 if (current_log_)
847 return;
848
849 current_log_ = new MetricsLog(client_id_, session_id_);
850 if (state_ == INITIALIZED) {
851 // We only need to schedule that run once.
[email protected]85ed9d42010-06-08 22:37:44852 state_ = INIT_TASK_SCHEDULED;
initial.commit09911bf2008-07-26 23:55:29853
[email protected]85ed9d42010-06-08 22:37:44854 // Schedules a task on the file thread for execution of slower
855 // initialization steps (such as plugin list generation) necessary
856 // for sending the initial log. This avoids blocking the main UI
857 // thread.
[email protected]7f2e792e2009-11-30 23:18:29858 g_browser_process->file_thread()->message_loop()->PostDelayedTask(FROM_HERE,
[email protected]85ed9d42010-06-08 22:37:44859 new InitTask(MessageLoop::current()),
[email protected]252873ef2008-08-04 21:59:45860 kInitialInterlogDuration * 1000 / 2);
initial.commit09911bf2008-07-26 23:55:29861 }
862}
863
[email protected]1226abb2010-06-10 18:01:28864void MetricsService::StopRecording(MetricsLogBase** log) {
initial.commit09911bf2008-07-26 23:55:29865 if (!current_log_)
866 return;
867
[email protected]1226abb2010-06-10 18:01:28868 MetricsLog* current_log = current_log_->AsMetricsLog();
869 DCHECK(current_log);
870 current_log->set_hardware_class(hardware_class_); // Adds to ongoing logs.
[email protected]85ed9d42010-06-08 22:37:44871
[email protected]68475e602008-08-22 03:21:15872 // TODO(jar): Integrate bounds on log recording more consistently, so that we
873 // can stop recording logs that are too big much sooner.
[email protected]d01b8732008-10-16 02:18:07874 if (current_log_->num_events() > log_event_limit_) {
[email protected]553dba62009-02-24 19:08:23875 UMA_HISTOGRAM_COUNTS("UMA.Discarded Log Events",
[email protected]68475e602008-08-22 03:21:15876 current_log_->num_events());
877 current_log_->CloseLog();
878 delete current_log_;
[email protected]294638782008-09-24 00:22:41879 current_log_ = NULL;
[email protected]68475e602008-08-22 03:21:15880 StartRecording(); // Start trivial log to hold our histograms.
881 }
882
[email protected]0b33f80b2008-12-17 21:34:36883 // Put incremental data (histogram deltas, and realtime stats deltas) at the
[email protected]147bbc0b2009-01-06 19:37:40884 // end of all log transmissions (initial log handles this separately).
initial.commit09911bf2008-07-26 23:55:29885 // Don't bother if we're going to discard current_log_.
[email protected]0b33f80b2008-12-17 21:34:36886 if (log) {
[email protected]1226abb2010-06-10 18:01:28887 current_log->RecordIncrementalStabilityElements();
initial.commit09911bf2008-07-26 23:55:29888 RecordCurrentHistograms();
[email protected]0b33f80b2008-12-17 21:34:36889 }
initial.commit09911bf2008-07-26 23:55:29890
891 current_log_->CloseLog();
[email protected]cac78842008-11-27 01:02:20892 if (log)
[email protected]1226abb2010-06-10 18:01:28893 *log = current_log;
[email protected]cac78842008-11-27 01:02:20894 else
initial.commit09911bf2008-07-26 23:55:29895 delete current_log_;
initial.commit09911bf2008-07-26 23:55:29896 current_log_ = NULL;
897}
898
initial.commit09911bf2008-07-26 23:55:29899void MetricsService::PushPendingLogsToUnsentLists() {
900 if (state_ < INITIAL_LOG_READY)
[email protected]28ab7f92009-01-06 21:39:04901 return; // We didn't and still don't have time to get plugin list etc.
initial.commit09911bf2008-07-26 23:55:29902
903 if (pending_log()) {
904 PreparePendingLogText();
905 if (state_ == INITIAL_LOG_READY) {
906 // We may race here, and send second copy of initial log later.
[email protected]46f89e142010-07-19 08:00:42907 unsent_initial_logs_.push_back(compressed_log_);
[email protected]d01b8732008-10-16 02:18:07908 state_ = SEND_OLD_INITIAL_LOGS;
initial.commit09911bf2008-07-26 23:55:29909 } else {
[email protected]281d2882009-01-20 20:32:42910 // TODO(jar): Verify correctness in other states, including sending unsent
[email protected]541f77922009-02-23 21:14:38911 // initial logs.
[email protected]68475e602008-08-22 03:21:15912 PushPendingLogTextToUnsentOngoingLogs();
initial.commit09911bf2008-07-26 23:55:29913 }
914 DiscardPendingLog();
915 }
916 DCHECK(!pending_log());
917 StopRecording(&pending_log_);
918 PreparePendingLogText();
[email protected]68475e602008-08-22 03:21:15919 PushPendingLogTextToUnsentOngoingLogs();
initial.commit09911bf2008-07-26 23:55:29920 DiscardPendingLog();
921 StoreUnsentLogs();
922}
923
[email protected]68475e602008-08-22 03:21:15924void MetricsService::PushPendingLogTextToUnsentOngoingLogs() {
[email protected]d01b8732008-10-16 02:18:07925 // If UMA response told us not to upload, there's no need to save the pending
926 // log. It wasn't supposed to be uploaded anyway.
927 if (!server_permits_upload_)
928 return;
[email protected]46f89e142010-07-19 08:00:42929 if (compressed_log_.length() >
[email protected]dc6f4962009-02-13 01:25:50930 static_cast<size_t>(kUploadLogAvoidRetransmitSize)) {
[email protected]553dba62009-02-24 19:08:23931 UMA_HISTOGRAM_COUNTS("UMA.Large Accumulated Log Not Persisted",
[email protected]46f89e142010-07-19 08:00:42932 static_cast<int>(compressed_log_.length()));
[email protected]68475e602008-08-22 03:21:15933 return;
934 }
[email protected]46f89e142010-07-19 08:00:42935 unsent_ongoing_logs_.push_back(compressed_log_);
[email protected]68475e602008-08-22 03:21:15936}
937
initial.commit09911bf2008-07-26 23:55:29938//------------------------------------------------------------------------------
939// Transmission of logs methods
940
941void MetricsService::StartLogTransmissionTimer() {
[email protected]d01b8732008-10-16 02:18:07942 // If we're not reporting, there's no point in starting a log transmission
943 // timer.
944 if (!reporting_active())
945 return;
946
initial.commit09911bf2008-07-26 23:55:29947 if (!current_log_)
948 return; // Recorder is shutdown.
[email protected]d01b8732008-10-16 02:18:07949
950 // If there is already a timer running, we leave it running.
951 // If timer_pending is true because the fetch is waiting for a response,
952 // we return for now and let the response handler start the timer.
953 if (timer_pending_)
initial.commit09911bf2008-07-26 23:55:29954 return;
[email protected]d01b8732008-10-16 02:18:07955
[email protected]d01b8732008-10-16 02:18:07956 // Before starting the timer, set timer_pending_ to true.
initial.commit09911bf2008-07-26 23:55:29957 timer_pending_ = true;
[email protected]d01b8732008-10-16 02:18:07958
959 // Right before the UMA transmission gets started, there's one more thing we'd
960 // like to record: the histogram of memory usage, so we spawn a task to
[email protected]c9a3ef82009-05-28 22:02:46961 // collect the memory details and when that task is finished, it will call
962 // OnMemoryDetailCollectionDone, which will call HistogramSynchronization to
963 // collect histograms from all renderers and then we will call
964 // OnHistogramSynchronizationDone to continue processing.
initial.commit09911bf2008-07-26 23:55:29965 MessageLoop::current()->PostDelayedTask(FROM_HERE,
966 log_sender_factory_.
[email protected]c9a3ef82009-05-28 22:02:46967 NewRunnableMethod(&MetricsService::LogTransmissionTimerDone),
[email protected]743ace42009-06-17 17:23:51968 interlog_duration_.InMilliseconds());
initial.commit09911bf2008-07-26 23:55:29969}
970
[email protected]c9a3ef82009-05-28 22:02:46971void MetricsService::LogTransmissionTimerDone() {
972 Task* task = log_sender_factory_.
973 NewRunnableMethod(&MetricsService::OnMemoryDetailCollectionDone);
974
[email protected]ad8e04a2010-11-01 04:16:27975 scoped_refptr<MetricsMemoryDetails> details(new MetricsMemoryDetails(task));
[email protected]c9a3ef82009-05-28 22:02:46976 details->StartFetch();
977
978 // Collect WebCore cache information to put into a histogram.
[email protected]019191a2009-10-02 20:37:27979 for (RenderProcessHost::iterator i(RenderProcessHost::AllHostsIterator());
980 !i.IsAtEnd(); i.Advance())
981 i.GetCurrentValue()->Send(new ViewMsg_GetCacheResourceStats());
[email protected]c9a3ef82009-05-28 22:02:46982}
983
984void MetricsService::OnMemoryDetailCollectionDone() {
985 DCHECK(IsSingleThreaded());
986
987 // HistogramSynchronizer will Collect histograms from all renderers and it
988 // will call OnHistogramSynchronizationDone (if wait time elapses before it
989 // heard from all renderers, then also it will call
990 // OnHistogramSynchronizationDone).
991
992 // Create a callback_task for OnHistogramSynchronizationDone.
993 Task* callback_task = log_sender_factory_.NewRunnableMethod(
994 &MetricsService::OnHistogramSynchronizationDone);
995
996 // Set up the callback to task to call after we receive histograms from all
997 // renderer processes. Wait time specifies how long to wait before absolutely
998 // calling us back on the task.
999 HistogramSynchronizer::FetchRendererHistogramsAsynchronously(
1000 MessageLoop::current(), callback_task,
1001 kMaxHistogramGatheringWaitDuration);
1002}
1003
1004void MetricsService::OnHistogramSynchronizationDone() {
initial.commit09911bf2008-07-26 23:55:291005 DCHECK(IsSingleThreaded());
1006
[email protected]d01b8732008-10-16 02:18:071007 // This function should only be called via timer, so timer_pending_
1008 // should be true.
1009 DCHECK(timer_pending_);
1010 timer_pending_ = false;
initial.commit09911bf2008-07-26 23:55:291011
1012 DCHECK(!current_fetch_.get());
initial.commit09911bf2008-07-26 23:55:291013
[email protected]d01b8732008-10-16 02:18:071014 // If we're getting no notifications, then the log won't have much in it, and
1015 // it's possible the computer is about to go to sleep, so don't upload and
1016 // don't restart the transmission timer.
1017 if (idle_since_last_transmission_)
1018 return;
1019
1020 // If somehow there is a fetch in progress, we return setting timer_pending_
1021 // to true and hope things work out.
1022 if (current_fetch_.get()) {
1023 timer_pending_ = true;
1024 return;
1025 }
1026
1027 // If uploads are forbidden by UMA response, there's no point in keeping
1028 // the current_log_, and the more often we delete it, the less likely it is
1029 // to expand forever.
1030 if (!server_permits_upload_ && current_log_) {
1031 StopRecording(NULL);
1032 StartRecording();
1033 }
initial.commit09911bf2008-07-26 23:55:291034
1035 if (!current_log_)
1036 return; // Logging was disabled.
[email protected]d01b8732008-10-16 02:18:071037 if (!reporting_active())
initial.commit09911bf2008-07-26 23:55:291038 return; // Don't do work if we're not going to send anything now.
1039
[email protected]d01b8732008-10-16 02:18:071040 MakePendingLog();
initial.commit09911bf2008-07-26 23:55:291041
[email protected]d01b8732008-10-16 02:18:071042 // MakePendingLog should have put something in the pending log, if it didn't,
1043 // we start the timer again, return and hope things work out.
1044 if (!pending_log()) {
1045 StartLogTransmissionTimer();
1046 return;
1047 }
initial.commit09911bf2008-07-26 23:55:291048
[email protected]d01b8732008-10-16 02:18:071049 // If we're not supposed to upload any UMA data because the response or the
1050 // user said so, cancel the upload at this point, but start the timer.
1051 if (!TransmissionPermitted()) {
1052 DiscardPendingLog();
1053 StartLogTransmissionTimer();
1054 return;
1055 }
initial.commit09911bf2008-07-26 23:55:291056
[email protected]d01b8732008-10-16 02:18:071057 PrepareFetchWithPendingLog();
1058
1059 if (!current_fetch_.get()) {
1060 // Compression failed, and log discarded :-/.
1061 DiscardPendingLog();
1062 StartLogTransmissionTimer(); // Maybe we'll do better next time
1063 // TODO(jar): If compression failed, we should have created a tiny log and
1064 // compressed that, so that we can signal that we're losing logs.
1065 return;
1066 }
1067
1068 DCHECK(!timer_pending_);
1069
1070 // The URL fetch is a like timer in that after a while we get called back
1071 // so we set timer_pending_ true just as we start the url fetch.
1072 timer_pending_ = true;
1073 current_fetch_->Start();
1074
1075 HandleIdleSinceLastTransmission(true);
1076}
1077
1078
1079void MetricsService::MakePendingLog() {
1080 if (pending_log())
1081 return;
1082
1083 switch (state_) {
1084 case INITIALIZED:
[email protected]85ed9d42010-06-08 22:37:441085 case INIT_TASK_SCHEDULED: // We should be further along by now.
[email protected]d01b8732008-10-16 02:18:071086 DCHECK(false);
1087 return;
1088
[email protected]85ed9d42010-06-08 22:37:441089 case INIT_TASK_DONE:
[email protected]d01b8732008-10-16 02:18:071090 // We need to wait for the initial log to be ready before sending
1091 // anything, because the server will tell us whether it wants to hear
1092 // from us.
1093 PrepareInitialLog();
[email protected]85ed9d42010-06-08 22:37:441094 DCHECK(state_ == INIT_TASK_DONE);
[email protected]d01b8732008-10-16 02:18:071095 RecallUnsentLogs();
1096 state_ = INITIAL_LOG_READY;
1097 break;
1098
1099 case SEND_OLD_INITIAL_LOGS:
[email protected]cac78842008-11-27 01:02:201100 if (!unsent_initial_logs_.empty()) {
[email protected]46f89e142010-07-19 08:00:421101 compressed_log_ = unsent_initial_logs_.back();
[email protected]cac78842008-11-27 01:02:201102 break;
1103 }
[email protected]d01b8732008-10-16 02:18:071104 state_ = SENDING_OLD_LOGS;
1105 // Fall through.
initial.commit09911bf2008-07-26 23:55:291106
[email protected]d01b8732008-10-16 02:18:071107 case SENDING_OLD_LOGS:
1108 if (!unsent_ongoing_logs_.empty()) {
[email protected]46f89e142010-07-19 08:00:421109 compressed_log_ = unsent_ongoing_logs_.back();
[email protected]d01b8732008-10-16 02:18:071110 break;
1111 }
1112 state_ = SENDING_CURRENT_LOGS;
1113 // Fall through.
1114
1115 case SENDING_CURRENT_LOGS:
1116 StopRecording(&pending_log_);
1117 StartRecording();
1118 break;
1119
1120 default:
[email protected]a063c102010-07-22 22:20:191121 NOTREACHED();
[email protected]d01b8732008-10-16 02:18:071122 return;
1123 }
1124
1125 DCHECK(pending_log());
1126}
1127
1128bool MetricsService::TransmissionPermitted() const {
1129 // If the user forbids uploading that's they're business, and we don't upload
1130 // anything. If the server forbids uploading, that's our business, so we take
1131 // that to mean it forbids current logs, but we still send up the inital logs
1132 // and any old logs.
[email protected]d01b8732008-10-16 02:18:071133 if (!user_permits_upload_)
1134 return false;
[email protected]cac78842008-11-27 01:02:201135 if (server_permits_upload_)
[email protected]d01b8732008-10-16 02:18:071136 return true;
initial.commit09911bf2008-07-26 23:55:291137
[email protected]cac78842008-11-27 01:02:201138 switch (state_) {
1139 case INITIAL_LOG_READY:
1140 case SEND_OLD_INITIAL_LOGS:
1141 case SENDING_OLD_LOGS:
1142 return true;
1143
1144 case SENDING_CURRENT_LOGS:
1145 default:
1146 return false;
[email protected]8c8824b2008-09-20 01:55:501147 }
initial.commit09911bf2008-07-26 23:55:291148}
1149
initial.commit09911bf2008-07-26 23:55:291150void MetricsService::PrepareInitialLog() {
[email protected]85ed9d42010-06-08 22:37:441151 DCHECK(state_ == INIT_TASK_DONE);
initial.commit09911bf2008-07-26 23:55:291152
1153 MetricsLog* log = new MetricsLog(client_id_, session_id_);
[email protected]85ed9d42010-06-08 22:37:441154 log->set_hardware_class(hardware_class_); // Adds to initial log.
[email protected]35fa6a22009-08-15 00:04:011155 log->RecordEnvironment(plugins_, profile_dictionary_.get());
initial.commit09911bf2008-07-26 23:55:291156
1157 // Histograms only get written to current_log_, so setup for the write.
[email protected]1226abb2010-06-10 18:01:281158 MetricsLogBase* save_log = current_log_;
initial.commit09911bf2008-07-26 23:55:291159 current_log_ = log;
1160 RecordCurrentHistograms(); // Into current_log_... which is really log.
1161 current_log_ = save_log;
1162
1163 log->CloseLog();
1164 DCHECK(!pending_log());
1165 pending_log_ = log;
1166}
1167
[email protected]46f89e142010-07-19 08:00:421168// static
1169MetricsService::LogRecallStatus MetricsService::RecallUnsentLogsHelper(
1170 const ListValue& list,
1171 std::vector<std::string>* local_list) {
1172 DCHECK(local_list->empty());
1173 if (list.GetSize() == 0)
1174 return MakeRecallStatusHistogram(LIST_EMPTY);
1175 if (list.GetSize() < 3)
1176 return MakeRecallStatusHistogram(LIST_SIZE_TOO_SMALL);
initial.commit09911bf2008-07-26 23:55:291177
[email protected]46f89e142010-07-19 08:00:421178 // The size is stored at the beginning of the list.
1179 int size;
1180 bool valid = (*list.begin())->GetAsInteger(&size);
1181 if (!valid)
1182 return MakeRecallStatusHistogram(LIST_SIZE_MISSING);
1183
1184 // Account for checksum and size included in the list.
1185 if (static_cast<unsigned int>(size) !=
1186 list.GetSize() - kChecksumEntryCount)
1187 return MakeRecallStatusHistogram(LIST_SIZE_CORRUPTION);
1188
1189 MD5Context ctx;
1190 MD5Init(&ctx);
1191 std::string encoded_log;
1192 std::string decoded_log;
1193 for (ListValue::const_iterator it = list.begin() + 1;
1194 it != list.end() - 1; ++it) { // Last element is the checksum.
1195 valid = (*it)->GetAsString(&encoded_log);
1196 if (!valid) {
1197 local_list->clear();
1198 return MakeRecallStatusHistogram(LOG_STRING_CORRUPTION);
1199 }
1200
1201 MD5Update(&ctx, encoded_log.data(), encoded_log.length());
1202
1203 if (!base::Base64Decode(encoded_log, &decoded_log)) {
1204 local_list->clear();
1205 return MakeRecallStatusHistogram(DECODE_FAIL);
1206 }
1207 local_list->push_back(decoded_log);
1208 }
1209
1210 // Verify checksum.
1211 MD5Digest digest;
1212 MD5Final(&digest, &ctx);
1213 std::string recovered_md5;
1214 // We store the hash at the end of the list.
1215 valid = (*(list.end() - 1))->GetAsString(&recovered_md5);
1216 if (!valid) {
1217 local_list->clear();
1218 return MakeRecallStatusHistogram(CHECKSUM_STRING_CORRUPTION);
1219 }
1220 if (recovered_md5 != MD5DigestToBase16(digest)) {
1221 local_list->clear();
1222 return MakeRecallStatusHistogram(CHECKSUM_CORRUPTION);
1223 }
1224 return MakeRecallStatusHistogram(RECALL_SUCCESS);
1225}
1226void MetricsService::RecallUnsentLogs() {
initial.commit09911bf2008-07-26 23:55:291227 PrefService* local_state = g_browser_process->local_state();
1228 DCHECK(local_state);
1229
1230 ListValue* unsent_initial_logs = local_state->GetMutableList(
1231 prefs::kMetricsInitialLogs);
[email protected]46f89e142010-07-19 08:00:421232 RecallUnsentLogsHelper(*unsent_initial_logs, &unsent_initial_logs_);
initial.commit09911bf2008-07-26 23:55:291233
1234 ListValue* unsent_ongoing_logs = local_state->GetMutableList(
1235 prefs::kMetricsOngoingLogs);
[email protected]46f89e142010-07-19 08:00:421236 RecallUnsentLogsHelper(*unsent_ongoing_logs, &unsent_ongoing_logs_);
1237}
1238
1239// static
1240void MetricsService::StoreUnsentLogsHelper(
1241 const std::vector<std::string>& local_list,
1242 const size_t kMaxLocalListSize,
1243 ListValue* list) {
1244 list->Clear();
1245 size_t start = 0;
1246 if (local_list.size() > kMaxLocalListSize)
1247 start = local_list.size() - kMaxLocalListSize;
1248 DCHECK(start <= local_list.size());
1249 if (local_list.size() == start)
1250 return;
1251
1252 // Store size at the beginning of the list.
1253 list->Append(Value::CreateIntegerValue(local_list.size() - start));
1254
1255 MD5Context ctx;
1256 MD5Init(&ctx);
1257 std::string encoded_log;
1258 for (std::vector<std::string>::const_iterator it = local_list.begin() + start;
1259 it != local_list.end(); ++it) {
1260 // We encode the compressed log as Value::CreateStringValue() expects to
1261 // take a valid UTF8 string.
1262 if (!base::Base64Encode(*it, &encoded_log)) {
1263 MakeStoreStatusHistogram(ENCODE_FAIL);
1264 list->Clear();
1265 return;
1266 }
1267 MD5Update(&ctx, encoded_log.data(), encoded_log.length());
1268 list->Append(Value::CreateStringValue(encoded_log));
initial.commit09911bf2008-07-26 23:55:291269 }
[email protected]46f89e142010-07-19 08:00:421270
1271 // Append hash to the end of the list.
1272 MD5Digest digest;
1273 MD5Final(&digest, &ctx);
1274 list->Append(Value::CreateStringValue(MD5DigestToBase16(digest)));
1275 DCHECK(list->GetSize() >= 3); // Minimum of 3 elements (size, data, hash).
[email protected]4e95d202010-07-24 01:47:561276 MakeStoreStatusHistogram(STORE_SUCCESS);
initial.commit09911bf2008-07-26 23:55:291277}
1278
1279void MetricsService::StoreUnsentLogs() {
1280 if (state_ < INITIAL_LOG_READY)
1281 return; // We never Recalled the prior unsent logs.
1282
1283 PrefService* local_state = g_browser_process->local_state();
1284 DCHECK(local_state);
1285
1286 ListValue* unsent_initial_logs = local_state->GetMutableList(
1287 prefs::kMetricsInitialLogs);
[email protected]46f89e142010-07-19 08:00:421288 StoreUnsentLogsHelper(unsent_initial_logs_, kMaxInitialLogsPersisted,
1289 unsent_initial_logs);
initial.commit09911bf2008-07-26 23:55:291290
1291 ListValue* unsent_ongoing_logs = local_state->GetMutableList(
1292 prefs::kMetricsOngoingLogs);
[email protected]46f89e142010-07-19 08:00:421293 StoreUnsentLogsHelper(unsent_ongoing_logs_, kMaxOngoingLogsPersisted,
1294 unsent_ongoing_logs);
initial.commit09911bf2008-07-26 23:55:291295}
1296
1297void MetricsService::PreparePendingLogText() {
1298 DCHECK(pending_log());
[email protected]46f89e142010-07-19 08:00:421299 if (!compressed_log_.empty())
initial.commit09911bf2008-07-26 23:55:291300 return;
[email protected]9ffcccf42009-09-15 22:19:181301 int text_size = pending_log_->GetEncodedLogSize();
1302
[email protected]46f89e142010-07-19 08:00:421303 std::string pending_log_text;
1304 // Leave room for the NULL terminator.
1305 pending_log_->GetEncodedLog(WriteInto(&pending_log_text, text_size + 1),
[email protected]9ffcccf42009-09-15 22:19:181306 text_size);
[email protected]46f89e142010-07-19 08:00:421307
1308 if (Bzip2Compress(pending_log_text, &compressed_log_)) {
1309 // Allow security conscious users to see all metrics logs that we send.
[email protected]666205032010-10-21 20:56:581310 VLOG(1) << "COMPRESSED FOLLOWING METRICS LOG: " << pending_log_text;
[email protected]46f89e142010-07-19 08:00:421311 } else {
1312 LOG(DFATAL) << "Failed to compress log for transmission.";
1313 // We can't discard the logs as other caller functions expect that
1314 // |compressed_log_| not be empty. We can detect this failure at the server
1315 // after we transmit.
1316 compressed_log_ = "Unable to compress!";
1317 MakeStoreStatusHistogram(COMPRESS_FAIL);
1318 return;
1319 }
initial.commit09911bf2008-07-26 23:55:291320}
1321
[email protected]d01b8732008-10-16 02:18:071322void MetricsService::PrepareFetchWithPendingLog() {
initial.commit09911bf2008-07-26 23:55:291323 DCHECK(pending_log());
1324 DCHECK(!current_fetch_.get());
1325 PreparePendingLogText();
[email protected]46f89e142010-07-19 08:00:421326 DCHECK(!compressed_log_.empty());
[email protected]cac78842008-11-27 01:02:201327
[email protected]79bf0b72009-04-27 21:30:551328 current_fetch_.reset(new URLFetcher(GURL(WideToUTF16(server_url_)),
1329 URLFetcher::POST,
initial.commit09911bf2008-07-26 23:55:291330 this));
1331 current_fetch_->set_request_context(Profile::GetDefaultRequestContext());
[email protected]46f89e142010-07-19 08:00:421332 current_fetch_->set_upload_data(kMetricsType, compressed_log_);
initial.commit09911bf2008-07-26 23:55:291333}
1334
initial.commit09911bf2008-07-26 23:55:291335static const char* StatusToString(const URLRequestStatus& status) {
1336 switch (status.status()) {
1337 case URLRequestStatus::SUCCESS:
1338 return "SUCCESS";
1339
1340 case URLRequestStatus::IO_PENDING:
1341 return "IO_PENDING";
1342
1343 case URLRequestStatus::HANDLED_EXTERNALLY:
1344 return "HANDLED_EXTERNALLY";
1345
1346 case URLRequestStatus::CANCELED:
1347 return "CANCELED";
1348
1349 case URLRequestStatus::FAILED:
1350 return "FAILED";
1351
1352 default:
[email protected]a063c102010-07-22 22:20:191353 NOTREACHED();
initial.commit09911bf2008-07-26 23:55:291354 return "Unknown";
1355 }
1356}
1357
1358void MetricsService::OnURLFetchComplete(const URLFetcher* source,
1359 const GURL& url,
1360 const URLRequestStatus& status,
1361 int response_code,
1362 const ResponseCookies& cookies,
1363 const std::string& data) {
1364 DCHECK(timer_pending_);
1365 timer_pending_ = false;
1366 DCHECK(current_fetch_.get());
1367 current_fetch_.reset(NULL); // We're not allowed to re-use it.
1368
1369 // Confirm send so that we can move on.
[email protected]666205032010-10-21 20:56:581370 VLOG(1) << "METRICS RESPONSE CODE: " << response_code
1371 << " status=" << StatusToString(status);
[email protected]252873ef2008-08-04 21:59:451372
[email protected]0eb34fee2009-01-21 08:04:381373 // Provide boolean for error recovery (allow us to ignore response_code).
[email protected]dc6f4962009-02-13 01:25:501374 bool discard_log = false;
[email protected]0eb34fee2009-01-21 08:04:381375
[email protected]68475e602008-08-22 03:21:151376 if (response_code != 200 &&
[email protected]46f89e142010-07-19 08:00:421377 (compressed_log_.length() >
1378 static_cast<size_t>(kUploadLogAvoidRetransmitSize))) {
[email protected]553dba62009-02-24 19:08:231379 UMA_HISTOGRAM_COUNTS("UMA.Large Rejected Log was Discarded",
[email protected]46f89e142010-07-19 08:00:421380 static_cast<int>(compressed_log_.length()));
[email protected]0eb34fee2009-01-21 08:04:381381 discard_log = true;
1382 } else if (response_code == 400) {
1383 // Bad syntax. Retransmission won't work.
[email protected]553dba62009-02-24 19:08:231384 UMA_HISTOGRAM_COUNTS("UMA.Unacceptable_Log_Discarded", state_);
[email protected]0eb34fee2009-01-21 08:04:381385 discard_log = true;
[email protected]68475e602008-08-22 03:21:151386 }
1387
[email protected]0eb34fee2009-01-21 08:04:381388 if (response_code != 200 && !discard_log) {
[email protected]666205032010-10-21 20:56:581389 VLOG(1) << "METRICS: transmission attempt returned a failure code: "
1390 << response_code << ". Verify network connectivity";
[email protected]252873ef2008-08-04 21:59:451391 HandleBadResponseCode();
[email protected]0eb34fee2009-01-21 08:04:381392 } else { // Successful receipt (or we are discarding log).
[email protected]666205032010-10-21 20:56:581393 VLOG(1) << "METRICS RESPONSE DATA: " << data;
initial.commit09911bf2008-07-26 23:55:291394 switch (state_) {
1395 case INITIAL_LOG_READY:
1396 state_ = SEND_OLD_INITIAL_LOGS;
1397 break;
1398
1399 case SEND_OLD_INITIAL_LOGS:
1400 DCHECK(!unsent_initial_logs_.empty());
1401 unsent_initial_logs_.pop_back();
1402 StoreUnsentLogs();
1403 break;
1404
1405 case SENDING_OLD_LOGS:
1406 DCHECK(!unsent_ongoing_logs_.empty());
1407 unsent_ongoing_logs_.pop_back();
1408 StoreUnsentLogs();
1409 break;
1410
1411 case SENDING_CURRENT_LOGS:
1412 break;
1413
1414 default:
[email protected]a063c102010-07-22 22:20:191415 NOTREACHED();
initial.commit09911bf2008-07-26 23:55:291416 break;
1417 }
[email protected]d01b8732008-10-16 02:18:071418
initial.commit09911bf2008-07-26 23:55:291419 DiscardPendingLog();
[email protected]29be92552008-08-07 22:49:271420 // Since we sent a log, make sure our in-memory state is recorded to disk.
1421 PrefService* local_state = g_browser_process->local_state();
1422 DCHECK(local_state);
1423 if (local_state)
[email protected]6faa0e0d2009-04-28 06:50:361424 local_state->ScheduleSavePersistentPrefs();
[email protected]252873ef2008-08-04 21:59:451425
[email protected]147bbc0b2009-01-06 19:37:401426 // Provide a default (free of exponetial backoff, other varances) in case
1427 // the server does not specify a value.
1428 interlog_duration_ = TimeDelta::FromSeconds(kMinSecondsPerLog);
1429
[email protected]252873ef2008-08-04 21:59:451430 GetSettingsFromResponseData(data);
[email protected]252873ef2008-08-04 21:59:451431 // Override server specified interlog delay if there are unsent logs to
[email protected]29be92552008-08-07 22:49:271432 // transmit.
initial.commit09911bf2008-07-26 23:55:291433 if (unsent_logs()) {
1434 DCHECK(state_ < SENDING_CURRENT_LOGS);
1435 interlog_duration_ = TimeDelta::FromSeconds(kUnsentLogDelay);
initial.commit09911bf2008-07-26 23:55:291436 }
1437 }
[email protected]252873ef2008-08-04 21:59:451438
initial.commit09911bf2008-07-26 23:55:291439 StartLogTransmissionTimer();
1440}
1441
[email protected]252873ef2008-08-04 21:59:451442void MetricsService::HandleBadResponseCode() {
[email protected]666205032010-10-21 20:56:581443 VLOG(1) << "Verify your metrics logs are formatted correctly. Verify server "
1444 "is active at " << server_url_;
[email protected]252873ef2008-08-04 21:59:451445 if (!pending_log()) {
[email protected]666205032010-10-21 20:56:581446 VLOG(1) << "METRICS: Recorder shutdown during log transmission.";
[email protected]252873ef2008-08-04 21:59:451447 } else {
1448 // Send progressively less frequently.
1449 DCHECK(kBackoff > 1.0);
1450 interlog_duration_ = TimeDelta::FromMicroseconds(
1451 static_cast<int64>(kBackoff * interlog_duration_.InMicroseconds()));
1452
1453 if (kMaxBackoff * TimeDelta::FromSeconds(kMinSecondsPerLog) <
[email protected]cac78842008-11-27 01:02:201454 interlog_duration_) {
[email protected]252873ef2008-08-04 21:59:451455 interlog_duration_ = kMaxBackoff *
1456 TimeDelta::FromSeconds(kMinSecondsPerLog);
[email protected]cac78842008-11-27 01:02:201457 }
[email protected]252873ef2008-08-04 21:59:451458
[email protected]666205032010-10-21 20:56:581459 VLOG(1) << "METRICS: transmission retry being scheduled in "
1460 << interlog_duration_.InSeconds() << " seconds for "
1461 << compressed_log_;
initial.commit09911bf2008-07-26 23:55:291462 }
initial.commit09911bf2008-07-26 23:55:291463}
1464
[email protected]252873ef2008-08-04 21:59:451465void MetricsService::GetSettingsFromResponseData(const std::string& data) {
1466 // We assume that the file is structured as a block opened by <response>
[email protected]d01b8732008-10-16 02:18:071467 // and that inside response, there is a block opened by tag <chrome_config>
1468 // other tags are ignored for now except the content of <chrome_config>.
[email protected]666205032010-10-21 20:56:581469 VLOG(1) << "METRICS: getting settings from response data: " << data;
[email protected]d01b8732008-10-16 02:18:071470
[email protected]252873ef2008-08-04 21:59:451471 int data_size = static_cast<int>(data.size());
1472 if (data_size < 0) {
[email protected]666205032010-10-21 20:56:581473 VLOG(1) << "METRICS: server response data bad size: " << data_size
1474 << "; aborting extraction of settings";
[email protected]252873ef2008-08-04 21:59:451475 return;
1476 }
[email protected]cac78842008-11-27 01:02:201477 xmlDocPtr doc = xmlReadMemory(data.c_str(), data_size, "", NULL, 0);
[email protected]d01b8732008-10-16 02:18:071478 // If the document is malformed, we just use the settings that were there.
1479 if (!doc) {
[email protected]666205032010-10-21 20:56:581480 VLOG(1) << "METRICS: reading xml from server response data failed";
[email protected]252873ef2008-08-04 21:59:451481 return;
[email protected]d01b8732008-10-16 02:18:071482 }
[email protected]252873ef2008-08-04 21:59:451483
[email protected]d01b8732008-10-16 02:18:071484 xmlNodePtr top_node = xmlDocGetRootElement(doc), chrome_config_node = NULL;
1485 // Here, we find the chrome_config node by name.
[email protected]252873ef2008-08-04 21:59:451486 for (xmlNodePtr p = top_node->children; p; p = p->next) {
[email protected]d01b8732008-10-16 02:18:071487 if (xmlStrEqual(p->name, BAD_CAST "chrome_config")) {
1488 chrome_config_node = p;
[email protected]252873ef2008-08-04 21:59:451489 break;
1490 }
1491 }
1492 // If the server data is formatted wrong and there is no
1493 // config node where we expect, we just drop out.
[email protected]d01b8732008-10-16 02:18:071494 if (chrome_config_node != NULL)
1495 GetSettingsFromChromeConfigNode(chrome_config_node);
[email protected]252873ef2008-08-04 21:59:451496 xmlFreeDoc(doc);
1497}
1498
[email protected]d01b8732008-10-16 02:18:071499void MetricsService::GetSettingsFromChromeConfigNode(
1500 xmlNodePtr chrome_config_node) {
1501 // Iterate through all children of the config node.
1502 for (xmlNodePtr current_node = chrome_config_node->children;
1503 current_node;
1504 current_node = current_node->next) {
1505 // If we find the upload tag, we appeal to another function
1506 // GetSettingsFromUploadNode to read all the data in it.
[email protected]252873ef2008-08-04 21:59:451507 if (xmlStrEqual(current_node->name, BAD_CAST "upload")) {
[email protected]d01b8732008-10-16 02:18:071508 GetSettingsFromUploadNode(current_node);
[email protected]252873ef2008-08-04 21:59:451509 continue;
1510 }
1511 }
1512}
initial.commit09911bf2008-07-26 23:55:291513
[email protected]d01b8732008-10-16 02:18:071514void MetricsService::InheritedProperties::OverwriteWhereNeeded(
1515 xmlNodePtr node) {
1516 xmlChar* salt_value = xmlGetProp(node, BAD_CAST "salt");
1517 if (salt_value) // If the property isn't there, xmlGetProp returns NULL.
1518 salt = atoi(reinterpret_cast<char*>(salt_value));
1519 // If the property isn't there, we keep the value the property had before
1520
1521 xmlChar* denominator_value = xmlGetProp(node, BAD_CAST "denominator");
1522 if (denominator_value)
1523 denominator = atoi(reinterpret_cast<char*>(denominator_value));
1524}
1525
1526void MetricsService::GetSettingsFromUploadNode(xmlNodePtr upload_node) {
1527 InheritedProperties props;
1528 GetSettingsFromUploadNodeRecursive(upload_node, props, "", true);
1529}
1530
[email protected]cac78842008-11-27 01:02:201531void MetricsService::GetSettingsFromUploadNodeRecursive(
1532 xmlNodePtr node,
1533 InheritedProperties props,
1534 std::string path_prefix,
1535 bool uploadOn) {
[email protected]d01b8732008-10-16 02:18:071536 props.OverwriteWhereNeeded(node);
1537
1538 // The bool uploadOn is set to true if the data represented by current
1539 // node should be uploaded. This gets inherited in the tree; the children
1540 // of a node that has already been rejected for upload get rejected for
1541 // upload.
1542 uploadOn = uploadOn && NodeProbabilityTest(node, props);
1543
1544 // The path is a / separated list of the node names ancestral to the current
1545 // one. So, if you want to check if the current node has a certain name,
1546 // compare to name. If you want to check if it is a certan tag at a certain
1547 // place in the tree, compare to the whole path.
1548 std::string name = std::string(reinterpret_cast<const char*>(node->name));
1549 std::string path = path_prefix + "/" + name;
1550
1551 if (path == "/upload") {
1552 xmlChar* upload_interval_val = xmlGetProp(node, BAD_CAST "interval");
1553 if (upload_interval_val) {
1554 interlog_duration_ = TimeDelta::FromSeconds(
1555 atoi(reinterpret_cast<char*>(upload_interval_val)));
1556 }
1557
1558 server_permits_upload_ = uploadOn;
[email protected]24d07e32010-07-10 00:31:271559 } else if (path == "/upload/logs") {
[email protected]d01b8732008-10-16 02:18:071560 xmlChar* log_event_limit_val = xmlGetProp(node, BAD_CAST "event_limit");
1561 if (log_event_limit_val)
1562 log_event_limit_ = atoi(reinterpret_cast<char*>(log_event_limit_val));
1563 }
[email protected]d01b8732008-10-16 02:18:071564
1565 // Recursive call. If the node is a leaf i.e. if it ends in a "/>", then it
1566 // doesn't have children, so node->children is NULL, and this loop doesn't
1567 // call (that's how the recursion ends).
1568 for (xmlNodePtr child_node = node->children;
[email protected]cac78842008-11-27 01:02:201569 child_node;
1570 child_node = child_node->next) {
[email protected]d01b8732008-10-16 02:18:071571 GetSettingsFromUploadNodeRecursive(child_node, props, path, uploadOn);
1572 }
1573}
1574
1575bool MetricsService::NodeProbabilityTest(xmlNodePtr node,
[email protected]cac78842008-11-27 01:02:201576 InheritedProperties props) const {
[email protected]d01b8732008-10-16 02:18:071577 // Default value of probability on any node is 1, but recall that
1578 // its parents can already have been rejected for upload.
1579 double probability = 1;
1580
1581 // If a probability is specified in the node, we use it instead.
1582 xmlChar* probability_value = xmlGetProp(node, BAD_CAST "probability");
1583 if (probability_value)
[email protected]0b33f80b2008-12-17 21:34:361584 probability = atoi(reinterpret_cast<char*>(probability_value));
[email protected]d01b8732008-10-16 02:18:071585
1586 return ProbabilityTest(probability, props.salt, props.denominator);
1587}
1588
1589bool MetricsService::ProbabilityTest(double probability,
1590 int salt,
1591 int denominator) const {
1592 // Okay, first we figure out how many of the digits of the
1593 // client_id_ we need in order to make a nice pseudorandomish
1594 // number in the range [0,denominator). Too many digits is
1595 // fine.
[email protected]d01b8732008-10-16 02:18:071596
1597 // n is the length of the client_id_ string
1598 size_t n = client_id_.size();
1599
1600 // idnumber is a positive integer generated from the client_id_.
1601 // It plus salt is going to give us our pseudorandom number.
1602 int idnumber = 0;
1603 const char* client_id_c_str = client_id_.c_str();
1604
1605 // Here we hash the relevant digits of the client_id_
1606 // string somehow to get a big integer idnumber (could be negative
1607 // from wraparound)
1608 int big = 1;
[email protected]5ed73342009-03-18 17:39:431609 int last_pos = n - 1;
1610 for (size_t j = 0; j < n; ++j) {
1611 idnumber += static_cast<int>(client_id_c_str[last_pos - j]) * big;
[email protected]d01b8732008-10-16 02:18:071612 big *= 10;
1613 }
1614
1615 // Mod id number by denominator making sure to get a non-negative
1616 // answer.
[email protected]cac78842008-11-27 01:02:201617 idnumber = ((idnumber % denominator) + denominator) % denominator;
[email protected]d01b8732008-10-16 02:18:071618
[email protected]cac78842008-11-27 01:02:201619 // ((idnumber + salt) % denominator) / denominator is in the range [0,1]
[email protected]d01b8732008-10-16 02:18:071620 // if it's less than probability we call that an affirmative coin
1621 // toss.
[email protected]cac78842008-11-27 01:02:201622 return static_cast<double>((idnumber + salt) % denominator) <
1623 probability * denominator;
[email protected]d01b8732008-10-16 02:18:071624}
1625
initial.commit09911bf2008-07-26 23:55:291626void MetricsService::LogWindowChange(NotificationType type,
1627 const NotificationSource& source,
1628 const NotificationDetails& details) {
[email protected]534e54b2008-08-13 15:40:091629 int controller_id = -1;
1630 uintptr_t window_or_tab = source.map_key();
initial.commit09911bf2008-07-26 23:55:291631 MetricsLog::WindowEventType window_type;
1632
1633 // Note: since we stop all logging when a single OTR session is active, it is
1634 // possible that we start getting notifications about a window that we don't
1635 // know about.
[email protected]534e54b2008-08-13 15:40:091636 if (window_map_.find(window_or_tab) == window_map_.end()) {
1637 controller_id = next_window_id_++;
1638 window_map_[window_or_tab] = controller_id;
initial.commit09911bf2008-07-26 23:55:291639 } else {
[email protected]534e54b2008-08-13 15:40:091640 controller_id = window_map_[window_or_tab];
initial.commit09911bf2008-07-26 23:55:291641 }
[email protected]92745242009-06-12 16:52:211642 DCHECK_NE(controller_id, -1);
initial.commit09911bf2008-07-26 23:55:291643
[email protected]bfd04a62009-02-01 18:16:561644 switch (type.value) {
1645 case NotificationType::TAB_PARENTED:
1646 case NotificationType::BROWSER_OPENED:
initial.commit09911bf2008-07-26 23:55:291647 window_type = MetricsLog::WINDOW_CREATE;
1648 break;
1649
[email protected]bfd04a62009-02-01 18:16:561650 case NotificationType::TAB_CLOSING:
1651 case NotificationType::BROWSER_CLOSED:
[email protected]534e54b2008-08-13 15:40:091652 window_map_.erase(window_map_.find(window_or_tab));
initial.commit09911bf2008-07-26 23:55:291653 window_type = MetricsLog::WINDOW_DESTROY;
1654 break;
1655
1656 default:
[email protected]a063c102010-07-22 22:20:191657 NOTREACHED();
[email protected]68d74f02009-02-13 01:36:501658 return;
initial.commit09911bf2008-07-26 23:55:291659 }
1660
[email protected]534e54b2008-08-13 15:40:091661 // TODO(brettw) we should have some kind of ID for the parent.
1662 current_log_->RecordWindowEvent(window_type, controller_id, 0);
initial.commit09911bf2008-07-26 23:55:291663}
1664
1665void MetricsService::LogLoadComplete(NotificationType type,
1666 const NotificationSource& source,
1667 const NotificationDetails& details) {
1668 if (details == NotificationService::NoDetails())
1669 return;
1670
[email protected]68475e602008-08-22 03:21:151671 // TODO(jar): There is a bug causing this to be called too many times, and
1672 // the log overflows. For now, we won't record these events.
[email protected]553dba62009-02-24 19:08:231673 UMA_HISTOGRAM_COUNTS("UMA.LogLoadComplete called", 1);
[email protected]68475e602008-08-22 03:21:151674 return;
1675
initial.commit09911bf2008-07-26 23:55:291676 const Details<LoadNotificationDetails> load_details(details);
[email protected]534e54b2008-08-13 15:40:091677 int controller_id = window_map_[details.map_key()];
1678 current_log_->RecordLoadEvent(controller_id,
initial.commit09911bf2008-07-26 23:55:291679 load_details->url(),
1680 load_details->origin(),
1681 load_details->session_index(),
1682 load_details->load_time());
1683}
1684
[email protected]57ecc4b2010-08-11 03:02:511685void MetricsService::IncrementPrefValue(const char* path) {
[email protected]e73c01972008-08-13 00:18:241686 PrefService* pref = g_browser_process->local_state();
1687 DCHECK(pref);
1688 int value = pref->GetInteger(path);
1689 pref->SetInteger(path, value + 1);
1690}
1691
[email protected]57ecc4b2010-08-11 03:02:511692void MetricsService::IncrementLongPrefsValue(const char* path) {
[email protected]0bb1a622009-03-04 03:22:321693 PrefService* pref = g_browser_process->local_state();
1694 DCHECK(pref);
1695 int64 value = pref->GetInt64(path);
[email protected]b42c5e42010-06-03 20:43:251696 pref->SetInt64(path, value + 1);
[email protected]0bb1a622009-03-04 03:22:321697}
1698
initial.commit09911bf2008-07-26 23:55:291699void MetricsService::LogLoadStarted() {
[email protected]e73c01972008-08-13 00:18:241700 IncrementPrefValue(prefs::kStabilityPageLoadCount);
[email protected]0bb1a622009-03-04 03:22:321701 IncrementLongPrefsValue(prefs::kUninstallMetricsPageLoadCount);
[email protected]0b33f80b2008-12-17 21:34:361702 // We need to save the prefs, as page load count is a critical stat, and it
1703 // might be lost due to a crash :-(.
initial.commit09911bf2008-07-26 23:55:291704}
1705
initial.commit09911bf2008-07-26 23:55:291706void MetricsService::LogRendererCrash() {
[email protected]e73c01972008-08-13 00:18:241707 IncrementPrefValue(prefs::kStabilityRendererCrashCount);
initial.commit09911bf2008-07-26 23:55:291708}
1709
[email protected]1f085622009-12-04 05:33:451710void MetricsService::LogExtensionRendererCrash() {
1711 IncrementPrefValue(prefs::kStabilityExtensionRendererCrashCount);
1712}
1713
initial.commit09911bf2008-07-26 23:55:291714void MetricsService::LogRendererHang() {
[email protected]e73c01972008-08-13 00:18:241715 IncrementPrefValue(prefs::kStabilityRendererHangCount);
initial.commit09911bf2008-07-26 23:55:291716}
1717
[email protected]a27a9382009-02-11 23:55:101718void MetricsService::LogChildProcessChange(
1719 NotificationType type,
1720 const NotificationSource& source,
1721 const NotificationDetails& details) {
[email protected]0d84c5d2009-10-09 01:10:421722 Details<ChildProcessInfo> child_details(details);
1723 const std::wstring& child_name = child_details->name();
1724
[email protected]a27a9382009-02-11 23:55:101725 if (child_process_stats_buffer_.find(child_name) ==
1726 child_process_stats_buffer_.end()) {
[email protected]0d84c5d2009-10-09 01:10:421727 child_process_stats_buffer_[child_name] =
1728 ChildProcessStats(child_details->type());
initial.commit09911bf2008-07-26 23:55:291729 }
1730
[email protected]a27a9382009-02-11 23:55:101731 ChildProcessStats& stats = child_process_stats_buffer_[child_name];
[email protected]bfd04a62009-02-01 18:16:561732 switch (type.value) {
[email protected]a27a9382009-02-11 23:55:101733 case NotificationType::CHILD_PROCESS_HOST_CONNECTED:
initial.commit09911bf2008-07-26 23:55:291734 stats.process_launches++;
1735 break;
1736
[email protected]a27a9382009-02-11 23:55:101737 case NotificationType::CHILD_INSTANCE_CREATED:
initial.commit09911bf2008-07-26 23:55:291738 stats.instances++;
1739 break;
1740
[email protected]a27a9382009-02-11 23:55:101741 case NotificationType::CHILD_PROCESS_CRASHED:
initial.commit09911bf2008-07-26 23:55:291742 stats.process_crashes++;
[email protected]1f085622009-12-04 05:33:451743 // Exclude plugin crashes from the count below because we report them via
1744 // a separate UMA metric.
1745 if (child_details->type() != ChildProcessInfo::PLUGIN_PROCESS) {
1746 IncrementPrefValue(prefs::kStabilityChildProcessCrashCount);
1747 }
initial.commit09911bf2008-07-26 23:55:291748 break;
1749
1750 default:
[email protected]a063c102010-07-22 22:20:191751 NOTREACHED() << "Unexpected notification type " << type.value;
initial.commit09911bf2008-07-26 23:55:291752 return;
1753 }
1754}
1755
1756// Recursively counts the number of bookmarks and folders in node.
[email protected]b3c33d462009-06-26 22:29:201757static void CountBookmarks(const BookmarkNode* node,
1758 int* bookmarks,
1759 int* folders) {
[email protected]037db002009-10-19 20:06:081760 if (node->type() == BookmarkNode::URL)
initial.commit09911bf2008-07-26 23:55:291761 (*bookmarks)++;
1762 else
1763 (*folders)++;
1764 for (int i = 0; i < node->GetChildCount(); ++i)
1765 CountBookmarks(node->GetChild(i), bookmarks, folders);
1766}
1767
[email protected]b3c33d462009-06-26 22:29:201768void MetricsService::LogBookmarks(const BookmarkNode* node,
[email protected]57ecc4b2010-08-11 03:02:511769 const char* num_bookmarks_key,
1770 const char* num_folders_key) {
initial.commit09911bf2008-07-26 23:55:291771 DCHECK(node);
1772 int num_bookmarks = 0;
1773 int num_folders = 0;
1774 CountBookmarks(node, &num_bookmarks, &num_folders);
1775 num_folders--; // Don't include the root folder in the count.
1776
1777 PrefService* pref = g_browser_process->local_state();
1778 DCHECK(pref);
1779 pref->SetInteger(num_bookmarks_key, num_bookmarks);
1780 pref->SetInteger(num_folders_key, num_folders);
1781}
1782
[email protected]d8e41ed2008-09-11 15:22:321783void MetricsService::LogBookmarks(BookmarkModel* model) {
initial.commit09911bf2008-07-26 23:55:291784 DCHECK(model);
1785 LogBookmarks(model->GetBookmarkBarNode(),
1786 prefs::kNumBookmarksOnBookmarkBar,
1787 prefs::kNumFoldersOnBookmarkBar);
1788 LogBookmarks(model->other_node(),
1789 prefs::kNumBookmarksInOtherBookmarkFolder,
1790 prefs::kNumFoldersInOtherBookmarkFolder);
1791 ScheduleNextStateSave();
1792}
1793
1794void MetricsService::LogKeywords(const TemplateURLModel* url_model) {
1795 DCHECK(url_model);
1796
1797 PrefService* pref = g_browser_process->local_state();
1798 DCHECK(pref);
1799 pref->SetInteger(prefs::kNumKeywords,
1800 static_cast<int>(url_model->GetTemplateURLs().size()));
1801 ScheduleNextStateSave();
1802}
1803
1804void MetricsService::RecordPluginChanges(PrefService* pref) {
1805 ListValue* plugins = pref->GetMutableList(prefs::kStabilityPluginStats);
1806 DCHECK(plugins);
1807
1808 for (ListValue::iterator value_iter = plugins->begin();
1809 value_iter != plugins->end(); ++value_iter) {
1810 if (!(*value_iter)->IsType(Value::TYPE_DICTIONARY)) {
[email protected]a063c102010-07-22 22:20:191811 NOTREACHED();
initial.commit09911bf2008-07-26 23:55:291812 continue;
1813 }
1814
1815 DictionaryValue* plugin_dict = static_cast<DictionaryValue*>(*value_iter);
[email protected]57ecc4b2010-08-11 03:02:511816 std::string plugin_name;
[email protected]8e50b602009-03-03 22:59:431817 plugin_dict->GetString(prefs::kStabilityPluginName, &plugin_name);
[email protected]6470ee8f2009-03-03 20:46:401818 if (plugin_name.empty()) {
[email protected]a063c102010-07-22 22:20:191819 NOTREACHED();
initial.commit09911bf2008-07-26 23:55:291820 continue;
1821 }
1822
[email protected]57ecc4b2010-08-11 03:02:511823 // TODO(viettrungluu): remove conversions
1824 if (child_process_stats_buffer_.find(UTF8ToWide(plugin_name)) ==
[email protected]a27a9382009-02-11 23:55:101825 child_process_stats_buffer_.end())
initial.commit09911bf2008-07-26 23:55:291826 continue;
1827
[email protected]57ecc4b2010-08-11 03:02:511828 ChildProcessStats stats =
1829 child_process_stats_buffer_[UTF8ToWide(plugin_name)];
initial.commit09911bf2008-07-26 23:55:291830 if (stats.process_launches) {
1831 int launches = 0;
[email protected]8e50b602009-03-03 22:59:431832 plugin_dict->GetInteger(prefs::kStabilityPluginLaunches, &launches);
initial.commit09911bf2008-07-26 23:55:291833 launches += stats.process_launches;
[email protected]8e50b602009-03-03 22:59:431834 plugin_dict->SetInteger(prefs::kStabilityPluginLaunches, launches);
initial.commit09911bf2008-07-26 23:55:291835 }
1836 if (stats.process_crashes) {
1837 int crashes = 0;
[email protected]8e50b602009-03-03 22:59:431838 plugin_dict->GetInteger(prefs::kStabilityPluginCrashes, &crashes);
initial.commit09911bf2008-07-26 23:55:291839 crashes += stats.process_crashes;
[email protected]8e50b602009-03-03 22:59:431840 plugin_dict->SetInteger(prefs::kStabilityPluginCrashes, crashes);
initial.commit09911bf2008-07-26 23:55:291841 }
1842 if (stats.instances) {
1843 int instances = 0;
[email protected]8e50b602009-03-03 22:59:431844 plugin_dict->GetInteger(prefs::kStabilityPluginInstances, &instances);
initial.commit09911bf2008-07-26 23:55:291845 instances += stats.instances;
[email protected]8e50b602009-03-03 22:59:431846 plugin_dict->SetInteger(prefs::kStabilityPluginInstances, instances);
initial.commit09911bf2008-07-26 23:55:291847 }
1848
[email protected]57ecc4b2010-08-11 03:02:511849 child_process_stats_buffer_.erase(UTF8ToWide(plugin_name));
initial.commit09911bf2008-07-26 23:55:291850 }
1851
1852 // Now go through and add dictionaries for plugins that didn't already have
1853 // reports in Local State.
[email protected]a27a9382009-02-11 23:55:101854 for (std::map<std::wstring, ChildProcessStats>::iterator cache_iter =
1855 child_process_stats_buffer_.begin();
1856 cache_iter != child_process_stats_buffer_.end(); ++cache_iter) {
[email protected]a27a9382009-02-11 23:55:101857 ChildProcessStats stats = cache_iter->second;
[email protected]0d84c5d2009-10-09 01:10:421858
1859 // Insert only plugins information into the plugins list.
1860 if (ChildProcessInfo::PLUGIN_PROCESS != stats.process_type)
1861 continue;
1862
[email protected]57ecc4b2010-08-11 03:02:511863 // TODO(viettrungluu): remove conversion
1864 std::string plugin_name = WideToUTF8(cache_iter->first);
[email protected]0d84c5d2009-10-09 01:10:421865
initial.commit09911bf2008-07-26 23:55:291866 DictionaryValue* plugin_dict = new DictionaryValue;
1867
[email protected]8e50b602009-03-03 22:59:431868 plugin_dict->SetString(prefs::kStabilityPluginName, plugin_name);
1869 plugin_dict->SetInteger(prefs::kStabilityPluginLaunches,
initial.commit09911bf2008-07-26 23:55:291870 stats.process_launches);
[email protected]8e50b602009-03-03 22:59:431871 plugin_dict->SetInteger(prefs::kStabilityPluginCrashes,
initial.commit09911bf2008-07-26 23:55:291872 stats.process_crashes);
[email protected]8e50b602009-03-03 22:59:431873 plugin_dict->SetInteger(prefs::kStabilityPluginInstances,
initial.commit09911bf2008-07-26 23:55:291874 stats.instances);
1875 plugins->Append(plugin_dict);
1876 }
[email protected]a27a9382009-02-11 23:55:101877 child_process_stats_buffer_.clear();
initial.commit09911bf2008-07-26 23:55:291878}
1879
1880bool MetricsService::CanLogNotification(NotificationType type,
1881 const NotificationSource& source,
1882 const NotificationDetails& details) {
1883 // We simply don't log anything to UMA if there is a single off the record
1884 // session visible. The problem is that we always notify using the orginal
1885 // profile in order to simplify notification processing.
1886 return !BrowserList::IsOffTheRecordSessionActive();
1887}
1888
[email protected]57ecc4b2010-08-11 03:02:511889void MetricsService::RecordBooleanPrefValue(const char* path, bool value) {
initial.commit09911bf2008-07-26 23:55:291890 DCHECK(IsSingleThreaded());
1891
1892 PrefService* pref = g_browser_process->local_state();
1893 DCHECK(pref);
1894
1895 pref->SetBoolean(path, value);
1896 RecordCurrentState(pref);
1897}
1898
1899void MetricsService::RecordCurrentState(PrefService* pref) {
[email protected]0bb1a622009-03-04 03:22:321900 pref->SetInt64(prefs::kStabilityLastTimestampSec, Time::Now().ToTimeT());
initial.commit09911bf2008-07-26 23:55:291901
1902 RecordPluginChanges(pref);
1903}
1904
initial.commit09911bf2008-07-26 23:55:291905static bool IsSingleThreaded() {
[email protected]ce072a72010-12-31 20:02:161906 static base::PlatformThreadId thread_id = 0;
initial.commit09911bf2008-07-26 23:55:291907 if (!thread_id)
[email protected]ce072a72010-12-31 20:02:161908 thread_id = base::PlatformThread::CurrentId();
1909 return base::PlatformThread::CurrentId() == thread_id;
initial.commit09911bf2008-07-26 23:55:291910}
[email protected]5ccaa412009-11-13 22:00:161911
1912#if defined(OS_CHROMEOS)
[email protected]29cf16772010-04-21 15:13:471913void MetricsService::StartExternalMetrics() {
[email protected]5ccaa412009-11-13 22:00:161914 external_metrics_ = new chromeos::ExternalMetrics;
[email protected]29cf16772010-04-21 15:13:471915 external_metrics_->Start();
[email protected]5ccaa412009-11-13 22:00:161916}
1917#endif