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