blob: 77ac6d5618459257467ff36b25ca5a03ed049558 [file] [log] [blame]
tfarina@chromium.orgf90bf0d92011-01-13 02:12:441// Copyright (c) 2011 The Chromium Authors. All rights reserved.
license.botbf09a502008-08-24 00:55:552// Use of this source code is governed by a BSD-style license that can be
3// found in the LICENSE file.
initial.commit09911bf2008-07-26 23:55:294
initial.commit09911bf2008-07-26 23:55:295//------------------------------------------------------------------------------
6// Description of the life cycle of a instance of MetricsService.
7//
8// OVERVIEW
9//
10// A MetricsService instance is typically created at application startup. It
11// is the central controller for the acquisition of log data, and the automatic
12// transmission of that log data to an external server. Its major job is to
13// manage logs, grouping them for transmission, and transmitting them. As part
14// of its grouping, MS finalizes logs by including some just-in-time gathered
15// memory statistics, snapshotting the current stats of numerous histograms,
16// closing the logs, translating to XML text, and compressing the results for
17// transmission. Transmission includes submitting a compressed log as data in a
jar@chromium.org281d2882009-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
ziadh@chromium.org46f89e142010-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//
jar@chromium.org281d2882009-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
jar@chromium.org281d2882009-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)
jar@google.com0b33f80b2008-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
jar@chromium.org281d2882009-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
jar@chromium.org281d2882009-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.
zelidrag@chromium.org85ed9d42010-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//
zelidrag@chromium.org85ed9d42010-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
zelidrag@chromium.org85ed9d42010-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//
zelidrag@chromium.org85ed9d42010-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
zelidrag@chromium.org85ed9d42010-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.
jar@google.com0b33f80b2008-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
jar@chromium.org281d2882009-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
jar@chromium.org281d2882009-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
maruel@chromium.org40bcc302009-03-02 20:50:39157#include "chrome/browser/metrics/metrics_service.h"
158
ziadh@chromium.org46f89e142010-07-19 08:00:42159#include "base/base64.h"
erg@google.com5d91c9e2010-07-28 17:25:28160#include "base/command_line.h"
ziadh@chromium.org46f89e142010-07-19 08:00:42161#include "base/md5.h"
brettw@chromium.org835d7c82010-10-14 04:38:38162#include "base/metrics/histogram.h"
brettw@chromium.org528c56d2010-07-30 19:28:44163#include "base/string_number_conversions.h"
brettw@chromium.org34b99632011-01-01 01:01:06164#include "base/threading/thread.h"
brettw@chromium.orgce072a72010-12-31 20:02:16165#include "base/threading/platform_thread.h"
viettrungluu@chromium.org440b37b22010-08-30 05:31:40166#include "base/utf_string_conversions.h"
erg@google.com679082052010-07-21 21:30:13167#include "base/values.h"
sky@google.comd8e41ed2008-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"
phajdan.jr@chromium.org7c927b62010-02-24 09:54:13173#include "chrome/browser/metrics/histogram_synchronizer.h"
erg@google.com679082052010-07-21 21:30:13174#include "chrome/browser/metrics/metrics_log.h"
evan@chromium.org37858e52010-08-26 00:22:02175#include "chrome/browser/prefs/pref_service.h"
ben@chromium.org8ecad5e2010-12-02 21:18:33176#include "chrome/browser/profiles/profile.h"
brettw@chromium.org8c8657d62009-01-16 18:31:26177#include "chrome/browser/renderer_host/render_process_host.h"
ben@chromium.orgd54e03a52009-01-16 00:31:04178#include "chrome/browser/search_engines/template_url_model.h"
erg@google.com679082052010-07-21 21:30:13179#include "chrome/common/child_process_info.h"
kuchhal@chromium.org157d5472009-11-05 22:31:03180#include "chrome/common/child_process_logging.h"
jar@chromium.org92745242009-06-12 16:52:21181#include "chrome/common/chrome_switches.h"
sergeyu@chromium.org3eb0d8f72010-12-15 23:38:25182#include "chrome/common/guid.h"
brettw@chromium.orgbfd04a62009-02-01 18:16:56183#include "chrome/common/notification_service.h"
initial.commit09911bf2008-07-26 23:55:29184#include "chrome/common/pref_names.h"
jam@chromium.orge09ba552009-02-05 03:26:29185#include "chrome/common/render_messages.h"
brettw@chromium.org191eb3f72010-12-21 06:27:50186#include "webkit/plugins/npapi/plugin_list.h"
187#include "webkit/plugins/npapi/webplugininfo.h"
mad@google.comae393ec702010-06-27 16:23:14188#include "libxml/xmlwriter.h"
initial.commit09911bf2008-07-26 23:55:29189
phajdan.jr@chromium.orge06131d2010-02-10 18:40:33190// TODO(port): port browser_distribution.h.
191#if !defined(OS_POSIX)
kuchhal@chromium.org79bf0b72009-04-27 21:30:55192#include "chrome/installer/util/browser_distribution.h"
paul@chromium.orgdc6f4962009-02-13 01:25:50193#endif
194
rvargas@google.com5ccaa412009-11-13 22:00:16195#if defined(OS_CHROMEOS)
stevenjb@chromium.orgdb342d52010-08-09 21:19:37196#include "chrome/browser/chromeos/cros/cros_library.h"
197#include "chrome/browser/chromeos/cros/system_library.h"
rvargas@google.com5ccaa412009-11-13 22:00:16198#include "chrome/browser/chromeos/external_metrics.h"
199#endif
200
ziadh@chromium.org46f89e142010-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) {
ziadh@chromium.org4e95d202010-07-24 01:47:56211 UMA_HISTOGRAM_ENUMERATION("PrefService.PersistentLogStore2", status,
ziadh@chromium.org46f89e142010-07-19 08:00:42212 MetricsService::END_STORE_STATUS);
213}
214} // namespace
215
dsh@google.come1acf6f2008-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.
petersont@google.com252873ef2008-08-04 21:59:45225static const int kInitialInterlogDuration = 60; // one minute
226
jar@chromium.orgc9a3ef82009-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
petersont@google.com252873ef2008-08-04 21:59:45231// The default maximum number of events in a log uploaded to the UMA server.
jar@google.com0b33f80b2008-12-17 21:34:36232static const int kInitialEventLimit = 2400;
jar@google.com68475e602008-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
jar@chromium.org2fe42fe2010-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
jar@chromium.org281d2882009-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).
jar@chromium.org281d2882009-01-20 20:32:42279static const size_t kMaxOngoingLogsPersisted = 8;
initial.commit09911bf2008-07-26 23:55:29280
ziadh@chromium.org46f89e142010-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
erg@google.com679082052010-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:
jam@chromium.orge6e6ba42009-11-07 01:56:19330 ~MetricsMemoryDetails() {}
331
initial.commit09911bf2008-07-26 23:55:29332 Task* completion_;
tfarina@chromium.org4d818fee2010-06-06 13:32:27333 DISALLOW_COPY_AND_ASSIGN(MetricsMemoryDetails);
initial.commit09911bf2008-07-26 23:55:29334};
335
zelidrag@chromium.org85ed9d42010-06-08 22:37:44336class MetricsService::InitTaskComplete : public Task {
jam@chromium.org35fa6a22009-08-15 00:04:01337 public:
brettw@chromium.org191eb3f72010-12-21 06:27:50338 explicit InitTaskComplete(
339 const std::string& hardware_class,
340 const std::vector<webkit::npapi::WebPluginInfo>& plugins)
zelidrag@chromium.org85ed9d42010-06-08 22:37:44341 : hardware_class_(hardware_class), plugins_(plugins) {}
342
jamesr@chromium.org7f2e792e2009-11-30 23:18:29343 virtual void Run() {
zelidrag@chromium.org85ed9d42010-06-08 22:37:44344 g_browser_process->metrics_service()->OnInitTaskComplete(
345 hardware_class_, plugins_);
initial.commit09911bf2008-07-26 23:55:29346 }
jam@chromium.org35fa6a22009-08-15 00:04:01347
jamesr@chromium.org7f2e792e2009-11-30 23:18:29348 private:
zelidrag@chromium.org85ed9d42010-06-08 22:37:44349 std::string hardware_class_;
brettw@chromium.org191eb3f72010-12-21 06:27:50350 std::vector<webkit::npapi::WebPluginInfo> plugins_;
initial.commit09911bf2008-07-26 23:55:29351};
352
zelidrag@chromium.org85ed9d42010-06-08 22:37:44353class MetricsService::InitTask : public Task {
jamesr@chromium.org7f2e792e2009-11-30 23:18:29354 public:
zelidrag@chromium.org85ed9d42010-06-08 22:37:44355 explicit InitTask(MessageLoop* callback_loop)
jamesr@chromium.org7f2e792e2009-11-30 23:18:29356 : callback_loop_(callback_loop) {}
357
358 virtual void Run() {
brettw@chromium.org191eb3f72010-12-21 06:27:50359 std::vector<webkit::npapi::WebPluginInfo> plugins;
360 webkit::npapi::PluginList::Singleton()->GetPlugins(false, &plugins);
zelidrag@chromium.org85ed9d42010-06-08 22:37:44361 std::string hardware_class; // Empty string by default.
362#if defined(OS_CHROMEOS)
stevenjb@chromium.orgdb342d52010-08-09 21:19:37363 chromeos::SystemLibrary* system_library =
brettw@chromium.org191eb3f72010-12-21 06:27:50364 chromeos::CrosLibrary::Get()->GetSystemLibrary();
stevenjb@chromium.orgdb342d52010-08-09 21:19:37365 system_library->GetMachineStatistic("hardware_class", &hardware_class);
zelidrag@chromium.org85ed9d42010-06-08 22:37:44366#endif // OS_CHROMEOS
367 callback_loop_->PostTask(FROM_HERE, new InitTaskComplete(
368 hardware_class, plugins));
jamesr@chromium.org7f2e792e2009-11-30 23:18:29369 }
370
371 private:
372 MessageLoop* callback_loop_;
373};
evan@chromium.org90d41372009-11-30 21:52:32374
initial.commit09911bf2008-07-26 23:55:29375// static
376void MetricsService::RegisterPrefs(PrefService* local_state) {
377 DCHECK(IsSingleThreaded());
estade@chromium.org20ce516d2010-06-18 02:20:04378 local_state->RegisterStringPref(prefs::kMetricsClientID, "");
robertshield@google.com0bb1a622009-03-04 03:22:32379 local_state->RegisterInt64Pref(prefs::kMetricsClientIDTimestamp, 0);
380 local_state->RegisterInt64Pref(prefs::kStabilityLaunchTimeSec, 0);
381 local_state->RegisterInt64Pref(prefs::kStabilityLastTimestampSec, 0);
estade@chromium.org20ce516d2010-06-18 02:20:04382 local_state->RegisterStringPref(prefs::kStabilityStatsVersion, "");
jar@chromium.org225c50842010-01-19 21:19:13383 local_state->RegisterInt64Pref(prefs::kStabilityStatsBuildTime, 0);
initial.commit09911bf2008-07-26 23:55:29384 local_state->RegisterBooleanPref(prefs::kStabilityExitedCleanly, true);
385 local_state->RegisterBooleanPref(prefs::kStabilitySessionEndCompleted, true);
386 local_state->RegisterIntegerPref(prefs::kMetricsSessionID, -1);
387 local_state->RegisterIntegerPref(prefs::kStabilityLaunchCount, 0);
388 local_state->RegisterIntegerPref(prefs::kStabilityCrashCount, 0);
389 local_state->RegisterIntegerPref(prefs::kStabilityIncompleteSessionEndCount,
390 0);
391 local_state->RegisterIntegerPref(prefs::kStabilityPageLoadCount, 0);
initial.commit09911bf2008-07-26 23:55:29392 local_state->RegisterIntegerPref(prefs::kStabilityRendererCrashCount, 0);
asargent@chromium.org1f085622009-12-04 05:33:45393 local_state->RegisterIntegerPref(prefs::kStabilityExtensionRendererCrashCount,
394 0);
initial.commit09911bf2008-07-26 23:55:29395 local_state->RegisterIntegerPref(prefs::kStabilityRendererHangCount, 0);
asargent@chromium.org1f085622009-12-04 05:33:45396 local_state->RegisterIntegerPref(prefs::kStabilityChildProcessCrashCount, 0);
cpu@google.come73c01972008-08-13 00:18:24397 local_state->RegisterIntegerPref(prefs::kStabilityBreakpadRegistrationFail,
398 0);
399 local_state->RegisterIntegerPref(prefs::kStabilityBreakpadRegistrationSuccess,
400 0);
401 local_state->RegisterIntegerPref(prefs::kStabilityDebuggerPresent, 0);
402 local_state->RegisterIntegerPref(prefs::kStabilityDebuggerNotPresent, 0);
petkov@chromium.orgc1834a92011-01-21 18:21:03403#if defined(OS_CHROMEOS)
404 local_state->RegisterIntegerPref(prefs::kStabilityOtherUserCrashCount, 0);
405 local_state->RegisterIntegerPref(prefs::kStabilityKernelCrashCount, 0);
406 local_state->RegisterIntegerPref(prefs::kStabilitySystemUncleanShutdownCount,
407 0);
408#endif // OS_CHROMEOS
cpu@google.come73c01972008-08-13 00:18:24409
initial.commit09911bf2008-07-26 23:55:29410 local_state->RegisterDictionaryPref(prefs::kProfileMetrics);
411 local_state->RegisterIntegerPref(prefs::kNumBookmarksOnBookmarkBar, 0);
412 local_state->RegisterIntegerPref(prefs::kNumFoldersOnBookmarkBar, 0);
413 local_state->RegisterIntegerPref(prefs::kNumBookmarksInOtherBookmarkFolder,
414 0);
415 local_state->RegisterIntegerPref(prefs::kNumFoldersInOtherBookmarkFolder, 0);
416 local_state->RegisterIntegerPref(prefs::kNumKeywords, 0);
417 local_state->RegisterListPref(prefs::kMetricsInitialLogs);
418 local_state->RegisterListPref(prefs::kMetricsOngoingLogs);
robertshield@google.com0bb1a622009-03-04 03:22:32419
420 local_state->RegisterInt64Pref(prefs::kUninstallMetricsPageLoadCount, 0);
421 local_state->RegisterInt64Pref(prefs::kUninstallLaunchCount, 0);
robertshield@google.com6b5f21d2009-04-13 17:01:35422 local_state->RegisterInt64Pref(prefs::kUninstallMetricsInstallDate, 0);
robertshield@google.com0bb1a622009-03-04 03:22:32423 local_state->RegisterInt64Pref(prefs::kUninstallMetricsUptimeSec, 0);
424 local_state->RegisterInt64Pref(prefs::kUninstallLastLaunchTimeSec, 0);
425 local_state->RegisterInt64Pref(prefs::kUninstallLastObservedRunTimeSec, 0);
initial.commit09911bf2008-07-26 23:55:29426}
427
jar@chromium.org541f77922009-02-23 21:14:38428// static
429void MetricsService::DiscardOldStabilityStats(PrefService* local_state) {
430 local_state->SetBoolean(prefs::kStabilityExitedCleanly, true);
jar@chromium.orgc9abf242009-07-18 06:00:38431 local_state->SetBoolean(prefs::kStabilitySessionEndCompleted, true);
jar@chromium.org541f77922009-02-23 21:14:38432
433 local_state->SetInteger(prefs::kStabilityIncompleteSessionEndCount, 0);
434 local_state->SetInteger(prefs::kStabilityBreakpadRegistrationSuccess, 0);
435 local_state->SetInteger(prefs::kStabilityBreakpadRegistrationFail, 0);
436 local_state->SetInteger(prefs::kStabilityDebuggerPresent, 0);
437 local_state->SetInteger(prefs::kStabilityDebuggerNotPresent, 0);
438
439 local_state->SetInteger(prefs::kStabilityLaunchCount, 0);
440 local_state->SetInteger(prefs::kStabilityCrashCount, 0);
441
442 local_state->SetInteger(prefs::kStabilityPageLoadCount, 0);
443 local_state->SetInteger(prefs::kStabilityRendererCrashCount, 0);
444 local_state->SetInteger(prefs::kStabilityRendererHangCount, 0);
445
jar@chromium.org9165f742010-03-10 22:55:01446 local_state->SetInt64(prefs::kStabilityLaunchTimeSec, 0);
447 local_state->SetInt64(prefs::kStabilityLastTimestampSec, 0);
jar@chromium.org541f77922009-02-23 21:14:38448
449 local_state->ClearPref(prefs::kStabilityPluginStats);
jar@chromium.orgae155cb92009-06-19 06:10:37450
451 ListValue* unsent_initial_logs = local_state->GetMutableList(
452 prefs::kMetricsInitialLogs);
453 unsent_initial_logs->Clear();
454
455 ListValue* unsent_ongoing_logs = local_state->GetMutableList(
456 prefs::kMetricsOngoingLogs);
457 unsent_ongoing_logs->Clear();
jar@chromium.org541f77922009-02-23 21:14:38458}
459
initial.commit09911bf2008-07-26 23:55:29460MetricsService::MetricsService()
petersont@google.comd01b8732008-10-16 02:18:07461 : recording_active_(false),
462 reporting_active_(false),
463 user_permits_upload_(false),
464 server_permits_upload_(true),
465 state_(INITIALIZED),
initial.commit09911bf2008-07-26 23:55:29466 current_fetch_(NULL),
petersont@google.comd01b8732008-10-16 02:18:07467 idle_since_last_transmission_(false),
initial.commit09911bf2008-07-26 23:55:29468 next_window_id_(0),
maruel@chromium.org40bcc302009-03-02 20:50:39469 ALLOW_THIS_IN_INITIALIZER_LIST(log_sender_factory_(this)),
470 ALLOW_THIS_IN_INITIALIZER_LIST(state_saver_factory_(this)),
petersont@google.com252873ef2008-08-04 21:59:45471 interlog_duration_(TimeDelta::FromSeconds(kInitialInterlogDuration)),
petersont@google.comd01b8732008-10-16 02:18:07472 log_event_limit_(kInitialEventLimit),
initial.commit09911bf2008-07-26 23:55:29473 timer_pending_(false) {
474 DCHECK(IsSingleThreaded());
475 InitializeMetricsState();
476}
477
478MetricsService::~MetricsService() {
479 SetRecording(false);
480}
481
petersont@google.comd01b8732008-10-16 02:18:07482void MetricsService::SetUserPermitsUpload(bool enabled) {
483 HandleIdleSinceLastTransmission(false);
484 user_permits_upload_ = enabled;
485}
486
487void MetricsService::Start() {
488 SetRecording(true);
489 SetReporting(true);
490}
491
492void MetricsService::StartRecordingOnly() {
493 SetRecording(true);
494 SetReporting(false);
495}
496
497void MetricsService::Stop() {
498 SetReporting(false);
499 SetRecording(false);
500}
501
initial.commit09911bf2008-07-26 23:55:29502void MetricsService::SetRecording(bool enabled) {
503 DCHECK(IsSingleThreaded());
504
petersont@google.comd01b8732008-10-16 02:18:07505 if (enabled == recording_active_)
initial.commit09911bf2008-07-26 23:55:29506 return;
507
508 if (enabled) {
jar@chromium.orgb0c819f2009-03-08 04:52:15509 if (client_id_.empty()) {
510 PrefService* pref = g_browser_process->local_state();
511 DCHECK(pref);
estade@chromium.orgddd231e2010-06-29 20:35:19512 client_id_ = pref->GetString(prefs::kMetricsClientID);
jar@chromium.orgb0c819f2009-03-08 04:52:15513 if (client_id_.empty()) {
514 client_id_ = GenerateClientID();
estade@chromium.orgddd231e2010-06-29 20:35:19515 pref->SetString(prefs::kMetricsClientID, client_id_);
jar@chromium.orgb0c819f2009-03-08 04:52:15516
517 // Might as well make a note of how long this ID has existed
518 pref->SetString(prefs::kMetricsClientIDTimestamp,
brettw@chromium.org528c56d2010-07-30 19:28:44519 base::Int64ToString(Time::Now().ToTimeT()));
jar@chromium.orgb0c819f2009-03-08 04:52:15520 }
521 }
kuchhal@chromium.org157d5472009-11-05 22:31:03522 child_process_logging::SetClientId(client_id_);
initial.commit09911bf2008-07-26 23:55:29523 StartRecording();
pkasting@chromium.org005ef3e2009-05-22 20:55:46524
525 registrar_.Add(this, NotificationType::BROWSER_OPENED,
526 NotificationService::AllSources());
527 registrar_.Add(this, NotificationType::BROWSER_CLOSED,
528 NotificationService::AllSources());
529 registrar_.Add(this, NotificationType::USER_ACTION,
530 NotificationService::AllSources());
531 registrar_.Add(this, NotificationType::TAB_PARENTED,
532 NotificationService::AllSources());
533 registrar_.Add(this, NotificationType::TAB_CLOSING,
534 NotificationService::AllSources());
535 registrar_.Add(this, NotificationType::LOAD_START,
536 NotificationService::AllSources());
537 registrar_.Add(this, NotificationType::LOAD_STOP,
538 NotificationService::AllSources());
kkania@chromium.orgcd69619b2010-05-05 02:41:38539 registrar_.Add(this, NotificationType::RENDERER_PROCESS_CLOSED,
pkasting@chromium.org005ef3e2009-05-22 20:55:46540 NotificationService::AllSources());
541 registrar_.Add(this, NotificationType::RENDERER_PROCESS_HANG,
542 NotificationService::AllSources());
543 registrar_.Add(this, NotificationType::CHILD_PROCESS_HOST_CONNECTED,
544 NotificationService::AllSources());
545 registrar_.Add(this, NotificationType::CHILD_INSTANCE_CREATED,
546 NotificationService::AllSources());
547 registrar_.Add(this, NotificationType::CHILD_PROCESS_CRASHED,
548 NotificationService::AllSources());
549 registrar_.Add(this, NotificationType::TEMPLATE_URL_MODEL_LOADED,
550 NotificationService::AllSources());
551 registrar_.Add(this, NotificationType::OMNIBOX_OPENED_URL,
552 NotificationService::AllSources());
553 registrar_.Add(this, NotificationType::BOOKMARK_MODEL_LOADED,
554 NotificationService::AllSources());
initial.commit09911bf2008-07-26 23:55:29555 } else {
pkasting@chromium.org005ef3e2009-05-22 20:55:46556 registrar_.RemoveAll();
initial.commit09911bf2008-07-26 23:55:29557 PushPendingLogsToUnsentLists();
558 DCHECK(!pending_log());
559 if (state_ > INITIAL_LOG_READY && unsent_logs())
560 state_ = SEND_OLD_INITIAL_LOGS;
561 }
petersont@google.comd01b8732008-10-16 02:18:07562 recording_active_ = enabled;
initial.commit09911bf2008-07-26 23:55:29563}
564
petersont@google.comd01b8732008-10-16 02:18:07565bool MetricsService::recording_active() const {
initial.commit09911bf2008-07-26 23:55:29566 DCHECK(IsSingleThreaded());
petersont@google.comd01b8732008-10-16 02:18:07567 return recording_active_;
initial.commit09911bf2008-07-26 23:55:29568}
569
petersont@google.comd01b8732008-10-16 02:18:07570void MetricsService::SetReporting(bool enable) {
571 if (reporting_active_ != enable) {
572 reporting_active_ = enable;
573 if (reporting_active_)
initial.commit09911bf2008-07-26 23:55:29574 StartLogTransmissionTimer();
575 }
petersont@google.comd01b8732008-10-16 02:18:07576}
577
578bool MetricsService::reporting_active() const {
579 DCHECK(IsSingleThreaded());
580 return reporting_active_;
initial.commit09911bf2008-07-26 23:55:29581}
582
583void MetricsService::Observe(NotificationType type,
584 const NotificationSource& source,
585 const NotificationDetails& details) {
586 DCHECK(current_log_);
587 DCHECK(IsSingleThreaded());
588
589 if (!CanLogNotification(type, source, details))
590 return;
591
brettw@chromium.orgbfd04a62009-02-01 18:16:56592 switch (type.value) {
593 case NotificationType::USER_ACTION:
evan@chromium.orgafe3a1672009-11-17 19:04:12594 current_log_->RecordUserAction(*Details<const char*>(details).ptr());
initial.commit09911bf2008-07-26 23:55:29595 break;
596
brettw@chromium.orgbfd04a62009-02-01 18:16:56597 case NotificationType::BROWSER_OPENED:
598 case NotificationType::BROWSER_CLOSED:
initial.commit09911bf2008-07-26 23:55:29599 LogWindowChange(type, source, details);
600 break;
601
brettw@chromium.orgbfd04a62009-02-01 18:16:56602 case NotificationType::TAB_PARENTED:
603 case NotificationType::TAB_CLOSING:
initial.commit09911bf2008-07-26 23:55:29604 LogWindowChange(type, source, details);
605 break;
606
brettw@chromium.orgbfd04a62009-02-01 18:16:56607 case NotificationType::LOAD_STOP:
initial.commit09911bf2008-07-26 23:55:29608 LogLoadComplete(type, source, details);
609 break;
610
brettw@chromium.orgbfd04a62009-02-01 18:16:56611 case NotificationType::LOAD_START:
initial.commit09911bf2008-07-26 23:55:29612 LogLoadStarted();
613 break;
614
gspencer@chromium.org443b80e2010-12-14 00:42:23615 case NotificationType::RENDERER_PROCESS_CLOSED: {
kkania@chromium.orgcd69619b2010-05-05 02:41:38616 RenderProcessHost::RendererClosedDetails* process_details =
617 Details<RenderProcessHost::RendererClosedDetails>(details).ptr();
gspencer@chromium.org443b80e2010-12-14 00:42:23618 if (process_details->status ==
619 base::TERMINATION_STATUS_PROCESS_CRASHED ||
620 process_details->status ==
621 base::TERMINATION_STATUS_ABNORMAL_TERMINATION) {
kkania@chromium.orgcd69619b2010-05-05 02:41:38622 if (process_details->was_extension_renderer) {
623 LogExtensionRendererCrash();
624 } else {
625 LogRendererCrash();
626 }
627 }
asargent@chromium.org1f085622009-12-04 05:33:45628 }
initial.commit09911bf2008-07-26 23:55:29629 break;
630
brettw@chromium.orgbfd04a62009-02-01 18:16:56631 case NotificationType::RENDERER_PROCESS_HANG:
initial.commit09911bf2008-07-26 23:55:29632 LogRendererHang();
633 break;
634
jam@chromium.orga27a9382009-02-11 23:55:10635 case NotificationType::CHILD_PROCESS_HOST_CONNECTED:
636 case NotificationType::CHILD_PROCESS_CRASHED:
637 case NotificationType::CHILD_INSTANCE_CREATED:
638 LogChildProcessChange(type, source, details);
initial.commit09911bf2008-07-26 23:55:29639 break;
640
brettw@chromium.orgbfd04a62009-02-01 18:16:56641 case NotificationType::TEMPLATE_URL_MODEL_LOADED:
initial.commit09911bf2008-07-26 23:55:29642 LogKeywords(Source<TemplateURLModel>(source).ptr());
643 break;
644
ananta@chromium.org1226abb2010-06-10 18:01:28645 case NotificationType::OMNIBOX_OPENED_URL: {
646 MetricsLog* current_log = current_log_->AsMetricsLog();
647 DCHECK(current_log);
648 current_log->RecordOmniboxOpenedURL(
initial.commit09911bf2008-07-26 23:55:29649 *Details<AutocompleteLog>(details).ptr());
650 break;
ananta@chromium.org1226abb2010-06-10 18:01:28651 }
initial.commit09911bf2008-07-26 23:55:29652
tim@chromium.orgb61236c62009-04-09 22:43:55653 case NotificationType::BOOKMARK_MODEL_LOADED: {
654 Profile* p = Source<Profile>(source).ptr();
655 if (p)
656 LogBookmarks(p->GetBookmarkModel());
initial.commit09911bf2008-07-26 23:55:29657 break;
tim@chromium.orgb61236c62009-04-09 22:43:55658 }
initial.commit09911bf2008-07-26 23:55:29659 default:
jar@chromium.orga063c102010-07-22 22:20:19660 NOTREACHED();
initial.commit09911bf2008-07-26 23:55:29661 break;
662 }
petersont@google.comd01b8732008-10-16 02:18:07663
664 HandleIdleSinceLastTransmission(false);
665
666 if (current_log_)
pkasting@chromium.org666205032010-10-21 20:56:58667 DVLOG(1) << "METRICS: NUMBER OF EVENTS = " << current_log_->num_events();
petersont@google.comd01b8732008-10-16 02:18:07668}
669
670void MetricsService::HandleIdleSinceLastTransmission(bool in_idle) {
671 // If there wasn't a lot of action, maybe the computer was asleep, in which
672 // case, the log transmissions should have stopped. Here we start them up
673 // again.
pkasting@chromium.orgcac78842008-11-27 01:02:20674 if (!in_idle && idle_since_last_transmission_)
675 StartLogTransmissionTimer();
676 idle_since_last_transmission_ = in_idle;
initial.commit09911bf2008-07-26 23:55:29677}
678
679void MetricsService::RecordCleanShutdown() {
680 RecordBooleanPrefValue(prefs::kStabilityExitedCleanly, true);
681}
682
683void MetricsService::RecordStartOfSessionEnd() {
684 RecordBooleanPrefValue(prefs::kStabilitySessionEndCompleted, false);
685}
686
687void MetricsService::RecordCompletedSessionEnd() {
688 RecordBooleanPrefValue(prefs::kStabilitySessionEndCompleted, true);
689}
690
cpu@google.come73c01972008-08-13 00:18:24691void MetricsService:: RecordBreakpadRegistration(bool success) {
jar@google.com68475e602008-08-22 03:21:15692 if (!success)
cpu@google.come73c01972008-08-13 00:18:24693 IncrementPrefValue(prefs::kStabilityBreakpadRegistrationFail);
694 else
695 IncrementPrefValue(prefs::kStabilityBreakpadRegistrationSuccess);
696}
697
698void MetricsService::RecordBreakpadHasDebugger(bool has_debugger) {
699 if (!has_debugger)
700 IncrementPrefValue(prefs::kStabilityDebuggerNotPresent);
701 else
jar@google.com68475e602008-08-22 03:21:15702 IncrementPrefValue(prefs::kStabilityDebuggerPresent);
cpu@google.come73c01972008-08-13 00:18:24703}
704
initial.commit09911bf2008-07-26 23:55:29705//------------------------------------------------------------------------------
706// private methods
707//------------------------------------------------------------------------------
708
709
710//------------------------------------------------------------------------------
711// Initialization methods
712
713void MetricsService::InitializeMetricsState() {
kuchhal@chromium.org79bf0b72009-04-27 21:30:55714#if defined(OS_POSIX)
715 server_url_ = L"https://clients4.google.com/firefox/metrics/collect";
716#else
717 BrowserDistribution* dist = BrowserDistribution::GetDistribution();
718 server_url_ = dist->GetStatsServerURL();
719#endif
720
initial.commit09911bf2008-07-26 23:55:29721 PrefService* pref = g_browser_process->local_state();
722 DCHECK(pref);
723
jar@chromium.org225c50842010-01-19 21:19:13724 if ((pref->GetInt64(prefs::kStabilityStatsBuildTime)
725 != MetricsLog::GetBuildTime()) ||
estade@chromium.orgddd231e2010-06-29 20:35:19726 (pref->GetString(prefs::kStabilityStatsVersion)
jar@chromium.org225c50842010-01-19 21:19:13727 != MetricsLog::GetVersionString())) {
jar@chromium.org541f77922009-02-23 21:14:38728 // This is a new version, so we don't want to confuse the stats about the
729 // old version with info that we upload.
730 DiscardOldStabilityStats(pref);
731 pref->SetString(prefs::kStabilityStatsVersion,
estade@chromium.orgddd231e2010-06-29 20:35:19732 MetricsLog::GetVersionString());
jar@chromium.org225c50842010-01-19 21:19:13733 pref->SetInt64(prefs::kStabilityStatsBuildTime,
734 MetricsLog::GetBuildTime());
jar@chromium.org541f77922009-02-23 21:14:38735 }
736
initial.commit09911bf2008-07-26 23:55:29737 // Update session ID
738 session_id_ = pref->GetInteger(prefs::kMetricsSessionID);
739 ++session_id_;
740 pref->SetInteger(prefs::kMetricsSessionID, session_id_);
741
initial.commit09911bf2008-07-26 23:55:29742 // Stability bookkeeping
cpu@google.come73c01972008-08-13 00:18:24743 IncrementPrefValue(prefs::kStabilityLaunchCount);
initial.commit09911bf2008-07-26 23:55:29744
cpu@google.come73c01972008-08-13 00:18:24745 if (!pref->GetBoolean(prefs::kStabilityExitedCleanly)) {
746 IncrementPrefValue(prefs::kStabilityCrashCount);
initial.commit09911bf2008-07-26 23:55:29747 }
cpu@google.come73c01972008-08-13 00:18:24748
749 // This will be set to 'true' if we exit cleanly.
initial.commit09911bf2008-07-26 23:55:29750 pref->SetBoolean(prefs::kStabilityExitedCleanly, false);
751
cpu@google.come73c01972008-08-13 00:18:24752 if (!pref->GetBoolean(prefs::kStabilitySessionEndCompleted)) {
753 IncrementPrefValue(prefs::kStabilityIncompleteSessionEndCount);
jar@chromium.orgc9abf242009-07-18 06:00:38754 // This is marked false when we get a WM_ENDSESSION.
755 pref->SetBoolean(prefs::kStabilitySessionEndCompleted, true);
initial.commit09911bf2008-07-26 23:55:29756 }
initial.commit09911bf2008-07-26 23:55:29757
jar@chromium.org9165f742010-03-10 22:55:01758 // Initialize uptime counters.
759 int64 startup_uptime = MetricsLog::GetIncrementalUptime(pref);
mad@google.comae393ec702010-06-27 16:23:14760 DCHECK_EQ(0, startup_uptime);
jar@chromium.org9165f742010-03-10 22:55:01761 // For backwards compatibility, leave this intact in case Omaha is checking
762 // them. prefs::kStabilityLastTimestampSec may also be useless now.
763 // TODO(jar): Delete these if they have no uses.
robertshield@google.com0bb1a622009-03-04 03:22:32764 pref->SetInt64(prefs::kStabilityLaunchTimeSec, Time::Now().ToTimeT());
765
766 // Bookkeeping for the uninstall metrics.
767 IncrementLongPrefsValue(prefs::kUninstallLaunchCount);
initial.commit09911bf2008-07-26 23:55:29768
769 // Save profile metrics.
770 PrefService* prefs = g_browser_process->local_state();
771 if (prefs) {
772 // Remove the current dictionary and store it for use when sending data to
773 // server. By removing the value we prune potentially dead profiles
774 // (and keys). All valid values are added back once services startup.
775 const DictionaryValue* profile_dictionary =
776 prefs->GetDictionary(prefs::kProfileMetrics);
777 if (profile_dictionary) {
778 // Do a deep copy of profile_dictionary since ClearPref will delete it.
779 profile_dictionary_.reset(static_cast<DictionaryValue*>(
780 profile_dictionary->DeepCopy()));
781 prefs->ClearPref(prefs::kProfileMetrics);
782 }
783 }
784
jar@chromium.org92745242009-06-12 16:52:21785 // Get stats on use of command line.
786 const CommandLine* command_line(CommandLine::ForCurrentProcess());
787 size_t common_commands = 0;
788 if (command_line->HasSwitch(switches::kUserDataDir)) {
789 ++common_commands;
790 UMA_HISTOGRAM_COUNTS_100("Chrome.CommandLineDatDirCount", 1);
791 }
792
793 if (command_line->HasSwitch(switches::kApp)) {
794 ++common_commands;
795 UMA_HISTOGRAM_COUNTS_100("Chrome.CommandLineAppModeCount", 1);
796 }
797
798 UMA_HISTOGRAM_COUNTS_100("Chrome.CommandLineFlagCount",
799 command_line->GetSwitchCount());
800 UMA_HISTOGRAM_COUNTS_100("Chrome.CommandLineUncommonFlagCount",
801 command_line->GetSwitchCount() - common_commands);
802
initial.commit09911bf2008-07-26 23:55:29803 // Kick off the process of saving the state (so the uptime numbers keep
804 // getting updated) every n minutes.
805 ScheduleNextStateSave();
806}
807
zelidrag@chromium.org85ed9d42010-06-08 22:37:44808void MetricsService::OnInitTaskComplete(
809 const std::string& hardware_class,
brettw@chromium.org191eb3f72010-12-21 06:27:50810 const std::vector<webkit::npapi::WebPluginInfo>& plugins) {
zelidrag@chromium.org85ed9d42010-06-08 22:37:44811 DCHECK(state_ == INIT_TASK_SCHEDULED);
812 hardware_class_ = hardware_class;
jam@chromium.org35fa6a22009-08-15 00:04:01813 plugins_ = plugins;
zelidrag@chromium.org85ed9d42010-06-08 22:37:44814 if (state_ == INIT_TASK_SCHEDULED)
815 state_ = INIT_TASK_DONE;
initial.commit09911bf2008-07-26 23:55:29816}
817
818std::string MetricsService::GenerateClientID() {
dhollowa@chromium.org3469e7e2010-10-14 20:34:59819 return guid::GenerateGUID();
initial.commit09911bf2008-07-26 23:55:29820}
821
initial.commit09911bf2008-07-26 23:55:29822//------------------------------------------------------------------------------
823// State save methods
824
825void MetricsService::ScheduleNextStateSave() {
826 state_saver_factory_.RevokeAll();
827
828 MessageLoop::current()->PostDelayedTask(FROM_HERE,
829 state_saver_factory_.NewRunnableMethod(&MetricsService::SaveLocalState),
830 kSaveStateInterval * 1000);
831}
832
833void MetricsService::SaveLocalState() {
834 PrefService* pref = g_browser_process->local_state();
835 if (!pref) {
jar@chromium.orga063c102010-07-22 22:20:19836 NOTREACHED();
initial.commit09911bf2008-07-26 23:55:29837 return;
838 }
839
840 RecordCurrentState(pref);
phajdan.jr@chromium.org6faa0e0d2009-04-28 06:50:36841 pref->ScheduleSavePersistentPrefs();
initial.commit09911bf2008-07-26 23:55:29842
jar@chromium.org281d2882009-01-20 20:32:42843 // TODO(jar): Does this run down the batteries????
initial.commit09911bf2008-07-26 23:55:29844 ScheduleNextStateSave();
845}
846
847
848//------------------------------------------------------------------------------
849// Recording control methods
850
851void MetricsService::StartRecording() {
852 if (current_log_)
853 return;
854
855 current_log_ = new MetricsLog(client_id_, session_id_);
856 if (state_ == INITIALIZED) {
857 // We only need to schedule that run once.
zelidrag@chromium.org85ed9d42010-06-08 22:37:44858 state_ = INIT_TASK_SCHEDULED;
initial.commit09911bf2008-07-26 23:55:29859
zelidrag@chromium.org85ed9d42010-06-08 22:37:44860 // Schedules a task on the file thread for execution of slower
861 // initialization steps (such as plugin list generation) necessary
862 // for sending the initial log. This avoids blocking the main UI
863 // thread.
jamesr@chromium.org7f2e792e2009-11-30 23:18:29864 g_browser_process->file_thread()->message_loop()->PostDelayedTask(FROM_HERE,
zelidrag@chromium.org85ed9d42010-06-08 22:37:44865 new InitTask(MessageLoop::current()),
petersont@google.com252873ef2008-08-04 21:59:45866 kInitialInterlogDuration * 1000 / 2);
initial.commit09911bf2008-07-26 23:55:29867 }
868}
869
ananta@chromium.org1226abb2010-06-10 18:01:28870void MetricsService::StopRecording(MetricsLogBase** log) {
initial.commit09911bf2008-07-26 23:55:29871 if (!current_log_)
872 return;
873
ananta@chromium.org1226abb2010-06-10 18:01:28874 MetricsLog* current_log = current_log_->AsMetricsLog();
875 DCHECK(current_log);
876 current_log->set_hardware_class(hardware_class_); // Adds to ongoing logs.
zelidrag@chromium.org85ed9d42010-06-08 22:37:44877
jar@google.com68475e602008-08-22 03:21:15878 // TODO(jar): Integrate bounds on log recording more consistently, so that we
879 // can stop recording logs that are too big much sooner.
petersont@google.comd01b8732008-10-16 02:18:07880 if (current_log_->num_events() > log_event_limit_) {
dsh@google.com553dba62009-02-24 19:08:23881 UMA_HISTOGRAM_COUNTS("UMA.Discarded Log Events",
jar@google.com68475e602008-08-22 03:21:15882 current_log_->num_events());
883 current_log_->CloseLog();
884 delete current_log_;
jar@google.com294638782008-09-24 00:22:41885 current_log_ = NULL;
jar@google.com68475e602008-08-22 03:21:15886 StartRecording(); // Start trivial log to hold our histograms.
887 }
888
jar@google.com0b33f80b2008-12-17 21:34:36889 // Put incremental data (histogram deltas, and realtime stats deltas) at the
jar@google.com147bbc0b2009-01-06 19:37:40890 // end of all log transmissions (initial log handles this separately).
initial.commit09911bf2008-07-26 23:55:29891 // Don't bother if we're going to discard current_log_.
jar@google.com0b33f80b2008-12-17 21:34:36892 if (log) {
ananta@chromium.org1226abb2010-06-10 18:01:28893 current_log->RecordIncrementalStabilityElements();
initial.commit09911bf2008-07-26 23:55:29894 RecordCurrentHistograms();
jar@google.com0b33f80b2008-12-17 21:34:36895 }
initial.commit09911bf2008-07-26 23:55:29896
897 current_log_->CloseLog();
pkasting@chromium.orgcac78842008-11-27 01:02:20898 if (log)
ananta@chromium.org1226abb2010-06-10 18:01:28899 *log = current_log;
pkasting@chromium.orgcac78842008-11-27 01:02:20900 else
initial.commit09911bf2008-07-26 23:55:29901 delete current_log_;
initial.commit09911bf2008-07-26 23:55:29902 current_log_ = NULL;
903}
904
initial.commit09911bf2008-07-26 23:55:29905void MetricsService::PushPendingLogsToUnsentLists() {
906 if (state_ < INITIAL_LOG_READY)
avi@google.com28ab7f92009-01-06 21:39:04907 return; // We didn't and still don't have time to get plugin list etc.
initial.commit09911bf2008-07-26 23:55:29908
909 if (pending_log()) {
910 PreparePendingLogText();
911 if (state_ == INITIAL_LOG_READY) {
912 // We may race here, and send second copy of initial log later.
ziadh@chromium.org46f89e142010-07-19 08:00:42913 unsent_initial_logs_.push_back(compressed_log_);
petersont@google.comd01b8732008-10-16 02:18:07914 state_ = SEND_OLD_INITIAL_LOGS;
initial.commit09911bf2008-07-26 23:55:29915 } else {
jar@chromium.org281d2882009-01-20 20:32:42916 // TODO(jar): Verify correctness in other states, including sending unsent
jar@chromium.org541f77922009-02-23 21:14:38917 // initial logs.
jar@google.com68475e602008-08-22 03:21:15918 PushPendingLogTextToUnsentOngoingLogs();
initial.commit09911bf2008-07-26 23:55:29919 }
920 DiscardPendingLog();
921 }
922 DCHECK(!pending_log());
923 StopRecording(&pending_log_);
924 PreparePendingLogText();
jar@google.com68475e602008-08-22 03:21:15925 PushPendingLogTextToUnsentOngoingLogs();
initial.commit09911bf2008-07-26 23:55:29926 DiscardPendingLog();
927 StoreUnsentLogs();
928}
929
jar@google.com68475e602008-08-22 03:21:15930void MetricsService::PushPendingLogTextToUnsentOngoingLogs() {
petersont@google.comd01b8732008-10-16 02:18:07931 // If UMA response told us not to upload, there's no need to save the pending
932 // log. It wasn't supposed to be uploaded anyway.
933 if (!server_permits_upload_)
934 return;
ziadh@chromium.org46f89e142010-07-19 08:00:42935 if (compressed_log_.length() >
paul@chromium.orgdc6f4962009-02-13 01:25:50936 static_cast<size_t>(kUploadLogAvoidRetransmitSize)) {
dsh@google.com553dba62009-02-24 19:08:23937 UMA_HISTOGRAM_COUNTS("UMA.Large Accumulated Log Not Persisted",
ziadh@chromium.org46f89e142010-07-19 08:00:42938 static_cast<int>(compressed_log_.length()));
jar@google.com68475e602008-08-22 03:21:15939 return;
940 }
ziadh@chromium.org46f89e142010-07-19 08:00:42941 unsent_ongoing_logs_.push_back(compressed_log_);
jar@google.com68475e602008-08-22 03:21:15942}
943
initial.commit09911bf2008-07-26 23:55:29944//------------------------------------------------------------------------------
945// Transmission of logs methods
946
947void MetricsService::StartLogTransmissionTimer() {
petersont@google.comd01b8732008-10-16 02:18:07948 // If we're not reporting, there's no point in starting a log transmission
949 // timer.
950 if (!reporting_active())
951 return;
952
initial.commit09911bf2008-07-26 23:55:29953 if (!current_log_)
954 return; // Recorder is shutdown.
petersont@google.comd01b8732008-10-16 02:18:07955
956 // If there is already a timer running, we leave it running.
957 // If timer_pending is true because the fetch is waiting for a response,
958 // we return for now and let the response handler start the timer.
959 if (timer_pending_)
initial.commit09911bf2008-07-26 23:55:29960 return;
petersont@google.comd01b8732008-10-16 02:18:07961
petersont@google.comd01b8732008-10-16 02:18:07962 // Before starting the timer, set timer_pending_ to true.
initial.commit09911bf2008-07-26 23:55:29963 timer_pending_ = true;
petersont@google.comd01b8732008-10-16 02:18:07964
965 // Right before the UMA transmission gets started, there's one more thing we'd
966 // like to record: the histogram of memory usage, so we spawn a task to
jar@chromium.orgc9a3ef82009-05-28 22:02:46967 // collect the memory details and when that task is finished, it will call
968 // OnMemoryDetailCollectionDone, which will call HistogramSynchronization to
969 // collect histograms from all renderers and then we will call
970 // OnHistogramSynchronizationDone to continue processing.
initial.commit09911bf2008-07-26 23:55:29971 MessageLoop::current()->PostDelayedTask(FROM_HERE,
972 log_sender_factory_.
jar@chromium.orgc9a3ef82009-05-28 22:02:46973 NewRunnableMethod(&MetricsService::LogTransmissionTimerDone),
phajdan.jr@chromium.org743ace42009-06-17 17:23:51974 interlog_duration_.InMilliseconds());
initial.commit09911bf2008-07-26 23:55:29975}
976
jar@chromium.orgc9a3ef82009-05-28 22:02:46977void MetricsService::LogTransmissionTimerDone() {
978 Task* task = log_sender_factory_.
979 NewRunnableMethod(&MetricsService::OnMemoryDetailCollectionDone);
980
thakis@chromium.orgad8e04a2010-11-01 04:16:27981 scoped_refptr<MetricsMemoryDetails> details(new MetricsMemoryDetails(task));
jar@chromium.orgc9a3ef82009-05-28 22:02:46982 details->StartFetch();
983
984 // Collect WebCore cache information to put into a histogram.
pkasting@chromium.org019191a2009-10-02 20:37:27985 for (RenderProcessHost::iterator i(RenderProcessHost::AllHostsIterator());
986 !i.IsAtEnd(); i.Advance())
987 i.GetCurrentValue()->Send(new ViewMsg_GetCacheResourceStats());
jar@chromium.orgc9a3ef82009-05-28 22:02:46988}
989
990void MetricsService::OnMemoryDetailCollectionDone() {
991 DCHECK(IsSingleThreaded());
992
993 // HistogramSynchronizer will Collect histograms from all renderers and it
994 // will call OnHistogramSynchronizationDone (if wait time elapses before it
995 // heard from all renderers, then also it will call
996 // OnHistogramSynchronizationDone).
997
998 // Create a callback_task for OnHistogramSynchronizationDone.
999 Task* callback_task = log_sender_factory_.NewRunnableMethod(
1000 &MetricsService::OnHistogramSynchronizationDone);
1001
1002 // Set up the callback to task to call after we receive histograms from all
1003 // renderer processes. Wait time specifies how long to wait before absolutely
1004 // calling us back on the task.
1005 HistogramSynchronizer::FetchRendererHistogramsAsynchronously(
1006 MessageLoop::current(), callback_task,
1007 kMaxHistogramGatheringWaitDuration);
1008}
1009
1010void MetricsService::OnHistogramSynchronizationDone() {
initial.commit09911bf2008-07-26 23:55:291011 DCHECK(IsSingleThreaded());
1012
petersont@google.comd01b8732008-10-16 02:18:071013 // This function should only be called via timer, so timer_pending_
1014 // should be true.
1015 DCHECK(timer_pending_);
1016 timer_pending_ = false;
initial.commit09911bf2008-07-26 23:55:291017
1018 DCHECK(!current_fetch_.get());
initial.commit09911bf2008-07-26 23:55:291019
petersont@google.comd01b8732008-10-16 02:18:071020 // If we're getting no notifications, then the log won't have much in it, and
1021 // it's possible the computer is about to go to sleep, so don't upload and
1022 // don't restart the transmission timer.
1023 if (idle_since_last_transmission_)
1024 return;
1025
1026 // If somehow there is a fetch in progress, we return setting timer_pending_
1027 // to true and hope things work out.
1028 if (current_fetch_.get()) {
1029 timer_pending_ = true;
1030 return;
1031 }
1032
1033 // If uploads are forbidden by UMA response, there's no point in keeping
1034 // the current_log_, and the more often we delete it, the less likely it is
1035 // to expand forever.
1036 if (!server_permits_upload_ && current_log_) {
1037 StopRecording(NULL);
1038 StartRecording();
1039 }
initial.commit09911bf2008-07-26 23:55:291040
1041 if (!current_log_)
1042 return; // Logging was disabled.
petersont@google.comd01b8732008-10-16 02:18:071043 if (!reporting_active())
initial.commit09911bf2008-07-26 23:55:291044 return; // Don't do work if we're not going to send anything now.
1045
petersont@google.comd01b8732008-10-16 02:18:071046 MakePendingLog();
initial.commit09911bf2008-07-26 23:55:291047
petersont@google.comd01b8732008-10-16 02:18:071048 // MakePendingLog should have put something in the pending log, if it didn't,
1049 // we start the timer again, return and hope things work out.
1050 if (!pending_log()) {
1051 StartLogTransmissionTimer();
1052 return;
1053 }
initial.commit09911bf2008-07-26 23:55:291054
petersont@google.comd01b8732008-10-16 02:18:071055 // If we're not supposed to upload any UMA data because the response or the
1056 // user said so, cancel the upload at this point, but start the timer.
1057 if (!TransmissionPermitted()) {
1058 DiscardPendingLog();
1059 StartLogTransmissionTimer();
1060 return;
1061 }
initial.commit09911bf2008-07-26 23:55:291062
petersont@google.comd01b8732008-10-16 02:18:071063 PrepareFetchWithPendingLog();
1064
1065 if (!current_fetch_.get()) {
1066 // Compression failed, and log discarded :-/.
1067 DiscardPendingLog();
1068 StartLogTransmissionTimer(); // Maybe we'll do better next time
1069 // TODO(jar): If compression failed, we should have created a tiny log and
1070 // compressed that, so that we can signal that we're losing logs.
1071 return;
1072 }
1073
1074 DCHECK(!timer_pending_);
1075
1076 // The URL fetch is a like timer in that after a while we get called back
1077 // so we set timer_pending_ true just as we start the url fetch.
1078 timer_pending_ = true;
1079 current_fetch_->Start();
1080
1081 HandleIdleSinceLastTransmission(true);
1082}
1083
1084
1085void MetricsService::MakePendingLog() {
1086 if (pending_log())
1087 return;
1088
1089 switch (state_) {
1090 case INITIALIZED:
zelidrag@chromium.org85ed9d42010-06-08 22:37:441091 case INIT_TASK_SCHEDULED: // We should be further along by now.
petersont@google.comd01b8732008-10-16 02:18:071092 DCHECK(false);
1093 return;
1094
zelidrag@chromium.org85ed9d42010-06-08 22:37:441095 case INIT_TASK_DONE:
petersont@google.comd01b8732008-10-16 02:18:071096 // We need to wait for the initial log to be ready before sending
1097 // anything, because the server will tell us whether it wants to hear
1098 // from us.
1099 PrepareInitialLog();
zelidrag@chromium.org85ed9d42010-06-08 22:37:441100 DCHECK(state_ == INIT_TASK_DONE);
petersont@google.comd01b8732008-10-16 02:18:071101 RecallUnsentLogs();
1102 state_ = INITIAL_LOG_READY;
1103 break;
1104
1105 case SEND_OLD_INITIAL_LOGS:
pkasting@chromium.orgcac78842008-11-27 01:02:201106 if (!unsent_initial_logs_.empty()) {
ziadh@chromium.org46f89e142010-07-19 08:00:421107 compressed_log_ = unsent_initial_logs_.back();
pkasting@chromium.orgcac78842008-11-27 01:02:201108 break;
1109 }
petersont@google.comd01b8732008-10-16 02:18:071110 state_ = SENDING_OLD_LOGS;
1111 // Fall through.
initial.commit09911bf2008-07-26 23:55:291112
petersont@google.comd01b8732008-10-16 02:18:071113 case SENDING_OLD_LOGS:
1114 if (!unsent_ongoing_logs_.empty()) {
ziadh@chromium.org46f89e142010-07-19 08:00:421115 compressed_log_ = unsent_ongoing_logs_.back();
petersont@google.comd01b8732008-10-16 02:18:071116 break;
1117 }
1118 state_ = SENDING_CURRENT_LOGS;
1119 // Fall through.
1120
1121 case SENDING_CURRENT_LOGS:
1122 StopRecording(&pending_log_);
1123 StartRecording();
1124 break;
1125
1126 default:
jar@chromium.orga063c102010-07-22 22:20:191127 NOTREACHED();
petersont@google.comd01b8732008-10-16 02:18:071128 return;
1129 }
1130
1131 DCHECK(pending_log());
1132}
1133
1134bool MetricsService::TransmissionPermitted() const {
1135 // If the user forbids uploading that's they're business, and we don't upload
1136 // anything. If the server forbids uploading, that's our business, so we take
1137 // that to mean it forbids current logs, but we still send up the inital logs
1138 // and any old logs.
petersont@google.comd01b8732008-10-16 02:18:071139 if (!user_permits_upload_)
1140 return false;
pkasting@chromium.orgcac78842008-11-27 01:02:201141 if (server_permits_upload_)
petersont@google.comd01b8732008-10-16 02:18:071142 return true;
initial.commit09911bf2008-07-26 23:55:291143
pkasting@chromium.orgcac78842008-11-27 01:02:201144 switch (state_) {
1145 case INITIAL_LOG_READY:
1146 case SEND_OLD_INITIAL_LOGS:
1147 case SENDING_OLD_LOGS:
1148 return true;
1149
1150 case SENDING_CURRENT_LOGS:
1151 default:
1152 return false;
nsylvain@chromium.org8c8824b2008-09-20 01:55:501153 }
initial.commit09911bf2008-07-26 23:55:291154}
1155
initial.commit09911bf2008-07-26 23:55:291156void MetricsService::PrepareInitialLog() {
zelidrag@chromium.org85ed9d42010-06-08 22:37:441157 DCHECK(state_ == INIT_TASK_DONE);
initial.commit09911bf2008-07-26 23:55:291158
1159 MetricsLog* log = new MetricsLog(client_id_, session_id_);
zelidrag@chromium.org85ed9d42010-06-08 22:37:441160 log->set_hardware_class(hardware_class_); // Adds to initial log.
jam@chromium.org35fa6a22009-08-15 00:04:011161 log->RecordEnvironment(plugins_, profile_dictionary_.get());
initial.commit09911bf2008-07-26 23:55:291162
1163 // Histograms only get written to current_log_, so setup for the write.
ananta@chromium.org1226abb2010-06-10 18:01:281164 MetricsLogBase* save_log = current_log_;
initial.commit09911bf2008-07-26 23:55:291165 current_log_ = log;
1166 RecordCurrentHistograms(); // Into current_log_... which is really log.
1167 current_log_ = save_log;
1168
1169 log->CloseLog();
1170 DCHECK(!pending_log());
1171 pending_log_ = log;
1172}
1173
ziadh@chromium.org46f89e142010-07-19 08:00:421174// static
1175MetricsService::LogRecallStatus MetricsService::RecallUnsentLogsHelper(
1176 const ListValue& list,
1177 std::vector<std::string>* local_list) {
1178 DCHECK(local_list->empty());
1179 if (list.GetSize() == 0)
1180 return MakeRecallStatusHistogram(LIST_EMPTY);
1181 if (list.GetSize() < 3)
1182 return MakeRecallStatusHistogram(LIST_SIZE_TOO_SMALL);
initial.commit09911bf2008-07-26 23:55:291183
ziadh@chromium.org46f89e142010-07-19 08:00:421184 // The size is stored at the beginning of the list.
1185 int size;
1186 bool valid = (*list.begin())->GetAsInteger(&size);
1187 if (!valid)
1188 return MakeRecallStatusHistogram(LIST_SIZE_MISSING);
1189
1190 // Account for checksum and size included in the list.
1191 if (static_cast<unsigned int>(size) !=
1192 list.GetSize() - kChecksumEntryCount)
1193 return MakeRecallStatusHistogram(LIST_SIZE_CORRUPTION);
1194
1195 MD5Context ctx;
1196 MD5Init(&ctx);
1197 std::string encoded_log;
1198 std::string decoded_log;
1199 for (ListValue::const_iterator it = list.begin() + 1;
1200 it != list.end() - 1; ++it) { // Last element is the checksum.
1201 valid = (*it)->GetAsString(&encoded_log);
1202 if (!valid) {
1203 local_list->clear();
1204 return MakeRecallStatusHistogram(LOG_STRING_CORRUPTION);
1205 }
1206
1207 MD5Update(&ctx, encoded_log.data(), encoded_log.length());
1208
1209 if (!base::Base64Decode(encoded_log, &decoded_log)) {
1210 local_list->clear();
1211 return MakeRecallStatusHistogram(DECODE_FAIL);
1212 }
1213 local_list->push_back(decoded_log);
1214 }
1215
1216 // Verify checksum.
1217 MD5Digest digest;
1218 MD5Final(&digest, &ctx);
1219 std::string recovered_md5;
1220 // We store the hash at the end of the list.
1221 valid = (*(list.end() - 1))->GetAsString(&recovered_md5);
1222 if (!valid) {
1223 local_list->clear();
1224 return MakeRecallStatusHistogram(CHECKSUM_STRING_CORRUPTION);
1225 }
1226 if (recovered_md5 != MD5DigestToBase16(digest)) {
1227 local_list->clear();
1228 return MakeRecallStatusHistogram(CHECKSUM_CORRUPTION);
1229 }
1230 return MakeRecallStatusHistogram(RECALL_SUCCESS);
1231}
1232void MetricsService::RecallUnsentLogs() {
initial.commit09911bf2008-07-26 23:55:291233 PrefService* local_state = g_browser_process->local_state();
1234 DCHECK(local_state);
1235
1236 ListValue* unsent_initial_logs = local_state->GetMutableList(
1237 prefs::kMetricsInitialLogs);
ziadh@chromium.org46f89e142010-07-19 08:00:421238 RecallUnsentLogsHelper(*unsent_initial_logs, &unsent_initial_logs_);
initial.commit09911bf2008-07-26 23:55:291239
1240 ListValue* unsent_ongoing_logs = local_state->GetMutableList(
1241 prefs::kMetricsOngoingLogs);
ziadh@chromium.org46f89e142010-07-19 08:00:421242 RecallUnsentLogsHelper(*unsent_ongoing_logs, &unsent_ongoing_logs_);
1243}
1244
1245// static
1246void MetricsService::StoreUnsentLogsHelper(
1247 const std::vector<std::string>& local_list,
1248 const size_t kMaxLocalListSize,
1249 ListValue* list) {
1250 list->Clear();
1251 size_t start = 0;
1252 if (local_list.size() > kMaxLocalListSize)
1253 start = local_list.size() - kMaxLocalListSize;
1254 DCHECK(start <= local_list.size());
1255 if (local_list.size() == start)
1256 return;
1257
1258 // Store size at the beginning of the list.
1259 list->Append(Value::CreateIntegerValue(local_list.size() - start));
1260
1261 MD5Context ctx;
1262 MD5Init(&ctx);
1263 std::string encoded_log;
1264 for (std::vector<std::string>::const_iterator it = local_list.begin() + start;
1265 it != local_list.end(); ++it) {
1266 // We encode the compressed log as Value::CreateStringValue() expects to
1267 // take a valid UTF8 string.
1268 if (!base::Base64Encode(*it, &encoded_log)) {
1269 MakeStoreStatusHistogram(ENCODE_FAIL);
1270 list->Clear();
1271 return;
1272 }
1273 MD5Update(&ctx, encoded_log.data(), encoded_log.length());
1274 list->Append(Value::CreateStringValue(encoded_log));
initial.commit09911bf2008-07-26 23:55:291275 }
ziadh@chromium.org46f89e142010-07-19 08:00:421276
1277 // Append hash to the end of the list.
1278 MD5Digest digest;
1279 MD5Final(&digest, &ctx);
1280 list->Append(Value::CreateStringValue(MD5DigestToBase16(digest)));
1281 DCHECK(list->GetSize() >= 3); // Minimum of 3 elements (size, data, hash).
ziadh@chromium.org4e95d202010-07-24 01:47:561282 MakeStoreStatusHistogram(STORE_SUCCESS);
initial.commit09911bf2008-07-26 23:55:291283}
1284
1285void MetricsService::StoreUnsentLogs() {
1286 if (state_ < INITIAL_LOG_READY)
1287 return; // We never Recalled the prior unsent logs.
1288
1289 PrefService* local_state = g_browser_process->local_state();
1290 DCHECK(local_state);
1291
1292 ListValue* unsent_initial_logs = local_state->GetMutableList(
1293 prefs::kMetricsInitialLogs);
ziadh@chromium.org46f89e142010-07-19 08:00:421294 StoreUnsentLogsHelper(unsent_initial_logs_, kMaxInitialLogsPersisted,
1295 unsent_initial_logs);
initial.commit09911bf2008-07-26 23:55:291296
1297 ListValue* unsent_ongoing_logs = local_state->GetMutableList(
1298 prefs::kMetricsOngoingLogs);
ziadh@chromium.org46f89e142010-07-19 08:00:421299 StoreUnsentLogsHelper(unsent_ongoing_logs_, kMaxOngoingLogsPersisted,
1300 unsent_ongoing_logs);
initial.commit09911bf2008-07-26 23:55:291301}
1302
1303void MetricsService::PreparePendingLogText() {
1304 DCHECK(pending_log());
ziadh@chromium.org46f89e142010-07-19 08:00:421305 if (!compressed_log_.empty())
initial.commit09911bf2008-07-26 23:55:291306 return;
mark@chromium.org9ffcccf42009-09-15 22:19:181307 int text_size = pending_log_->GetEncodedLogSize();
1308
ziadh@chromium.org46f89e142010-07-19 08:00:421309 std::string pending_log_text;
1310 // Leave room for the NULL terminator.
1311 pending_log_->GetEncodedLog(WriteInto(&pending_log_text, text_size + 1),
mark@chromium.org9ffcccf42009-09-15 22:19:181312 text_size);
ziadh@chromium.org46f89e142010-07-19 08:00:421313
1314 if (Bzip2Compress(pending_log_text, &compressed_log_)) {
1315 // Allow security conscious users to see all metrics logs that we send.
pkasting@chromium.org666205032010-10-21 20:56:581316 VLOG(1) << "COMPRESSED FOLLOWING METRICS LOG: " << pending_log_text;
ziadh@chromium.org46f89e142010-07-19 08:00:421317 } else {
1318 LOG(DFATAL) << "Failed to compress log for transmission.";
1319 // We can't discard the logs as other caller functions expect that
1320 // |compressed_log_| not be empty. We can detect this failure at the server
1321 // after we transmit.
1322 compressed_log_ = "Unable to compress!";
1323 MakeStoreStatusHistogram(COMPRESS_FAIL);
1324 return;
1325 }
initial.commit09911bf2008-07-26 23:55:291326}
1327
petersont@google.comd01b8732008-10-16 02:18:071328void MetricsService::PrepareFetchWithPendingLog() {
initial.commit09911bf2008-07-26 23:55:291329 DCHECK(pending_log());
1330 DCHECK(!current_fetch_.get());
1331 PreparePendingLogText();
ziadh@chromium.org46f89e142010-07-19 08:00:421332 DCHECK(!compressed_log_.empty());
pkasting@chromium.orgcac78842008-11-27 01:02:201333
kuchhal@chromium.org79bf0b72009-04-27 21:30:551334 current_fetch_.reset(new URLFetcher(GURL(WideToUTF16(server_url_)),
1335 URLFetcher::POST,
initial.commit09911bf2008-07-26 23:55:291336 this));
1337 current_fetch_->set_request_context(Profile::GetDefaultRequestContext());
ziadh@chromium.org46f89e142010-07-19 08:00:421338 current_fetch_->set_upload_data(kMetricsType, compressed_log_);
initial.commit09911bf2008-07-26 23:55:291339}
1340
tfarina@chromium.orgf90bf0d92011-01-13 02:12:441341static const char* StatusToString(const net::URLRequestStatus& status) {
initial.commit09911bf2008-07-26 23:55:291342 switch (status.status()) {
tfarina@chromium.orgf90bf0d92011-01-13 02:12:441343 case net::URLRequestStatus::SUCCESS:
initial.commit09911bf2008-07-26 23:55:291344 return "SUCCESS";
1345
tfarina@chromium.orgf90bf0d92011-01-13 02:12:441346 case net::URLRequestStatus::IO_PENDING:
initial.commit09911bf2008-07-26 23:55:291347 return "IO_PENDING";
1348
tfarina@chromium.orgf90bf0d92011-01-13 02:12:441349 case net::URLRequestStatus::HANDLED_EXTERNALLY:
initial.commit09911bf2008-07-26 23:55:291350 return "HANDLED_EXTERNALLY";
1351
tfarina@chromium.orgf90bf0d92011-01-13 02:12:441352 case net::URLRequestStatus::CANCELED:
initial.commit09911bf2008-07-26 23:55:291353 return "CANCELED";
1354
tfarina@chromium.orgf90bf0d92011-01-13 02:12:441355 case net::URLRequestStatus::FAILED:
initial.commit09911bf2008-07-26 23:55:291356 return "FAILED";
1357
1358 default:
jar@chromium.orga063c102010-07-22 22:20:191359 NOTREACHED();
initial.commit09911bf2008-07-26 23:55:291360 return "Unknown";
1361 }
1362}
1363
1364void MetricsService::OnURLFetchComplete(const URLFetcher* source,
1365 const GURL& url,
tfarina@chromium.orgf90bf0d92011-01-13 02:12:441366 const net::URLRequestStatus& status,
initial.commit09911bf2008-07-26 23:55:291367 int response_code,
1368 const ResponseCookies& cookies,
1369 const std::string& data) {
1370 DCHECK(timer_pending_);
1371 timer_pending_ = false;
1372 DCHECK(current_fetch_.get());
1373 current_fetch_.reset(NULL); // We're not allowed to re-use it.
1374
1375 // Confirm send so that we can move on.
pkasting@chromium.org666205032010-10-21 20:56:581376 VLOG(1) << "METRICS RESPONSE CODE: " << response_code
1377 << " status=" << StatusToString(status);
petersont@google.com252873ef2008-08-04 21:59:451378
jar@chromium.org0eb34fee2009-01-21 08:04:381379 // Provide boolean for error recovery (allow us to ignore response_code).
paul@chromium.orgdc6f4962009-02-13 01:25:501380 bool discard_log = false;
jar@chromium.org0eb34fee2009-01-21 08:04:381381
jar@google.com68475e602008-08-22 03:21:151382 if (response_code != 200 &&
ziadh@chromium.org46f89e142010-07-19 08:00:421383 (compressed_log_.length() >
1384 static_cast<size_t>(kUploadLogAvoidRetransmitSize))) {
dsh@google.com553dba62009-02-24 19:08:231385 UMA_HISTOGRAM_COUNTS("UMA.Large Rejected Log was Discarded",
ziadh@chromium.org46f89e142010-07-19 08:00:421386 static_cast<int>(compressed_log_.length()));
jar@chromium.org0eb34fee2009-01-21 08:04:381387 discard_log = true;
1388 } else if (response_code == 400) {
1389 // Bad syntax. Retransmission won't work.
dsh@google.com553dba62009-02-24 19:08:231390 UMA_HISTOGRAM_COUNTS("UMA.Unacceptable_Log_Discarded", state_);
jar@chromium.org0eb34fee2009-01-21 08:04:381391 discard_log = true;
jar@google.com68475e602008-08-22 03:21:151392 }
1393
jar@chromium.org0eb34fee2009-01-21 08:04:381394 if (response_code != 200 && !discard_log) {
pkasting@chromium.org666205032010-10-21 20:56:581395 VLOG(1) << "METRICS: transmission attempt returned a failure code: "
1396 << response_code << ". Verify network connectivity";
petersont@google.com252873ef2008-08-04 21:59:451397 HandleBadResponseCode();
jar@chromium.org0eb34fee2009-01-21 08:04:381398 } else { // Successful receipt (or we are discarding log).
pkasting@chromium.org666205032010-10-21 20:56:581399 VLOG(1) << "METRICS RESPONSE DATA: " << data;
initial.commit09911bf2008-07-26 23:55:291400 switch (state_) {
1401 case INITIAL_LOG_READY:
1402 state_ = SEND_OLD_INITIAL_LOGS;
1403 break;
1404
1405 case SEND_OLD_INITIAL_LOGS:
1406 DCHECK(!unsent_initial_logs_.empty());
1407 unsent_initial_logs_.pop_back();
1408 StoreUnsentLogs();
1409 break;
1410
1411 case SENDING_OLD_LOGS:
1412 DCHECK(!unsent_ongoing_logs_.empty());
1413 unsent_ongoing_logs_.pop_back();
1414 StoreUnsentLogs();
1415 break;
1416
1417 case SENDING_CURRENT_LOGS:
1418 break;
1419
1420 default:
jar@chromium.orga063c102010-07-22 22:20:191421 NOTREACHED();
initial.commit09911bf2008-07-26 23:55:291422 break;
1423 }
petersont@google.comd01b8732008-10-16 02:18:071424
initial.commit09911bf2008-07-26 23:55:291425 DiscardPendingLog();
jar@google.com29be92552008-08-07 22:49:271426 // Since we sent a log, make sure our in-memory state is recorded to disk.
1427 PrefService* local_state = g_browser_process->local_state();
1428 DCHECK(local_state);
1429 if (local_state)
phajdan.jr@chromium.org6faa0e0d2009-04-28 06:50:361430 local_state->ScheduleSavePersistentPrefs();
petersont@google.com252873ef2008-08-04 21:59:451431
jar@google.com147bbc0b2009-01-06 19:37:401432 // Provide a default (free of exponetial backoff, other varances) in case
1433 // the server does not specify a value.
1434 interlog_duration_ = TimeDelta::FromSeconds(kMinSecondsPerLog);
1435
petersont@google.com252873ef2008-08-04 21:59:451436 GetSettingsFromResponseData(data);
petersont@google.com252873ef2008-08-04 21:59:451437 // Override server specified interlog delay if there are unsent logs to
jar@google.com29be92552008-08-07 22:49:271438 // transmit.
initial.commit09911bf2008-07-26 23:55:291439 if (unsent_logs()) {
1440 DCHECK(state_ < SENDING_CURRENT_LOGS);
1441 interlog_duration_ = TimeDelta::FromSeconds(kUnsentLogDelay);
initial.commit09911bf2008-07-26 23:55:291442 }
1443 }
petersont@google.com252873ef2008-08-04 21:59:451444
initial.commit09911bf2008-07-26 23:55:291445 StartLogTransmissionTimer();
1446}
1447
petersont@google.com252873ef2008-08-04 21:59:451448void MetricsService::HandleBadResponseCode() {
pkasting@chromium.org666205032010-10-21 20:56:581449 VLOG(1) << "Verify your metrics logs are formatted correctly. Verify server "
1450 "is active at " << server_url_;
petersont@google.com252873ef2008-08-04 21:59:451451 if (!pending_log()) {
pkasting@chromium.org666205032010-10-21 20:56:581452 VLOG(1) << "METRICS: Recorder shutdown during log transmission.";
petersont@google.com252873ef2008-08-04 21:59:451453 } else {
1454 // Send progressively less frequently.
1455 DCHECK(kBackoff > 1.0);
1456 interlog_duration_ = TimeDelta::FromMicroseconds(
1457 static_cast<int64>(kBackoff * interlog_duration_.InMicroseconds()));
1458
1459 if (kMaxBackoff * TimeDelta::FromSeconds(kMinSecondsPerLog) <
pkasting@chromium.orgcac78842008-11-27 01:02:201460 interlog_duration_) {
petersont@google.com252873ef2008-08-04 21:59:451461 interlog_duration_ = kMaxBackoff *
1462 TimeDelta::FromSeconds(kMinSecondsPerLog);
pkasting@chromium.orgcac78842008-11-27 01:02:201463 }
petersont@google.com252873ef2008-08-04 21:59:451464
pkasting@chromium.org666205032010-10-21 20:56:581465 VLOG(1) << "METRICS: transmission retry being scheduled in "
1466 << interlog_duration_.InSeconds() << " seconds for "
1467 << compressed_log_;
initial.commit09911bf2008-07-26 23:55:291468 }
initial.commit09911bf2008-07-26 23:55:291469}
1470
petersont@google.com252873ef2008-08-04 21:59:451471void MetricsService::GetSettingsFromResponseData(const std::string& data) {
1472 // We assume that the file is structured as a block opened by <response>
petersont@google.comd01b8732008-10-16 02:18:071473 // and that inside response, there is a block opened by tag <chrome_config>
1474 // other tags are ignored for now except the content of <chrome_config>.
pkasting@chromium.org666205032010-10-21 20:56:581475 VLOG(1) << "METRICS: getting settings from response data: " << data;
petersont@google.comd01b8732008-10-16 02:18:071476
petersont@google.com252873ef2008-08-04 21:59:451477 int data_size = static_cast<int>(data.size());
1478 if (data_size < 0) {
pkasting@chromium.org666205032010-10-21 20:56:581479 VLOG(1) << "METRICS: server response data bad size: " << data_size
1480 << "; aborting extraction of settings";
petersont@google.com252873ef2008-08-04 21:59:451481 return;
1482 }
pkasting@chromium.orgcac78842008-11-27 01:02:201483 xmlDocPtr doc = xmlReadMemory(data.c_str(), data_size, "", NULL, 0);
petersont@google.comd01b8732008-10-16 02:18:071484 // If the document is malformed, we just use the settings that were there.
1485 if (!doc) {
pkasting@chromium.org666205032010-10-21 20:56:581486 VLOG(1) << "METRICS: reading xml from server response data failed";
petersont@google.com252873ef2008-08-04 21:59:451487 return;
petersont@google.comd01b8732008-10-16 02:18:071488 }
petersont@google.com252873ef2008-08-04 21:59:451489
petersont@google.comd01b8732008-10-16 02:18:071490 xmlNodePtr top_node = xmlDocGetRootElement(doc), chrome_config_node = NULL;
1491 // Here, we find the chrome_config node by name.
petersont@google.com252873ef2008-08-04 21:59:451492 for (xmlNodePtr p = top_node->children; p; p = p->next) {
petersont@google.comd01b8732008-10-16 02:18:071493 if (xmlStrEqual(p->name, BAD_CAST "chrome_config")) {
1494 chrome_config_node = p;
petersont@google.com252873ef2008-08-04 21:59:451495 break;
1496 }
1497 }
1498 // If the server data is formatted wrong and there is no
1499 // config node where we expect, we just drop out.
petersont@google.comd01b8732008-10-16 02:18:071500 if (chrome_config_node != NULL)
1501 GetSettingsFromChromeConfigNode(chrome_config_node);
petersont@google.com252873ef2008-08-04 21:59:451502 xmlFreeDoc(doc);
1503}
1504
petersont@google.comd01b8732008-10-16 02:18:071505void MetricsService::GetSettingsFromChromeConfigNode(
1506 xmlNodePtr chrome_config_node) {
1507 // Iterate through all children of the config node.
1508 for (xmlNodePtr current_node = chrome_config_node->children;
1509 current_node;
1510 current_node = current_node->next) {
1511 // If we find the upload tag, we appeal to another function
1512 // GetSettingsFromUploadNode to read all the data in it.
petersont@google.com252873ef2008-08-04 21:59:451513 if (xmlStrEqual(current_node->name, BAD_CAST "upload")) {
petersont@google.comd01b8732008-10-16 02:18:071514 GetSettingsFromUploadNode(current_node);
petersont@google.com252873ef2008-08-04 21:59:451515 continue;
1516 }
1517 }
1518}
initial.commit09911bf2008-07-26 23:55:291519
petersont@google.comd01b8732008-10-16 02:18:071520void MetricsService::InheritedProperties::OverwriteWhereNeeded(
1521 xmlNodePtr node) {
1522 xmlChar* salt_value = xmlGetProp(node, BAD_CAST "salt");
1523 if (salt_value) // If the property isn't there, xmlGetProp returns NULL.
1524 salt = atoi(reinterpret_cast<char*>(salt_value));
1525 // If the property isn't there, we keep the value the property had before
1526
1527 xmlChar* denominator_value = xmlGetProp(node, BAD_CAST "denominator");
1528 if (denominator_value)
1529 denominator = atoi(reinterpret_cast<char*>(denominator_value));
1530}
1531
1532void MetricsService::GetSettingsFromUploadNode(xmlNodePtr upload_node) {
1533 InheritedProperties props;
1534 GetSettingsFromUploadNodeRecursive(upload_node, props, "", true);
1535}
1536
pkasting@chromium.orgcac78842008-11-27 01:02:201537void MetricsService::GetSettingsFromUploadNodeRecursive(
1538 xmlNodePtr node,
1539 InheritedProperties props,
1540 std::string path_prefix,
1541 bool uploadOn) {
petersont@google.comd01b8732008-10-16 02:18:071542 props.OverwriteWhereNeeded(node);
1543
1544 // The bool uploadOn is set to true if the data represented by current
1545 // node should be uploaded. This gets inherited in the tree; the children
1546 // of a node that has already been rejected for upload get rejected for
1547 // upload.
1548 uploadOn = uploadOn && NodeProbabilityTest(node, props);
1549
1550 // The path is a / separated list of the node names ancestral to the current
1551 // one. So, if you want to check if the current node has a certain name,
1552 // compare to name. If you want to check if it is a certan tag at a certain
1553 // place in the tree, compare to the whole path.
1554 std::string name = std::string(reinterpret_cast<const char*>(node->name));
1555 std::string path = path_prefix + "/" + name;
1556
1557 if (path == "/upload") {
1558 xmlChar* upload_interval_val = xmlGetProp(node, BAD_CAST "interval");
1559 if (upload_interval_val) {
1560 interlog_duration_ = TimeDelta::FromSeconds(
1561 atoi(reinterpret_cast<char*>(upload_interval_val)));
1562 }
1563
1564 server_permits_upload_ = uploadOn;
ziadh@chromium.org24d07e32010-07-10 00:31:271565 } else if (path == "/upload/logs") {
petersont@google.comd01b8732008-10-16 02:18:071566 xmlChar* log_event_limit_val = xmlGetProp(node, BAD_CAST "event_limit");
1567 if (log_event_limit_val)
1568 log_event_limit_ = atoi(reinterpret_cast<char*>(log_event_limit_val));
1569 }
petersont@google.comd01b8732008-10-16 02:18:071570
1571 // Recursive call. If the node is a leaf i.e. if it ends in a "/>", then it
1572 // doesn't have children, so node->children is NULL, and this loop doesn't
1573 // call (that's how the recursion ends).
1574 for (xmlNodePtr child_node = node->children;
pkasting@chromium.orgcac78842008-11-27 01:02:201575 child_node;
1576 child_node = child_node->next) {
petersont@google.comd01b8732008-10-16 02:18:071577 GetSettingsFromUploadNodeRecursive(child_node, props, path, uploadOn);
1578 }
1579}
1580
1581bool MetricsService::NodeProbabilityTest(xmlNodePtr node,
pkasting@chromium.orgcac78842008-11-27 01:02:201582 InheritedProperties props) const {
petersont@google.comd01b8732008-10-16 02:18:071583 // Default value of probability on any node is 1, but recall that
1584 // its parents can already have been rejected for upload.
1585 double probability = 1;
1586
1587 // If a probability is specified in the node, we use it instead.
1588 xmlChar* probability_value = xmlGetProp(node, BAD_CAST "probability");
1589 if (probability_value)
jar@google.com0b33f80b2008-12-17 21:34:361590 probability = atoi(reinterpret_cast<char*>(probability_value));
petersont@google.comd01b8732008-10-16 02:18:071591
1592 return ProbabilityTest(probability, props.salt, props.denominator);
1593}
1594
1595bool MetricsService::ProbabilityTest(double probability,
1596 int salt,
1597 int denominator) const {
1598 // Okay, first we figure out how many of the digits of the
1599 // client_id_ we need in order to make a nice pseudorandomish
1600 // number in the range [0,denominator). Too many digits is
1601 // fine.
petersont@google.comd01b8732008-10-16 02:18:071602
1603 // n is the length of the client_id_ string
1604 size_t n = client_id_.size();
1605
1606 // idnumber is a positive integer generated from the client_id_.
1607 // It plus salt is going to give us our pseudorandom number.
1608 int idnumber = 0;
1609 const char* client_id_c_str = client_id_.c_str();
1610
1611 // Here we hash the relevant digits of the client_id_
1612 // string somehow to get a big integer idnumber (could be negative
1613 // from wraparound)
1614 int big = 1;
robertshield@google.com5ed73342009-03-18 17:39:431615 int last_pos = n - 1;
1616 for (size_t j = 0; j < n; ++j) {
1617 idnumber += static_cast<int>(client_id_c_str[last_pos - j]) * big;
petersont@google.comd01b8732008-10-16 02:18:071618 big *= 10;
1619 }
1620
1621 // Mod id number by denominator making sure to get a non-negative
1622 // answer.
pkasting@chromium.orgcac78842008-11-27 01:02:201623 idnumber = ((idnumber % denominator) + denominator) % denominator;
petersont@google.comd01b8732008-10-16 02:18:071624
pkasting@chromium.orgcac78842008-11-27 01:02:201625 // ((idnumber + salt) % denominator) / denominator is in the range [0,1]
petersont@google.comd01b8732008-10-16 02:18:071626 // if it's less than probability we call that an affirmative coin
1627 // toss.
pkasting@chromium.orgcac78842008-11-27 01:02:201628 return static_cast<double>((idnumber + salt) % denominator) <
1629 probability * denominator;
petersont@google.comd01b8732008-10-16 02:18:071630}
1631
initial.commit09911bf2008-07-26 23:55:291632void MetricsService::LogWindowChange(NotificationType type,
1633 const NotificationSource& source,
1634 const NotificationDetails& details) {
brettw@google.com534e54b2008-08-13 15:40:091635 int controller_id = -1;
1636 uintptr_t window_or_tab = source.map_key();
initial.commit09911bf2008-07-26 23:55:291637 MetricsLog::WindowEventType window_type;
1638
1639 // Note: since we stop all logging when a single OTR session is active, it is
1640 // possible that we start getting notifications about a window that we don't
1641 // know about.
brettw@google.com534e54b2008-08-13 15:40:091642 if (window_map_.find(window_or_tab) == window_map_.end()) {
1643 controller_id = next_window_id_++;
1644 window_map_[window_or_tab] = controller_id;
initial.commit09911bf2008-07-26 23:55:291645 } else {
brettw@google.com534e54b2008-08-13 15:40:091646 controller_id = window_map_[window_or_tab];
initial.commit09911bf2008-07-26 23:55:291647 }
jar@chromium.org92745242009-06-12 16:52:211648 DCHECK_NE(controller_id, -1);
initial.commit09911bf2008-07-26 23:55:291649
brettw@chromium.orgbfd04a62009-02-01 18:16:561650 switch (type.value) {
1651 case NotificationType::TAB_PARENTED:
1652 case NotificationType::BROWSER_OPENED:
initial.commit09911bf2008-07-26 23:55:291653 window_type = MetricsLog::WINDOW_CREATE;
1654 break;
1655
brettw@chromium.orgbfd04a62009-02-01 18:16:561656 case NotificationType::TAB_CLOSING:
1657 case NotificationType::BROWSER_CLOSED:
brettw@google.com534e54b2008-08-13 15:40:091658 window_map_.erase(window_map_.find(window_or_tab));
initial.commit09911bf2008-07-26 23:55:291659 window_type = MetricsLog::WINDOW_DESTROY;
1660 break;
1661
1662 default:
jar@chromium.orga063c102010-07-22 22:20:191663 NOTREACHED();
paul@chromium.org68d74f02009-02-13 01:36:501664 return;
initial.commit09911bf2008-07-26 23:55:291665 }
1666
brettw@google.com534e54b2008-08-13 15:40:091667 // TODO(brettw) we should have some kind of ID for the parent.
1668 current_log_->RecordWindowEvent(window_type, controller_id, 0);
initial.commit09911bf2008-07-26 23:55:291669}
1670
1671void MetricsService::LogLoadComplete(NotificationType type,
1672 const NotificationSource& source,
1673 const NotificationDetails& details) {
1674 if (details == NotificationService::NoDetails())
1675 return;
1676
jar@google.com68475e602008-08-22 03:21:151677 // TODO(jar): There is a bug causing this to be called too many times, and
1678 // the log overflows. For now, we won't record these events.
dsh@google.com553dba62009-02-24 19:08:231679 UMA_HISTOGRAM_COUNTS("UMA.LogLoadComplete called", 1);
jar@google.com68475e602008-08-22 03:21:151680 return;
1681
initial.commit09911bf2008-07-26 23:55:291682 const Details<LoadNotificationDetails> load_details(details);
brettw@google.com534e54b2008-08-13 15:40:091683 int controller_id = window_map_[details.map_key()];
1684 current_log_->RecordLoadEvent(controller_id,
initial.commit09911bf2008-07-26 23:55:291685 load_details->url(),
1686 load_details->origin(),
1687 load_details->session_index(),
1688 load_details->load_time());
1689}
1690
viettrungluu@chromium.org57ecc4b2010-08-11 03:02:511691void MetricsService::IncrementPrefValue(const char* path) {
cpu@google.come73c01972008-08-13 00:18:241692 PrefService* pref = g_browser_process->local_state();
1693 DCHECK(pref);
1694 int value = pref->GetInteger(path);
1695 pref->SetInteger(path, value + 1);
1696}
1697
viettrungluu@chromium.org57ecc4b2010-08-11 03:02:511698void MetricsService::IncrementLongPrefsValue(const char* path) {
robertshield@google.com0bb1a622009-03-04 03:22:321699 PrefService* pref = g_browser_process->local_state();
1700 DCHECK(pref);
1701 int64 value = pref->GetInt64(path);
jar@chromium.orgb42c5e42010-06-03 20:43:251702 pref->SetInt64(path, value + 1);
robertshield@google.com0bb1a622009-03-04 03:22:321703}
1704
initial.commit09911bf2008-07-26 23:55:291705void MetricsService::LogLoadStarted() {
cpu@google.come73c01972008-08-13 00:18:241706 IncrementPrefValue(prefs::kStabilityPageLoadCount);
robertshield@google.com0bb1a622009-03-04 03:22:321707 IncrementLongPrefsValue(prefs::kUninstallMetricsPageLoadCount);
jar@google.com0b33f80b2008-12-17 21:34:361708 // We need to save the prefs, as page load count is a critical stat, and it
1709 // might be lost due to a crash :-(.
initial.commit09911bf2008-07-26 23:55:291710}
1711
initial.commit09911bf2008-07-26 23:55:291712void MetricsService::LogRendererCrash() {
cpu@google.come73c01972008-08-13 00:18:241713 IncrementPrefValue(prefs::kStabilityRendererCrashCount);
initial.commit09911bf2008-07-26 23:55:291714}
1715
asargent@chromium.org1f085622009-12-04 05:33:451716void MetricsService::LogExtensionRendererCrash() {
1717 IncrementPrefValue(prefs::kStabilityExtensionRendererCrashCount);
1718}
1719
initial.commit09911bf2008-07-26 23:55:291720void MetricsService::LogRendererHang() {
cpu@google.come73c01972008-08-13 00:18:241721 IncrementPrefValue(prefs::kStabilityRendererHangCount);
initial.commit09911bf2008-07-26 23:55:291722}
1723
petkov@chromium.orgc1834a92011-01-21 18:21:031724#if defined(OS_CHROMEOS)
1725void MetricsService::LogChromeOSCrash(const std::string &crash_type) {
1726 if (crash_type == "user")
1727 IncrementPrefValue(prefs::kStabilityOtherUserCrashCount);
1728 else if (crash_type == "kernel")
1729 IncrementPrefValue(prefs::kStabilityKernelCrashCount);
1730 else if (crash_type == "uncleanshutdown")
1731 IncrementPrefValue(prefs::kStabilitySystemUncleanShutdownCount);
1732 else
1733 NOTREACHED() << "Unexpected Chrome OS crash type " << crash_type;
1734 // Wake up metrics logs sending if necessary now that new
1735 // log data is available.
1736 HandleIdleSinceLastTransmission(false);
1737}
1738#endif // OS_CHROMEOS
1739
jam@chromium.orga27a9382009-02-11 23:55:101740void MetricsService::LogChildProcessChange(
1741 NotificationType type,
1742 const NotificationSource& source,
1743 const NotificationDetails& details) {
gregoryd@google.com0d84c5d2009-10-09 01:10:421744 Details<ChildProcessInfo> child_details(details);
1745 const std::wstring& child_name = child_details->name();
1746
jam@chromium.orga27a9382009-02-11 23:55:101747 if (child_process_stats_buffer_.find(child_name) ==
1748 child_process_stats_buffer_.end()) {
gregoryd@google.com0d84c5d2009-10-09 01:10:421749 child_process_stats_buffer_[child_name] =
1750 ChildProcessStats(child_details->type());
initial.commit09911bf2008-07-26 23:55:291751 }
1752
jam@chromium.orga27a9382009-02-11 23:55:101753 ChildProcessStats& stats = child_process_stats_buffer_[child_name];
brettw@chromium.orgbfd04a62009-02-01 18:16:561754 switch (type.value) {
jam@chromium.orga27a9382009-02-11 23:55:101755 case NotificationType::CHILD_PROCESS_HOST_CONNECTED:
initial.commit09911bf2008-07-26 23:55:291756 stats.process_launches++;
1757 break;
1758
jam@chromium.orga27a9382009-02-11 23:55:101759 case NotificationType::CHILD_INSTANCE_CREATED:
initial.commit09911bf2008-07-26 23:55:291760 stats.instances++;
1761 break;
1762
jam@chromium.orga27a9382009-02-11 23:55:101763 case NotificationType::CHILD_PROCESS_CRASHED:
initial.commit09911bf2008-07-26 23:55:291764 stats.process_crashes++;
asargent@chromium.org1f085622009-12-04 05:33:451765 // Exclude plugin crashes from the count below because we report them via
1766 // a separate UMA metric.
1767 if (child_details->type() != ChildProcessInfo::PLUGIN_PROCESS) {
1768 IncrementPrefValue(prefs::kStabilityChildProcessCrashCount);
1769 }
initial.commit09911bf2008-07-26 23:55:291770 break;
1771
1772 default:
jar@chromium.orga063c102010-07-22 22:20:191773 NOTREACHED() << "Unexpected notification type " << type.value;
initial.commit09911bf2008-07-26 23:55:291774 return;
1775 }
1776}
1777
1778// Recursively counts the number of bookmarks and folders in node.
munjal@chromium.orgb3c33d462009-06-26 22:29:201779static void CountBookmarks(const BookmarkNode* node,
1780 int* bookmarks,
1781 int* folders) {
sky@chromium.org037db002009-10-19 20:06:081782 if (node->type() == BookmarkNode::URL)
initial.commit09911bf2008-07-26 23:55:291783 (*bookmarks)++;
1784 else
1785 (*folders)++;
1786 for (int i = 0; i < node->GetChildCount(); ++i)
1787 CountBookmarks(node->GetChild(i), bookmarks, folders);
1788}
1789
munjal@chromium.orgb3c33d462009-06-26 22:29:201790void MetricsService::LogBookmarks(const BookmarkNode* node,
viettrungluu@chromium.org57ecc4b2010-08-11 03:02:511791 const char* num_bookmarks_key,
1792 const char* num_folders_key) {
initial.commit09911bf2008-07-26 23:55:291793 DCHECK(node);
1794 int num_bookmarks = 0;
1795 int num_folders = 0;
1796 CountBookmarks(node, &num_bookmarks, &num_folders);
1797 num_folders--; // Don't include the root folder in the count.
1798
1799 PrefService* pref = g_browser_process->local_state();
1800 DCHECK(pref);
1801 pref->SetInteger(num_bookmarks_key, num_bookmarks);
1802 pref->SetInteger(num_folders_key, num_folders);
1803}
1804
sky@google.comd8e41ed2008-09-11 15:22:321805void MetricsService::LogBookmarks(BookmarkModel* model) {
initial.commit09911bf2008-07-26 23:55:291806 DCHECK(model);
1807 LogBookmarks(model->GetBookmarkBarNode(),
1808 prefs::kNumBookmarksOnBookmarkBar,
1809 prefs::kNumFoldersOnBookmarkBar);
1810 LogBookmarks(model->other_node(),
1811 prefs::kNumBookmarksInOtherBookmarkFolder,
1812 prefs::kNumFoldersInOtherBookmarkFolder);
1813 ScheduleNextStateSave();
1814}
1815
1816void MetricsService::LogKeywords(const TemplateURLModel* url_model) {
1817 DCHECK(url_model);
1818
1819 PrefService* pref = g_browser_process->local_state();
1820 DCHECK(pref);
1821 pref->SetInteger(prefs::kNumKeywords,
1822 static_cast<int>(url_model->GetTemplateURLs().size()));
1823 ScheduleNextStateSave();
1824}
1825
1826void MetricsService::RecordPluginChanges(PrefService* pref) {
1827 ListValue* plugins = pref->GetMutableList(prefs::kStabilityPluginStats);
1828 DCHECK(plugins);
1829
1830 for (ListValue::iterator value_iter = plugins->begin();
1831 value_iter != plugins->end(); ++value_iter) {
1832 if (!(*value_iter)->IsType(Value::TYPE_DICTIONARY)) {
jar@chromium.orga063c102010-07-22 22:20:191833 NOTREACHED();
initial.commit09911bf2008-07-26 23:55:291834 continue;
1835 }
1836
1837 DictionaryValue* plugin_dict = static_cast<DictionaryValue*>(*value_iter);
viettrungluu@chromium.org57ecc4b2010-08-11 03:02:511838 std::string plugin_name;
nsylvain@chromium.org8e50b602009-03-03 22:59:431839 plugin_dict->GetString(prefs::kStabilityPluginName, &plugin_name);
nsylvain@chromium.org6470ee8f2009-03-03 20:46:401840 if (plugin_name.empty()) {
jar@chromium.orga063c102010-07-22 22:20:191841 NOTREACHED();
initial.commit09911bf2008-07-26 23:55:291842 continue;
1843 }
1844
viettrungluu@chromium.org57ecc4b2010-08-11 03:02:511845 // TODO(viettrungluu): remove conversions
1846 if (child_process_stats_buffer_.find(UTF8ToWide(plugin_name)) ==
jam@chromium.orga27a9382009-02-11 23:55:101847 child_process_stats_buffer_.end())
initial.commit09911bf2008-07-26 23:55:291848 continue;
1849
viettrungluu@chromium.org57ecc4b2010-08-11 03:02:511850 ChildProcessStats stats =
1851 child_process_stats_buffer_[UTF8ToWide(plugin_name)];
initial.commit09911bf2008-07-26 23:55:291852 if (stats.process_launches) {
1853 int launches = 0;
nsylvain@chromium.org8e50b602009-03-03 22:59:431854 plugin_dict->GetInteger(prefs::kStabilityPluginLaunches, &launches);
initial.commit09911bf2008-07-26 23:55:291855 launches += stats.process_launches;
nsylvain@chromium.org8e50b602009-03-03 22:59:431856 plugin_dict->SetInteger(prefs::kStabilityPluginLaunches, launches);
initial.commit09911bf2008-07-26 23:55:291857 }
1858 if (stats.process_crashes) {
1859 int crashes = 0;
nsylvain@chromium.org8e50b602009-03-03 22:59:431860 plugin_dict->GetInteger(prefs::kStabilityPluginCrashes, &crashes);
initial.commit09911bf2008-07-26 23:55:291861 crashes += stats.process_crashes;
nsylvain@chromium.org8e50b602009-03-03 22:59:431862 plugin_dict->SetInteger(prefs::kStabilityPluginCrashes, crashes);
initial.commit09911bf2008-07-26 23:55:291863 }
1864 if (stats.instances) {
1865 int instances = 0;
nsylvain@chromium.org8e50b602009-03-03 22:59:431866 plugin_dict->GetInteger(prefs::kStabilityPluginInstances, &instances);
initial.commit09911bf2008-07-26 23:55:291867 instances += stats.instances;
nsylvain@chromium.org8e50b602009-03-03 22:59:431868 plugin_dict->SetInteger(prefs::kStabilityPluginInstances, instances);
initial.commit09911bf2008-07-26 23:55:291869 }
1870
viettrungluu@chromium.org57ecc4b2010-08-11 03:02:511871 child_process_stats_buffer_.erase(UTF8ToWide(plugin_name));
initial.commit09911bf2008-07-26 23:55:291872 }
1873
1874 // Now go through and add dictionaries for plugins that didn't already have
1875 // reports in Local State.
jam@chromium.orga27a9382009-02-11 23:55:101876 for (std::map<std::wstring, ChildProcessStats>::iterator cache_iter =
1877 child_process_stats_buffer_.begin();
1878 cache_iter != child_process_stats_buffer_.end(); ++cache_iter) {
jam@chromium.orga27a9382009-02-11 23:55:101879 ChildProcessStats stats = cache_iter->second;
gregoryd@google.com0d84c5d2009-10-09 01:10:421880
1881 // Insert only plugins information into the plugins list.
1882 if (ChildProcessInfo::PLUGIN_PROCESS != stats.process_type)
1883 continue;
1884
viettrungluu@chromium.org57ecc4b2010-08-11 03:02:511885 // TODO(viettrungluu): remove conversion
1886 std::string plugin_name = WideToUTF8(cache_iter->first);
gregoryd@google.com0d84c5d2009-10-09 01:10:421887
initial.commit09911bf2008-07-26 23:55:291888 DictionaryValue* plugin_dict = new DictionaryValue;
1889
nsylvain@chromium.org8e50b602009-03-03 22:59:431890 plugin_dict->SetString(prefs::kStabilityPluginName, plugin_name);
1891 plugin_dict->SetInteger(prefs::kStabilityPluginLaunches,
initial.commit09911bf2008-07-26 23:55:291892 stats.process_launches);
nsylvain@chromium.org8e50b602009-03-03 22:59:431893 plugin_dict->SetInteger(prefs::kStabilityPluginCrashes,
initial.commit09911bf2008-07-26 23:55:291894 stats.process_crashes);
nsylvain@chromium.org8e50b602009-03-03 22:59:431895 plugin_dict->SetInteger(prefs::kStabilityPluginInstances,
initial.commit09911bf2008-07-26 23:55:291896 stats.instances);
1897 plugins->Append(plugin_dict);
1898 }
jam@chromium.orga27a9382009-02-11 23:55:101899 child_process_stats_buffer_.clear();
initial.commit09911bf2008-07-26 23:55:291900}
1901
1902bool MetricsService::CanLogNotification(NotificationType type,
1903 const NotificationSource& source,
1904 const NotificationDetails& details) {
1905 // We simply don't log anything to UMA if there is a single off the record
1906 // session visible. The problem is that we always notify using the orginal
1907 // profile in order to simplify notification processing.
1908 return !BrowserList::IsOffTheRecordSessionActive();
1909}
1910
viettrungluu@chromium.org57ecc4b2010-08-11 03:02:511911void MetricsService::RecordBooleanPrefValue(const char* path, bool value) {
initial.commit09911bf2008-07-26 23:55:291912 DCHECK(IsSingleThreaded());
1913
1914 PrefService* pref = g_browser_process->local_state();
1915 DCHECK(pref);
1916
1917 pref->SetBoolean(path, value);
1918 RecordCurrentState(pref);
1919}
1920
1921void MetricsService::RecordCurrentState(PrefService* pref) {
robertshield@google.com0bb1a622009-03-04 03:22:321922 pref->SetInt64(prefs::kStabilityLastTimestampSec, Time::Now().ToTimeT());
initial.commit09911bf2008-07-26 23:55:291923
1924 RecordPluginChanges(pref);
1925}
1926
initial.commit09911bf2008-07-26 23:55:291927static bool IsSingleThreaded() {
brettw@chromium.orgce072a72010-12-31 20:02:161928 static base::PlatformThreadId thread_id = 0;
initial.commit09911bf2008-07-26 23:55:291929 if (!thread_id)
brettw@chromium.orgce072a72010-12-31 20:02:161930 thread_id = base::PlatformThread::CurrentId();
1931 return base::PlatformThread::CurrentId() == thread_id;
initial.commit09911bf2008-07-26 23:55:291932}
rvargas@google.com5ccaa412009-11-13 22:00:161933
1934#if defined(OS_CHROMEOS)
sky@chromium.org29cf16772010-04-21 15:13:471935void MetricsService::StartExternalMetrics() {
rvargas@google.com5ccaa412009-11-13 22:00:161936 external_metrics_ = new chromeos::ExternalMetrics;
sky@chromium.org29cf16772010-04-21 15:13:471937 external_metrics_->Start();
rvargas@google.com5ccaa412009-11-13 22:00:161938}
1939#endif