blob: d331803b0637a36171cf7da9077d143f820f4313 [file] [log] [blame]
initial.commit09911bf2008-07-26 23:55:291// Copyright 2008, Google Inc.
2// All rights reserved.
3//
4// Redistribution and use in source and binary forms, with or without
5// modification, are permitted provided that the following conditions are
6// met:
7//
8// * Redistributions of source code must retain the above copyright
9// notice, this list of conditions and the following disclaimer.
10// * Redistributions in binary form must reproduce the above
11// copyright notice, this list of conditions and the following disclaimer
12// in the documentation and/or other materials provided with the
13// distribution.
14// * Neither the name of Google Inc. nor the names of its
15// contributors may be used to endorse or promote products derived from
16// this software without specific prior written permission.
17//
18// THIS SOFTWARE IS PROVIDED BY THE COPYRIGHT HOLDERS AND CONTRIBUTORS
19// "AS IS" AND ANY EXPRESS OR IMPLIED WARRANTIES, INCLUDING, BUT NOT
20// LIMITED TO, THE IMPLIED WARRANTIES OF MERCHANTABILITY AND FITNESS FOR
21// A PARTICULAR PURPOSE ARE DISCLAIMED. IN NO EVENT SHALL THE COPYRIGHT
22// OWNER OR CONTRIBUTORS BE LIABLE FOR ANY DIRECT, INDIRECT, INCIDENTAL,
23// SPECIAL, EXEMPLARY, OR CONSEQUENTIAL DAMAGES (INCLUDING, BUT NOT
24// LIMITED TO, PROCUREMENT OF SUBSTITUTE GOODS OR SERVICES; LOSS OF USE,
25// DATA, OR PROFITS; OR BUSINESS INTERRUPTION) HOWEVER CAUSED AND ON ANY
26// THEORY OF LIABILITY, WHETHER IN CONTRACT, STRICT LIABILITY, OR TORT
27// (INCLUDING NEGLIGENCE OR OTHERWISE) ARISING IN ANY WAY OUT OF THE USE
28// OF THIS SOFTWARE, EVEN IF ADVISED OF THE POSSIBILITY OF SUCH DAMAGE.
29
30
31
32//------------------------------------------------------------------------------
33// Description of the life cycle of a instance of MetricsService.
34//
35// OVERVIEW
36//
37// A MetricsService instance is typically created at application startup. It
38// is the central controller for the acquisition of log data, and the automatic
39// transmission of that log data to an external server. Its major job is to
40// manage logs, grouping them for transmission, and transmitting them. As part
41// of its grouping, MS finalizes logs by including some just-in-time gathered
42// memory statistics, snapshotting the current stats of numerous histograms,
43// closing the logs, translating to XML text, and compressing the results for
44// transmission. Transmission includes submitting a compressed log as data in a
45// URL-get, and retransmitting (or retaining at process termination) if the
46// attempted transmission failed. Retention across process terminations is done
47// using the the PrefServices facilities. The format for the retained
48// logs (ones that never got transmitted) is always the uncompressed textual
49// representation.
50//
51// Logs fall into one of two categories: "Initial logs," and "ongoing logs."
52// There is at most one initial log sent for each complete run of the chrome
53// product (from startup, to browser shutdown). An initial log is generally
54// transmitted some short time (1 minute?) after startup, and includes stats
55// such as recent crash info, the number and types of plugins, etc. The
56// external server's response to the initial log conceptually tells
57// this MS if it should continue transmitting logs (during this session). The
58// server response can actually be much more detailed, and always includes (at
59// a minimum) how often additional ongoing logs should be sent.
60//
61// After the above initial log, a series of ongoing logs will be transmitted.
62// The first ongoing log actually begins to accumulate information stating when
63// the MS was first constructed. Note that even though the initial log is
64// commonly sent a full minute after startup, the initial log does not include
65// much in the way of user stats. The most common interlog period (delay)
66// is 5 minutes. That time period starts when the first user action causes a
67// logging event. This means that if there is no user action, there may be long
68// periods without any (ongoing) log transmissions. Ongoing log typically
69// contain very detailed records of user activities (ex: opened tab, closed
70// tab, fetched URL, maximized window, etc.) In addition, just before an
71// ongoing log is closed out, a call is made to gather memory statistics. Those
72// memory statistics are deposited into a histogram, and the log finalization
73// code is then called. In the finalization, a call to a Histogram server
74// acquires a list of all local histograms that have been flagged for upload
75// to the UMA server.
76//
77// When the browser shuts down, there will typically be a fragment of an ongoing
78// log that has not yet been transmitted. At shutdown time, that fragment
79// is closed (including snapshotting histograms), and converted to text. Note
80// that memory stats are not gathered during shutdown, as gathering *might* be
81// too time consuming. The textual representation of the fragment of the
82// ongoing log is then stored persistently as a string in the PrefServices, for
83// potential transmission during a future run of the product.
84//
85// There are two slightly abnormal shutdown conditions. There is a
86// "disconnected scenario," and a "really fast startup and shutdown" scenario.
87// In the "never connected" situation, the user has (during the running of the
88// process) never established an internet connection. As a result, attempts to
89// transmit the initial log have failed, and a lot(?) of data has accumulated in
90// the ongoing log (which didn't yet get closed, because there was never even a
91// contemplation of sending it). There is also a kindred "lost connection"
92// situation, where a loss of connection prevented an ongoing log from being
93// transmitted, and a (still open) log was stuck accumulating a lot(?) of data,
94// while the earlier log retried its transmission. In both of these
95// disconnected situations, two logs need to be, and are, persistently stored
96// for future transmission.
97//
98// The other unusual shutdown condition, termed "really fast startup and
99// shutdown," involves the deliberate user termination of the process before
100// the initial log is even formed or transmitted. In that situation, no logging
101// is done, but the historical crash statistics remain (unlogged) for inclusion
102// in a future run's initial log. (i.e., we don't lose crash stats).
103//
104// With the above overview, we can now describe the state machine's various
105// stats, based on the State enum specified in the state_ member. Those states
106// are:
107//
108// INITIALIZED, // Constructor was called.
109// PLUGIN_LIST_REQUESTED, // Waiting for DLL list to be loaded.
110// PLUGIN_LIST_ARRIVED, // Waiting for timer to send initial log.
111// INITIAL_LOG_READY, // Initial log generated, and waiting for reply.
112// SEND_OLD_INITIAL_LOGS, // Sending unsent logs from previous session.
113// SENDING_OLD_LOGS, // Sending unsent logs from previous session.
114// SENDING_CURRENT_LOGS, // Sending standard current logs as they accrue.
115//
116// In more detail, we have:
117//
118// INITIALIZED, // Constructor was called.
119// The MS has been constructed, but has taken no actions to compose the
120// initial log.
121//
122// PLUGIN_LIST_REQUESTED, // Waiting for DLL list to be loaded.
123// Typically about 30 seconds after startup, a task is sent to a second thread
124// to get the list of plugins. That task will (when complete) make an async
125// callback (via a Task) to indicate the completion.
126//
127// PLUGIN_LIST_ARRIVED, // Waiting for timer to send initial log.
128// The callback has arrived, and it is now possible for an initial log to be
129// created. This callback typically arrives back less than one second after
130// the task is dispatched.
131//
132// INITIAL_LOG_READY, // Initial log generated, and waiting for reply.
133// This state is entered only after an initial log has been composed, and
134// prepared for transmission. It is also the case that any previously unsent
135// logs have been loaded into instance variables for possible transmission.
136//
137// SEND_OLD_INITIAL_LOGS, // Sending unsent logs from previous session.
138// This state indicates that the initial log for this session has been
139// successfully sent and it is now time to send any "initial logs" that were
140// saved from previous sessions. Most commonly, there are none, but all old
141// logs that were "initial logs" must be sent before this state is exited.
142//
143// SENDING_OLD_LOGS, // Sending unsent logs from previous session.
144// This state indicates that there are no more unsent initial logs, and now any
145// ongoing logs from previous sessions should be transmitted. All such logs
146// will be transmitted before exiting this state, and proceeding with ongoing
147// logs from the current session (see next state).
148//
149// SENDING_CURRENT_LOGS, // Sending standard current logs as they accrue.
150// Current logs are being accumulated. Typically every 5 minutes a log is
151// closed and finalized for transmission, at the same time as a new log is
152// started.
153//
154// The progression through the above states is simple, and sequential, in the
155// most common use cases. States proceed from INITIAL to SENDING_CURRENT_LOGS,
156// and remain in the latter until shutdown.
157//
158// The one unusual case is when the user asks that we stop logging. When that
159// happens, any pending (transmission in progress) log is pushed into the list
160// of old unsent logs (the appropriate list, depending on whether it is an
161// initial log, or an ongoing log). An addition, any log that is currently
162// accumulating is also finalized, and pushed into the unsent log list. With
163// those pushed performed, we regress back to the SEND_OLD_INITIAL_LOGS state in
164// case the user enables log recording again during this session. This way
165// anything we have "pushed back" will be sent automatically if/when we progress
166// back to SENDING_CURRENT_LOG state.
167//
168// Also note that whenever the member variables containing unsent logs are
169// modified (i.e., when we send an old log), we mirror the list of logs into
170// the PrefServices. This ensures that IF we crash, we won't start up and
171// retransmit our old logs again.
172//
173// Due to race conditions, it is always possible that a log file could be sent
174// twice. For example, if a log file is sent, but not yet acknowledged by
175// the external server, and the user shuts down, then a copy of the log may be
176// saved for re-transmission. These duplicates could be filtered out server
177// side, but are not expected to be a significantly statistical problem.
178//
179//
180//------------------------------------------------------------------------------
181
182#include <windows.h>
183
184#include "chrome/browser/metrics_service.h"
185
186#include "base/histogram.h"
187#include "base/path_service.h"
188#include "base/string_util.h"
189#include "base/task.h"
190#include "chrome/app/google_update_settings.h"
191#include "chrome/browser/bookmark_bar_model.h"
192#include "chrome/browser/browser.h"
193#include "chrome/browser/browser_list.h"
194#include "chrome/browser/browser_process.h"
195#include "chrome/browser/load_notification_details.h"
196#include "chrome/browser/memory_details.h"
197#include "chrome/browser/plugin_process_info.h"
198#include "chrome/browser/plugin_service.h"
199#include "chrome/browser/profile.h"
200#include "chrome/browser/render_process_host.h"
201#include "chrome/browser/template_url.h"
202#include "chrome/browser/template_url_model.h"
203#include "chrome/common/chrome_paths.h"
204#include "chrome/common/pref_names.h"
205#include "chrome/common/pref_service.h"
206#include "googleurl/src/gurl.h"
207#include "net/base/load_flags.h"
208#include "third_party/bzip2/bzlib.h"
209
210// Check to see that we're being called on only one thread.
211static bool IsSingleThreaded();
212
213static const char kMetricsURL[] =
214 "https://toolbarqueries.google.com/firefox/metrics/collect";
215
216static const char kMetricsType[] = "application/vnd.mozilla.metrics.bz2";
217
218// The delay, in seconds, after startup before sending the first log message.
219static const int kInitialLogDelay = 60; // one minute
220
221// When we have logs from previous Chrome sessions to send, how long should we
222// delay (in seconds) between each log transmission.
223static const int kUnsentLogDelay = 15; // 15 seconds
224
225// Minimum time a log typically exists before sending, in seconds.
226// This number is supplied by the server, but until we parse it out of a server
227// response, we use this duration to specify how long we should wait before
228// sending the next log. If the channel is busy, such as when there is a
229// failure during an attempt to transmit a previous log, then a log may wait
230// (and continue to accrue now log entries) for a much greater period of time.
231static const int kMinSecondsPerLog = 5 * 60; // five minutes
232
233// We accept suggestions from the log server for how long to wait between
234// submitting logs. We validate that this "suggestion" is at least the
235// following:
236static const int kMinSuggestedSecondsPerLog = 60;
237
238// When we don't succeed at transmitting a log to a server, we progressively
239// wait longer and longer before sending the next log. This backoff process
240// help reduce load on the server, and makes the amount of backoff vary between
241// clients so that a collision (server overload?) on retransmit is less likely.
242// The following is the constant we use to expand that inter-log duration.
243static const double kBackoff = 1.1;
244// We limit the maximum backoff to be no greater than some multiple of the
245// default kMinSecondsPerLog. The following is that maximum ratio.
246static const int kMaxBackoff = 10;
247
248// Interval, in seconds, between state saves.
249static const int kSaveStateInterval = 5 * 60; // five minutes
250
251// The number of "initial" logs we're willing to save, and hope to send during
252// a future Chrome session. Initial logs contain crash stats, and are pretty
253// small.
254static const size_t kMaxInitialLogsPersisted = 20;
255
256// The number of ongoing logs we're willing to save persistently, and hope to
257// send during a this or future sessions. Note that each log will be pretty
258// large, as presumably the related "initial" log wasn't sent (probably nothing
259// was, as the user was probably off-line). As a result, the log probably kept
260// accumulating while the "initial" log was stalled (pending_), and couldn't be
261// sent. As a result, we don't want to save too many of these mega-logs.
262// A "standard shutdown" will create a small log, including just the data that
263// was not yet been transmitted, and that is normal (to have exactly one
264// ongoing_log_ at startup).
265static const size_t kMaxOngoingLogsPersisted = 4;
266
267
268// Handles asynchronous fetching of memory details.
269// Will run the provided task after finished.
270class MetricsMemoryDetails : public MemoryDetails {
271 public:
272 explicit MetricsMemoryDetails(Task* completion) : completion_(completion) {}
273
274 virtual void OnDetailsAvailable() {
275 MessageLoop::current()->PostTask(FROM_HERE, completion_);
276 }
277
278 private:
279 Task* completion_;
280 DISALLOW_EVIL_CONSTRUCTORS(MetricsMemoryDetails);
281};
282
283class MetricsService::GetPluginListTaskComplete : public Task {
284 virtual void Run() {
285 g_browser_process->metrics_service()->OnGetPluginListTaskComplete();
286 }
287};
288
289class MetricsService::GetPluginListTask : public Task {
290 public:
291 explicit GetPluginListTask(MessageLoop* callback_loop)
292 : callback_loop_(callback_loop) {}
293
294 virtual void Run() {
295 std::vector<WebPluginInfo> plugins;
296 PluginService::GetInstance()->GetPlugins(false, &plugins);
297
298 callback_loop_->PostTask(FROM_HERE, new GetPluginListTaskComplete());
299 }
300
301 private:
302 MessageLoop* callback_loop_;
303};
304
305// static
306void MetricsService::RegisterPrefs(PrefService* local_state) {
307 DCHECK(IsSingleThreaded());
308 local_state->RegisterStringPref(prefs::kMetricsClientID, L"");
309 local_state->RegisterStringPref(prefs::kMetricsClientIDTimestamp, L"0");
310 local_state->RegisterStringPref(prefs::kStabilityLaunchTimeSec, L"0");
311 local_state->RegisterStringPref(prefs::kStabilityLastTimestampSec, L"0");
312 local_state->RegisterStringPref(prefs::kStabilityUptimeSec, L"0");
313 local_state->RegisterBooleanPref(prefs::kStabilityExitedCleanly, true);
314 local_state->RegisterBooleanPref(prefs::kStabilitySessionEndCompleted, true);
315 local_state->RegisterIntegerPref(prefs::kMetricsSessionID, -1);
316 local_state->RegisterIntegerPref(prefs::kStabilityLaunchCount, 0);
317 local_state->RegisterIntegerPref(prefs::kStabilityCrashCount, 0);
318 local_state->RegisterIntegerPref(prefs::kStabilityIncompleteSessionEndCount,
319 0);
320 local_state->RegisterIntegerPref(prefs::kStabilityPageLoadCount, 0);
321 local_state->RegisterIntegerPref(prefs::kSecurityRendererOnSboxDesktop, 0);
322 local_state->RegisterIntegerPref(prefs::kSecurityRendererOnDefaultDesktop, 0);
323 local_state->RegisterIntegerPref(prefs::kStabilityRendererCrashCount, 0);
324 local_state->RegisterIntegerPref(prefs::kStabilityRendererHangCount, 0);
325 local_state->RegisterDictionaryPref(prefs::kProfileMetrics);
326 local_state->RegisterIntegerPref(prefs::kNumBookmarksOnBookmarkBar, 0);
327 local_state->RegisterIntegerPref(prefs::kNumFoldersOnBookmarkBar, 0);
328 local_state->RegisterIntegerPref(prefs::kNumBookmarksInOtherBookmarkFolder,
329 0);
330 local_state->RegisterIntegerPref(prefs::kNumFoldersInOtherBookmarkFolder, 0);
331 local_state->RegisterIntegerPref(prefs::kNumKeywords, 0);
332 local_state->RegisterListPref(prefs::kMetricsInitialLogs);
333 local_state->RegisterListPref(prefs::kMetricsOngoingLogs);
334}
335
336MetricsService::MetricsService()
337 : recording_(false),
338 reporting_(true),
339 pending_log_(NULL),
340 pending_log_text_(""),
341 current_fetch_(NULL),
342 current_log_(NULL),
343 state_(INITIALIZED),
344 next_window_id_(0),
345 log_sender_factory_(this),
346 state_saver_factory_(this),
347 logged_samples_(),
348 interlog_duration_(TimeDelta::FromSeconds(kInitialLogDelay)),
349 timer_pending_(false) {
350 DCHECK(IsSingleThreaded());
351 InitializeMetricsState();
352}
353
354MetricsService::~MetricsService() {
355 SetRecording(false);
356}
357
358void MetricsService::SetRecording(bool enabled) {
359 DCHECK(IsSingleThreaded());
360
361 if (enabled == recording_)
362 return;
363
364 if (enabled) {
365 StartRecording();
366 ListenerRegistration(true);
367 } else {
368 // Turn off all observers.
369 ListenerRegistration(false);
370 PushPendingLogsToUnsentLists();
371 DCHECK(!pending_log());
372 if (state_ > INITIAL_LOG_READY && unsent_logs())
373 state_ = SEND_OLD_INITIAL_LOGS;
374 }
375 recording_ = enabled;
376}
377
378bool MetricsService::IsRecording() const {
379 DCHECK(IsSingleThreaded());
380 return recording_;
381}
382
383bool MetricsService::EnableReporting(bool enable) {
384 bool done = GoogleUpdateSettings::SetCollectStatsConsent(enable);
385 if (!done) {
386 bool update_pref = GoogleUpdateSettings::GetCollectStatsConsent();
387 if (enable != update_pref) {
388 DLOG(INFO) << "METRICS: Unable to set crash report status to " << enable;
389 return false;
390 }
391 }
392 if (reporting_ != enable) {
393 reporting_ = enable;
394 if (reporting_)
395 StartLogTransmissionTimer();
396 }
397 return true;
398}
399
400void MetricsService::Observe(NotificationType type,
401 const NotificationSource& source,
402 const NotificationDetails& details) {
403 DCHECK(current_log_);
404 DCHECK(IsSingleThreaded());
405
406 if (!CanLogNotification(type, source, details))
407 return;
408
409 switch (type) {
410 case NOTIFY_USER_ACTION:
411 current_log_->RecordUserAction(*Details<const wchar_t*>(details).ptr());
412 break;
413
414 case NOTIFY_BROWSER_OPENED:
415 case NOTIFY_BROWSER_CLOSED:
416 LogWindowChange(type, source, details);
417 break;
418
419 case NOTIFY_TAB_APPENDED:
420 case NOTIFY_TAB_CLOSING:
421 LogWindowChange(type, source, details);
422 break;
423
424 case NOTIFY_LOAD_STOP:
425 LogLoadComplete(type, source, details);
426 break;
427
428 case NOTIFY_LOAD_START:
429 LogLoadStarted();
430 break;
431
432 case NOTIFY_RENDERER_PROCESS_TERMINATED:
433 if (!*Details<bool>(details).ptr())
434 LogRendererCrash();
435 break;
436
437 case NOTIFY_RENDERER_PROCESS_HANG:
438 LogRendererHang();
439 break;
440
441 case NOTIFY_RENDERER_PROCESS_IN_SBOX:
442 LogRendererInSandbox(*Details<bool>(details).ptr());
443 break;
444
445 case NOTIFY_PLUGIN_PROCESS_HOST_CONNECTED:
446 case NOTIFY_PLUGIN_PROCESS_CRASHED:
447 case NOTIFY_PLUGIN_INSTANCE_CREATED:
448 LogPluginChange(type, source, details);
449 break;
450
451 case TEMPLATE_URL_MODEL_LOADED:
452 LogKeywords(Source<TemplateURLModel>(source).ptr());
453 break;
454
455 case NOTIFY_OMNIBOX_OPENED_URL:
456 current_log_->RecordOmniboxOpenedURL(
457 *Details<AutocompleteLog>(details).ptr());
458 break;
459
460 case NOTIFY_BOOKMARK_MODEL_LOADED:
461 LogBookmarks(Source<Profile>(source)->GetBookmarkBarModel());
462 break;
463
464 default:
465 NOTREACHED();
466 break;
467 }
468 StartLogTransmissionTimer();
469}
470
471void MetricsService::RecordCleanShutdown() {
472 RecordBooleanPrefValue(prefs::kStabilityExitedCleanly, true);
473}
474
475void MetricsService::RecordStartOfSessionEnd() {
476 RecordBooleanPrefValue(prefs::kStabilitySessionEndCompleted, false);
477}
478
479void MetricsService::RecordCompletedSessionEnd() {
480 RecordBooleanPrefValue(prefs::kStabilitySessionEndCompleted, true);
481}
482
483//------------------------------------------------------------------------------
484// private methods
485//------------------------------------------------------------------------------
486
487
488//------------------------------------------------------------------------------
489// Initialization methods
490
491void MetricsService::InitializeMetricsState() {
492 PrefService* pref = g_browser_process->local_state();
493 DCHECK(pref);
494
495 client_id_ = WideToUTF8(pref->GetString(prefs::kMetricsClientID));
496 if (client_id_.empty()) {
497 client_id_ = GenerateClientID();
498 pref->SetString(prefs::kMetricsClientID, UTF8ToWide(client_id_));
499
500 // Might as well make a note of how long this ID has existed
501 pref->SetString(prefs::kMetricsClientIDTimestamp,
502 Int64ToWString(Time::Now().ToTimeT()));
503 }
504
505 // Update session ID
506 session_id_ = pref->GetInteger(prefs::kMetricsSessionID);
507 ++session_id_;
508 pref->SetInteger(prefs::kMetricsSessionID, session_id_);
509
510 bool done = EnableReporting(GoogleUpdateSettings::GetCollectStatsConsent());
511 DCHECK(done);
512
513 // Stability bookkeeping
514 int launches = pref->GetInteger(prefs::kStabilityLaunchCount);
515 pref->SetInteger(prefs::kStabilityLaunchCount, launches + 1);
516
517 bool exited_cleanly = pref->GetBoolean(prefs::kStabilityExitedCleanly);
518 if (!exited_cleanly) {
519 int crashes = pref->GetInteger(prefs::kStabilityCrashCount);
520 pref->SetInteger(prefs::kStabilityCrashCount, crashes + 1);
521 }
522 pref->SetBoolean(prefs::kStabilityExitedCleanly, false);
523
524 bool shutdown_cleanly =
525 pref->GetBoolean(prefs::kStabilitySessionEndCompleted);
526 if (!shutdown_cleanly) {
527 int incomplete_session_end_count = pref->GetInteger(
528 prefs::kStabilityIncompleteSessionEndCount);
529 pref->SetInteger(prefs::kStabilityIncompleteSessionEndCount,
530 incomplete_session_end_count + 1);
531 }
532 // This is marked false when we get a WM_ENDSESSION.
533 pref->SetBoolean(prefs::kStabilitySessionEndCompleted, true);
534
535 int64 last_start_time =
536 StringToInt64(pref->GetString(prefs::kStabilityLaunchTimeSec));
537 int64 last_end_time =
538 StringToInt64(pref->GetString(prefs::kStabilityLastTimestampSec));
539 int64 uptime =
540 StringToInt64(pref->GetString(prefs::kStabilityUptimeSec));
541
542 if (last_start_time && last_end_time) {
543 // TODO(JAR): Exclude sleep time. ... which must be gathered in UI loop.
544 uptime += last_end_time - last_start_time;
545 pref->SetString(prefs::kStabilityUptimeSec, Int64ToWString(uptime));
546 }
547 pref->SetString(prefs::kStabilityLaunchTimeSec,
548 Int64ToWString(Time::Now().ToTimeT()));
549
550 // Save profile metrics.
551 PrefService* prefs = g_browser_process->local_state();
552 if (prefs) {
553 // Remove the current dictionary and store it for use when sending data to
554 // server. By removing the value we prune potentially dead profiles
555 // (and keys). All valid values are added back once services startup.
556 const DictionaryValue* profile_dictionary =
557 prefs->GetDictionary(prefs::kProfileMetrics);
558 if (profile_dictionary) {
559 // Do a deep copy of profile_dictionary since ClearPref will delete it.
560 profile_dictionary_.reset(static_cast<DictionaryValue*>(
561 profile_dictionary->DeepCopy()));
562 prefs->ClearPref(prefs::kProfileMetrics);
563 }
564 }
565
566 // Kick off the process of saving the state (so the uptime numbers keep
567 // getting updated) every n minutes.
568 ScheduleNextStateSave();
569}
570
571void MetricsService::OnGetPluginListTaskComplete() {
572 DCHECK(state_ == PLUGIN_LIST_REQUESTED);
573 if (state_ == PLUGIN_LIST_REQUESTED)
574 state_ = PLUGIN_LIST_ARRIVED;
575}
576
577std::string MetricsService::GenerateClientID() {
578 const int kGUIDSize = 39;
579
580 GUID guid;
581 HRESULT guid_result = CoCreateGuid(&guid);
582 DCHECK(SUCCEEDED(guid_result));
583
584 std::wstring guid_string;
585 int result = StringFromGUID2(guid,
586 WriteInto(&guid_string, kGUIDSize), kGUIDSize);
587 DCHECK(result == kGUIDSize);
588
589 return WideToUTF8(guid_string.substr(1, guid_string.length() - 2));
590}
591
592
593//------------------------------------------------------------------------------
594// State save methods
595
596void MetricsService::ScheduleNextStateSave() {
597 state_saver_factory_.RevokeAll();
598
599 MessageLoop::current()->PostDelayedTask(FROM_HERE,
600 state_saver_factory_.NewRunnableMethod(&MetricsService::SaveLocalState),
601 kSaveStateInterval * 1000);
602}
603
604void MetricsService::SaveLocalState() {
605 PrefService* pref = g_browser_process->local_state();
606 if (!pref) {
607 NOTREACHED();
608 return;
609 }
610
611 RecordCurrentState(pref);
612 pref->ScheduleSavePersistentPrefs(g_browser_process->file_thread());
613
614 ScheduleNextStateSave();
615}
616
617
618//------------------------------------------------------------------------------
619// Recording control methods
620
621void MetricsService::StartRecording() {
622 if (current_log_)
623 return;
624
625 current_log_ = new MetricsLog(client_id_, session_id_);
626 if (state_ == INITIALIZED) {
627 // We only need to schedule that run once.
628 state_ = PLUGIN_LIST_REQUESTED;
629
630 // Make sure the plugin list is loaded before the inital log is sent, so
631 // that the main thread isn't blocked generating the list.
632 g_browser_process->file_thread()->message_loop()->PostDelayedTask(FROM_HERE,
633 new GetPluginListTask(MessageLoop::current()),
634 kInitialLogDelay * 1000 / 2);
635 }
636}
637
638void MetricsService::StopRecording(MetricsLog** log) {
639 if (!current_log_)
640 return;
641
642 // Put incremental histogram data at the end of every log transmission.
643 // Don't bother if we're going to discard current_log_.
644 if (log)
645 RecordCurrentHistograms();
646
647 current_log_->CloseLog();
648 if (log) {
649 *log = current_log_;
650 } else {
651 delete current_log_;
652 }
653 current_log_ = NULL;
654}
655
656void MetricsService::ListenerRegistration(bool start_listening) {
657 AddOrRemoveObserver(this, NOTIFY_BROWSER_OPENED, start_listening);
658 AddOrRemoveObserver(this, NOTIFY_BROWSER_CLOSED, start_listening);
659 AddOrRemoveObserver(this, NOTIFY_USER_ACTION, start_listening);
660 AddOrRemoveObserver(this, NOTIFY_TAB_APPENDED, start_listening);
661 AddOrRemoveObserver(this, NOTIFY_TAB_CLOSING, start_listening);
662 AddOrRemoveObserver(this, NOTIFY_LOAD_START, start_listening);
663 AddOrRemoveObserver(this, NOTIFY_LOAD_STOP, start_listening);
664 AddOrRemoveObserver(this, NOTIFY_RENDERER_PROCESS_IN_SBOX, start_listening);
665 AddOrRemoveObserver(this, NOTIFY_RENDERER_PROCESS_TERMINATED,
666 start_listening);
667 AddOrRemoveObserver(this, NOTIFY_RENDERER_PROCESS_HANG, start_listening);
668 AddOrRemoveObserver(this, NOTIFY_PLUGIN_PROCESS_HOST_CONNECTED,
669 start_listening);
670 AddOrRemoveObserver(this, NOTIFY_PLUGIN_INSTANCE_CREATED, start_listening);
671 AddOrRemoveObserver(this, NOTIFY_PLUGIN_PROCESS_CRASHED, start_listening);
672 AddOrRemoveObserver(this, TEMPLATE_URL_MODEL_LOADED, start_listening);
673 AddOrRemoveObserver(this, NOTIFY_OMNIBOX_OPENED_URL, start_listening);
674 AddOrRemoveObserver(this, NOTIFY_BOOKMARK_MODEL_LOADED, start_listening);
675}
676
677// static
678void MetricsService::AddOrRemoveObserver(NotificationObserver* observer,
679 NotificationType type,
680 bool is_add) {
681 NotificationService* service = NotificationService::current();
682
683 if (is_add) {
684 service->AddObserver(observer, type, NotificationService::AllSources());
685 } else {
686 service->RemoveObserver(observer, type, NotificationService::AllSources());
687 }
688}
689
690void MetricsService::PushPendingLogsToUnsentLists() {
691 if (state_ < INITIAL_LOG_READY)
692 return; // We didn't and still don't have time to get DLL list etc.
693
694 if (pending_log()) {
695 PreparePendingLogText();
696 if (state_ == INITIAL_LOG_READY) {
697 // We may race here, and send second copy of initial log later.
698 unsent_initial_logs_.push_back(pending_log_text_);
699 state_ = SENDING_CURRENT_LOGS;
700 } else {
701 unsent_ongoing_logs_.push_back(pending_log_text_);
702 }
703 DiscardPendingLog();
704 }
705 DCHECK(!pending_log());
706 StopRecording(&pending_log_);
707 PreparePendingLogText();
708 unsent_ongoing_logs_.push_back(pending_log_text_);
709 DiscardPendingLog();
710 StoreUnsentLogs();
711}
712
713//------------------------------------------------------------------------------
714// Transmission of logs methods
715
716void MetricsService::StartLogTransmissionTimer() {
717 if (!current_log_)
718 return; // Recorder is shutdown.
719 if (timer_pending_ || !reporting_)
720 return;
721 // If there is no work to do, don't set a timer yet.
722 if (!current_log_->num_events() && !pending_log() && !unsent_logs())
723 return;
724 timer_pending_ = true;
725 MessageLoop::current()->PostDelayedTask(FROM_HERE,
726 log_sender_factory_.
727 NewRunnableMethod(&MetricsService::CollectMemoryDetails),
728 static_cast<int>(interlog_duration_.InMilliseconds()));
729}
730
731void MetricsService::TryToStartTransmission() {
732 DCHECK(IsSingleThreaded());
733
734 DCHECK(timer_pending_); // ONLY call via timer.
735
736 DCHECK(!current_fetch_.get());
737 if (current_fetch_.get())
738 return; // Redundant defensive coding.
739
740 timer_pending_ = false;
741
742 if (!current_log_)
743 return; // Logging was disabled.
744 if (!reporting_ )
745 return; // Don't do work if we're not going to send anything now.
746
747 if (!pending_log())
748 switch (state_) {
749 case INITIALIZED: // We must be further along by now.
750 DCHECK(false);
751 return;
752
753 case PLUGIN_LIST_REQUESTED:
754 StartLogTransmissionTimer();
755 return;
756
757 case PLUGIN_LIST_ARRIVED:
758 // We need to wait for the initial log to be ready before sending
759 // anything, because the server will tell us whether it wants to hear
760 // from us.
761 PrepareInitialLog();
762 DCHECK(state_ == PLUGIN_LIST_ARRIVED);
763 RecallUnsentLogs();
764 state_ = INITIAL_LOG_READY;
765 break;
766
767 case SEND_OLD_INITIAL_LOGS:
768 if (!unsent_initial_logs_.empty()) {
769 pending_log_text_ = unsent_initial_logs_.back();
770 break;
771 }
772 state_ = SENDING_OLD_LOGS;
773 // Fall through.
774
775 case SENDING_OLD_LOGS:
776 if (!unsent_ongoing_logs_.empty()) {
777 pending_log_text_ = unsent_ongoing_logs_.back();
778 break;
779 }
780 state_ = SENDING_CURRENT_LOGS;
781 // Fall through.
782
783 case SENDING_CURRENT_LOGS:
784 if (!current_log_->num_events())
785 return; // Nothing to send.
786 StopRecording(&pending_log_);
787 StartRecording();
788 break;
789
790 default:
791 DCHECK(false);
792 return;
793 }
794 DCHECK(pending_log());
795
796 PreparePendingLogForTransmission();
797 if (!current_fetch_.get())
798 return; // Compression failed, and log discarded :-/.
799
800 DCHECK(!timer_pending_);
801 timer_pending_ = true; // The URL fetch is a pseudo timer.
802 current_fetch_->Start();
803}
804
805void MetricsService::CollectMemoryDetails() {
806 Task* task = log_sender_factory_.
807 NewRunnableMethod(&MetricsService::TryToStartTransmission);
808 MetricsMemoryDetails* details = new MetricsMemoryDetails(task);
809 details->StartFetch();
810
811 // Collect WebCore cache information to put into a histogram.
812 for (RenderProcessHost::iterator it = RenderProcessHost::begin();
813 it != RenderProcessHost::end(); ++it) {
814 it->second->Send(new ViewMsg_GetCacheResourceStats());
815 }
816}
817
818void MetricsService::PrepareInitialLog() {
819 DCHECK(state_ == PLUGIN_LIST_ARRIVED);
820 std::vector<WebPluginInfo> plugins;
821 PluginService::GetInstance()->GetPlugins(false, &plugins);
822
823 MetricsLog* log = new MetricsLog(client_id_, session_id_);
824 log->RecordEnvironment(plugins, profile_dictionary_.get());
825
826 // Histograms only get written to current_log_, so setup for the write.
827 MetricsLog* save_log = current_log_;
828 current_log_ = log;
829 RecordCurrentHistograms(); // Into current_log_... which is really log.
830 current_log_ = save_log;
831
832 log->CloseLog();
833 DCHECK(!pending_log());
834 pending_log_ = log;
835}
836
837void MetricsService::RecallUnsentLogs() {
838 DCHECK(unsent_initial_logs_.empty());
839 DCHECK(unsent_ongoing_logs_.empty());
840
841 PrefService* local_state = g_browser_process->local_state();
842 DCHECK(local_state);
843
844 ListValue* unsent_initial_logs = local_state->GetMutableList(
845 prefs::kMetricsInitialLogs);
846 for (ListValue::iterator it = unsent_initial_logs->begin();
847 it != unsent_initial_logs->end(); ++it) {
848 std::wstring wide_log;
849 (*it)->GetAsString(&wide_log);
850 unsent_initial_logs_.push_back(WideToUTF8(wide_log));
851 }
852
853 ListValue* unsent_ongoing_logs = local_state->GetMutableList(
854 prefs::kMetricsOngoingLogs);
855 for (ListValue::iterator it = unsent_ongoing_logs->begin();
856 it != unsent_ongoing_logs->end(); ++it) {
857 std::wstring wide_log;
858 (*it)->GetAsString(&wide_log);
859 unsent_ongoing_logs_.push_back(WideToUTF8(wide_log));
860 }
861}
862
863void MetricsService::StoreUnsentLogs() {
864 if (state_ < INITIAL_LOG_READY)
865 return; // We never Recalled the prior unsent logs.
866
867 PrefService* local_state = g_browser_process->local_state();
868 DCHECK(local_state);
869
870 ListValue* unsent_initial_logs = local_state->GetMutableList(
871 prefs::kMetricsInitialLogs);
872 unsent_initial_logs->Clear();
873 size_t start = 0;
874 if (unsent_initial_logs_.size() > kMaxInitialLogsPersisted)
875 start = unsent_initial_logs_.size() - kMaxInitialLogsPersisted;
876 for (size_t i = start; i < unsent_initial_logs_.size(); ++i)
877 unsent_initial_logs->Append(
878 Value::CreateStringValue(UTF8ToWide(unsent_initial_logs_[i])));
879
880 ListValue* unsent_ongoing_logs = local_state->GetMutableList(
881 prefs::kMetricsOngoingLogs);
882 unsent_ongoing_logs->Clear();
883 start = 0;
884 if (unsent_ongoing_logs_.size() > kMaxOngoingLogsPersisted)
885 start = unsent_ongoing_logs_.size() - kMaxOngoingLogsPersisted;
886 for (size_t i = start; i < unsent_ongoing_logs_.size(); ++i)
887 unsent_ongoing_logs->Append(
888 Value::CreateStringValue(UTF8ToWide(unsent_ongoing_logs_[i])));
889}
890
891void MetricsService::PreparePendingLogText() {
892 DCHECK(pending_log());
893 if (!pending_log_text_.empty())
894 return;
895 int original_size = pending_log_->GetEncodedLogSize();
896 pending_log_->GetEncodedLog(WriteInto(&pending_log_text_, original_size),
897 original_size);
898}
899
900void MetricsService::PreparePendingLogForTransmission() {
901 DCHECK(pending_log());
902 DCHECK(!current_fetch_.get());
903 PreparePendingLogText();
904 DCHECK(!pending_log_text_.empty());
905
906 // Allow security conscious users to see all metrics logs that we send.
907 LOG(INFO) << "METRICS LOG: " << pending_log_text_;
908
909 std::string compressed_log;
910 bool result = Bzip2Compress(pending_log_text_, &compressed_log);
911
912 if (!result) {
913 NOTREACHED() << "Failed to compress log for transmission.";
914 DiscardPendingLog();
915 StartLogTransmissionTimer(); // Maybe we'll do better on next log :-/.
916 return;
917 }
918 current_fetch_.reset(new URLFetcher(GURL(kMetricsURL), URLFetcher::POST,
919 this));
920 current_fetch_->set_request_context(Profile::GetDefaultRequestContext());
921 current_fetch_->set_upload_data(kMetricsType, compressed_log);
922 // This flag works around the cert mismatch on toolbarqueries.google.com.
923 current_fetch_->set_load_flags(net::LOAD_IGNORE_CERT_COMMON_NAME_INVALID);
924}
925
926void MetricsService::DiscardPendingLog() {
927 if (pending_log_) { // Shutdown might have deleted it!
928 delete pending_log_;
929 pending_log_ = NULL;
930 }
931 pending_log_text_.clear();
932}
933
934// This implementation is based on the Firefox MetricsService implementation.
935bool MetricsService::Bzip2Compress(const std::string& input,
936 std::string* output) {
937 bz_stream stream = {0};
938 // As long as our input is smaller than the bzip2 block size, we should get
939 // the best compression. For example, if your input was 250k, using a block
940 // size of 300k or 500k should result in the same compression ratio. Since
941 // our data should be under 100k, using the minimum block size of 100k should
942 // allocate less temporary memory, but result in the same compression ratio.
943 int result = BZ2_bzCompressInit(&stream,
944 1, // 100k (min) block size
945 0, // quiet
946 0); // default "work factor"
947 if (result != BZ_OK) { // out of memory?
948 return false;
949 }
950
951 output->clear();
952
953 stream.next_in = const_cast<char*>(input.data());
954 stream.avail_in = static_cast<int>(input.size());
955 // NOTE: we don't need a BZ_RUN phase since our input buffer contains
956 // the entire input
957 do {
958 output->resize(output->size() + 1024);
959 stream.next_out = &((*output)[stream.total_out_lo32]);
960 stream.avail_out = static_cast<int>(output->size()) - stream.total_out_lo32;
961 result = BZ2_bzCompress(&stream, BZ_FINISH);
962 } while (result == BZ_FINISH_OK);
963 if (result != BZ_STREAM_END) // unknown failure?
964 return false;
965 result = BZ2_bzCompressEnd(&stream);
966 DCHECK(result == BZ_OK);
967
968 output->resize(stream.total_out_lo32);
969
970 return true;
971}
972
973static const char* StatusToString(const URLRequestStatus& status) {
974 switch (status.status()) {
975 case URLRequestStatus::SUCCESS:
976 return "SUCCESS";
977
978 case URLRequestStatus::IO_PENDING:
979 return "IO_PENDING";
980
981 case URLRequestStatus::HANDLED_EXTERNALLY:
982 return "HANDLED_EXTERNALLY";
983
984 case URLRequestStatus::CANCELED:
985 return "CANCELED";
986
987 case URLRequestStatus::FAILED:
988 return "FAILED";
989
990 default:
991 NOTREACHED();
992 return "Unknown";
993 }
994}
995
996void MetricsService::OnURLFetchComplete(const URLFetcher* source,
997 const GURL& url,
998 const URLRequestStatus& status,
999 int response_code,
1000 const ResponseCookies& cookies,
1001 const std::string& data) {
1002 DCHECK(timer_pending_);
1003 timer_pending_ = false;
1004 DCHECK(current_fetch_.get());
1005 current_fetch_.reset(NULL); // We're not allowed to re-use it.
1006
1007 // Confirm send so that we can move on.
1008 DLOG(INFO) << "METRICS RESPONSE CODE: " << response_code
1009 << " status=" << StatusToString(status);
1010 if (response_code == 200) { // Success.
1011 switch (state_) {
1012 case INITIAL_LOG_READY:
1013 state_ = SEND_OLD_INITIAL_LOGS;
1014 break;
1015
1016 case SEND_OLD_INITIAL_LOGS:
1017 DCHECK(!unsent_initial_logs_.empty());
1018 unsent_initial_logs_.pop_back();
1019 StoreUnsentLogs();
1020 break;
1021
1022 case SENDING_OLD_LOGS:
1023 DCHECK(!unsent_ongoing_logs_.empty());
1024 unsent_ongoing_logs_.pop_back();
1025 StoreUnsentLogs();
1026 break;
1027
1028 case SENDING_CURRENT_LOGS:
1029 break;
1030
1031 default:
1032 DCHECK(false);
1033 break;
1034 }
1035
1036 DLOG(INFO) << "METRICS RESPONSE DATA: " << data;
1037 DiscardPendingLog();
1038 if (unsent_logs()) {
1039 DCHECK(state_ < SENDING_CURRENT_LOGS);
1040 interlog_duration_ = TimeDelta::FromSeconds(kUnsentLogDelay);
1041 } else {
1042 GetSuggestedInterlogTime(data);
1043 }
1044 } else {
1045 DLOG(INFO) << "METRICS: transmission attempt returned a failure code. "
1046 "Verify network connectivity";
1047#ifndef NDEBUG
1048 DLOG(INFO) << "Verify your metrics logs are formatted correctly."
1049 " Verify server is active at " << kMetricsURL;
1050#endif
1051 if (!pending_log()) {
1052 DLOG(INFO) << "METRICS: Recorder shutdown during log transmission.";
1053 } else {
1054 // Send progressively less frequently.
1055 DCHECK(kBackoff > 1.0);
1056 interlog_duration_ = TimeDelta::FromMicroseconds(
1057 static_cast<int64>(kBackoff * interlog_duration_.InMicroseconds()));
1058
1059 if (kMaxBackoff * TimeDelta::FromSeconds(kMinSecondsPerLog) <
1060 interlog_duration_)
1061 interlog_duration_ = kMaxBackoff *
1062 TimeDelta::FromSeconds(kMinSecondsPerLog);
1063
1064 DLOG(INFO) << "METRICS: transmission retry being scheduled in " <<
1065 interlog_duration_.InSeconds() << " seconds for " <<
1066 pending_log_text_;
1067 }
1068 }
1069 StartLogTransmissionTimer();
1070}
1071
1072// TODO(JAR): Carfully parse XML, rather than hacking.
1073void MetricsService::GetSuggestedInterlogTime(const std::string& server_data) {
1074 int interlog_seconds = kMinSecondsPerLog;
1075 const char* prefix = "<upload interval=\"";
1076 size_t seconds_indent = server_data.find(prefix);
1077 if (std::string::npos != seconds_indent) {
1078 int seconds;
1079 int result = sscanf(server_data.c_str() + seconds_indent + strlen(prefix),
1080 "%d", &seconds);
1081 if (1 == result && seconds > kMinSuggestedSecondsPerLog)
1082 interlog_seconds = seconds;
1083 }
1084 interlog_duration_ = TimeDelta::FromSeconds(interlog_seconds);
1085}
1086
1087
1088void MetricsService::LogWindowChange(NotificationType type,
1089 const NotificationSource& source,
1090 const NotificationDetails& details) {
1091 int window_id = -1;
1092 int parent_id = -1;
1093 uintptr_t window_key = source.map_key();
1094 MetricsLog::WindowEventType window_type;
1095
1096 // Note: since we stop all logging when a single OTR session is active, it is
1097 // possible that we start getting notifications about a window that we don't
1098 // know about.
1099 if (window_map_.find(window_key) == window_map_.end()) {
1100 window_id = next_window_id_++;
1101 window_map_[window_key] = window_id;
1102 } else {
1103 window_id = window_map_[window_key];
1104 }
1105
1106 DCHECK(window_id != -1);
1107
1108 if (type == NOTIFY_TAB_APPENDED) {
1109 parent_id = window_map_[details.map_key()];
1110 }
1111
1112 switch (type) {
1113 case NOTIFY_TAB_APPENDED:
1114 case NOTIFY_BROWSER_OPENED:
1115 window_type = MetricsLog::WINDOW_CREATE;
1116 break;
1117
1118 case NOTIFY_TAB_CLOSING:
1119 case NOTIFY_BROWSER_CLOSED:
1120 window_map_.erase(window_map_.find(window_key));
1121 window_type = MetricsLog::WINDOW_DESTROY;
1122 break;
1123
1124 default:
1125 NOTREACHED();
1126 break;
1127 }
1128
1129 current_log_->RecordWindowEvent(window_type, window_id, parent_id);
1130}
1131
1132void MetricsService::LogLoadComplete(NotificationType type,
1133 const NotificationSource& source,
1134 const NotificationDetails& details) {
1135 if (details == NotificationService::NoDetails())
1136 return;
1137
1138 const Details<LoadNotificationDetails> load_details(details);
1139
1140 int window_id =
1141 window_map_[reinterpret_cast<uintptr_t>(load_details->controller())];
1142 current_log_->RecordLoadEvent(window_id,
1143 load_details->url(),
1144 load_details->origin(),
1145 load_details->session_index(),
1146 load_details->load_time());
1147}
1148
1149void MetricsService::LogLoadStarted() {
1150 PrefService* prefs = g_browser_process->local_state();
1151 DCHECK(prefs);
1152 int loads = prefs->GetInteger(prefs::kStabilityPageLoadCount);
1153 prefs->SetInteger(prefs::kStabilityPageLoadCount, loads + 1);
1154 // We need to save the prefs, as page load count is a critical stat, and
1155 // it might be lost due to a crash :-(.
1156}
1157
1158void MetricsService::LogRendererInSandbox(bool on_sandbox_desktop) {
1159 PrefService* prefs = g_browser_process->local_state();
1160 DCHECK(prefs);
1161 if (on_sandbox_desktop) {
1162 int count = prefs->GetInteger(prefs::kSecurityRendererOnSboxDesktop);
1163 prefs->SetInteger(prefs::kSecurityRendererOnSboxDesktop, count + 1);
1164 } else {
1165 int count = prefs->GetInteger(prefs::kSecurityRendererOnDefaultDesktop);
1166 prefs->SetInteger(prefs::kSecurityRendererOnDefaultDesktop, count + 1);
1167 }
1168}
1169
1170void MetricsService::LogRendererCrash() {
1171 PrefService* prefs = g_browser_process->local_state();
1172 DCHECK(prefs);
1173 int crashes = prefs->GetInteger(prefs::kStabilityRendererCrashCount);
1174 prefs->SetInteger(prefs::kStabilityRendererCrashCount, crashes + 1);
1175}
1176
1177void MetricsService::LogRendererHang() {
1178 PrefService* prefs = g_browser_process->local_state();
1179 DCHECK(prefs);
1180 int hangs = prefs->GetInteger(prefs::kStabilityRendererHangCount);
1181 prefs->SetInteger(prefs::kStabilityRendererHangCount, hangs + 1);
1182}
1183
1184void MetricsService::LogPluginChange(NotificationType type,
1185 const NotificationSource& source,
1186 const NotificationDetails& details) {
1187 std::wstring plugin = Details<PluginProcessInfo>(details)->dll_path();
1188
1189 if (plugin_stats_buffer_.find(plugin) == plugin_stats_buffer_.end()) {
1190 plugin_stats_buffer_[plugin] = PluginStats();
1191 }
1192
1193 PluginStats& stats = plugin_stats_buffer_[plugin];
1194 switch (type) {
1195 case NOTIFY_PLUGIN_PROCESS_HOST_CONNECTED:
1196 stats.process_launches++;
1197 break;
1198
1199 case NOTIFY_PLUGIN_INSTANCE_CREATED:
1200 stats.instances++;
1201 break;
1202
1203 case NOTIFY_PLUGIN_PROCESS_CRASHED:
1204 stats.process_crashes++;
1205 break;
1206
1207 default:
1208 NOTREACHED() << "Unexpected notification type " << type;
1209 return;
1210 }
1211}
1212
1213// Recursively counts the number of bookmarks and folders in node.
1214static void CountBookmarks(BookmarkBarNode* node,
1215 int* bookmarks,
1216 int* folders) {
1217 if (node->GetType() == history::StarredEntry::URL)
1218 (*bookmarks)++;
1219 else
1220 (*folders)++;
1221 for (int i = 0; i < node->GetChildCount(); ++i)
1222 CountBookmarks(node->GetChild(i), bookmarks, folders);
1223}
1224
1225void MetricsService::LogBookmarks(BookmarkBarNode* node,
1226 const wchar_t* num_bookmarks_key,
1227 const wchar_t* num_folders_key) {
1228 DCHECK(node);
1229 int num_bookmarks = 0;
1230 int num_folders = 0;
1231 CountBookmarks(node, &num_bookmarks, &num_folders);
1232 num_folders--; // Don't include the root folder in the count.
1233
1234 PrefService* pref = g_browser_process->local_state();
1235 DCHECK(pref);
1236 pref->SetInteger(num_bookmarks_key, num_bookmarks);
1237 pref->SetInteger(num_folders_key, num_folders);
1238}
1239
1240void MetricsService::LogBookmarks(BookmarkBarModel* model) {
1241 DCHECK(model);
1242 LogBookmarks(model->GetBookmarkBarNode(),
1243 prefs::kNumBookmarksOnBookmarkBar,
1244 prefs::kNumFoldersOnBookmarkBar);
1245 LogBookmarks(model->other_node(),
1246 prefs::kNumBookmarksInOtherBookmarkFolder,
1247 prefs::kNumFoldersInOtherBookmarkFolder);
1248 ScheduleNextStateSave();
1249}
1250
1251void MetricsService::LogKeywords(const TemplateURLModel* url_model) {
1252 DCHECK(url_model);
1253
1254 PrefService* pref = g_browser_process->local_state();
1255 DCHECK(pref);
1256 pref->SetInteger(prefs::kNumKeywords,
1257 static_cast<int>(url_model->GetTemplateURLs().size()));
1258 ScheduleNextStateSave();
1259}
1260
1261void MetricsService::RecordPluginChanges(PrefService* pref) {
1262 ListValue* plugins = pref->GetMutableList(prefs::kStabilityPluginStats);
1263 DCHECK(plugins);
1264
1265 for (ListValue::iterator value_iter = plugins->begin();
1266 value_iter != plugins->end(); ++value_iter) {
1267 if (!(*value_iter)->IsType(Value::TYPE_DICTIONARY)) {
1268 NOTREACHED();
1269 continue;
1270 }
1271
1272 DictionaryValue* plugin_dict = static_cast<DictionaryValue*>(*value_iter);
1273 std::wstring plugin_path;
1274 plugin_dict->GetString(prefs::kStabilityPluginPath, &plugin_path);
1275 if (plugin_path.empty()) {
1276 NOTREACHED();
1277 continue;
1278 }
1279
1280 if (plugin_stats_buffer_.find(plugin_path) == plugin_stats_buffer_.end())
1281 continue;
1282
1283 PluginStats stats = plugin_stats_buffer_[plugin_path];
1284 if (stats.process_launches) {
1285 int launches = 0;
1286 plugin_dict->GetInteger(prefs::kStabilityPluginLaunches, &launches);
1287 launches += stats.process_launches;
1288 plugin_dict->SetInteger(prefs::kStabilityPluginLaunches, launches);
1289 }
1290 if (stats.process_crashes) {
1291 int crashes = 0;
1292 plugin_dict->GetInteger(prefs::kStabilityPluginCrashes, &crashes);
1293 crashes += stats.process_crashes;
1294 plugin_dict->SetInteger(prefs::kStabilityPluginCrashes, crashes);
1295 }
1296 if (stats.instances) {
1297 int instances = 0;
1298 plugin_dict->GetInteger(prefs::kStabilityPluginInstances, &instances);
1299 instances += stats.instances;
1300 plugin_dict->SetInteger(prefs::kStabilityPluginInstances, instances);
1301 }
1302
1303 plugin_stats_buffer_.erase(plugin_path);
1304 }
1305
1306 // Now go through and add dictionaries for plugins that didn't already have
1307 // reports in Local State.
1308 for (std::map<std::wstring, PluginStats>::iterator cache_iter =
1309 plugin_stats_buffer_.begin();
1310 cache_iter != plugin_stats_buffer_.end(); ++cache_iter) {
1311 std::wstring plugin_path = cache_iter->first;
1312 PluginStats stats = cache_iter->second;
1313 DictionaryValue* plugin_dict = new DictionaryValue;
1314
1315 plugin_dict->SetString(prefs::kStabilityPluginPath, plugin_path);
1316 plugin_dict->SetInteger(prefs::kStabilityPluginLaunches,
1317 stats.process_launches);
1318 plugin_dict->SetInteger(prefs::kStabilityPluginCrashes,
1319 stats.process_crashes);
1320 plugin_dict->SetInteger(prefs::kStabilityPluginInstances,
1321 stats.instances);
1322 plugins->Append(plugin_dict);
1323 }
1324 plugin_stats_buffer_.clear();
1325}
1326
1327bool MetricsService::CanLogNotification(NotificationType type,
1328 const NotificationSource& source,
1329 const NotificationDetails& details) {
1330 // We simply don't log anything to UMA if there is a single off the record
1331 // session visible. The problem is that we always notify using the orginal
1332 // profile in order to simplify notification processing.
1333 return !BrowserList::IsOffTheRecordSessionActive();
1334}
1335
1336void MetricsService::RecordBooleanPrefValue(const wchar_t* path, bool value) {
1337 DCHECK(IsSingleThreaded());
1338
1339 PrefService* pref = g_browser_process->local_state();
1340 DCHECK(pref);
1341
1342 pref->SetBoolean(path, value);
1343 RecordCurrentState(pref);
1344}
1345
1346void MetricsService::RecordCurrentState(PrefService* pref) {
1347 pref->SetString(prefs::kStabilityLastTimestampSec,
1348 Int64ToWString(Time::Now().ToTimeT()));
1349
1350 RecordPluginChanges(pref);
1351}
1352
1353void MetricsService::RecordCurrentHistograms() {
1354 DCHECK(current_log_);
1355
1356 StatisticsRecorder::Histograms histograms;
1357 StatisticsRecorder::GetHistograms(&histograms);
1358 for (StatisticsRecorder::Histograms::iterator it = histograms.begin();
1359 histograms.end() != it;
1360 it++) {
1361 if ((*it)->flags() & kUmaTargetedHistogramFlag)
1362 RecordHistogram(**it);
1363 }
1364}
1365
1366void MetricsService::RecordHistogram(const Histogram& histogram) {
1367 // Get up-to-date snapshot of sample stats.
1368 Histogram::SampleSet snapshot;
1369 histogram.SnapshotSample(&snapshot);
1370
1371 const std::string& histogram_name = histogram.histogram_name();
1372
1373 // Find the already sent stats, or create an empty set.
1374 LoggedSampleMap::iterator it = logged_samples_.find(histogram_name);
1375 Histogram::SampleSet* already_logged;
1376 if (logged_samples_.end() == it) {
1377 // Add new entry
1378 already_logged = &logged_samples_[histogram.histogram_name()];
1379 already_logged->Resize(histogram); // Complete initialization.
1380 } else {
1381 already_logged = &(it->second);
1382 // Deduct any stats we've already logged from our snapshot.
1383 snapshot.Subtract(*already_logged);
1384 }
1385
1386 // snapshot now contains only a delta to what we've already_logged.
1387
1388 if (snapshot.TotalCount() > 0) {
1389 current_log_->RecordHistogramDelta(histogram, snapshot);
1390 // Add new data into our running total.
1391 already_logged->Add(snapshot);
1392 }
1393}
1394
1395void MetricsService::AddProfileMetric(Profile* profile,
1396 const std::wstring& key,
1397 int value) {
1398 // Restriction of types is needed for writing values. See
1399 // MetricsLog::WriteProfileMetrics.
1400 DCHECK(profile && !key.empty());
1401 PrefService* prefs = g_browser_process->local_state();
1402 DCHECK(prefs);
1403
1404 // Key is stored in prefs, which interpret '.'s as paths. As such, key
1405 // shouldn't have any '.'s in it.
1406 DCHECK(key.find(L'.') == std::wstring::npos);
1407 // The id is most likely an email address. We shouldn't send it to the server.
1408 const std::wstring id_hash =
1409 UTF8ToWide(MetricsLog::CreateBase64Hash(WideToUTF8(profile->GetID())));
1410 DCHECK(id_hash.find('.') == std::string::npos);
1411
1412 DictionaryValue* prof_prefs = prefs->GetMutableDictionary(
1413 prefs::kProfileMetrics);
1414 DCHECK(prof_prefs);
1415 const std::wstring pref_key = std::wstring(prefs::kProfilePrefix) + id_hash +
1416 L"." + key;
1417 prof_prefs->SetInteger(pref_key.c_str(), value);
1418}
1419
1420static bool IsSingleThreaded() {
1421 static int thread_id = 0;
1422 if (!thread_id)
1423 thread_id = GetCurrentThreadId();
1424 return GetCurrentThreadId() == thread_id;
1425}