diff options
author | ben@chromium.org <ben@chromium.org@0039d316-1c4b-4281-b951-d872f2087c98> | 2009-01-16 01:29:22 +0000 |
---|---|---|
committer | ben@chromium.org <ben@chromium.org@0039d316-1c4b-4281-b951-d872f2087c98> | 2009-01-16 01:29:22 +0000 |
commit | cd1adc2666bdba7d27a2eac2dbf8b70fb7f3c36e (patch) | |
tree | ed83f1798c522ad4db2a810b458e282835748f0a /chrome/browser/metrics | |
parent | 946e05246a5e2a3cd3f9510dd8fd0f6eb84f7d69 (diff) | |
download | chromium_src-cd1adc2666bdba7d27a2eac2dbf8b70fb7f3c36e.zip chromium_src-cd1adc2666bdba7d27a2eac2dbf8b70fb7f3c36e.tar.gz chromium_src-cd1adc2666bdba7d27a2eac2dbf8b70fb7f3c36e.tar.bz2 |
Move metrics files into a subdir
Review URL: http://codereview.chromium.org/18302
git-svn-id: svn://svn.chromium.org/chrome/trunk/src@8156 0039d316-1c4b-4281-b951-d872f2087c98
Diffstat (limited to 'chrome/browser/metrics')
-rw-r--r-- | chrome/browser/metrics/metrics_log.cc | 695 | ||||
-rw-r--r-- | chrome/browser/metrics/metrics_log.h | 206 | ||||
-rw-r--r-- | chrome/browser/metrics/metrics_log_unittest.cc | 130 | ||||
-rw-r--r-- | chrome/browser/metrics/metrics_response.cc | 83 | ||||
-rw-r--r-- | chrome/browser/metrics/metrics_response.h | 58 | ||||
-rw-r--r-- | chrome/browser/metrics/metrics_response_unittest.cc | 110 | ||||
-rw-r--r-- | chrome/browser/metrics/metrics_service.cc | 1755 | ||||
-rw-r--r-- | chrome/browser/metrics/metrics_service.h | 464 | ||||
-rw-r--r-- | chrome/browser/metrics/metrics_service_uitest.cc | 111 | ||||
-rw-r--r-- | chrome/browser/metrics/user_metrics.cc | 20 | ||||
-rw-r--r-- | chrome/browser/metrics/user_metrics.h | 41 |
11 files changed, 3673 insertions, 0 deletions
diff --git a/chrome/browser/metrics/metrics_log.cc b/chrome/browser/metrics/metrics_log.cc new file mode 100644 index 0000000..3603e0c --- /dev/null +++ b/chrome/browser/metrics/metrics_log.cc @@ -0,0 +1,695 @@ +// Copyright (c) 2006-2008 The Chromium Authors. All rights reserved. +// Use of this source code is governed by a BSD-style license that can be +// found in the LICENSE file. + +#include "chrome/browser/metrics/metrics_log.h" + +#include "base/basictypes.h" +#include "base/file_util.h" +#include "base/file_version_info.h" +#include "base/md5.h" +#include "base/scoped_ptr.h" +#include "base/string_util.h" +#include "base/sys_info.h" +#include "chrome/browser/autocomplete/autocomplete.h" +#include "chrome/browser/browser_process.h" +#include "chrome/common/logging_chrome.h" +#include "chrome/common/pref_names.h" +#include "chrome/common/pref_service.h" +#include "googleurl/src/gurl.h" +#include "net/base/base64.h" + +#define OPEN_ELEMENT_FOR_SCOPE(name) ScopedElement scoped_element(this, name) + +using base::Time; +using base::TimeDelta; + +// http://blogs.msdn.com/oldnewthing/archive/2004/10/25/247180.aspx +#if defined(OS_WIN) +extern "C" IMAGE_DOS_HEADER __ImageBase; +#endif + +// libxml take xmlChar*, which is unsigned char* +inline const unsigned char* UnsignedChar(const char* input) { + return reinterpret_cast<const unsigned char*>(input); +} + +// static +void MetricsLog::RegisterPrefs(PrefService* local_state) { + local_state->RegisterListPref(prefs::kStabilityPluginStats); +} + +MetricsLog::MetricsLog(const std::string& client_id, int session_id) + : start_time_(Time::Now()), + client_id_(client_id), + session_id_(IntToString(session_id)), + locked_(false), + buffer_(NULL), + writer_(NULL), + num_events_(0) { + + buffer_ = xmlBufferCreate(); + DCHECK(buffer_); + + writer_ = xmlNewTextWriterMemory(buffer_, 0); + DCHECK(writer_); + + int result = xmlTextWriterSetIndent(writer_, 2); + DCHECK_EQ(0, result); + + StartElement("log"); + WriteAttribute("clientid", client_id_); + + DCHECK_GE(result, 0); +} + +MetricsLog::~MetricsLog() { + if (writer_) + xmlFreeTextWriter(writer_); + + if (buffer_) + xmlBufferFree(buffer_); +} + +void MetricsLog::CloseLog() { + DCHECK(!locked_); + locked_ = true; + + int result = xmlTextWriterEndDocument(writer_); + DCHECK(result >= 0); + + result = xmlTextWriterFlush(writer_); + DCHECK(result >= 0); +} + +int MetricsLog::GetEncodedLogSize() { + DCHECK(locked_); + return buffer_->use; +} + +bool MetricsLog::GetEncodedLog(char* buffer, int buffer_size) { + DCHECK(locked_); + if (buffer_size < GetEncodedLogSize()) + return false; + + memcpy(buffer, buffer_->content, GetEncodedLogSize()); + return true; +} + +int MetricsLog::GetElapsedSeconds() { + return static_cast<int>((Time::Now() - start_time_).InSeconds()); +} + +std::string MetricsLog::CreateHash(const std::string& value) { + MD5Context ctx; + MD5Init(&ctx); + MD5Update(&ctx, value.data(), value.length()); + + MD5Digest digest; + MD5Final(&digest, &ctx); + + unsigned char reverse[8]; // UMA only uses first 8 chars of hash. + DCHECK(arraysize(digest.a) >= arraysize(reverse)); + for (size_t i = 0; i < arraysize(reverse); ++i) + reverse[i] = digest.a[arraysize(reverse) - i - 1]; + LOG(INFO) << "Metrics: Hash numeric [" << value << "]=[" + << *reinterpret_cast<const uint64*>(&reverse[0]) << "]"; + return std::string(reinterpret_cast<char*>(digest.a), arraysize(digest.a)); +} + +std::string MetricsLog::CreateBase64Hash(const std::string& string) { + std::string encoded_digest; + if (net::Base64Encode(CreateHash(string), &encoded_digest)) { + DLOG(INFO) << "Metrics: Hash [" << encoded_digest << "]=[" << string << "]"; + return encoded_digest; + } + return std::string(); +} + +void MetricsLog::RecordUserAction(const wchar_t* key) { + DCHECK(!locked_); + + std::string command_hash = CreateBase64Hash(WideToUTF8(key)); + if (command_hash.empty()) { + NOTREACHED() << "Unable generate encoded hash of command: " << key; + return; + } + + OPEN_ELEMENT_FOR_SCOPE("uielement"); + WriteAttribute("action", "command"); + WriteAttribute("targetidhash", command_hash); + + // TODO(jhughes): Properly track windows. + WriteIntAttribute("window", 0); + WriteCommonEventAttributes(); + + ++num_events_; +} + +void MetricsLog::RecordLoadEvent(int window_id, + const GURL& url, + PageTransition::Type origin, + int session_index, + TimeDelta load_time) { + DCHECK(!locked_); + + OPEN_ELEMENT_FOR_SCOPE("document"); + WriteAttribute("action", "load"); + WriteIntAttribute("docid", session_index); + WriteIntAttribute("window", window_id); + WriteAttribute("loadtime", Int64ToString(load_time.InMilliseconds())); + + std::string origin_string; + + switch (PageTransition::StripQualifier(origin)) { + // TODO(jhughes): Some of these mappings aren't right... we need to add + // some values to the server's enum. + case PageTransition::LINK: + case PageTransition::MANUAL_SUBFRAME: + origin_string = "link"; + break; + + case PageTransition::TYPED: + origin_string = "typed"; + break; + + case PageTransition::AUTO_BOOKMARK: + origin_string = "bookmark"; + break; + + case PageTransition::AUTO_SUBFRAME: + case PageTransition::RELOAD: + origin_string = "refresh"; + break; + + case PageTransition::GENERATED: + origin_string = "global-history"; + break; + + case PageTransition::START_PAGE: + origin_string = "start-page"; + break; + + case PageTransition::FORM_SUBMIT: + origin_string = "form-submit"; + break; + + default: + NOTREACHED() << "Received an unknown page transition type: " << + PageTransition::StripQualifier(origin); + } + if (!origin_string.empty()) + WriteAttribute("origin", origin_string); + + WriteCommonEventAttributes(); + + ++num_events_; +} + +void MetricsLog::RecordWindowEvent(WindowEventType type, + int window_id, + int parent_id) { + DCHECK(!locked_); + + OPEN_ELEMENT_FOR_SCOPE("window"); + WriteAttribute("action", WindowEventTypeToString(type)); + WriteAttribute("windowid", IntToString(window_id)); + if (parent_id >= 0) + WriteAttribute("parent", IntToString(parent_id)); + WriteCommonEventAttributes(); + + ++num_events_; +} + +std::string MetricsLog::GetCurrentTimeString() { + return Uint64ToString(Time::Now().ToTimeT()); +} + +// These are the attributes that are common to every event. +void MetricsLog::WriteCommonEventAttributes() { + WriteAttribute("session", session_id_); + WriteAttribute("time", GetCurrentTimeString()); +} + +void MetricsLog::WriteAttribute(const std::string& name, + const std::string& value) { + DCHECK(!locked_); + DCHECK(!name.empty()); + + int result = xmlTextWriterWriteAttribute(writer_, + UnsignedChar(name.c_str()), + UnsignedChar(value.c_str())); + DCHECK_GE(result, 0); +} + +void MetricsLog::WriteIntAttribute(const std::string& name, int value) { + WriteAttribute(name, IntToString(value)); +} + +void MetricsLog::WriteInt64Attribute(const std::string& name, int64 value) { + WriteAttribute(name, Int64ToString(value)); +} + +// static +const char* MetricsLog::WindowEventTypeToString(WindowEventType type) { + switch (type) { + case WINDOW_CREATE: return "create"; + case WINDOW_OPEN: return "open"; + case WINDOW_CLOSE: return "close"; + case WINDOW_DESTROY: return "destroy"; + + default: + NOTREACHED(); + return "unknown"; // Can't return NULL as this is used in a required + // attribute. + } +} + +void MetricsLog::StartElement(const char* name) { + DCHECK(!locked_); + DCHECK(name); + + int result = xmlTextWriterStartElement(writer_, UnsignedChar(name)); + DCHECK_GE(result, 0); +} + +void MetricsLog::EndElement() { + DCHECK(!locked_); + + int result = xmlTextWriterEndElement(writer_); + DCHECK_GE(result, 0); +} + +std::string MetricsLog::GetVersionString() const { + scoped_ptr<FileVersionInfo> version_info( + FileVersionInfo::CreateFileVersionInfoForCurrentModule()); + if (version_info.get()) { + std::string version = WideToUTF8(version_info->product_version()); + if (!version_info->is_official_build()) + version.append("-devel"); + return version; + } else { + NOTREACHED() << "Unable to retrieve version string."; + } + + return std::string(); +} + +std::string MetricsLog::GetInstallDate() const { + PrefService* pref = g_browser_process->local_state(); + if (pref) { + return WideToUTF8(pref->GetString(prefs::kMetricsClientIDTimestamp)); + } else { + NOTREACHED(); + return "0"; + } +} + +void MetricsLog::RecordIncrementalStabilityElements() { + DCHECK(!locked_); + + PrefService* pref = g_browser_process->local_state(); + DCHECK(pref); + + OPEN_ELEMENT_FOR_SCOPE("profile"); + WriteCommonEventAttributes(); + + WriteInstallElement(); // Supply appversion. + + { + OPEN_ELEMENT_FOR_SCOPE("stability"); // Minimal set of stability elements. + WriteRequiredStabilityAttributes(pref); + WriteRealtimeStabilityAttributes(pref); + + WritePluginStabilityElements(pref); + } +} + +void MetricsLog::WriteStabilityElement() { + DCHECK(!locked_); + + PrefService* pref = g_browser_process->local_state(); + DCHECK(pref); + + // Get stability attributes out of Local State, zeroing out stored values. + // NOTE: This could lead to some data loss if this report isn't successfully + // sent, but that's true for all the metrics. + + OPEN_ELEMENT_FOR_SCOPE("stability"); + WriteRequiredStabilityAttributes(pref); + WriteRealtimeStabilityAttributes(pref); + + // TODO(jar): The following are all optional, so we *could* optimize them for + // values of zero (and not include them). + WriteIntAttribute("incompleteshutdowncount", + pref->GetInteger( + prefs::kStabilityIncompleteSessionEndCount)); + pref->SetInteger(prefs::kStabilityIncompleteSessionEndCount, 0); + + + WriteIntAttribute("breakpadregistrationok", + pref->GetInteger(prefs::kStabilityBreakpadRegistrationSuccess)); + pref->SetInteger(prefs::kStabilityBreakpadRegistrationSuccess, 0); + WriteIntAttribute("breakpadregistrationfail", + pref->GetInteger(prefs::kStabilityBreakpadRegistrationFail)); + pref->SetInteger(prefs::kStabilityBreakpadRegistrationFail, 0); + WriteIntAttribute("debuggerpresent", + pref->GetInteger(prefs::kStabilityDebuggerPresent)); + pref->SetInteger(prefs::kStabilityDebuggerPresent, 0); + WriteIntAttribute("debuggernotpresent", + pref->GetInteger(prefs::kStabilityDebuggerNotPresent)); + pref->SetInteger(prefs::kStabilityDebuggerNotPresent, 0); + + // Uptime is stored as a string, since there's no int64 in Value/JSON. + WriteAttribute("uptimesec", + WideToUTF8(pref->GetString(prefs::kStabilityUptimeSec))); + pref->SetString(prefs::kStabilityUptimeSec, L"0"); + + WritePluginStabilityElements(pref); +} + +void MetricsLog::WritePluginStabilityElements(PrefService* pref) { + // Now log plugin stability info. + const ListValue* plugin_stats_list = pref->GetList( + prefs::kStabilityPluginStats); + if (plugin_stats_list) { + OPEN_ELEMENT_FOR_SCOPE("plugins"); + for (ListValue::const_iterator iter = plugin_stats_list->begin(); + iter != plugin_stats_list->end(); ++iter) { + if (!(*iter)->IsType(Value::TYPE_DICTIONARY)) { + NOTREACHED(); + continue; + } + DictionaryValue* plugin_dict = static_cast<DictionaryValue*>(*iter); + + std::wstring plugin_path; + plugin_dict->GetString(prefs::kStabilityPluginPath, &plugin_path); + plugin_path = file_util::GetFilenameFromPath(plugin_path); + if (plugin_path.empty()) { + NOTREACHED(); + continue; + } + + OPEN_ELEMENT_FOR_SCOPE("pluginstability"); + WriteAttribute("filename", CreateBase64Hash(WideToUTF8(plugin_path))); + + int launches = 0; + plugin_dict->GetInteger(prefs::kStabilityPluginLaunches, &launches); + WriteIntAttribute("launchcount", launches); + + int instances = 0; + plugin_dict->GetInteger(prefs::kStabilityPluginInstances, &instances); + WriteIntAttribute("instancecount", instances); + + int crashes = 0; + plugin_dict->GetInteger(prefs::kStabilityPluginCrashes, &crashes); + WriteIntAttribute("crashcount", crashes); + } + + pref->ClearPref(prefs::kStabilityPluginStats); + } +} + +void MetricsLog::WriteRequiredStabilityAttributes(PrefService* pref) { + // The server refuses data that doesn't have certain values. crashcount and + // launchcount are currently "required" in the "stability" group. + WriteIntAttribute("launchcount", + pref->GetInteger(prefs::kStabilityLaunchCount)); + pref->SetInteger(prefs::kStabilityLaunchCount, 0); + WriteIntAttribute("crashcount", + pref->GetInteger(prefs::kStabilityCrashCount)); + pref->SetInteger(prefs::kStabilityCrashCount, 0); +} + +void MetricsLog::WriteRealtimeStabilityAttributes(PrefService* pref) { + // Update the stats which are critical for real-time stability monitoring. + // Since these are "optional," only list ones that are non-zero, as the counts + // are aggergated (summed) server side. + + int count = pref->GetInteger(prefs::kStabilityPageLoadCount); + if (count) { + WriteIntAttribute("pageloadcount", count); + pref->SetInteger(prefs::kStabilityPageLoadCount, 0); + } + + count = pref->GetInteger(prefs::kStabilityRendererCrashCount); + if (count) { + WriteIntAttribute("renderercrashcount", count); + pref->SetInteger(prefs::kStabilityRendererCrashCount, 0); + } + + count = pref->GetInteger(prefs::kStabilityRendererHangCount); + if (count) { + WriteIntAttribute("rendererhangcount", count); + pref->SetInteger(prefs::kStabilityRendererHangCount, 0); + } +} + +void MetricsLog::WritePluginList( + const std::vector<WebPluginInfo>& plugin_list) { + DCHECK(!locked_); + + OPEN_ELEMENT_FOR_SCOPE("plugins"); + + for (std::vector<WebPluginInfo>::const_iterator iter = plugin_list.begin(); + iter != plugin_list.end(); ++iter) { + OPEN_ELEMENT_FOR_SCOPE("plugin"); + + // Plugin name and filename are hashed for the privacy of those + // testing unreleased new extensions. + WriteAttribute("name", CreateBase64Hash(WideToUTF8(iter->name))); + WriteAttribute("filename", + CreateBase64Hash(WideToUTF8(iter->path.BaseName().ToWStringHack()))); + WriteAttribute("version", WideToUTF8(iter->version)); + } +} + +void MetricsLog::WriteInstallElement() { + OPEN_ELEMENT_FOR_SCOPE("install"); + WriteAttribute("installdate", GetInstallDate()); + WriteIntAttribute("buildid", 0); // We're using appversion instead. + WriteAttribute("appversion", GetVersionString()); +} + +void MetricsLog::RecordEnvironment( + const std::vector<WebPluginInfo>& plugin_list, + const DictionaryValue* profile_metrics) { + DCHECK(!locked_); + + PrefService* pref = g_browser_process->local_state(); + + OPEN_ELEMENT_FOR_SCOPE("profile"); + WriteCommonEventAttributes(); + + WriteInstallElement(); + + WritePluginList(plugin_list); + + WriteStabilityElement(); + + { + OPEN_ELEMENT_FOR_SCOPE("cpu"); + WriteAttribute("arch", base::SysInfo::CPUArchitecture()); + } + + { + OPEN_ELEMENT_FOR_SCOPE("security"); + WriteIntAttribute("rendereronsboxdesktop", + pref->GetInteger(prefs::kSecurityRendererOnSboxDesktop)); + pref->SetInteger(prefs::kSecurityRendererOnSboxDesktop, 0); + + WriteIntAttribute("rendererondefaultdesktop", + pref->GetInteger(prefs::kSecurityRendererOnDefaultDesktop)); + pref->SetInteger(prefs::kSecurityRendererOnDefaultDesktop, 0); + } + + { + OPEN_ELEMENT_FOR_SCOPE("memory"); + WriteIntAttribute("mb", base::SysInfo::AmountOfPhysicalMemoryMB()); +#if defined(OS_WIN) + WriteIntAttribute("dllbase", reinterpret_cast<int>(&__ImageBase)); +#endif + } + + { + OPEN_ELEMENT_FOR_SCOPE("os"); + WriteAttribute("name", + base::SysInfo::OperatingSystemName()); + WriteAttribute("version", + base::SysInfo::OperatingSystemVersion()); + } + + { + OPEN_ELEMENT_FOR_SCOPE("display"); + int width = 0; + int height = 0; + base::SysInfo::GetPrimaryDisplayDimensions(&width, &height); + WriteIntAttribute("xsize", width); + WriteIntAttribute("ysize", height); + WriteIntAttribute("screens", base::SysInfo::DisplayCount()); + } + + { + OPEN_ELEMENT_FOR_SCOPE("bookmarks"); + int num_bookmarks_on_bookmark_bar = + pref->GetInteger(prefs::kNumBookmarksOnBookmarkBar); + int num_folders_on_bookmark_bar = + pref->GetInteger(prefs::kNumFoldersOnBookmarkBar); + int num_bookmarks_in_other_bookmarks_folder = + pref->GetInteger(prefs::kNumBookmarksInOtherBookmarkFolder); + int num_folders_in_other_bookmarks_folder = + pref->GetInteger(prefs::kNumFoldersInOtherBookmarkFolder); + { + OPEN_ELEMENT_FOR_SCOPE("bookmarklocation"); + WriteAttribute("name", "full-tree"); + WriteIntAttribute("foldercount", + num_folders_on_bookmark_bar + num_folders_in_other_bookmarks_folder); + WriteIntAttribute("itemcount", + num_bookmarks_on_bookmark_bar + + num_bookmarks_in_other_bookmarks_folder); + } + { + OPEN_ELEMENT_FOR_SCOPE("bookmarklocation"); + WriteAttribute("name", "toolbar"); + WriteIntAttribute("foldercount", num_folders_on_bookmark_bar); + WriteIntAttribute("itemcount", num_bookmarks_on_bookmark_bar); + } + } + + { + OPEN_ELEMENT_FOR_SCOPE("keywords"); + WriteIntAttribute("count", pref->GetInteger(prefs::kNumKeywords)); + } + + if (profile_metrics) + WriteAllProfilesMetrics(*profile_metrics); +} + +void MetricsLog::WriteAllProfilesMetrics( + const DictionaryValue& all_profiles_metrics) { + const std::wstring profile_prefix(prefs::kProfilePrefix); + for (DictionaryValue::key_iterator i = all_profiles_metrics.begin_keys(); + i != all_profiles_metrics.end_keys(); ++i) { + const std::wstring& key_name = *i; + if (key_name.compare(0, profile_prefix.size(), profile_prefix) == 0) { + DictionaryValue* profile; + if (all_profiles_metrics.GetDictionary(key_name, &profile)) + WriteProfileMetrics(key_name.substr(profile_prefix.size()), *profile); + } + } +} + +void MetricsLog::WriteProfileMetrics(const std::wstring& profileidhash, + const DictionaryValue& profile_metrics) { + OPEN_ELEMENT_FOR_SCOPE("userprofile"); + WriteAttribute("profileidhash", WideToUTF8(profileidhash)); + for (DictionaryValue::key_iterator i = profile_metrics.begin_keys(); + i != profile_metrics.end_keys(); ++i) { + Value* value; + if (profile_metrics.Get(*i, &value)) { + DCHECK(*i != L"id"); + switch (value->GetType()) { + case Value::TYPE_STRING: { + std::string string_value; + if (value->GetAsString(&string_value)) { + OPEN_ELEMENT_FOR_SCOPE("profileparam"); + WriteAttribute("name", WideToUTF8(*i)); + WriteAttribute("value", string_value); + } + break; + } + + case Value::TYPE_BOOLEAN: { + bool bool_value; + if (value->GetAsBoolean(&bool_value)) { + OPEN_ELEMENT_FOR_SCOPE("profileparam"); + WriteAttribute("name", WideToUTF8(*i)); + WriteIntAttribute("value", bool_value ? 1 : 0); + } + break; + } + + case Value::TYPE_INTEGER: { + int int_value; + if (value->GetAsInteger(&int_value)) { + OPEN_ELEMENT_FOR_SCOPE("profileparam"); + WriteAttribute("name", WideToUTF8(*i)); + WriteIntAttribute("value", int_value); + } + break; + } + + default: + NOTREACHED(); + break; + } + } + } +} + +void MetricsLog::RecordOmniboxOpenedURL(const AutocompleteLog& log) { + DCHECK(!locked_); + + OPEN_ELEMENT_FOR_SCOPE("uielement"); + WriteAttribute("action", "autocomplete"); + WriteAttribute("targetidhash", ""); + // TODO(kochi): Properly track windows. + WriteIntAttribute("window", 0); + WriteCommonEventAttributes(); + + { + OPEN_ELEMENT_FOR_SCOPE("autocomplete"); + + WriteIntAttribute("typedlength", static_cast<int>(log.text.length())); + WriteIntAttribute("selectedindex", static_cast<int>(log.selected_index)); + WriteIntAttribute("completedlength", + static_cast<int>(log.inline_autocompleted_length)); + const std::string input_type( + AutocompleteInput::TypeToString(log.input_type)); + if (!input_type.empty()) + WriteAttribute("inputtype", input_type); + + for (AutocompleteResult::const_iterator i(log.result.begin()); + i != log.result.end(); ++i) { + OPEN_ELEMENT_FOR_SCOPE("autocompleteitem"); + if (i->provider) + WriteAttribute("provider", i->provider->name()); + const std::string result_type(AutocompleteMatch::TypeToString(i->type)); + if (!result_type.empty()) + WriteAttribute("resulttype", result_type); + WriteIntAttribute("relevance", i->relevance); + WriteIntAttribute("isstarred", i->starred ? 1 : 0); + } + } + + ++num_events_; +} + +// TODO(JAR): A The following should really be part of the histogram class. +// Internal state is being needlessly exposed, and it would be hard to reuse +// this code. If we moved this into the Histogram class, then we could use +// the same infrastructure for logging StatsCounters, RatesCounters, etc. +void MetricsLog::RecordHistogramDelta(const Histogram& histogram, + const Histogram::SampleSet& snapshot) { + DCHECK(!locked_); + DCHECK(0 != snapshot.TotalCount()); + snapshot.CheckSize(histogram); + + // We will ignore the MAX_INT/infinite value in the last element of range[]. + + OPEN_ELEMENT_FOR_SCOPE("histogram"); + + WriteAttribute("name", CreateBase64Hash(histogram.histogram_name())); + + WriteInt64Attribute("sum", snapshot.sum()); + WriteInt64Attribute("sumsquares", snapshot.square_sum()); + + for (size_t i = 0; i < histogram.bucket_count(); i++) { + if (snapshot.counts(i)) { + OPEN_ELEMENT_FOR_SCOPE("histogrambucket"); + WriteIntAttribute("min", histogram.ranges(i)); + WriteIntAttribute("max", histogram.ranges(i + 1)); + WriteIntAttribute("count", snapshot.counts(i)); + } + } +} diff --git a/chrome/browser/metrics/metrics_log.h b/chrome/browser/metrics/metrics_log.h new file mode 100644 index 0000000..63ac23d --- /dev/null +++ b/chrome/browser/metrics/metrics_log.h @@ -0,0 +1,206 @@ +// Copyright (c) 2006-2008 The Chromium Authors. All rights reserved. +// Use of this source code is governed by a BSD-style license that can be +// found in the LICENSE file. + +// This file defines a set of user experience metrics data recorded by +// the MetricsService. This is the unit of data that is sent to the server. + +#ifndef CHROME_BROWSER_METRICS_LOG_H__ +#define CHROME_BROWSER_METRICS_LOG_H__ + +#include <libxml/xmlwriter.h> + +#include <string> +#include <vector> + +#include "base/basictypes.h" +#include "base/histogram.h" +#include "base/time.h" +#include "chrome/common/page_transition_types.h" +#include "webkit/glue/webplugin.h" + +struct AutocompleteLog; +class DictionaryValue; +class GURL; +class PrefService; + +class MetricsLog { + public: + // Creates a new metrics log + // client_id is the identifier for this profile on this installation + // session_id is an integer that's incremented on each application launch + MetricsLog(const std::string& client_id, int session_id); + virtual ~MetricsLog(); + + static void RegisterPrefs(PrefService* prefs); + + // Records a user-initiated action. + void RecordUserAction(const wchar_t* key); + + enum WindowEventType { + WINDOW_CREATE = 0, + WINDOW_OPEN, + WINDOW_CLOSE, + WINDOW_DESTROY + }; + + void RecordWindowEvent(WindowEventType type, int window_id, int parent_id); + + // Records a page load. + // window_id - the index of the tab in which the load took place + // url - which URL was loaded + // origin - what kind of action initiated the load + // load_time - how long it took to load the page + void RecordLoadEvent(int window_id, + const GURL& url, + PageTransition::Type origin, + int session_index, + base::TimeDelta load_time); + + // Records the current operating environment. Takes the list of installed + // plugins as a parameter because that can't be obtained synchronously + // from the UI thread. + // profile_metrics, if non-null, gives a dictionary of all profile metrics + // that are to be recorded. Each value in profile_metrics should be a + // dictionary giving the metrics for the profile. + void RecordEnvironment(const std::vector<WebPluginInfo>& plugin_list, + const DictionaryValue* profile_metrics); + + // Records the input text, available choices, and selected entry when the + // user uses the Omnibox to open a URL. + void RecordOmniboxOpenedURL(const AutocompleteLog& log); + + // Record any changes in a given histogram for transmission. + void RecordHistogramDelta(const Histogram& histogram, + const Histogram::SampleSet& snapshot); + + // Record recent delta for critical stability metrics. We can't wait for a + // restart to gather these, as that delay biases our observation away from + // users that run happily for a looooong time. We send increments with each + // uma log upload, just as we send histogram data. + void RecordIncrementalStabilityElements(); + + // Stop writing to this record and generate the encoded representation. + // None of the Record* methods can be called after this is called. + void CloseLog(); + + // These methods allow retrieval of the encoded representation of the + // record. They can only be called after CloseLog() has been called. + // GetEncodedLog returns false if buffer_size is less than + // GetEncodedLogSize(); + int GetEncodedLogSize(); + bool GetEncodedLog(char* buffer, int buffer_size); + + // Returns the amount of time in seconds that this log has been in use. + int GetElapsedSeconds(); + + int num_events() { return num_events_; } + + // Creates an MD5 hash of the given value, and returns hash as a byte + // buffer encoded as a std::string. + static std::string CreateHash(const std::string& value); + + // Return a base64-encoded MD5 hash of the given string. + static std::string CreateBase64Hash(const std::string& string); + + protected: + // Returns a string containing the current time. + // Virtual so that it can be overridden for testing. + virtual std::string GetCurrentTimeString(); + + private: + // Helper class that invokes StartElement from constructor, and EndElement + // from destructor. + // + // Use the macro OPEN_ELEMENT_FOR_SCOPE to help avoid usage problems. + class ScopedElement { + public: + ScopedElement(MetricsLog* log, const std::string& name) : log_(log) { + DCHECK(log); + log->StartElement(name.c_str()); + } + + ScopedElement(MetricsLog* log, const char* name) : log_(log) { + DCHECK(log); + log->StartElement(name); + } + + ~ScopedElement() { + log_->EndElement(); + } + + private: + MetricsLog* log_; + }; + friend class ScopedElement; + + static const char* WindowEventTypeToString(WindowEventType type); + + // Convenience versions of xmlWriter functions + void StartElement(const char* name); + void EndElement(); + void WriteAttribute(const std::string& name, const std::string& value); + void WriteIntAttribute(const std::string& name, int value); + void WriteInt64Attribute(const std::string& name, int64 value); + + // Write the attributes that are common to every metrics event type. + void WriteCommonEventAttributes(); + + // Get the current version of the application as a string. + std::string GetVersionString() const; + + // Returns the date at which the current metrics client ID was created as + // a string containing milliseconds since the epoch, or "0" if none was found. + std::string GetInstallDate() const; + + // Writes application stability metrics (as part of the profile log). + // NOTE: Has the side-effect of clearing those counts. + void WriteStabilityElement(); + + // Within stability group, write plugin crash stats. + void WritePluginStabilityElements(PrefService* pref); + + // Within the stability group, write required attributes. + void WriteRequiredStabilityAttributes(PrefService* pref); + + // Within the stability group, write attributes that need to be updated asap + // and can't be delayed until the user decides to restart chromium. + // Delaying these stats would bias metrics away from happy long lived + // chromium processes (ones that don't crash, and keep on running). + void WriteRealtimeStabilityAttributes(PrefService* pref); + + // Writes the list of installed plugins. + void WritePluginList(const std::vector<WebPluginInfo>& plugin_list); + + // Within the profile group, write basic install info including appversion. + void WriteInstallElement(); + + // Writes all profile metrics. This invokes WriteProfileMetrics for each key + // in all_profiles_metrics that starts with kProfilePrefix. + void WriteAllProfilesMetrics(const DictionaryValue& all_profiles_metrics); + + // Writes metrics for the profile identified by key. This writes all + // key/value pairs in profile_metrics. + void WriteProfileMetrics(const std::wstring& key, + const DictionaryValue& profile_metrics); + + base::Time start_time_; + base::Time end_time_; + + std::string client_id_; + std::string session_id_; + + // locked_ is true when record has been packed up for sending, and should + // no longer be written to. It is only used for sanity checking and is + // not a real lock. + bool locked_; + + xmlBufferPtr buffer_; + xmlTextWriterPtr writer_; + int num_events_; // the number of events recorded in this log + + DISALLOW_EVIL_CONSTRUCTORS(MetricsLog); +}; + +#endif // CHROME_BROWSER_METRICS_LOG_H__ + diff --git a/chrome/browser/metrics/metrics_log_unittest.cc b/chrome/browser/metrics/metrics_log_unittest.cc new file mode 100644 index 0000000..4899b43 --- /dev/null +++ b/chrome/browser/metrics/metrics_log_unittest.cc @@ -0,0 +1,130 @@ +// Copyright (c) 2006-2008 The Chromium Authors. All rights reserved. +// Use of this source code is governed by a BSD-style license that can be +// found in the LICENSE file. + +#include <string> + +#include "base/string_util.h" +#include "base/time.h" +#include "chrome/browser/metrics/metrics_log.h" +#include "googleurl/src/gurl.h" +#include "testing/gtest/include/gtest/gtest.h" + +using base::TimeDelta; + +namespace { + class MetricsLogTest : public testing::Test { + }; +}; + +TEST(MetricsLogTest, EmptyRecord) { + std::string expected_output = "<log clientid=\"bogus client ID\"/>"; + + MetricsLog log("bogus client ID", 0); + log.CloseLog(); + + int size = log.GetEncodedLogSize(); + ASSERT_GT(size, 0); + + std::string encoded; + ASSERT_TRUE(log.GetEncodedLog(WriteInto(&encoded, size), size)); + + ASSERT_EQ(expected_output, encoded); +} + +namespace { + +class NoTimeMetricsLog : public MetricsLog { + public: + NoTimeMetricsLog(std::string client_id, int session_id): + MetricsLog(client_id, session_id) {} + virtual ~NoTimeMetricsLog() {} + + // Override this so that output is testable. + virtual std::string GetCurrentTimeString() { + return std::string(); + } +}; + +}; // namespace + +TEST(MetricsLogTest, WindowEvent) { + std::string expected_output = + "<log clientid=\"bogus client ID\">\n" + " <window action=\"create\" windowid=\"0\" session=\"0\" time=\"\"/>\n" + " <window action=\"open\" windowid=\"1\" parent=\"0\" " + "session=\"0\" time=\"\"/>\n" + " <window action=\"close\" windowid=\"1\" parent=\"0\" " + "session=\"0\" time=\"\"/>\n" + " <window action=\"destroy\" windowid=\"0\" session=\"0\" time=\"\"/>\n" + "</log>"; + + NoTimeMetricsLog log("bogus client ID", 0); + log.RecordWindowEvent(MetricsLog::WINDOW_CREATE, 0, -1); + log.RecordWindowEvent(MetricsLog::WINDOW_OPEN, 1, 0); + log.RecordWindowEvent(MetricsLog::WINDOW_CLOSE, 1, 0); + log.RecordWindowEvent(MetricsLog::WINDOW_DESTROY, 0, -1); + log.CloseLog(); + + ASSERT_EQ(4, log.num_events()); + + int size = log.GetEncodedLogSize(); + ASSERT_GT(size, 0); + + std::string encoded; + ASSERT_TRUE(log.GetEncodedLog(WriteInto(&encoded, size), size)); + + ASSERT_EQ(expected_output, encoded); +} + +TEST(MetricsLogTest, LoadEvent) { + std::string expected_output = + "<log clientid=\"bogus client ID\">\n" + " <document action=\"load\" docid=\"1\" window=\"3\" loadtime=\"7219\" " + "origin=\"link\" " + "session=\"0\" time=\"\"/>\n" + "</log>"; + + NoTimeMetricsLog log("bogus client ID", 0); + log.RecordLoadEvent(3, GURL("http://google.com"), PageTransition::LINK, + 1, TimeDelta::FromMilliseconds(7219)); + + log.CloseLog(); + + ASSERT_EQ(1, log.num_events()); + + int size = log.GetEncodedLogSize(); + ASSERT_GT(size, 0); + + std::string encoded; + ASSERT_TRUE(log.GetEncodedLog(WriteInto(&encoded, size), size)); + + ASSERT_EQ(expected_output, encoded); +} + +// Make sure our ID hashes are the same as what we see on the server side. +TEST(MetricsLogTest, CreateHash) { + static const struct { + std::string input; + std::string output; + } cases[] = { + {"Back", "0x0557fa923dcee4d0"}, + {"Forward", "0x67d2f6740a8eaebf"}, + {"NewTab", "0x290eb683f96572f1"}, + }; + + for (size_t i = 0; i < ARRAYSIZE_UNSAFE(cases); i++) { + std::string hash_string = MetricsLog::CreateHash(cases[i].input); + + // Convert to hex string + // We're only checking the first 8 bytes, because that's what + // the metrics server uses. + std::string hash_hex = "0x"; + for (size_t j = 0; j < 8; j++) { + StringAppendF(&hash_hex, "%02x", + static_cast<uint8>(hash_string.data()[j])); + } + EXPECT_EQ(cases[i].output, hash_hex); + } +}; + diff --git a/chrome/browser/metrics/metrics_response.cc b/chrome/browser/metrics/metrics_response.cc new file mode 100644 index 0000000..1bb6afa --- /dev/null +++ b/chrome/browser/metrics/metrics_response.cc @@ -0,0 +1,83 @@ +// Copyright (c) 2006-2008 The Chromium Authors. All rights reserved. +// Use of this source code is governed by a BSD-style license that can be +// found in the LICENSE file. + +#include <libxml/parser.h> + +#include "chrome/browser/metrics/metrics_response.h" + +// State to pass around during SAX parsing. +struct SAXState { + int collectors; + int events; + int interval; +}; + +// libxml uses xmlChar*, which is unsigned char* +inline const char* Char(const xmlChar* input) { + return reinterpret_cast<const char*>(input); +} + +static void SAXStartElement(void* user_data, + const xmlChar* name, + const xmlChar** attrs) { + if (!name || !attrs) + return; + + SAXState* state = static_cast<SAXState*>(user_data); + + if (strcmp(Char(name), "upload") == 0) { + for (int i = 0; attrs[i] && attrs[i + i]; i += 2) { + if (strcmp(Char(attrs[i]), "interval") == 0) { + state->interval = atoi(Char(attrs[i + 1])); + return; + } + } + } else if (strcmp(Char(name), "limit") == 0) { + for (int i = 0; attrs[i] && attrs[i + 1]; i += 2) { + if (strcmp(Char(attrs[i]), "events") == 0) { + state->events = atoi(Char(attrs[i + 1])); + return; + } + } + } else if (strcmp(Char(name), "collector") == 0) { + for (int i = 0; attrs[i] && attrs[i + 1]; i += 2) { + if (strcmp(Char(attrs[i]), "type") == 0) { + const char* type = Char(attrs[i + 1]); + if (strcmp(type, "document") == 0) { + state->collectors |= MetricsResponse::COLLECTOR_DOCUMENT; + } else if (strcmp(type, "profile") == 0) { + state->collectors |= MetricsResponse::COLLECTOR_PROFILE; + } else if (strcmp(type, "window") == 0) { + state->collectors |= MetricsResponse::COLLECTOR_WINDOW; + } else if (strcmp(type, "ui") == 0) { + state->collectors |= MetricsResponse::COLLECTOR_UI; + } + return; + } + } + } +} + +MetricsResponse::MetricsResponse(const std::string& response_xml) + : valid_(false), + collectors_(COLLECTOR_NONE), + events_(0), + interval_(0) { + if (response_xml.empty()) + return; + + xmlSAXHandler handler = {0}; + handler.startElement = SAXStartElement; + SAXState state = {0}; + + valid_ = !xmlSAXUserParseMemory(&handler, &state, + response_xml.data(), + static_cast<int>(response_xml.size())); + + collectors_ = state.collectors; + events_ = state.events; + interval_ = state.interval; +} + + diff --git a/chrome/browser/metrics/metrics_response.h b/chrome/browser/metrics/metrics_response.h new file mode 100644 index 0000000..c653fcf --- /dev/null +++ b/chrome/browser/metrics/metrics_response.h @@ -0,0 +1,58 @@ +// Copyright (c) 2006-2008 The Chromium Authors. All rights reserved. +// Use of this source code is governed by a BSD-style license that can be +// found in the LICENSE file. + +// This class exists to interpret the response from the metrics server. + +#ifndef CHROME_BROWSER_METRICS_RESPONSE_H__ +#define CHROME_BROWSER_METRICS_RESPONSE_H__ + +#include <string> + +#include "base/basictypes.h" + +class MetricsResponse { +public: + // Parses metrics response XML into the information we care about + // (how often to send metrics info, which info to send). + MetricsResponse(const std::string& response_xml); + + // True if the XML passed to the constructor was valid and parseable. + bool valid() { return valid_; } + + // Each flag (except NONE) defined here represents one type of metrics + // event that the server is interested in. + enum CollectorType { + COLLECTOR_NONE = 0x0, + COLLECTOR_PROFILE = 0x1, + COLLECTOR_WINDOW = 0x2, + COLLECTOR_DOCUMENT = 0x4, + COLLECTOR_UI = 0x8 + }; + + // This is the collection of CollectorTypes that are desired by the + // server, ORed together into one value. + int collectors() { return collectors_; } + + // Returns true if the given CollectorType is desired by the server. + bool collector_active(CollectorType type) { return !!(collectors_ & type); } + + // Returns the maximum number of event that the server wants in each + // metrics log sent. (If 0, no value was provided.) + int events() { return events_; } + + // Returns the size of the time interval that the server wants us to include + // in each log (in seconds). (If 0, no value was provided.) + int interval() { return interval_; } + +private: + bool valid_; + int collectors_; + int events_; + int interval_; + + DISALLOW_EVIL_CONSTRUCTORS(MetricsResponse); +}; + +#endif // CHROME_BROWSER_METRICS_RESPONSE_H__ + diff --git a/chrome/browser/metrics/metrics_response_unittest.cc b/chrome/browser/metrics/metrics_response_unittest.cc new file mode 100644 index 0000000..e3c4568 --- /dev/null +++ b/chrome/browser/metrics/metrics_response_unittest.cc @@ -0,0 +1,110 @@ +// Copyright (c) 2006-2008 The Chromium Authors. All rights reserved. +// Use of this source code is governed by a BSD-style license that can be +// found in the LICENSE file. + +#include <string> + +#include "chrome/browser/metrics/metrics_response.h" +#include "chrome/browser/metrics/metrics_service.h" +#include "base/string_util.h" +#include "testing/gtest/include/gtest/gtest.h" + +namespace { + class MetricsResponseTest : public testing::Test { + }; +}; + +static const char kNoLogResponse[] = + "<response xmlns=\"http://www.mozilla.org/metrics\"><config>" + "</config></response>"; + +static const char kLogResponse1[] = + "<response xmlns=\"http://www.mozilla.org/metrics\"><config>" + "<collectors>" + "<collector type=\"profile\"/>" + "<collector type=\"document\"/>" + "<collector type=\"window\"/>" + "<collector type=\"ui\"/>" + "</collectors>" + "<limit events=\"500\"/><upload interval=\"600\"/>" + "</config></response>"; + +static const char kLogResponse2[] = + "<response xmlns=\"http://www.mozilla.org/metrics\"><config>" + "<collectors>" + "<collector type=\"profile\"/>" + "<collector type=\"document\"/>" + "<collector type=\"window\"/>" + "</collectors>" + "<limit events=\"250\"/><upload interval=\"900\"/>" + "</config></response>"; + + +static const struct ResponseCase { + const char* response_xml; + int collectors; + int events; + int interval; + bool profile_active; + bool window_active; + bool document_active; + bool ui_active; +} response_cases[] = { + { + kNoLogResponse, + MetricsResponse::COLLECTOR_NONE, + 0, 0, + false, false, false, false + }, + { + kLogResponse1, + MetricsResponse::COLLECTOR_PROFILE | + MetricsResponse::COLLECTOR_DOCUMENT | + MetricsResponse::COLLECTOR_WINDOW | + MetricsResponse::COLLECTOR_UI, + 500, 600, + true, true, true, true + }, + { + kLogResponse2, + MetricsResponse::COLLECTOR_PROFILE | + MetricsResponse::COLLECTOR_DOCUMENT | + MetricsResponse::COLLECTOR_WINDOW, + 250, 900, + true, true, true, false + }, +}; + +TEST(MetricsResponseTest, ParseResponse) { + for (size_t i = 0; i < arraysize(response_cases); ++i) { + ResponseCase rcase = response_cases[i]; + MetricsResponse response(rcase.response_xml); + EXPECT_TRUE(response.valid()); + EXPECT_EQ(rcase.collectors, response.collectors()) << + "Mismatch in case " << i; + EXPECT_EQ(rcase.events, response.events()) << "Mismatch in case " << i; + EXPECT_EQ(rcase.interval, response.interval()) << "Mismatch in case " << i; + EXPECT_EQ(rcase.profile_active, + response.collector_active(MetricsResponse::COLLECTOR_PROFILE)) << + "Mismatch in case " << i; + EXPECT_EQ(rcase.window_active, + response.collector_active(MetricsResponse::COLLECTOR_WINDOW)) << + "Mismatch in case " << i; + EXPECT_EQ(rcase.document_active, + response.collector_active(MetricsResponse::COLLECTOR_DOCUMENT)) << + "Mismatch in case " << i; + EXPECT_EQ(rcase.ui_active, + response.collector_active(MetricsResponse::COLLECTOR_UI)) << + "Mismatch in case " << i; + } +} + +static const char* bogus_responses[] = {"", "<respo"}; +TEST(MetricsResponseTest, ParseBogusResponse) { + for (size_t i = 0; i < arraysize(bogus_responses); ++i) { + MetricsResponse response(bogus_responses[i]); + EXPECT_FALSE(response.valid()); + } +} + + diff --git a/chrome/browser/metrics/metrics_service.cc b/chrome/browser/metrics/metrics_service.cc new file mode 100644 index 0000000..399db59 --- /dev/null +++ b/chrome/browser/metrics/metrics_service.cc @@ -0,0 +1,1755 @@ +// Copyright (c) 2006-2008 The Chromium Authors. All rights reserved. +// Use of this source code is governed by a BSD-style license that can be +// found in the LICENSE file. + + + +//------------------------------------------------------------------------------ +// Description of the life cycle of a instance of MetricsService. +// +// OVERVIEW +// +// A MetricsService instance is typically created at application startup. It +// is the central controller for the acquisition of log data, and the automatic +// transmission of that log data to an external server. Its major job is to +// manage logs, grouping them for transmission, and transmitting them. As part +// of its grouping, MS finalizes logs by including some just-in-time gathered +// memory statistics, snapshotting the current stats of numerous histograms, +// closing the logs, translating to XML text, and compressing the results for +// transmission. Transmission includes submitting a compressed log as data in a +// URL-get, and retransmitting (or retaining at process termination) if the +// attempted transmission failed. Retention across process terminations is done +// using the the PrefServices facilities. The format for the retained +// logs (ones that never got transmitted) is always the uncompressed textual +// representation. +// +// Logs fall into one of two categories: "Initial logs," and "ongoing logs." +// There is at most one initial log sent for each complete run of the chrome +// product (from startup, to browser shutdown). An initial log is generally +// transmitted some short time (1 minute?) after startup, and includes stats +// such as recent crash info, the number and types of plugins, etc. The +// external server's response to the initial log conceptually tells +// this MS if it should continue transmitting logs (during this session). The +// server response can actually be much more detailed, and always includes (at +// a minimum) how often additional ongoing logs should be sent. +// +// After the above initial log, a series of ongoing logs will be transmitted. +// The first ongoing log actually begins to accumulate information stating when +// the MS was first constructed. Note that even though the initial log is +// commonly sent a full minute after startup, the initial log does not include +// much in the way of user stats. The most common interlog period (delay) +// is 20 minutes. That time period starts when the first user action causes a +// logging event. This means that if there is no user action, there may be long +// periods without any (ongoing) log transmissions. Ongoing log typically +// contain very detailed records of user activities (ex: opened tab, closed +// tab, fetched URL, maximized window, etc.) In addition, just before an +// ongoing log is closed out, a call is made to gather memory statistics. Those +// memory statistics are deposited into a histogram, and the log finalization +// code is then called. In the finalization, a call to a Histogram server +// acquires a list of all local histograms that have been flagged for upload +// to the UMA server. +// +// When the browser shuts down, there will typically be a fragment of an ongoing +// log that has not yet been transmitted. At shutdown time, that fragment +// is closed (including snapshotting histograms), and converted to text. Note +// that memory stats are not gathered during shutdown, as gathering *might* be +// too time consuming. The textual representation of the fragment of the +// ongoing log is then stored persistently as a string in the PrefServices, for +// potential transmission during a future run of the product. +// +// There are two slightly abnormal shutdown conditions. There is a +// "disconnected scenario," and a "really fast startup and shutdown" scenario. +// In the "never connected" situation, the user has (during the running of the +// process) never established an internet connection. As a result, attempts to +// transmit the initial log have failed, and a lot(?) of data has accumulated in +// the ongoing log (which didn't yet get closed, because there was never even a +// contemplation of sending it). There is also a kindred "lost connection" +// situation, where a loss of connection prevented an ongoing log from being +// transmitted, and a (still open) log was stuck accumulating a lot(?) of data, +// while the earlier log retried its transmission. In both of these +// disconnected situations, two logs need to be, and are, persistently stored +// for future transmission. +// +// The other unusual shutdown condition, termed "really fast startup and +// shutdown," involves the deliberate user termination of the process before +// the initial log is even formed or transmitted. In that situation, no logging +// is done, but the historical crash statistics remain (unlogged) for inclusion +// in a future run's initial log. (i.e., we don't lose crash stats). +// +// With the above overview, we can now describe the state machine's various +// stats, based on the State enum specified in the state_ member. Those states +// are: +// +// INITIALIZED, // Constructor was called. +// PLUGIN_LIST_REQUESTED, // Waiting for plugin list to be loaded. +// PLUGIN_LIST_ARRIVED, // Waiting for timer to send initial log. +// INITIAL_LOG_READY, // Initial log generated, and waiting for reply. +// SEND_OLD_INITIAL_LOGS, // Sending unsent logs from previous session. +// SENDING_OLD_LOGS, // Sending unsent logs from previous session. +// SENDING_CURRENT_LOGS, // Sending standard current logs as they accrue. +// +// In more detail, we have: +// +// INITIALIZED, // Constructor was called. +// The MS has been constructed, but has taken no actions to compose the +// initial log. +// +// PLUGIN_LIST_REQUESTED, // Waiting for plugin list to be loaded. +// Typically about 30 seconds after startup, a task is sent to a second thread +// to get the list of plugins. That task will (when complete) make an async +// callback (via a Task) to indicate the completion. +// +// PLUGIN_LIST_ARRIVED, // Waiting for timer to send initial log. +// The callback has arrived, and it is now possible for an initial log to be +// created. This callback typically arrives back less than one second after +// the task is dispatched. +// +// INITIAL_LOG_READY, // Initial log generated, and waiting for reply. +// This state is entered only after an initial log has been composed, and +// prepared for transmission. It is also the case that any previously unsent +// logs have been loaded into instance variables for possible transmission. +// +// SEND_OLD_INITIAL_LOGS, // Sending unsent logs from previous session. +// This state indicates that the initial log for this session has been +// successfully sent and it is now time to send any "initial logs" that were +// saved from previous sessions. Most commonly, there are none, but all old +// logs that were "initial logs" must be sent before this state is exited. +// +// SENDING_OLD_LOGS, // Sending unsent logs from previous session. +// This state indicates that there are no more unsent initial logs, and now any +// ongoing logs from previous sessions should be transmitted. All such logs +// will be transmitted before exiting this state, and proceeding with ongoing +// logs from the current session (see next state). +// +// SENDING_CURRENT_LOGS, // Sending standard current logs as they accrue. +// Current logs are being accumulated. Typically every 20 minutes a log is +// closed and finalized for transmission, at the same time as a new log is +// started. +// +// The progression through the above states is simple, and sequential, in the +// most common use cases. States proceed from INITIAL to SENDING_CURRENT_LOGS, +// and remain in the latter until shutdown. +// +// The one unusual case is when the user asks that we stop logging. When that +// happens, any pending (transmission in progress) log is pushed into the list +// of old unsent logs (the appropriate list, depending on whether it is an +// initial log, or an ongoing log). An addition, any log that is currently +// accumulating is also finalized, and pushed into the unsent log list. With +// those pushed performed, we regress back to the SEND_OLD_INITIAL_LOGS state in +// case the user enables log recording again during this session. This way +// anything we have "pushed back" will be sent automatically if/when we progress +// back to SENDING_CURRENT_LOG state. +// +// Also note that whenever the member variables containing unsent logs are +// modified (i.e., when we send an old log), we mirror the list of logs into +// the PrefServices. This ensures that IF we crash, we won't start up and +// retransmit our old logs again. +// +// Due to race conditions, it is always possible that a log file could be sent +// twice. For example, if a log file is sent, but not yet acknowledged by +// the external server, and the user shuts down, then a copy of the log may be +// saved for re-transmission. These duplicates could be filtered out server +// side, but are not expected to be a significantly statistical problem. +// +// +//------------------------------------------------------------------------------ + +#include <windows.h> + +#include "chrome/browser/metrics/metrics_service.h" + +#include "base/file_path.h" +#include "base/histogram.h" +#include "base/path_service.h" +#include "base/string_util.h" +#include "base/task.h" +#include "chrome/browser/bookmarks/bookmark_model.h" +#include "chrome/browser/browser.h" +#include "chrome/browser/browser_list.h" +#include "chrome/browser/browser_process.h" +#include "chrome/browser/load_notification_details.h" +#include "chrome/browser/memory_details.h" +#include "chrome/browser/plugin_process_info.h" +#include "chrome/browser/plugin_service.h" +#include "chrome/browser/profile.h" +#include "chrome/browser/render_process_host.h" +#include "chrome/browser/search_engines/template_url.h" +#include "chrome/browser/search_engines/template_url_model.h" +#include "chrome/common/chrome_paths.h" +#include "chrome/common/libxml_utils.h" +#include "chrome/common/pref_names.h" +#include "chrome/common/pref_service.h" +#include "chrome/installer/util/google_update_settings.h" +#include "googleurl/src/gurl.h" +#include "net/base/load_flags.h" +#include "third_party/bzip2/bzlib.h" + +using base::Time; +using base::TimeDelta; + +// Check to see that we're being called on only one thread. +static bool IsSingleThreaded(); + +static const char kMetricsURL[] = + "https://toolbarqueries.google.com/firefox/metrics/collect"; + +static const char kMetricsType[] = "application/vnd.mozilla.metrics.bz2"; + +// The delay, in seconds, after startup before sending the first log message. +static const int kInitialInterlogDuration = 60; // one minute + +// The default maximum number of events in a log uploaded to the UMA server. +static const int kInitialEventLimit = 2400; + +// If an upload fails, and the transmission was over this byte count, then we +// will discard the log, and not try to retransmit it. We also don't persist +// the log to the prefs for transmission during the next chrome session if this +// limit is exceeded. +static const int kUploadLogAvoidRetransmitSize = 50000; + +// When we have logs from previous Chrome sessions to send, how long should we +// delay (in seconds) between each log transmission. +static const int kUnsentLogDelay = 15; // 15 seconds + +// Minimum time a log typically exists before sending, in seconds. +// This number is supplied by the server, but until we parse it out of a server +// response, we use this duration to specify how long we should wait before +// sending the next log. If the channel is busy, such as when there is a +// failure during an attempt to transmit a previous log, then a log may wait +// (and continue to accrue now log entries) for a much greater period of time. +static const int kMinSecondsPerLog = 20 * 60; // twenty minutes + +// When we don't succeed at transmitting a log to a server, we progressively +// wait longer and longer before sending the next log. This backoff process +// help reduce load on the server, and makes the amount of backoff vary between +// clients so that a collision (server overload?) on retransmit is less likely. +// The following is the constant we use to expand that inter-log duration. +static const double kBackoff = 1.1; +// We limit the maximum backoff to be no greater than some multiple of the +// default kMinSecondsPerLog. The following is that maximum ratio. +static const int kMaxBackoff = 10; + +// Interval, in seconds, between state saves. +static const int kSaveStateInterval = 5 * 60; // five minutes + +// The number of "initial" logs we're willing to save, and hope to send during +// a future Chrome session. Initial logs contain crash stats, and are pretty +// small. +static const size_t kMaxInitialLogsPersisted = 20; + +// The number of ongoing logs we're willing to save persistently, and hope to +// send during a this or future sessions. Note that each log will be pretty +// large, as presumably the related "initial" log wasn't sent (probably nothing +// was, as the user was probably off-line). As a result, the log probably kept +// accumulating while the "initial" log was stalled (pending_), and couldn't be +// sent. As a result, we don't want to save too many of these mega-logs. +// A "standard shutdown" will create a small log, including just the data that +// was not yet been transmitted, and that is normal (to have exactly one +// ongoing_log_ at startup). +static const size_t kMaxOngoingLogsPersisted = 4; + + +// Handles asynchronous fetching of memory details. +// Will run the provided task after finished. +class MetricsMemoryDetails : public MemoryDetails { + public: + explicit MetricsMemoryDetails(Task* completion) : completion_(completion) {} + + virtual void OnDetailsAvailable() { + MessageLoop::current()->PostTask(FROM_HERE, completion_); + } + + private: + Task* completion_; + DISALLOW_EVIL_CONSTRUCTORS(MetricsMemoryDetails); +}; + +class MetricsService::GetPluginListTaskComplete : public Task { + virtual void Run() { + g_browser_process->metrics_service()->OnGetPluginListTaskComplete(); + } +}; + +class MetricsService::GetPluginListTask : public Task { + public: + explicit GetPluginListTask(MessageLoop* callback_loop) + : callback_loop_(callback_loop) {} + + virtual void Run() { + std::vector<WebPluginInfo> plugins; + PluginService::GetInstance()->GetPlugins(false, &plugins); + + callback_loop_->PostTask(FROM_HERE, new GetPluginListTaskComplete()); + } + + private: + MessageLoop* callback_loop_; +}; + +// static +void MetricsService::RegisterPrefs(PrefService* local_state) { + DCHECK(IsSingleThreaded()); + local_state->RegisterStringPref(prefs::kMetricsClientID, L""); + local_state->RegisterStringPref(prefs::kMetricsClientIDTimestamp, L"0"); + local_state->RegisterStringPref(prefs::kStabilityLaunchTimeSec, L"0"); + local_state->RegisterStringPref(prefs::kStabilityLastTimestampSec, L"0"); + local_state->RegisterStringPref(prefs::kStabilityUptimeSec, L"0"); + local_state->RegisterBooleanPref(prefs::kStabilityExitedCleanly, true); + local_state->RegisterBooleanPref(prefs::kStabilitySessionEndCompleted, true); + local_state->RegisterIntegerPref(prefs::kMetricsSessionID, -1); + local_state->RegisterIntegerPref(prefs::kStabilityLaunchCount, 0); + local_state->RegisterIntegerPref(prefs::kStabilityCrashCount, 0); + local_state->RegisterIntegerPref(prefs::kStabilityIncompleteSessionEndCount, + 0); + local_state->RegisterIntegerPref(prefs::kStabilityPageLoadCount, 0); + local_state->RegisterIntegerPref(prefs::kSecurityRendererOnSboxDesktop, 0); + local_state->RegisterIntegerPref(prefs::kSecurityRendererOnDefaultDesktop, 0); + local_state->RegisterIntegerPref(prefs::kStabilityRendererCrashCount, 0); + local_state->RegisterIntegerPref(prefs::kStabilityRendererHangCount, 0); + local_state->RegisterIntegerPref(prefs::kStabilityBreakpadRegistrationFail, + 0); + local_state->RegisterIntegerPref(prefs::kStabilityBreakpadRegistrationSuccess, + 0); + local_state->RegisterIntegerPref(prefs::kStabilityDebuggerPresent, 0); + local_state->RegisterIntegerPref(prefs::kStabilityDebuggerNotPresent, 0); + + local_state->RegisterDictionaryPref(prefs::kProfileMetrics); + local_state->RegisterIntegerPref(prefs::kNumBookmarksOnBookmarkBar, 0); + local_state->RegisterIntegerPref(prefs::kNumFoldersOnBookmarkBar, 0); + local_state->RegisterIntegerPref(prefs::kNumBookmarksInOtherBookmarkFolder, + 0); + local_state->RegisterIntegerPref(prefs::kNumFoldersInOtherBookmarkFolder, 0); + local_state->RegisterIntegerPref(prefs::kNumKeywords, 0); + local_state->RegisterListPref(prefs::kMetricsInitialLogs); + local_state->RegisterListPref(prefs::kMetricsOngoingLogs); +} + +MetricsService::MetricsService() + : recording_active_(false), + reporting_active_(false), + user_permits_upload_(false), + server_permits_upload_(true), + state_(INITIALIZED), + pending_log_(NULL), + pending_log_text_(""), + current_fetch_(NULL), + current_log_(NULL), + idle_since_last_transmission_(false), + next_window_id_(0), + log_sender_factory_(this), + state_saver_factory_(this), + logged_samples_(), + interlog_duration_(TimeDelta::FromSeconds(kInitialInterlogDuration)), + log_event_limit_(kInitialEventLimit), + timer_pending_(false) { + DCHECK(IsSingleThreaded()); + InitializeMetricsState(); +} + +MetricsService::~MetricsService() { + SetRecording(false); +} + +void MetricsService::SetUserPermitsUpload(bool enabled) { + HandleIdleSinceLastTransmission(false); + user_permits_upload_ = enabled; +} + +void MetricsService::Start() { + SetRecording(true); + SetReporting(true); +} + +void MetricsService::StartRecordingOnly() { + SetRecording(true); + SetReporting(false); +} + +void MetricsService::Stop() { + SetReporting(false); + SetRecording(false); +} + +void MetricsService::SetRecording(bool enabled) { + DCHECK(IsSingleThreaded()); + + if (enabled == recording_active_) + return; + + if (enabled) { + StartRecording(); + ListenerRegistration(true); + } else { + // Turn off all observers. + ListenerRegistration(false); + PushPendingLogsToUnsentLists(); + DCHECK(!pending_log()); + if (state_ > INITIAL_LOG_READY && unsent_logs()) + state_ = SEND_OLD_INITIAL_LOGS; + } + recording_active_ = enabled; +} + +bool MetricsService::recording_active() const { + DCHECK(IsSingleThreaded()); + return recording_active_; +} + +void MetricsService::SetReporting(bool enable) { + if (reporting_active_ != enable) { + reporting_active_ = enable; + if (reporting_active_) + StartLogTransmissionTimer(); + } +} + +bool MetricsService::reporting_active() const { + DCHECK(IsSingleThreaded()); + return reporting_active_; +} + +void MetricsService::Observe(NotificationType type, + const NotificationSource& source, + const NotificationDetails& details) { + DCHECK(current_log_); + DCHECK(IsSingleThreaded()); + + if (!CanLogNotification(type, source, details)) + return; + + switch (type) { + case NOTIFY_USER_ACTION: + current_log_->RecordUserAction(*Details<const wchar_t*>(details).ptr()); + break; + + case NOTIFY_BROWSER_OPENED: + case NOTIFY_BROWSER_CLOSED: + LogWindowChange(type, source, details); + break; + + case NOTIFY_TAB_PARENTED: + case NOTIFY_TAB_CLOSING: + LogWindowChange(type, source, details); + break; + + case NOTIFY_LOAD_STOP: + LogLoadComplete(type, source, details); + break; + + case NOTIFY_LOAD_START: + LogLoadStarted(); + break; + + case NOTIFY_RENDERER_PROCESS_TERMINATED: + if (!*Details<bool>(details).ptr()) + LogRendererCrash(); + break; + + case NOTIFY_RENDERER_PROCESS_HANG: + LogRendererHang(); + break; + + case NOTIFY_RENDERER_PROCESS_IN_SBOX: + LogRendererInSandbox(*Details<bool>(details).ptr()); + break; + + case NOTIFY_PLUGIN_PROCESS_HOST_CONNECTED: + case NOTIFY_PLUGIN_PROCESS_CRASHED: + case NOTIFY_PLUGIN_INSTANCE_CREATED: + LogPluginChange(type, source, details); + break; + + case TEMPLATE_URL_MODEL_LOADED: + LogKeywords(Source<TemplateURLModel>(source).ptr()); + break; + + case NOTIFY_OMNIBOX_OPENED_URL: + current_log_->RecordOmniboxOpenedURL( + *Details<AutocompleteLog>(details).ptr()); + break; + + case NOTIFY_BOOKMARK_MODEL_LOADED: + LogBookmarks(Source<Profile>(source)->GetBookmarkModel()); + break; + + default: + NOTREACHED(); + break; + } + + HandleIdleSinceLastTransmission(false); + + if (current_log_) + DLOG(INFO) << "METRICS: NUMBER OF LOGS = " << current_log_->num_events(); +} + +void MetricsService::HandleIdleSinceLastTransmission(bool in_idle) { + // If there wasn't a lot of action, maybe the computer was asleep, in which + // case, the log transmissions should have stopped. Here we start them up + // again. + if (!in_idle && idle_since_last_transmission_) + StartLogTransmissionTimer(); + idle_since_last_transmission_ = in_idle; +} + +void MetricsService::RecordCleanShutdown() { + RecordBooleanPrefValue(prefs::kStabilityExitedCleanly, true); +} + +void MetricsService::RecordStartOfSessionEnd() { + RecordBooleanPrefValue(prefs::kStabilitySessionEndCompleted, false); +} + +void MetricsService::RecordCompletedSessionEnd() { + RecordBooleanPrefValue(prefs::kStabilitySessionEndCompleted, true); +} + +void MetricsService:: RecordBreakpadRegistration(bool success) { + if (!success) + IncrementPrefValue(prefs::kStabilityBreakpadRegistrationFail); + else + IncrementPrefValue(prefs::kStabilityBreakpadRegistrationSuccess); +} + +void MetricsService::RecordBreakpadHasDebugger(bool has_debugger) { + if (!has_debugger) + IncrementPrefValue(prefs::kStabilityDebuggerNotPresent); + else + IncrementPrefValue(prefs::kStabilityDebuggerPresent); +} + +//------------------------------------------------------------------------------ +// private methods +//------------------------------------------------------------------------------ + + +//------------------------------------------------------------------------------ +// Initialization methods + +void MetricsService::InitializeMetricsState() { + PrefService* pref = g_browser_process->local_state(); + DCHECK(pref); + + client_id_ = WideToUTF8(pref->GetString(prefs::kMetricsClientID)); + if (client_id_.empty()) { + client_id_ = GenerateClientID(); + pref->SetString(prefs::kMetricsClientID, UTF8ToWide(client_id_)); + + // Might as well make a note of how long this ID has existed + pref->SetString(prefs::kMetricsClientIDTimestamp, + Int64ToWString(Time::Now().ToTimeT())); + } + + // Update session ID + session_id_ = pref->GetInteger(prefs::kMetricsSessionID); + ++session_id_; + pref->SetInteger(prefs::kMetricsSessionID, session_id_); + + // Stability bookkeeping + IncrementPrefValue(prefs::kStabilityLaunchCount); + + if (!pref->GetBoolean(prefs::kStabilityExitedCleanly)) { + IncrementPrefValue(prefs::kStabilityCrashCount); + } + + // This will be set to 'true' if we exit cleanly. + pref->SetBoolean(prefs::kStabilityExitedCleanly, false); + + if (!pref->GetBoolean(prefs::kStabilitySessionEndCompleted)) { + IncrementPrefValue(prefs::kStabilityIncompleteSessionEndCount); + } + // This is marked false when we get a WM_ENDSESSION. + pref->SetBoolean(prefs::kStabilitySessionEndCompleted, true); + + int64 last_start_time = + StringToInt64(pref->GetString(prefs::kStabilityLaunchTimeSec)); + int64 last_end_time = + StringToInt64(pref->GetString(prefs::kStabilityLastTimestampSec)); + int64 uptime = + StringToInt64(pref->GetString(prefs::kStabilityUptimeSec)); + + if (last_start_time && last_end_time) { + // TODO(JAR): Exclude sleep time. ... which must be gathered in UI loop. + uptime += last_end_time - last_start_time; + pref->SetString(prefs::kStabilityUptimeSec, Int64ToWString(uptime)); + } + pref->SetString(prefs::kStabilityLaunchTimeSec, + Int64ToWString(Time::Now().ToTimeT())); + + // Save profile metrics. + PrefService* prefs = g_browser_process->local_state(); + if (prefs) { + // Remove the current dictionary and store it for use when sending data to + // server. By removing the value we prune potentially dead profiles + // (and keys). All valid values are added back once services startup. + const DictionaryValue* profile_dictionary = + prefs->GetDictionary(prefs::kProfileMetrics); + if (profile_dictionary) { + // Do a deep copy of profile_dictionary since ClearPref will delete it. + profile_dictionary_.reset(static_cast<DictionaryValue*>( + profile_dictionary->DeepCopy())); + prefs->ClearPref(prefs::kProfileMetrics); + } + } + + // Kick off the process of saving the state (so the uptime numbers keep + // getting updated) every n minutes. + ScheduleNextStateSave(); +} + +void MetricsService::OnGetPluginListTaskComplete() { + DCHECK(state_ == PLUGIN_LIST_REQUESTED); + if (state_ == PLUGIN_LIST_REQUESTED) + state_ = PLUGIN_LIST_ARRIVED; +} + +std::string MetricsService::GenerateClientID() { + const int kGUIDSize = 39; + + GUID guid; + HRESULT guid_result = CoCreateGuid(&guid); + DCHECK(SUCCEEDED(guid_result)); + + std::wstring guid_string; + int result = StringFromGUID2(guid, + WriteInto(&guid_string, kGUIDSize), kGUIDSize); + DCHECK(result == kGUIDSize); + + return WideToUTF8(guid_string.substr(1, guid_string.length() - 2)); +} + + +//------------------------------------------------------------------------------ +// State save methods + +void MetricsService::ScheduleNextStateSave() { + state_saver_factory_.RevokeAll(); + + MessageLoop::current()->PostDelayedTask(FROM_HERE, + state_saver_factory_.NewRunnableMethod(&MetricsService::SaveLocalState), + kSaveStateInterval * 1000); +} + +void MetricsService::SaveLocalState() { + PrefService* pref = g_browser_process->local_state(); + if (!pref) { + NOTREACHED(); + return; + } + + RecordCurrentState(pref); + pref->ScheduleSavePersistentPrefs(g_browser_process->file_thread()); + + ScheduleNextStateSave(); +} + + +//------------------------------------------------------------------------------ +// Recording control methods + +void MetricsService::StartRecording() { + if (current_log_) + return; + + current_log_ = new MetricsLog(client_id_, session_id_); + if (state_ == INITIALIZED) { + // We only need to schedule that run once. + state_ = PLUGIN_LIST_REQUESTED; + + // Make sure the plugin list is loaded before the inital log is sent, so + // that the main thread isn't blocked generating the list. + g_browser_process->file_thread()->message_loop()->PostDelayedTask(FROM_HERE, + new GetPluginListTask(MessageLoop::current()), + kInitialInterlogDuration * 1000 / 2); + } +} + +void MetricsService::StopRecording(MetricsLog** log) { + if (!current_log_) + return; + + // TODO(jar): Integrate bounds on log recording more consistently, so that we + // can stop recording logs that are too big much sooner. + if (current_log_->num_events() > log_event_limit_) { + UMA_HISTOGRAM_COUNTS(L"UMA.Discarded Log Events", + current_log_->num_events()); + current_log_->CloseLog(); + delete current_log_; + current_log_ = NULL; + StartRecording(); // Start trivial log to hold our histograms. + } + + // Put incremental data (histogram deltas, and realtime stats deltas) at the + // end of all log transmissions (initial log handles this separately). + // Don't bother if we're going to discard current_log_. + if (log) { + current_log_->RecordIncrementalStabilityElements(); + RecordCurrentHistograms(); + } + + current_log_->CloseLog(); + if (log) + *log = current_log_; + else + delete current_log_; + current_log_ = NULL; +} + +void MetricsService::ListenerRegistration(bool start_listening) { + AddOrRemoveObserver(this, NOTIFY_BROWSER_OPENED, start_listening); + AddOrRemoveObserver(this, NOTIFY_BROWSER_CLOSED, start_listening); + AddOrRemoveObserver(this, NOTIFY_USER_ACTION, start_listening); + AddOrRemoveObserver(this, NOTIFY_TAB_PARENTED, start_listening); + AddOrRemoveObserver(this, NOTIFY_TAB_CLOSING, start_listening); + AddOrRemoveObserver(this, NOTIFY_LOAD_START, start_listening); + AddOrRemoveObserver(this, NOTIFY_LOAD_STOP, start_listening); + AddOrRemoveObserver(this, NOTIFY_RENDERER_PROCESS_IN_SBOX, start_listening); + AddOrRemoveObserver(this, NOTIFY_RENDERER_PROCESS_TERMINATED, + start_listening); + AddOrRemoveObserver(this, NOTIFY_RENDERER_PROCESS_HANG, start_listening); + AddOrRemoveObserver(this, NOTIFY_PLUGIN_PROCESS_HOST_CONNECTED, + start_listening); + AddOrRemoveObserver(this, NOTIFY_PLUGIN_INSTANCE_CREATED, start_listening); + AddOrRemoveObserver(this, NOTIFY_PLUGIN_PROCESS_CRASHED, start_listening); + AddOrRemoveObserver(this, TEMPLATE_URL_MODEL_LOADED, start_listening); + AddOrRemoveObserver(this, NOTIFY_OMNIBOX_OPENED_URL, start_listening); + AddOrRemoveObserver(this, NOTIFY_BOOKMARK_MODEL_LOADED, start_listening); +} + +// static +void MetricsService::AddOrRemoveObserver(NotificationObserver* observer, + NotificationType type, + bool is_add) { + NotificationService* service = NotificationService::current(); + + if (is_add) + service->AddObserver(observer, type, NotificationService::AllSources()); + else + service->RemoveObserver(observer, type, NotificationService::AllSources()); +} + +void MetricsService::PushPendingLogsToUnsentLists() { + if (state_ < INITIAL_LOG_READY) + return; // We didn't and still don't have time to get plugin list etc. + + if (pending_log()) { + PreparePendingLogText(); + if (state_ == INITIAL_LOG_READY) { + // We may race here, and send second copy of initial log later. + unsent_initial_logs_.push_back(pending_log_text_); + state_ = SEND_OLD_INITIAL_LOGS; + } else { + PushPendingLogTextToUnsentOngoingLogs(); + } + DiscardPendingLog(); + } + DCHECK(!pending_log()); + StopRecording(&pending_log_); + PreparePendingLogText(); + PushPendingLogTextToUnsentOngoingLogs(); + DiscardPendingLog(); + StoreUnsentLogs(); +} + +void MetricsService::PushPendingLogTextToUnsentOngoingLogs() { + // If UMA response told us not to upload, there's no need to save the pending + // log. It wasn't supposed to be uploaded anyway. + if (!server_permits_upload_) + return; + + if (pending_log_text_.length() > kUploadLogAvoidRetransmitSize) { + UMA_HISTOGRAM_COUNTS(L"UMA.Large Accumulated Log Not Persisted", + static_cast<int>(pending_log_text_.length())); + return; + } + unsent_ongoing_logs_.push_back(pending_log_text_); +} + +//------------------------------------------------------------------------------ +// Transmission of logs methods + +void MetricsService::StartLogTransmissionTimer() { + // If we're not reporting, there's no point in starting a log transmission + // timer. + if (!reporting_active()) + return; + + if (!current_log_) + return; // Recorder is shutdown. + + // If there is already a timer running, we leave it running. + // If timer_pending is true because the fetch is waiting for a response, + // we return for now and let the response handler start the timer. + if (timer_pending_) + return; + + // Before starting the timer, set timer_pending_ to true. + timer_pending_ = true; + + // Right before the UMA transmission gets started, there's one more thing we'd + // like to record: the histogram of memory usage, so we spawn a task to + // collect the memory details and when that task is finished, we arrange for + // TryToStartTransmission to take over. + MessageLoop::current()->PostDelayedTask(FROM_HERE, + log_sender_factory_. + NewRunnableMethod(&MetricsService::CollectMemoryDetails), + static_cast<int>(interlog_duration_.InMilliseconds())); +} + +void MetricsService::TryToStartTransmission() { + DCHECK(IsSingleThreaded()); + + // This function should only be called via timer, so timer_pending_ + // should be true. + DCHECK(timer_pending_); + timer_pending_ = false; + + DCHECK(!current_fetch_.get()); + + // If we're getting no notifications, then the log won't have much in it, and + // it's possible the computer is about to go to sleep, so don't upload and + // don't restart the transmission timer. + if (idle_since_last_transmission_) + return; + + // If somehow there is a fetch in progress, we return setting timer_pending_ + // to true and hope things work out. + if (current_fetch_.get()) { + timer_pending_ = true; + return; + } + + // If uploads are forbidden by UMA response, there's no point in keeping + // the current_log_, and the more often we delete it, the less likely it is + // to expand forever. + if (!server_permits_upload_ && current_log_) { + StopRecording(NULL); + StartRecording(); + } + + if (!current_log_) + return; // Logging was disabled. + if (!reporting_active()) + return; // Don't do work if we're not going to send anything now. + + MakePendingLog(); + + // MakePendingLog should have put something in the pending log, if it didn't, + // we start the timer again, return and hope things work out. + if (!pending_log()) { + StartLogTransmissionTimer(); + return; + } + + // If we're not supposed to upload any UMA data because the response or the + // user said so, cancel the upload at this point, but start the timer. + if (!TransmissionPermitted()) { + DiscardPendingLog(); + StartLogTransmissionTimer(); + return; + } + + PrepareFetchWithPendingLog(); + + if (!current_fetch_.get()) { + // Compression failed, and log discarded :-/. + DiscardPendingLog(); + StartLogTransmissionTimer(); // Maybe we'll do better next time + // TODO(jar): If compression failed, we should have created a tiny log and + // compressed that, so that we can signal that we're losing logs. + return; + } + + DCHECK(!timer_pending_); + + // The URL fetch is a like timer in that after a while we get called back + // so we set timer_pending_ true just as we start the url fetch. + timer_pending_ = true; + current_fetch_->Start(); + + HandleIdleSinceLastTransmission(true); +} + + +void MetricsService::MakePendingLog() { + if (pending_log()) + return; + + switch (state_) { + case INITIALIZED: + case PLUGIN_LIST_REQUESTED: // We should be further along by now. + DCHECK(false); + return; + + case PLUGIN_LIST_ARRIVED: + // We need to wait for the initial log to be ready before sending + // anything, because the server will tell us whether it wants to hear + // from us. + PrepareInitialLog(); + DCHECK(state_ == PLUGIN_LIST_ARRIVED); + RecallUnsentLogs(); + state_ = INITIAL_LOG_READY; + break; + + case SEND_OLD_INITIAL_LOGS: + if (!unsent_initial_logs_.empty()) { + pending_log_text_ = unsent_initial_logs_.back(); + break; + } + state_ = SENDING_OLD_LOGS; + // Fall through. + + case SENDING_OLD_LOGS: + if (!unsent_ongoing_logs_.empty()) { + pending_log_text_ = unsent_ongoing_logs_.back(); + break; + } + state_ = SENDING_CURRENT_LOGS; + // Fall through. + + case SENDING_CURRENT_LOGS: + StopRecording(&pending_log_); + StartRecording(); + break; + + default: + DCHECK(false); + return; + } + + DCHECK(pending_log()); +} + +bool MetricsService::TransmissionPermitted() const { + // If the user forbids uploading that's they're business, and we don't upload + // anything. If the server forbids uploading, that's our business, so we take + // that to mean it forbids current logs, but we still send up the inital logs + // and any old logs. + if (!user_permits_upload_) + return false; + if (server_permits_upload_) + return true; + + switch (state_) { + case INITIAL_LOG_READY: + case SEND_OLD_INITIAL_LOGS: + case SENDING_OLD_LOGS: + return true; + + case SENDING_CURRENT_LOGS: + default: + return false; + } +} + +void MetricsService::CollectMemoryDetails() { + Task* task = log_sender_factory_. + NewRunnableMethod(&MetricsService::TryToStartTransmission); + MetricsMemoryDetails* details = new MetricsMemoryDetails(task); + details->StartFetch(); + + // Collect WebCore cache information to put into a histogram. + for (RenderProcessHost::iterator it = RenderProcessHost::begin(); + it != RenderProcessHost::end(); ++it) { + it->second->Send(new ViewMsg_GetCacheResourceStats()); + } +} + +void MetricsService::PrepareInitialLog() { + DCHECK(state_ == PLUGIN_LIST_ARRIVED); + std::vector<WebPluginInfo> plugins; + PluginService::GetInstance()->GetPlugins(false, &plugins); + + MetricsLog* log = new MetricsLog(client_id_, session_id_); + log->RecordEnvironment(plugins, profile_dictionary_.get()); + + // Histograms only get written to current_log_, so setup for the write. + MetricsLog* save_log = current_log_; + current_log_ = log; + RecordCurrentHistograms(); // Into current_log_... which is really log. + current_log_ = save_log; + + log->CloseLog(); + DCHECK(!pending_log()); + pending_log_ = log; +} + +void MetricsService::RecallUnsentLogs() { + DCHECK(unsent_initial_logs_.empty()); + DCHECK(unsent_ongoing_logs_.empty()); + + PrefService* local_state = g_browser_process->local_state(); + DCHECK(local_state); + + ListValue* unsent_initial_logs = local_state->GetMutableList( + prefs::kMetricsInitialLogs); + for (ListValue::iterator it = unsent_initial_logs->begin(); + it != unsent_initial_logs->end(); ++it) { + std::string log; + (*it)->GetAsString(&log); + unsent_initial_logs_.push_back(log); + } + + ListValue* unsent_ongoing_logs = local_state->GetMutableList( + prefs::kMetricsOngoingLogs); + for (ListValue::iterator it = unsent_ongoing_logs->begin(); + it != unsent_ongoing_logs->end(); ++it) { + std::string log; + (*it)->GetAsString(&log); + unsent_ongoing_logs_.push_back(log); + } +} + +void MetricsService::StoreUnsentLogs() { + if (state_ < INITIAL_LOG_READY) + return; // We never Recalled the prior unsent logs. + + PrefService* local_state = g_browser_process->local_state(); + DCHECK(local_state); + + ListValue* unsent_initial_logs = local_state->GetMutableList( + prefs::kMetricsInitialLogs); + unsent_initial_logs->Clear(); + size_t start = 0; + if (unsent_initial_logs_.size() > kMaxInitialLogsPersisted) + start = unsent_initial_logs_.size() - kMaxInitialLogsPersisted; + for (size_t i = start; i < unsent_initial_logs_.size(); ++i) + unsent_initial_logs->Append( + Value::CreateStringValue(unsent_initial_logs_[i])); + + ListValue* unsent_ongoing_logs = local_state->GetMutableList( + prefs::kMetricsOngoingLogs); + unsent_ongoing_logs->Clear(); + start = 0; + if (unsent_ongoing_logs_.size() > kMaxOngoingLogsPersisted) + start = unsent_ongoing_logs_.size() - kMaxOngoingLogsPersisted; + for (size_t i = start; i < unsent_ongoing_logs_.size(); ++i) + unsent_ongoing_logs->Append( + Value::CreateStringValue(unsent_ongoing_logs_[i])); +} + +void MetricsService::PreparePendingLogText() { + DCHECK(pending_log()); + if (!pending_log_text_.empty()) + return; + int original_size = pending_log_->GetEncodedLogSize(); + pending_log_->GetEncodedLog(WriteInto(&pending_log_text_, original_size), + original_size); +} + +void MetricsService::PrepareFetchWithPendingLog() { + DCHECK(pending_log()); + DCHECK(!current_fetch_.get()); + PreparePendingLogText(); + DCHECK(!pending_log_text_.empty()); + + // Allow security conscious users to see all metrics logs that we send. + LOG(INFO) << "METRICS LOG: " << pending_log_text_; + + std::string compressed_log; + if (!Bzip2Compress(pending_log_text_, &compressed_log)) { + NOTREACHED() << "Failed to compress log for transmission."; + DiscardPendingLog(); + StartLogTransmissionTimer(); // Maybe we'll do better on next log :-/. + return; + } + + current_fetch_.reset(new URLFetcher(GURL(kMetricsURL), URLFetcher::POST, + this)); + current_fetch_->set_request_context(Profile::GetDefaultRequestContext()); + current_fetch_->set_upload_data(kMetricsType, compressed_log); + // This flag works around the cert mismatch on toolbarqueries.google.com. + current_fetch_->set_load_flags(net::LOAD_IGNORE_CERT_COMMON_NAME_INVALID); +} + +void MetricsService::DiscardPendingLog() { + if (pending_log_) { // Shutdown might have deleted it! + delete pending_log_; + pending_log_ = NULL; + } + pending_log_text_.clear(); +} + +// This implementation is based on the Firefox MetricsService implementation. +bool MetricsService::Bzip2Compress(const std::string& input, + std::string* output) { + bz_stream stream = {0}; + // As long as our input is smaller than the bzip2 block size, we should get + // the best compression. For example, if your input was 250k, using a block + // size of 300k or 500k should result in the same compression ratio. Since + // our data should be under 100k, using the minimum block size of 100k should + // allocate less temporary memory, but result in the same compression ratio. + int result = BZ2_bzCompressInit(&stream, + 1, // 100k (min) block size + 0, // quiet + 0); // default "work factor" + if (result != BZ_OK) { // out of memory? + return false; + } + + output->clear(); + + stream.next_in = const_cast<char*>(input.data()); + stream.avail_in = static_cast<int>(input.size()); + // NOTE: we don't need a BZ_RUN phase since our input buffer contains + // the entire input + do { + output->resize(output->size() + 1024); + stream.next_out = &((*output)[stream.total_out_lo32]); + stream.avail_out = static_cast<int>(output->size()) - stream.total_out_lo32; + result = BZ2_bzCompress(&stream, BZ_FINISH); + } while (result == BZ_FINISH_OK); + if (result != BZ_STREAM_END) // unknown failure? + return false; + result = BZ2_bzCompressEnd(&stream); + DCHECK(result == BZ_OK); + + output->resize(stream.total_out_lo32); + + return true; +} + +static const char* StatusToString(const URLRequestStatus& status) { + switch (status.status()) { + case URLRequestStatus::SUCCESS: + return "SUCCESS"; + + case URLRequestStatus::IO_PENDING: + return "IO_PENDING"; + + case URLRequestStatus::HANDLED_EXTERNALLY: + return "HANDLED_EXTERNALLY"; + + case URLRequestStatus::CANCELED: + return "CANCELED"; + + case URLRequestStatus::FAILED: + return "FAILED"; + + default: + NOTREACHED(); + return "Unknown"; + } +} + +void MetricsService::OnURLFetchComplete(const URLFetcher* source, + const GURL& url, + const URLRequestStatus& status, + int response_code, + const ResponseCookies& cookies, + const std::string& data) { + DCHECK(timer_pending_); + timer_pending_ = false; + DCHECK(current_fetch_.get()); + current_fetch_.reset(NULL); // We're not allowed to re-use it. + + // Confirm send so that we can move on. + DLOG(INFO) << "METRICS RESPONSE CODE: " << response_code << " status=" << + StatusToString(status); + + // TODO(petersont): Refactor or remove the following so that we don't have to + // fake a valid response code. + if (response_code != 200 && + pending_log_text_.length() > kUploadLogAvoidRetransmitSize) { + UMA_HISTOGRAM_COUNTS(L"UMA.Large Rejected Log was Discarded", + static_cast<int>(pending_log_text_.length())); + response_code = 200; // Simulate transmission so we will discard log. + } + + if (response_code != 200) { + HandleBadResponseCode(); + } else { // Success. + DLOG(INFO) << "METRICS RESPONSE DATA: " << data; + switch (state_) { + case INITIAL_LOG_READY: + state_ = SEND_OLD_INITIAL_LOGS; + break; + + case SEND_OLD_INITIAL_LOGS: + DCHECK(!unsent_initial_logs_.empty()); + unsent_initial_logs_.pop_back(); + StoreUnsentLogs(); + break; + + case SENDING_OLD_LOGS: + DCHECK(!unsent_ongoing_logs_.empty()); + unsent_ongoing_logs_.pop_back(); + StoreUnsentLogs(); + break; + + case SENDING_CURRENT_LOGS: + break; + + default: + DCHECK(false); + break; + } + + DiscardPendingLog(); + // Since we sent a log, make sure our in-memory state is recorded to disk. + PrefService* local_state = g_browser_process->local_state(); + DCHECK(local_state); + if (local_state) + local_state->ScheduleSavePersistentPrefs( + g_browser_process->file_thread()); + + // Provide a default (free of exponetial backoff, other varances) in case + // the server does not specify a value. + interlog_duration_ = TimeDelta::FromSeconds(kMinSecondsPerLog); + + GetSettingsFromResponseData(data); + // Override server specified interlog delay if there are unsent logs to + // transmit. + if (unsent_logs()) { + DCHECK(state_ < SENDING_CURRENT_LOGS); + interlog_duration_ = TimeDelta::FromSeconds(kUnsentLogDelay); + } + } + + StartLogTransmissionTimer(); +} + +void MetricsService::HandleBadResponseCode() { + DLOG(INFO) << "METRICS: transmission attempt returned a failure code. " + "Verify network connectivity"; +#ifndef NDEBUG + DLOG(INFO) << "Verify your metrics logs are formatted correctly. " + "Verify server is active at " << kMetricsURL; +#endif + if (!pending_log()) { + DLOG(INFO) << "METRICS: Recorder shutdown during log transmission."; + } else { + // Send progressively less frequently. + DCHECK(kBackoff > 1.0); + interlog_duration_ = TimeDelta::FromMicroseconds( + static_cast<int64>(kBackoff * interlog_duration_.InMicroseconds())); + + if (kMaxBackoff * TimeDelta::FromSeconds(kMinSecondsPerLog) < + interlog_duration_) { + interlog_duration_ = kMaxBackoff * + TimeDelta::FromSeconds(kMinSecondsPerLog); + } + + DLOG(INFO) << "METRICS: transmission retry being scheduled in " << + interlog_duration_.InSeconds() << " seconds for " << + pending_log_text_; + } +} + +void MetricsService::GetSettingsFromResponseData(const std::string& data) { + // We assume that the file is structured as a block opened by <response> + // and that inside response, there is a block opened by tag <chrome_config> + // other tags are ignored for now except the content of <chrome_config>. + DLOG(INFO) << "METRICS: getting settings from response data: " << data; + + int data_size = static_cast<int>(data.size()); + if (data_size < 0) { + DLOG(INFO) << "METRICS: server response data bad size: " << data_size << + "; aborting extraction of settings"; + return; + } + xmlDocPtr doc = xmlReadMemory(data.c_str(), data_size, "", NULL, 0); + DCHECK(doc); + // If the document is malformed, we just use the settings that were there. + if (!doc) { + DLOG(INFO) << "METRICS: reading xml from server response data failed"; + return; + } + + xmlNodePtr top_node = xmlDocGetRootElement(doc), chrome_config_node = NULL; + // Here, we find the chrome_config node by name. + for (xmlNodePtr p = top_node->children; p; p = p->next) { + if (xmlStrEqual(p->name, BAD_CAST "chrome_config")) { + chrome_config_node = p; + break; + } + } + // If the server data is formatted wrong and there is no + // config node where we expect, we just drop out. + if (chrome_config_node != NULL) + GetSettingsFromChromeConfigNode(chrome_config_node); + xmlFreeDoc(doc); +} + +void MetricsService::GetSettingsFromChromeConfigNode( + xmlNodePtr chrome_config_node) { + // Iterate through all children of the config node. + for (xmlNodePtr current_node = chrome_config_node->children; + current_node; + current_node = current_node->next) { + // If we find the upload tag, we appeal to another function + // GetSettingsFromUploadNode to read all the data in it. + if (xmlStrEqual(current_node->name, BAD_CAST "upload")) { + GetSettingsFromUploadNode(current_node); + continue; + } + } +} + +void MetricsService::InheritedProperties::OverwriteWhereNeeded( + xmlNodePtr node) { + xmlChar* salt_value = xmlGetProp(node, BAD_CAST "salt"); + if (salt_value) // If the property isn't there, xmlGetProp returns NULL. + salt = atoi(reinterpret_cast<char*>(salt_value)); + // If the property isn't there, we keep the value the property had before + + xmlChar* denominator_value = xmlGetProp(node, BAD_CAST "denominator"); + if (denominator_value) + denominator = atoi(reinterpret_cast<char*>(denominator_value)); +} + +void MetricsService::GetSettingsFromUploadNode(xmlNodePtr upload_node) { + InheritedProperties props; + GetSettingsFromUploadNodeRecursive(upload_node, props, "", true); +} + +void MetricsService::GetSettingsFromUploadNodeRecursive( + xmlNodePtr node, + InheritedProperties props, + std::string path_prefix, + bool uploadOn) { + props.OverwriteWhereNeeded(node); + + // The bool uploadOn is set to true if the data represented by current + // node should be uploaded. This gets inherited in the tree; the children + // of a node that has already been rejected for upload get rejected for + // upload. + uploadOn = uploadOn && NodeProbabilityTest(node, props); + + // The path is a / separated list of the node names ancestral to the current + // one. So, if you want to check if the current node has a certain name, + // compare to name. If you want to check if it is a certan tag at a certain + // place in the tree, compare to the whole path. + std::string name = std::string(reinterpret_cast<const char*>(node->name)); + std::string path = path_prefix + "/" + name; + + if (path == "/upload") { + xmlChar* upload_interval_val = xmlGetProp(node, BAD_CAST "interval"); + if (upload_interval_val) { + interlog_duration_ = TimeDelta::FromSeconds( + atoi(reinterpret_cast<char*>(upload_interval_val))); + } + + server_permits_upload_ = uploadOn; + } + if (path == "/upload/logs") { + xmlChar* log_event_limit_val = xmlGetProp(node, BAD_CAST "event_limit"); + if (log_event_limit_val) + log_event_limit_ = atoi(reinterpret_cast<char*>(log_event_limit_val)); + } + if (name == "histogram") { + xmlChar* type_value = xmlGetProp(node, BAD_CAST "type"); + if (type_value) { + std::string type = (reinterpret_cast<char*>(type_value)); + if (uploadOn) + histograms_to_upload_.insert(type); + else + histograms_to_omit_.insert(type); + } + } + if (name == "log") { + xmlChar* type_value = xmlGetProp(node, BAD_CAST "type"); + if (type_value) { + std::string type = (reinterpret_cast<char*>(type_value)); + if (uploadOn) + logs_to_upload_.insert(type); + else + logs_to_omit_.insert(type); + } + } + + // Recursive call. If the node is a leaf i.e. if it ends in a "/>", then it + // doesn't have children, so node->children is NULL, and this loop doesn't + // call (that's how the recursion ends). + for (xmlNodePtr child_node = node->children; + child_node; + child_node = child_node->next) { + GetSettingsFromUploadNodeRecursive(child_node, props, path, uploadOn); + } +} + +bool MetricsService::NodeProbabilityTest(xmlNodePtr node, + InheritedProperties props) const { + // Default value of probability on any node is 1, but recall that + // its parents can already have been rejected for upload. + double probability = 1; + + // If a probability is specified in the node, we use it instead. + xmlChar* probability_value = xmlGetProp(node, BAD_CAST "probability"); + if (probability_value) + probability = atoi(reinterpret_cast<char*>(probability_value)); + + return ProbabilityTest(probability, props.salt, props.denominator); +} + +bool MetricsService::ProbabilityTest(double probability, + int salt, + int denominator) const { + // Okay, first we figure out how many of the digits of the + // client_id_ we need in order to make a nice pseudorandomish + // number in the range [0,denominator). Too many digits is + // fine. + int relevant_digits = + static_cast<int>(log10(static_cast<double>(denominator)) + 1.0); + + // n is the length of the client_id_ string + size_t n = client_id_.size(); + + // idnumber is a positive integer generated from the client_id_. + // It plus salt is going to give us our pseudorandom number. + int idnumber = 0; + const char* client_id_c_str = client_id_.c_str(); + + // Here we hash the relevant digits of the client_id_ + // string somehow to get a big integer idnumber (could be negative + // from wraparound) + int big = 1; + for (size_t j = n - 1; j >= 0; --j) { + idnumber += static_cast<int>(client_id_c_str[j]) * big; + big *= 10; + } + + // Mod id number by denominator making sure to get a non-negative + // answer. + idnumber = ((idnumber % denominator) + denominator) % denominator; + + // ((idnumber + salt) % denominator) / denominator is in the range [0,1] + // if it's less than probability we call that an affirmative coin + // toss. + return static_cast<double>((idnumber + salt) % denominator) < + probability * denominator; +} + +void MetricsService::LogWindowChange(NotificationType type, + const NotificationSource& source, + const NotificationDetails& details) { + int controller_id = -1; + uintptr_t window_or_tab = source.map_key(); + MetricsLog::WindowEventType window_type; + + // Note: since we stop all logging when a single OTR session is active, it is + // possible that we start getting notifications about a window that we don't + // know about. + if (window_map_.find(window_or_tab) == window_map_.end()) { + controller_id = next_window_id_++; + window_map_[window_or_tab] = controller_id; + } else { + controller_id = window_map_[window_or_tab]; + } + DCHECK(controller_id != -1); + + switch (type) { + case NOTIFY_TAB_PARENTED: + case NOTIFY_BROWSER_OPENED: + window_type = MetricsLog::WINDOW_CREATE; + break; + + case NOTIFY_TAB_CLOSING: + case NOTIFY_BROWSER_CLOSED: + window_map_.erase(window_map_.find(window_or_tab)); + window_type = MetricsLog::WINDOW_DESTROY; + break; + + default: + NOTREACHED(); + break; + } + + // TODO(brettw) we should have some kind of ID for the parent. + current_log_->RecordWindowEvent(window_type, controller_id, 0); +} + +void MetricsService::LogLoadComplete(NotificationType type, + const NotificationSource& source, + const NotificationDetails& details) { + if (details == NotificationService::NoDetails()) + return; + + // TODO(jar): There is a bug causing this to be called too many times, and + // the log overflows. For now, we won't record these events. + UMA_HISTOGRAM_COUNTS(L"UMA.LogLoadComplete called", 1); + return; + + const Details<LoadNotificationDetails> load_details(details); + int controller_id = window_map_[details.map_key()]; + current_log_->RecordLoadEvent(controller_id, + load_details->url(), + load_details->origin(), + load_details->session_index(), + load_details->load_time()); +} + +void MetricsService::IncrementPrefValue(const wchar_t* path) { + PrefService* pref = g_browser_process->local_state(); + DCHECK(pref); + int value = pref->GetInteger(path); + pref->SetInteger(path, value + 1); +} + +void MetricsService::LogLoadStarted() { + IncrementPrefValue(prefs::kStabilityPageLoadCount); + // We need to save the prefs, as page load count is a critical stat, and it + // might be lost due to a crash :-(. +} + +void MetricsService::LogRendererInSandbox(bool on_sandbox_desktop) { + PrefService* prefs = g_browser_process->local_state(); + DCHECK(prefs); + if (on_sandbox_desktop) + IncrementPrefValue(prefs::kSecurityRendererOnSboxDesktop); + else + IncrementPrefValue(prefs::kSecurityRendererOnDefaultDesktop); +} + +void MetricsService::LogRendererCrash() { + IncrementPrefValue(prefs::kStabilityRendererCrashCount); +} + +void MetricsService::LogRendererHang() { + IncrementPrefValue(prefs::kStabilityRendererHangCount); +} + +void MetricsService::LogPluginChange(NotificationType type, + const NotificationSource& source, + const NotificationDetails& details) { + FilePath plugin = Details<PluginProcessInfo>(details)->plugin_path(); + + if (plugin_stats_buffer_.find(plugin) == plugin_stats_buffer_.end()) { + plugin_stats_buffer_[plugin] = PluginStats(); + } + + PluginStats& stats = plugin_stats_buffer_[plugin]; + switch (type) { + case NOTIFY_PLUGIN_PROCESS_HOST_CONNECTED: + stats.process_launches++; + break; + + case NOTIFY_PLUGIN_INSTANCE_CREATED: + stats.instances++; + break; + + case NOTIFY_PLUGIN_PROCESS_CRASHED: + stats.process_crashes++; + break; + + default: + NOTREACHED() << "Unexpected notification type " << type; + return; + } +} + +// Recursively counts the number of bookmarks and folders in node. +static void CountBookmarks(BookmarkNode* node, int* bookmarks, int* folders) { + if (node->GetType() == history::StarredEntry::URL) + (*bookmarks)++; + else + (*folders)++; + for (int i = 0; i < node->GetChildCount(); ++i) + CountBookmarks(node->GetChild(i), bookmarks, folders); +} + +void MetricsService::LogBookmarks(BookmarkNode* node, + const wchar_t* num_bookmarks_key, + const wchar_t* num_folders_key) { + DCHECK(node); + int num_bookmarks = 0; + int num_folders = 0; + CountBookmarks(node, &num_bookmarks, &num_folders); + num_folders--; // Don't include the root folder in the count. + + PrefService* pref = g_browser_process->local_state(); + DCHECK(pref); + pref->SetInteger(num_bookmarks_key, num_bookmarks); + pref->SetInteger(num_folders_key, num_folders); +} + +void MetricsService::LogBookmarks(BookmarkModel* model) { + DCHECK(model); + LogBookmarks(model->GetBookmarkBarNode(), + prefs::kNumBookmarksOnBookmarkBar, + prefs::kNumFoldersOnBookmarkBar); + LogBookmarks(model->other_node(), + prefs::kNumBookmarksInOtherBookmarkFolder, + prefs::kNumFoldersInOtherBookmarkFolder); + ScheduleNextStateSave(); +} + +void MetricsService::LogKeywords(const TemplateURLModel* url_model) { + DCHECK(url_model); + + PrefService* pref = g_browser_process->local_state(); + DCHECK(pref); + pref->SetInteger(prefs::kNumKeywords, + static_cast<int>(url_model->GetTemplateURLs().size())); + ScheduleNextStateSave(); +} + +void MetricsService::RecordPluginChanges(PrefService* pref) { + ListValue* plugins = pref->GetMutableList(prefs::kStabilityPluginStats); + DCHECK(plugins); + + for (ListValue::iterator value_iter = plugins->begin(); + value_iter != plugins->end(); ++value_iter) { + if (!(*value_iter)->IsType(Value::TYPE_DICTIONARY)) { + NOTREACHED(); + continue; + } + + DictionaryValue* plugin_dict = static_cast<DictionaryValue*>(*value_iter); + FilePath::StringType plugin_path_str; + plugin_dict->GetString(prefs::kStabilityPluginPath, &plugin_path_str); + if (plugin_path_str.empty()) { + NOTREACHED(); + continue; + } + + FilePath plugin_path(plugin_path_str); + if (plugin_stats_buffer_.find(plugin_path) == plugin_stats_buffer_.end()) + continue; + + PluginStats stats = plugin_stats_buffer_[plugin_path]; + if (stats.process_launches) { + int launches = 0; + plugin_dict->GetInteger(prefs::kStabilityPluginLaunches, &launches); + launches += stats.process_launches; + plugin_dict->SetInteger(prefs::kStabilityPluginLaunches, launches); + } + if (stats.process_crashes) { + int crashes = 0; + plugin_dict->GetInteger(prefs::kStabilityPluginCrashes, &crashes); + crashes += stats.process_crashes; + plugin_dict->SetInteger(prefs::kStabilityPluginCrashes, crashes); + } + if (stats.instances) { + int instances = 0; + plugin_dict->GetInteger(prefs::kStabilityPluginInstances, &instances); + instances += stats.instances; + plugin_dict->SetInteger(prefs::kStabilityPluginInstances, instances); + } + + plugin_stats_buffer_.erase(plugin_path); + } + + // Now go through and add dictionaries for plugins that didn't already have + // reports in Local State. + for (std::map<FilePath, PluginStats>::iterator cache_iter = + plugin_stats_buffer_.begin(); + cache_iter != plugin_stats_buffer_.end(); ++cache_iter) { + FilePath plugin_path = cache_iter->first; + PluginStats stats = cache_iter->second; + DictionaryValue* plugin_dict = new DictionaryValue; + + plugin_dict->SetString(prefs::kStabilityPluginPath, plugin_path.value()); + plugin_dict->SetInteger(prefs::kStabilityPluginLaunches, + stats.process_launches); + plugin_dict->SetInteger(prefs::kStabilityPluginCrashes, + stats.process_crashes); + plugin_dict->SetInteger(prefs::kStabilityPluginInstances, + stats.instances); + plugins->Append(plugin_dict); + } + plugin_stats_buffer_.clear(); +} + +bool MetricsService::CanLogNotification(NotificationType type, + const NotificationSource& source, + const NotificationDetails& details) { + // We simply don't log anything to UMA if there is a single off the record + // session visible. The problem is that we always notify using the orginal + // profile in order to simplify notification processing. + return !BrowserList::IsOffTheRecordSessionActive(); +} + +void MetricsService::RecordBooleanPrefValue(const wchar_t* path, bool value) { + DCHECK(IsSingleThreaded()); + + PrefService* pref = g_browser_process->local_state(); + DCHECK(pref); + + pref->SetBoolean(path, value); + RecordCurrentState(pref); +} + +void MetricsService::RecordCurrentState(PrefService* pref) { + pref->SetString(prefs::kStabilityLastTimestampSec, + Int64ToWString(Time::Now().ToTimeT())); + + RecordPluginChanges(pref); +} + +void MetricsService::RecordCurrentHistograms() { + DCHECK(current_log_); + + StatisticsRecorder::Histograms histograms; + StatisticsRecorder::GetHistograms(&histograms); + for (StatisticsRecorder::Histograms::iterator it = histograms.begin(); + histograms.end() != it; + ++it) { + if ((*it)->flags() & kUmaTargetedHistogramFlag) + // TODO(petersont): Only record historgrams if they are not precluded by + // the UMA response data. + // Bug http://code.google.com/p/chromium/issues/detail?id=2739. + RecordHistogram(**it); + } +} + +void MetricsService::RecordHistogram(const Histogram& histogram) { + // Get up-to-date snapshot of sample stats. + Histogram::SampleSet snapshot; + histogram.SnapshotSample(&snapshot); + + const std::string& histogram_name = histogram.histogram_name(); + + // Find the already sent stats, or create an empty set. + LoggedSampleMap::iterator it = logged_samples_.find(histogram_name); + Histogram::SampleSet* already_logged; + if (logged_samples_.end() == it) { + // Add new entry + already_logged = &logged_samples_[histogram.histogram_name()]; + already_logged->Resize(histogram); // Complete initialization. + } else { + already_logged = &(it->second); + // Deduct any stats we've already logged from our snapshot. + snapshot.Subtract(*already_logged); + } + + // snapshot now contains only a delta to what we've already_logged. + + if (snapshot.TotalCount() > 0) { + current_log_->RecordHistogramDelta(histogram, snapshot); + // Add new data into our running total. + already_logged->Add(snapshot); + } +} + +void MetricsService::AddProfileMetric(Profile* profile, + const std::wstring& key, + int value) { + // Restriction of types is needed for writing values. See + // MetricsLog::WriteProfileMetrics. + DCHECK(profile && !key.empty()); + PrefService* prefs = g_browser_process->local_state(); + DCHECK(prefs); + + // Key is stored in prefs, which interpret '.'s as paths. As such, key + // shouldn't have any '.'s in it. + DCHECK(key.find(L'.') == std::wstring::npos); + // The id is most likely an email address. We shouldn't send it to the server. + const std::wstring id_hash = + UTF8ToWide(MetricsLog::CreateBase64Hash(WideToUTF8(profile->GetID()))); + DCHECK(id_hash.find('.') == std::string::npos); + + DictionaryValue* prof_prefs = prefs->GetMutableDictionary( + prefs::kProfileMetrics); + DCHECK(prof_prefs); + const std::wstring pref_key = std::wstring(prefs::kProfilePrefix) + id_hash + + L"." + key; + prof_prefs->SetInteger(pref_key.c_str(), value); +} + +static bool IsSingleThreaded() { + static int thread_id = 0; + if (!thread_id) + thread_id = GetCurrentThreadId(); + return GetCurrentThreadId() == thread_id; +} diff --git a/chrome/browser/metrics/metrics_service.h b/chrome/browser/metrics/metrics_service.h new file mode 100644 index 0000000..f0f69ed --- /dev/null +++ b/chrome/browser/metrics/metrics_service.h @@ -0,0 +1,464 @@ +// Copyright (c) 2006-2008 The Chromium Authors. All rights reserved. +// Use of this source code is governed by a BSD-style license that can be +// found in the LICENSE file. + +// This file defines a service that collects information about the user +// experience in order to help improve future versions of the app. + +#ifndef CHROME_BROWSER_METRICS_SERVICE_H__ +#define CHROME_BROWSER_METRICS_SERVICE_H__ + +#include <list> +#include <map> +#include <set> +#include <string> +#include <vector> + +#include "base/basictypes.h" +#include "base/file_path.h" +#include "base/histogram.h" +#include "base/scoped_ptr.h" +#include "base/values.h" +#include "chrome/browser/metrics/metrics_log.h" +#include "chrome/browser/url_fetcher.h" +#include "chrome/common/notification_service.h" +#include "webkit/glue/webplugin.h" + +class BookmarkModel; +class BookmarkNode; +class PrefService; +class Profile; +class TemplateURLModel; + +// This is used to quickly log stats from plugin-related notifications in +// MetricsService::plugin_stats_buffer_. The buffer's contents are transferred +// out when Local State is periodically saved. The information is then +// reported to the UMA server on next launch. +struct PluginStats { + public: + PluginStats() : process_launches(0), process_crashes(0), instances(0) {} + + // The number of times that the given plugin process has been launched + int process_launches; + + // The number of times that the given plugin process has crashed + int process_crashes; + + // The number of instances of this plugin that have been created. + // An instance is a DOM object rendered by this plugin during a page load. + int instances; +}; + +class MetricsService : public NotificationObserver, + public URLFetcher::Delegate { + public: + MetricsService(); + virtual ~MetricsService(); + + // Sets whether the user permits uploading. The argument of this function + // should match the checkbox in Options. + void SetUserPermitsUpload(bool enabled); + + // Start/stop the metrics recording and uploading machine. These should be + // used on startup and when the user clicks the checkbox in the prefs. + // StartRecordingOnly starts the metrics recording but not reporting, for use + // in tests only. + void Start(); + void StartRecordingOnly(); + void Stop(); + + // At startup, prefs needs to be called with a list of all the pref names and + // types we'll be using. + static void RegisterPrefs(PrefService* local_state); + + // Implementation of NotificationObserver + virtual void Observe(NotificationType type, + const NotificationSource& source, + const NotificationDetails& details); + + // This should be called when the application is shutting down, to record + // the fact that this was a clean shutdown in the stability metrics. + void RecordCleanShutdown(); + + // Invoked when we get a WM_SESSIONEND. This places a value in prefs that is + // reset when RecordCompletedSessionEnd is invoked. + void RecordStartOfSessionEnd(); + + // This should be called when the application is shutting down. It records + // that session end was successful. + void RecordCompletedSessionEnd(); + + // Saves in the preferences if the crash report registration was successful. + // This count is eventually send via UMA logs. + void RecordBreakpadRegistration(bool success); + + // Saves in the preferences if the browser is running under a debugger. + // This count is eventually send via UMA logs. + void RecordBreakpadHasDebugger(bool has_debugger); + + // Callback to let us knew that the plugin list is warmed up. + void OnGetPluginListTaskComplete(); + + // Save any unsent logs into a persistent store in a pref. We always do this + // at shutdown, but we can do it as we reduce the list as well. + void StoreUnsentLogs(); + + private: + // The MetricsService has a lifecycle that is stored as a state. + // See metrics_service.cc for description of this lifecycle. + enum State { + INITIALIZED, // Constructor was called. + PLUGIN_LIST_REQUESTED, // Waiting for plugin list to be loaded. + PLUGIN_LIST_ARRIVED, // Waiting for timer to send initial log. + INITIAL_LOG_READY, // Initial log generated, and waiting for reply. + SEND_OLD_INITIAL_LOGS, // Sending unsent logs from previous session. + SENDING_OLD_LOGS, // Sending unsent logs from previous session. + SENDING_CURRENT_LOGS, // Sending standard current logs as they acrue. + }; + + // Maintain a map of histogram names to the sample stats we've sent. + typedef std::map<std::string, Histogram::SampleSet> LoggedSampleMap; + + class GetPluginListTask; + class GetPluginListTaskComplete; + + // Sets and gets whether metrics recording is active. + // SetRecording(false) also forces a persistent save of logging state (if + // anything has been recorded, or transmitted). + void SetRecording(bool enabled); + bool recording_active() const; + + // Enable/disable transmission of accumulated logs and crash reports (dumps). + // Return value "true" indicates setting was definitively set as requested). + // Return value of "false" indicates that the enable state is effectively + // stuck in the other logical setting. + // Google Update maintains the authoritative preference in the registry, so + // the caller *might* not be able to actually change the setting. + // It is always possible to set this to at least one value, which matches the + // current value reported by querying Google Update. + void SetReporting(bool enabled); + bool reporting_active() const; + + // If in_idle is true, sets idle_since_last_transmission to true. + // If in_idle is false and idle_since_last_transmission_ is true, sets + // idle_since_last_transmission to false and starts the timer (provided + // starting the timer is permitted). + void HandleIdleSinceLastTransmission(bool in_idle); + + // Set up client ID, session ID, etc. + void InitializeMetricsState(); + + // Generates a new client ID to use to identify self to metrics server. + static std::string GenerateClientID(); + + // Schedule the next save of LocalState information. This is called + // automatically by the task that performs each save to schedule the next one. + void ScheduleNextStateSave(); + + // Save the LocalState information immediately. This should not be called by + // anybody other than the scheduler to avoid doing too many writes. When you + // make a change, call ScheduleNextStateSave() instead. + void SaveLocalState(); + + // Called to start recording user experience metrics. + // Constructs a new, empty current_log_. + void StartRecording(); + + // Called to stop recording user experience metrics. The caller takes + // ownership of the resulting MetricsLog object via the log parameter, + // or passes in NULL to indicate that the log should simply be deleted. + void StopRecording(MetricsLog** log); + + void ListenerRegistration(bool start_listening); + + // Adds or Removes (depending on the value of is_add) the given observer + // to the given notification type for all sources. + static void AddOrRemoveObserver(NotificationObserver* observer, + NotificationType type, + bool is_add); + + // Deletes pending_log_ and current_log_, and pushes their text into the + // appropriate unsent_log vectors. Called when Chrome shuts down. + void PushPendingLogsToUnsentLists(); + + // Save the pending_log_text_ persistently in a pref for transmission when we + // next run. Note that IF this text is "too large," we just dicard it. + void PushPendingLogTextToUnsentOngoingLogs(); + + // Start timer for next log transmission. + void StartLogTransmissionTimer(); + // Do not call TryToStartTransmission() directly. + // Use StartLogTransmissionTimer() to schedule a call. + void TryToStartTransmission(); + + // Takes whatever log should be uploaded next (according to the state_) + // and makes it the pending log. If pending_log_ is not NULL, + // MakePendingLog does nothing and returns. + void MakePendingLog(); + + // Determines from state_ and permissions set out by the server and by + // the user whether the pending_log_ should be sent or discarded. Called by + // TryToStartTransmission. + bool TransmissionPermitted() const; + + // Internal function to collect process memory information. + void CollectMemoryDetails(); + + // Check to see if there is a log that needs to be, or is being, transmitted. + bool pending_log() const { + return pending_log_ || !pending_log_text_.empty(); + } + // Check to see if there are any unsent logs from previous sessions. + bool unsent_logs() const { + return !unsent_initial_logs_.empty() || !unsent_ongoing_logs_.empty(); + } + // Record stats, client ID, Session ID, etc. in a special "first" log. + void PrepareInitialLog(); + // Pull copies of unsent logs from prefs into instance variables. + void RecallUnsentLogs(); + // Convert pending_log_ to XML in pending_log_text_ for transmission. + void PreparePendingLogText(); + + // Convert pending_log_ to XML, compress it, and prepare to pass to server. + // Upon return, current_fetch_ should be reset with its upload data set to + // a compressed copy of the pending log. + void PrepareFetchWithPendingLog(); + + // Discard pending_log_, and clear pending_log_text_. Called after processing + // of this log is complete. + void DiscardPendingLog(); + // Compress the report log in input using bzip2, store the result in output. + bool Bzip2Compress(const std::string& input, std::string* output); + // Implementation of URLFetcher::Delegate. Called after transmission + // completes (either successfully or with failure). + virtual void OnURLFetchComplete(const URLFetcher* source, + const GURL& url, + const URLRequestStatus& status, + int response_code, + const ResponseCookies& cookies, + const std::string& data); + + // Called by OnURLFetchComplete to handle the case when the server returned + // a response code not equal to 200. + void HandleBadResponseCode(); + + // Class to hold all attributes that gets inherited by children in the UMA + // response data xml tree. This is to make it convenient in the + // recursive function that does the tree traversal to pass all such + // data in the recursive call. If you want to add more such attributes, + // add them to this class. + class InheritedProperties { + public: + InheritedProperties() : salt(123123), denominator(1000000) {} + int salt, denominator; + // Notice salt and denominator are inherited from parent nodes, but + // not probability; the default value of probability is 1. + + // When a new node is reached it might have fields which overwrite inherited + // properties for that node (and its children). Call this method to + // overwrite those settings. + void OverwriteWhereNeeded(xmlNodePtr node); + }; + + // Called by OnURLFetchComplete with data as the argument + // parses the xml returned by the server in the call to OnURLFetchComplete + // and extracts settings for subsequent frequency and content of log posts. + void GetSettingsFromResponseData(const std::string& data); + + // This is a helper function for GetSettingsFromResponseData which iterates + // through the xml tree at the level of the <chrome_config> node. + void GetSettingsFromChromeConfigNode(xmlNodePtr chrome_config_node); + + // GetSettingsFromUploadNode handles iteration over the children of the + // <upload> child of the <chrome_config> node. It calls the recursive + // function GetSettingsFromUploadNodeRecursive which does the actual + // tree traversal. + void GetSettingsFromUploadNode(xmlNodePtr upload_node); + void GetSettingsFromUploadNodeRecursive(xmlNodePtr node, + InheritedProperties props, + std::string path_prefix, + bool uploadOn); + + // NodeProbabilityTest gets called at every node in the tree traversal + // performed by GetSettingsFromUploadNodeRecursive. It determines from + // the inherited attributes (salt, denominator) and the probability + // assiciated with the node whether that node and its contents should + // contribute to the upload. + bool NodeProbabilityTest(xmlNodePtr node, InheritedProperties props) const; + bool ProbabilityTest(double probability, int salt, int denominator) const; + + // Records a window-related notification. + void LogWindowChange(NotificationType type, + const NotificationSource& source, + const NotificationDetails& details); + + // Reads, increments and then sets the specified integer preference. + void IncrementPrefValue(const wchar_t* path); + + // Records a renderer process crash. + void LogRendererCrash(); + + // Records a renderer process hang. + void LogRendererHang(); + + // Records the desktop security status of a renderer in the sandbox at + // creation time. + void LogRendererInSandbox(bool on_sandbox_desktop); + + // Set the value in preferences for for the number of bookmarks and folders + // in node. The pref key for the number of bookmarks in num_bookmarks_key and + // the pref key for number of folders in num_folders_key. + void LogBookmarks(BookmarkNode* node, + const wchar_t* num_bookmarks_key, + const wchar_t* num_folders_key); + + // Sets preferences for the for the number of bookmarks in model. + void LogBookmarks(BookmarkModel* model); + + // Records a plugin-related notification. These are recorded to an in-object + // buffer because these notifications are sent on page load, and we don't + // want to slow that down. + void LogPluginChange(NotificationType type, + const NotificationSource& source, + const NotificationDetails& details); + + // Logs keywords specific metrics. Keyword metrics are recorded in the + // profile specific metrics. + void LogKeywords(const TemplateURLModel* url_model); + + // Saves plugin-related updates from the in-object buffer to Local State + // for retrieval next time we send a Profile log (generally next launch). + void RecordPluginChanges(PrefService* pref); + + // Records state that should be periodically saved, like uptime and + // buffered plugin stability statistics. + void RecordCurrentState(PrefService* pref); + + // Record complete list of histograms into the current log. + // Called when we close a log. + void RecordCurrentHistograms(); + // Record a specific histogram . + void RecordHistogram(const Histogram& histogram); + + // Logs the initiation of a page load + void LogLoadStarted(); + + // Records a page load notification. + void LogLoadComplete(NotificationType type, + const NotificationSource& source, + const NotificationDetails& details); + + // Adds a profile metric with the specified key/value pair. + void AddProfileMetric(Profile* profile, const std::wstring& key, + int value); + + // Checks whether a notification can be logged. + bool CanLogNotification(NotificationType type, + const NotificationSource& source, + const NotificationDetails& details); + + // Sets the value of the specified path in prefs and schedules a save. + void RecordBooleanPrefValue(const wchar_t* path, bool value); + + // Indicate whether recording and reporting are currently happening. + // These should not be set directly, but by calling SetRecording and + // SetReporting. + bool recording_active_; + bool reporting_active_; + + // Coincides with the check box in options window that lets the user control + // whether to upload. + bool user_permits_upload_; + + // The variable server_permits_upload_ is set true when the response + // data forbids uploading. This should coinside with the "die roll" + // with probability in the upload tag of the response data came out + // affirmative. + bool server_permits_upload_; + + // The progession of states made by the browser are recorded in the following + // state. + State state_; + + // A log that we are currently transmiting, or about to try to transmit. + MetricsLog* pending_log_; + + // An alternate form of pending_log_. We persistently save this text version + // into prefs if we can't transmit it. As a result, sometimes all we have is + // the text version (recalled from a previous session). + std::string pending_log_text_; + + // The outstanding transmission appears as a URL Fetch operation. + scoped_ptr<URLFetcher> current_fetch_; + + // The log that we are still appending to. + MetricsLog* current_log_; + + // The identifier that's sent to the server with the log reports. + std::string client_id_; + + // Whether the MetricsService object has received any notifications since + // the last time a transmission was sent. + bool idle_since_last_transmission_; + + // A number that identifies the how many times the app has been launched. + int session_id_; + + // When logs were not sent during a previous session they are queued to be + // sent instead of currently accumulating logs. We give preference to sending + // our inital log first, then unsent intial logs, then unsent ongoing logs. + // Unsent logs are gathered at shutdown, and save in a persistent pref, one + // log in each string in the following arrays. + // Note that the vector has the oldest logs listed first (early in the + // vector), and we'll discard old logs if we have gathered too many logs. + std::vector<std::string> unsent_initial_logs_; + std::vector<std::string> unsent_ongoing_logs_; + + // Maps NavigationControllers (corresponding to tabs) or Browser + // (corresponding to Windows) to a unique integer that we will use to identify + // it. |next_window_id_| is used to track which IDs we have used so far. + typedef std::map<uintptr_t, int> WindowMap; + WindowMap window_map_; + int next_window_id_; + + // Buffer of plugin notifications for quick access. See PluginStats + // documentation above for more details. + std::map<FilePath, PluginStats> plugin_stats_buffer_; + + ScopedRunnableMethodFactory<MetricsService> log_sender_factory_; + ScopedRunnableMethodFactory<MetricsService> state_saver_factory_; + + // Dictionary containing all the profile specific metrics. This is set + // at creation time from the prefs. + scoped_ptr<DictionaryValue> profile_dictionary_; + + // For histograms, record what we've already logged (as a sample for each + // histogram) so that we can send only the delta with the next log. + MetricsService::LoggedSampleMap logged_samples_; + + // The interval between consecutive log transmissions (to avoid hogging the + // outbound network link). This is usually also the duration for which we + // build up a log, but if other unsent-logs from previous sessions exist, we + // quickly transmit those unsent logs while we continue to build a log. + base::TimeDelta interlog_duration_; + + // The maximum number of events which get transmitted in a log. This defaults + // to a constant and otherwise is provided by the UMA server in the server + // response data. + int log_event_limit_; + + // The types of data that are to be included in the logs and histograms + // according to the UMA response data. + std::set<std::string> logs_to_upload_; + std::set<std::string> logs_to_omit_; + std::set<std::string> histograms_to_upload_; + std::set<std::string> histograms_to_omit_; + + // Indicate that a timer for sending the next log has already been queued. + bool timer_pending_; + + DISALLOW_EVIL_CONSTRUCTORS(MetricsService); +}; + +#endif // CHROME_BROWSER_METRICS_SERVICE_H__ + diff --git a/chrome/browser/metrics/metrics_service_uitest.cc b/chrome/browser/metrics/metrics_service_uitest.cc new file mode 100644 index 0000000..db35f1c --- /dev/null +++ b/chrome/browser/metrics/metrics_service_uitest.cc @@ -0,0 +1,111 @@ +// Copyright (c) 2006-2008 The Chromium Authors. All rights reserved. +// Use of this source code is governed by a BSD-style license that can be +// found in the LICENSE file. + +// Tests the MetricsService stat recording to make sure that the numbers are +// what we expect. + +#include <string> + +#include "base/file_util.h" +#include "base/path_service.h" +#include "base/process_util.h" +#include "chrome/app/chrome_dll_resource.h" +#include "chrome/common/chrome_constants.h" +#include "chrome/common/chrome_paths.h" +#include "chrome/common/pref_names.h" +#include "chrome/common/pref_service.h" +#include "chrome/test/automation/tab_proxy.h" +#include "chrome/test/automation/browser_proxy.h" +#include "chrome/test/ui/ui_test.h" +#include "net/base/net_util.h" + +class MetricsServiceTest : public UITest { + public: + MetricsServiceTest() : UITest(), window_(NULL) { + // We need to show the window so web content type tabs load. + show_window_ = true; + } + + // Open a few tabs of random content + void OpenTabs() { + window_ = automation()->GetBrowserWindow(0); + ASSERT_TRUE(window_); + + std::wstring page1_path; + ASSERT_TRUE(PathService::Get(chrome::DIR_TEST_DATA, &page1_path)); + file_util::AppendToPath(&page1_path, L"title2.html"); + ASSERT_TRUE(window_->AppendTab(net::FilePathToFileURL(page1_path))); + + std::wstring page2_path; + ASSERT_TRUE(PathService::Get(chrome::DIR_TEST_DATA, &page2_path)); + file_util::AppendToPath(&page2_path, L"iframe.html"); + ASSERT_TRUE(window_->AppendTab(net::FilePathToFileURL(page2_path))); + } + + // Get a PrefService whose contents correspond to the Local State file + // that was saved by the app as it closed. The caller takes ownership of the + // returned PrefService object. + PrefService* GetLocalState() { + std::wstring local_state_path = user_data_dir(); + file_util::AppendToPath(&local_state_path, chrome::kLocalStateFilename); + + PrefService* local_state(new PrefService(local_state_path)); + return local_state; + } + + virtual void TearDown() { + delete window_; + UITest::TearDown(); + } + + protected: + BrowserProxy* window_; +}; + +TEST_F(MetricsServiceTest, CloseRenderersNormally) { + OpenTabs(); + QuitBrowser(); + + scoped_ptr<PrefService> local_state(GetLocalState()); + local_state->RegisterBooleanPref(prefs::kStabilityExitedCleanly, true); + local_state->RegisterIntegerPref(prefs::kStabilityLaunchCount, 0); + local_state->RegisterIntegerPref(prefs::kStabilityPageLoadCount, 0); + local_state->RegisterIntegerPref(prefs::kStabilityRendererCrashCount, 0); + EXPECT_TRUE(local_state->GetBoolean(prefs::kStabilityExitedCleanly)); + EXPECT_EQ(1, local_state->GetInteger(prefs::kStabilityLaunchCount)); + EXPECT_EQ(3, local_state->GetInteger(prefs::kStabilityPageLoadCount)); + EXPECT_EQ(0, local_state->GetInteger(prefs::kStabilityRendererCrashCount)); +} + +TEST_F(MetricsServiceTest, CrashRenderers) { + // This doesn't make sense to test in single process mode. + if (in_process_renderer_) + return; + + OpenTabs(); + + // kill the process for one of the tabs + scoped_ptr<TabProxy> tab(window_->GetTab(1)); + ASSERT_TRUE(tab.get()); + int process_id = 0; + ASSERT_TRUE(tab->GetProcessID(&process_id)); + ASSERT_NE(0, process_id); + base::KillProcess(process_id, 0xc0000005, true); // Fake Access Violation. + + // Give the browser a chance to notice the crashed tab. + Sleep(1000); + + QuitBrowser(); + + scoped_ptr<PrefService> local_state(GetLocalState()); + local_state->RegisterBooleanPref(prefs::kStabilityExitedCleanly, true); + local_state->RegisterIntegerPref(prefs::kStabilityLaunchCount, 0); + local_state->RegisterIntegerPref(prefs::kStabilityPageLoadCount, 0); + local_state->RegisterIntegerPref(prefs::kStabilityRendererCrashCount, 0); + EXPECT_TRUE(local_state->GetBoolean(prefs::kStabilityExitedCleanly)); + EXPECT_EQ(1, local_state->GetInteger(prefs::kStabilityLaunchCount)); + EXPECT_EQ(3, local_state->GetInteger(prefs::kStabilityPageLoadCount)); + EXPECT_EQ(1, local_state->GetInteger(prefs::kStabilityRendererCrashCount)); +} + diff --git a/chrome/browser/metrics/user_metrics.cc b/chrome/browser/metrics/user_metrics.cc new file mode 100644 index 0000000..4049875 --- /dev/null +++ b/chrome/browser/metrics/user_metrics.cc @@ -0,0 +1,20 @@ +// Copyright (c) 2006-2008 The Chromium Authors. All rights reserved. +// Use of this source code is governed by a BSD-style license that can be +// found in the LICENSE file. + +#include "chrome/browser/metrics/user_metrics.h" +#include "chrome/browser/profile.h" +#include "chrome/common/notification_service.h" + +void UserMetrics::RecordAction(const wchar_t* action, Profile* profile) { + NotificationService::current()-> + Notify(NOTIFY_USER_ACTION, + Source<Profile>(profile), + Details<const wchar_t*>(&action)); +} + +void UserMetrics::RecordComputedAction(const std::wstring& action, + Profile* profile) { + RecordAction(action.c_str(), profile); +} + diff --git a/chrome/browser/metrics/user_metrics.h b/chrome/browser/metrics/user_metrics.h new file mode 100644 index 0000000..7c3ed4c --- /dev/null +++ b/chrome/browser/metrics/user_metrics.h @@ -0,0 +1,41 @@ +// Copyright (c) 2006-2008 The Chromium Authors. All rights reserved. +// Use of this source code is governed by a BSD-style license that can be +// found in the LICENSE file. + +#ifndef CHROME_BROWSER_USER_METRICS_H__ +#define CHROME_BROWSER_USER_METRICS_H__ + +#include <string> + +class Profile; + +// This module provides some helper functions for logging actions tracked by +// the user metrics system. + +class UserMetrics { + public: + // Record that the user performed an action. + // "Action" here means a user-generated event: + // good: "Reload", "CloseTab", and "IMEInvoked" + // not good: "SSLDialogShown", "PageLoaded", "DiskFull" + // We use this to gather anonymized information about how users are + // interacting with the browser. + // WARNING: Call this function exactly like this, with the string literal + // inline: + // UserMetrics::RecordAction(L"foo bar", profile); + // because otherwise our processing scripts won't pick up on new actions. + // + // For more complicated situations (like when there are many different + // possible actions), see RecordComputedAction. + static void RecordAction(const wchar_t* action, Profile* profile); + + // This function has identical input and behavior to RecordAction, but is + // not automatically found by the action-processing scripts. It can be used + // when it's a pain to enumerate all possible actions, but if you use this + // you need to also update the rules for extracting known actions. + static void RecordComputedAction(const std::wstring& action, + Profile* profile); +}; + +#endif // CHROME_BROWSER_USER_METRICS_H__ + |