components/metrics/metrics_log.cc

   1 // Copyright 2014 The Chromium Authors. All rights reserved.
   2 // Use of this source code is governed by a BSD-style license that can be
   3 // found in the LICENSE file.
   4
   5 #include "components/metrics/metrics_log.h"
   6
   7 #include <algorithm>
   8 #include <string>
   9 #include <vector>
  10
  11 #include "base/base64.h"
  12 #include "base/basictypes.h"
  13 #include "base/cpu.h"
  14 #include "base/memory/scoped_ptr.h"
  15 #include "base/metrics/histogram.h"
  16 #include "base/metrics/histogram_samples.h"
  17 #include "base/prefs/pref_registry_simple.h"
  18 #include "base/prefs/pref_service.h"
  19 #include "base/sha1.h"
  20 #include "base/strings/string_number_conversions.h"
  21 #include "base/strings/string_util.h"
  22 #include "base/strings/utf_string_conversions.h"
  23 #include "base/sys_info.h"
  24 #include "base/time/time.h"
  25 #include "components/metrics/metrics_hashes.h"
  26 #include "components/metrics/metrics_pref_names.h"
  27 #include "components/metrics/metrics_provider.h"
  28 #include "components/metrics/metrics_service_client.h"
  29 #include "components/metrics/proto/histogram_event.pb.h"
  30 #include "components/metrics/proto/system_profile.pb.h"
  31 #include "components/metrics/proto/user_action_event.pb.h"
  32 #include "components/variations/active_field_trials.h"
  33
  34 #if defined(OS_ANDROID)
  35 #include "base/android/build_info.h"
  36 #endif
  37
  38 #if defined(OS_WIN)
  39 #include "base/win/metro.h"
  40
  41 // http://blogs.msdn.com/oldnewthing/archive/2004/10/25/247180.aspx
  42 extern "C" IMAGE_DOS_HEADER __ImageBase;
  43 #endif
  44
  45 using base::SampleCountIterator;
  46 typedef variations::ActiveGroupId ActiveGroupId;
  47
  48 namespace metrics {
  49
  50 namespace {
  51
  52 // Any id less than 16 bytes is considered to be a testing id.
  53 bool IsTestingID(const std::string& id) {
  54   return id.size() < 16;
  55 }
  56
  57 // Returns the date at which the current metrics client ID was created as
  58 // a string containing seconds since the epoch, or "0" if none was found.
  59 std::string GetMetricsEnabledDate(PrefService* pref) {
  60   if (!pref) {
  61     NOTREACHED();
  62     return "0";
  63   }
  64
  65   return pref->GetString(metrics::prefs::kMetricsReportingEnabledTimestamp);
  66 }
  67
  68 // Computes a SHA-1 hash of |data| and returns it as a hex string.
  69 std::string ComputeSHA1(const std::string& data) {
  70   const std::string sha1 = base::SHA1HashString(data);
  71   return base::HexEncode(sha1.data(), sha1.size());
  72 }
  73
  74 void WriteFieldTrials(const std::vector<ActiveGroupId>& field_trial_ids,
  75                       SystemProfileProto* system_profile) {
  76   for (std::vector<ActiveGroupId>::const_iterator it =
  77        field_trial_ids.begin(); it != field_trial_ids.end(); ++it) {
  78     SystemProfileProto::FieldTrial* field_trial =
  79         system_profile->add_field_trial();
  80     field_trial->set_name_id(it->name);
  81     field_trial->set_group_id(it->group);
  82   }
  83 }
  84
  85 // Round a timestamp measured in seconds since epoch to one with a granularity
  86 // of an hour. This can be used before uploaded potentially sensitive
  87 // timestamps.
  88 int64 RoundSecondsToHour(int64 time_in_seconds) {
  89   return 3600 * (time_in_seconds / 3600);
  90 }
  91
  92 }  // namespace
  93
  94 MetricsLog::MetricsLog(const std::string& client_id,
  95                        int session_id,
  96                        LogType log_type,
  97                        metrics::MetricsServiceClient* client,
  98                        PrefService* local_state)
  99     : closed_(false),
 100       log_type_(log_type),
 101       client_(client),
 102       creation_time_(base::TimeTicks::Now()),
 103       local_state_(local_state) {
 104   if (IsTestingID(client_id))
 105     uma_proto_.set_client_id(0);
 106   else
 107     uma_proto_.set_client_id(Hash(client_id));
 108
 109   uma_proto_.set_session_id(session_id);
 110
 111   SystemProfileProto* system_profile = uma_proto_.mutable_system_profile();
 112   system_profile->set_build_timestamp(GetBuildTime());
 113   system_profile->set_app_version(client_->GetVersionString());
 114   system_profile->set_channel(client_->GetChannel());
 115 }
 116
 117 MetricsLog::~MetricsLog() {
 118 }
 119
 120 // static
 121 void MetricsLog::RegisterPrefs(PrefRegistrySimple* registry) {
 122   registry->RegisterIntegerPref(metrics::prefs::kStabilityLaunchCount, 0);
 123   registry->RegisterIntegerPref(metrics::prefs::kStabilityCrashCount, 0);
 124   registry->RegisterIntegerPref(
 125       metrics::prefs::kStabilityIncompleteSessionEndCount, 0);
 126   registry->RegisterIntegerPref(
 127       metrics::prefs::kStabilityBreakpadRegistrationFail, 0);
 128   registry->RegisterIntegerPref(
 129       metrics::prefs::kStabilityBreakpadRegistrationSuccess, 0);
 130   registry->RegisterIntegerPref(metrics::prefs::kStabilityDebuggerPresent, 0);
 131   registry->RegisterIntegerPref(metrics::prefs::kStabilityDebuggerNotPresent,
 132                                 0);
 133   registry->RegisterStringPref(metrics::prefs::kStabilitySavedSystemProfile,
 134                                std::string());
 135   registry->RegisterStringPref(metrics::prefs::kStabilitySavedSystemProfileHash,
 136                                std::string());
 137 }
 138
 139 // static
 140 uint64 MetricsLog::Hash(const std::string& value) {
 141   uint64 hash = metrics::HashMetricName(value);
 142
 143   // The following log is VERY helpful when folks add some named histogram into
 144   // the code, but forgot to update the descriptive list of histograms.  When
 145   // that happens, all we get to see (server side) is a hash of the histogram
 146   // name.  We can then use this logging to find out what histogram name was
 147   // being hashed to a given MD5 value by just running the version of Chromium
 148   // in question with --enable-logging.
 149   DVLOG(1) << "Metrics: Hash numeric [" << value << "]=[" << hash << "]";
 150
 151   return hash;
 152 }
 153
 154 // static
 155 int64 MetricsLog::GetBuildTime() {
 156   static int64 integral_build_time = 0;
 157   if (!integral_build_time) {
 158     base::Time time;
 159     static const char kDateTime[] = __DATE__ " " __TIME__ " GMT";
 160     bool result = base::Time::FromString(kDateTime, &time);
 161     DCHECK(result);
 162     integral_build_time = static_cast<int64>(time.ToTimeT());
 163   }
 164   return integral_build_time;
 165 }
 166
 167 // static
 168 int64 MetricsLog::GetCurrentTime() {
 169   return (base::TimeTicks::Now() - base::TimeTicks()).InSeconds();
 170 }
 171
 172 void MetricsLog::RecordUserAction(const std::string& key) {
 173   DCHECK(!closed_);
 174
 175   UserActionEventProto* user_action = uma_proto_.add_user_action_event();
 176   user_action->set_name_hash(Hash(key));
 177   user_action->set_time(GetCurrentTime());
 178 }
 179
 180 void MetricsLog::RecordHistogramDelta(const std::string& histogram_name,
 181                                       const base::HistogramSamples& snapshot) {
 182   DCHECK(!closed_);
 183   DCHECK_NE(0, snapshot.TotalCount());
 184
 185   // We will ignore the MAX_INT/infinite value in the last element of range[].
 186
 187   HistogramEventProto* histogram_proto = uma_proto_.add_histogram_event();
 188   histogram_proto->set_name_hash(Hash(histogram_name));
 189   histogram_proto->set_sum(snapshot.sum());
 190
 191   for (scoped_ptr<SampleCountIterator> it = snapshot.Iterator(); !it->Done();
 192        it->Next()) {
 193     base::Histogram::Sample min;
 194     base::Histogram::Sample max;
 195     base::Histogram::Count count;
 196     it->Get(&min, &max, &count);
 197     HistogramEventProto::Bucket* bucket = histogram_proto->add_bucket();
 198     bucket->set_min(min);
 199     bucket->set_max(max);
 200     bucket->set_count(count);
 201   }
 202
 203   // Omit fields to save space (see rules in histogram_event.proto comments).
 204   for (int i = 0; i < histogram_proto->bucket_size(); ++i) {
 205     HistogramEventProto::Bucket* bucket = histogram_proto->mutable_bucket(i);
 206     if (i + 1 < histogram_proto->bucket_size() &&
 207         bucket->max() == histogram_proto->bucket(i + 1).min()) {
 208       bucket->clear_max();
 209     } else if (bucket->max() == bucket->min() + 1) {
 210       bucket->clear_min();
 211     }
 212   }
 213 }
 214
 215 void MetricsLog::RecordStabilityMetrics(
 216     const std::vector<metrics::MetricsProvider*>& metrics_providers,
 217     base::TimeDelta incremental_uptime,
 218     base::TimeDelta uptime) {
 219   DCHECK(!closed_);
 220   DCHECK(HasEnvironment());
 221   DCHECK(!HasStabilityMetrics());
 222
 223   PrefService* pref = local_state_;
 224   DCHECK(pref);
 225
 226   // Get stability attributes out of Local State, zeroing out stored values.
 227   // NOTE: This could lead to some data loss if this report isn't successfully
 228   //       sent, but that's true for all the metrics.
 229
 230   WriteRequiredStabilityAttributes(pref);
 231
 232   // Record recent delta for critical stability metrics.  We can't wait for a
 233   // restart to gather these, as that delay biases our observation away from
 234   // users that run happily for a looooong time.  We send increments with each
 235   // uma log upload, just as we send histogram data.
 236   WriteRealtimeStabilityAttributes(pref, incremental_uptime, uptime);
 237
 238   SystemProfileProto* system_profile = uma_proto()->mutable_system_profile();
 239   for (size_t i = 0; i < metrics_providers.size(); ++i)
 240     metrics_providers[i]->ProvideStabilityMetrics(system_profile);
 241
 242   // Omit some stats unless this is the initial stability log.
 243   if (log_type() != INITIAL_STABILITY_LOG)
 244     return;
 245
 246   int incomplete_shutdown_count =
 247       pref->GetInteger(metrics::prefs::kStabilityIncompleteSessionEndCount);
 248   pref->SetInteger(metrics::prefs::kStabilityIncompleteSessionEndCount, 0);
 249   int breakpad_registration_success_count =
 250       pref->GetInteger(metrics::prefs::kStabilityBreakpadRegistrationSuccess);
 251   pref->SetInteger(metrics::prefs::kStabilityBreakpadRegistrationSuccess, 0);
 252   int breakpad_registration_failure_count =
 253       pref->GetInteger(metrics::prefs::kStabilityBreakpadRegistrationFail);
 254   pref->SetInteger(metrics::prefs::kStabilityBreakpadRegistrationFail, 0);
 255   int debugger_present_count =
 256       pref->GetInteger(metrics::prefs::kStabilityDebuggerPresent);
 257   pref->SetInteger(metrics::prefs::kStabilityDebuggerPresent, 0);
 258   int debugger_not_present_count =
 259       pref->GetInteger(metrics::prefs::kStabilityDebuggerNotPresent);
 260   pref->SetInteger(metrics::prefs::kStabilityDebuggerNotPresent, 0);
 261
 262   // TODO(jar): The following are all optional, so we *could* optimize them for
 263   // values of zero (and not include them).
 264   SystemProfileProto::Stability* stability =
 265       system_profile->mutable_stability();
 266   stability->set_incomplete_shutdown_count(incomplete_shutdown_count);
 267   stability->set_breakpad_registration_success_count(
 268       breakpad_registration_success_count);
 269   stability->set_breakpad_registration_failure_count(
 270       breakpad_registration_failure_count);
 271   stability->set_debugger_present_count(debugger_present_count);
 272   stability->set_debugger_not_present_count(debugger_not_present_count);
 273 }
 274
 275 void MetricsLog::RecordGeneralMetrics(
 276     const std::vector<metrics::MetricsProvider*>& metrics_providers) {
 277   for (size_t i = 0; i < metrics_providers.size(); ++i)
 278     metrics_providers[i]->ProvideGeneralMetrics(uma_proto());
 279 }
 280
 281 void MetricsLog::GetFieldTrialIds(
 282     std::vector<ActiveGroupId>* field_trial_ids) const {
 283   variations::GetFieldTrialActiveGroupIds(field_trial_ids);
 284 }
 285
 286 bool MetricsLog::HasEnvironment() const {
 287   return uma_proto()->system_profile().has_uma_enabled_date();
 288 }
 289
 290 bool MetricsLog::HasStabilityMetrics() const {
 291   return uma_proto()->system_profile().stability().has_launch_count();
 292 }
 293
 294 // The server refuses data that doesn't have certain values.  crashcount and
 295 // launchcount are currently "required" in the "stability" group.
 296 // TODO(isherman): Stop writing these attributes specially once the migration to
 297 // protobufs is complete.
 298 void MetricsLog::WriteRequiredStabilityAttributes(PrefService* pref) {
 299   int launch_count = pref->GetInteger(metrics::prefs::kStabilityLaunchCount);
 300   pref->SetInteger(metrics::prefs::kStabilityLaunchCount, 0);
 301   int crash_count = pref->GetInteger(metrics::prefs::kStabilityCrashCount);
 302   pref->SetInteger(metrics::prefs::kStabilityCrashCount, 0);
 303
 304   SystemProfileProto::Stability* stability =
 305       uma_proto()->mutable_system_profile()->mutable_stability();
 306   stability->set_launch_count(launch_count);
 307   stability->set_crash_count(crash_count);
 308 }
 309
 310 void MetricsLog::WriteRealtimeStabilityAttributes(
 311     PrefService* pref,
 312     base::TimeDelta incremental_uptime,
 313     base::TimeDelta uptime) {
 314   // Update the stats which are critical for real-time stability monitoring.
 315   // Since these are "optional," only list ones that are non-zero, as the counts
 316   // are aggregated (summed) server side.
 317
 318   SystemProfileProto::Stability* stability =
 319       uma_proto()->mutable_system_profile()->mutable_stability();
 320
 321   const uint64 incremental_uptime_sec = incremental_uptime.InSeconds();
 322   if (incremental_uptime_sec)
 323     stability->set_incremental_uptime_sec(incremental_uptime_sec);
 324   const uint64 uptime_sec = uptime.InSeconds();
 325   if (uptime_sec)
 326     stability->set_uptime_sec(uptime_sec);
 327 }
 328
 329 void MetricsLog::RecordEnvironment(
 330     const std::vector<metrics::MetricsProvider*>& metrics_providers,
 331     const std::vector<variations::ActiveGroupId>& synthetic_trials,
 332     int64 install_date) {
 333   DCHECK(!HasEnvironment());
 334
 335   SystemProfileProto* system_profile = uma_proto()->mutable_system_profile();
 336
 337   std::string brand_code;
 338   if (client_->GetBrand(&brand_code))
 339     system_profile->set_brand_code(brand_code);
 340
 341   int enabled_date;
 342   bool success =
 343       base::StringToInt(GetMetricsEnabledDate(local_state_), &enabled_date);
 344   DCHECK(success);
 345
 346   // Reduce granularity of the enabled_date field to nearest hour.
 347   system_profile->set_uma_enabled_date(RoundSecondsToHour(enabled_date));
 348
 349   // Reduce granularity of the install_date field to nearest hour.
 350   system_profile->set_install_date(RoundSecondsToHour(install_date));
 351
 352   system_profile->set_application_locale(client_->GetApplicationLocale());
 353
 354   SystemProfileProto::Hardware* hardware = system_profile->mutable_hardware();
 355
 356   // By default, the hardware class is empty (i.e., unknown).
 357   hardware->set_hardware_class(std::string());
 358
 359   hardware->set_cpu_architecture(base::SysInfo::OperatingSystemArchitecture());
 360   hardware->set_system_ram_mb(base::SysInfo::AmountOfPhysicalMemoryMB());
 361 #if defined(OS_WIN)
 362   hardware->set_dll_base(reinterpret_cast<uint64>(&__ImageBase));
 363 #endif
 364
 365   SystemProfileProto::OS* os = system_profile->mutable_os();
 366   std::string os_name = base::SysInfo::OperatingSystemName();
 367 #if defined(OS_WIN)
 368   // TODO(mad): This only checks whether the main process is a Metro process at
 369   // upload time; not whether the collected metrics were all gathered from
 370   // Metro.  This is ok as an approximation for now, since users will rarely be
 371   // switching from Metro to Desktop mode; but we should re-evaluate whether we
 372   // can distinguish metrics more cleanly in the future: http://crbug.com/140568
 373   if (base::win::IsMetroProcess())
 374     os_name += " (Metro)";
 375 #endif
 376   os->set_name(os_name);
 377   os->set_version(base::SysInfo::OperatingSystemVersion());
 378 #if defined(OS_ANDROID)
 379   os->set_fingerprint(
 380       base::android::BuildInfo::GetInstance()->android_build_fp());
 381 #endif
 382
 383   base::CPU cpu_info;
 384   SystemProfileProto::Hardware::CPU* cpu = hardware->mutable_cpu();
 385   cpu->set_vendor_name(cpu_info.vendor_name());
 386   cpu->set_signature(cpu_info.signature());
 387
 388   std::vector<ActiveGroupId> field_trial_ids;
 389   GetFieldTrialIds(&field_trial_ids);
 390   WriteFieldTrials(field_trial_ids, system_profile);
 391   WriteFieldTrials(synthetic_trials, system_profile);
 392
 393   for (size_t i = 0; i < metrics_providers.size(); ++i)
 394     metrics_providers[i]->ProvideSystemProfileMetrics(system_profile);
 395
 396   std::string serialied_system_profile;
 397   std::string base64_system_profile;
 398   if (system_profile->SerializeToString(&serialied_system_profile)) {
 399     base::Base64Encode(serialied_system_profile, &base64_system_profile);
 400     PrefService* local_state = local_state_;
 401     local_state->SetString(metrics::prefs::kStabilitySavedSystemProfile,
 402                            base64_system_profile);
 403     local_state->SetString(metrics::prefs::kStabilitySavedSystemProfileHash,
 404                            ComputeSHA1(serialied_system_profile));
 405   }
 406 }
 407
 408 bool MetricsLog::LoadSavedEnvironmentFromPrefs() {
 409   PrefService* local_state = local_state_;
 410   const std::string base64_system_profile =
 411       local_state->GetString(metrics::prefs::kStabilitySavedSystemProfile);
 412   if (base64_system_profile.empty())
 413     return false;
 414
 415   const std::string system_profile_hash =
 416       local_state->GetString(metrics::prefs::kStabilitySavedSystemProfileHash);
 417   local_state->ClearPref(metrics::prefs::kStabilitySavedSystemProfile);
 418   local_state->ClearPref(metrics::prefs::kStabilitySavedSystemProfileHash);
 419
 420   SystemProfileProto* system_profile = uma_proto()->mutable_system_profile();
 421   std::string serialied_system_profile;
 422   return base::Base64Decode(base64_system_profile, &serialied_system_profile) &&
 423          ComputeSHA1(serialied_system_profile) == system_profile_hash &&
 424          system_profile->ParseFromString(serialied_system_profile);
 425 }
 426
 427 void MetricsLog::CloseLog() {
 428   DCHECK(!closed_);
 429   closed_ = true;
 430 }
 431
 432 void MetricsLog::GetEncodedLog(std::string* encoded_log) {
 433   DCHECK(closed_);
 434   uma_proto_.SerializeToString(encoded_log);
 435 }
 436
 437 }  // namespace metrics