components/metrics/metrics_service_unittest.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_service.h"
   6
   7 #include <string>
   8
   9 #include "base/bind.h"
  10 #include "base/memory/scoped_ptr.h"
  11 #include "base/message_loop/message_loop.h"
  12 #include "base/metrics/statistics_recorder.h"
  13 #include "base/prefs/testing_pref_service.h"
  14 #include "base/threading/platform_thread.h"
  15 #include "components/metrics/client_info.h"
  16 #include "components/metrics/compression_utils.h"
  17 #include "components/metrics/metrics_hashes.h"
  18 #include "components/metrics/metrics_log.h"
  19 #include "components/metrics/metrics_pref_names.h"
  20 #include "components/metrics/metrics_state_manager.h"
  21 #include "components/metrics/test_metrics_provider.h"
  22 #include "components/metrics/test_metrics_service_client.h"
  23 #include "components/variations/metrics_util.h"
  24 #include "testing/gtest/include/gtest/gtest.h"
  25
  26 namespace metrics {
  27
  28 namespace {
  29
  30 void StoreNoClientInfoBackup(const ClientInfo& /* client_info */) {
  31 }
  32
  33 scoped_ptr<ClientInfo> ReturnNoBackup() {
  34   return scoped_ptr<ClientInfo>();
  35 }
  36
  37 class TestMetricsService : public MetricsService {
  38  public:
  39   TestMetricsService(MetricsStateManager* state_manager,
  40                      MetricsServiceClient* client,
  41                      PrefService* local_state)
  42       : MetricsService(state_manager, client, local_state) {}
  43   ~TestMetricsService() override {}
  44
  45   using MetricsService::log_manager;
  46
  47  private:
  48   DISALLOW_COPY_AND_ASSIGN(TestMetricsService);
  49 };
  50
  51 class TestMetricsLog : public MetricsLog {
  52  public:
  53   TestMetricsLog(const std::string& client_id,
  54                  int session_id,
  55                  MetricsServiceClient* client,
  56                  PrefService* local_state)
  57       : MetricsLog(client_id,
  58                    session_id,
  59                    MetricsLog::ONGOING_LOG,
  60                    client,
  61                    local_state) {}
  62
  63   ~TestMetricsLog() override {}
  64
  65  private:
  66   DISALLOW_COPY_AND_ASSIGN(TestMetricsLog);
  67 };
  68
  69 class MetricsServiceTest : public testing::Test {
  70  public:
  71   MetricsServiceTest() : is_metrics_reporting_enabled_(false) {
  72     MetricsService::RegisterPrefs(testing_local_state_.registry());
  73     metrics_state_manager_ = MetricsStateManager::Create(
  74         GetLocalState(),
  75         base::Bind(&MetricsServiceTest::is_metrics_reporting_enabled,
  76                    base::Unretained(this)),
  77         base::Bind(&StoreNoClientInfoBackup),
  78         base::Bind(&ReturnNoBackup));
  79   }
  80
  81   ~MetricsServiceTest() override {
  82     MetricsService::SetExecutionPhase(MetricsService::UNINITIALIZED_PHASE,
  83                                       GetLocalState());
  84   }
  85
  86   MetricsStateManager* GetMetricsStateManager() {
  87     return metrics_state_manager_.get();
  88   }
  89
  90   PrefService* GetLocalState() { return &testing_local_state_; }
  91
  92   // Sets metrics reporting as enabled for testing.
  93   void EnableMetricsReporting() {
  94     is_metrics_reporting_enabled_ = true;
  95   }
  96
  97   // Waits until base::TimeTicks::Now() no longer equals |value|. This should
  98   // take between 1-15ms per the documented resolution of base::TimeTicks.
  99   void WaitUntilTimeChanges(const base::TimeTicks& value) {
 100     while (base::TimeTicks::Now() == value) {
 101       base::PlatformThread::Sleep(base::TimeDelta::FromMilliseconds(1));
 102     }
 103   }
 104
 105   // Returns true if there is a synthetic trial in the given vector that matches
 106   // the given trial name and trial group; returns false otherwise.
 107   bool HasSyntheticTrial(
 108       const std::vector<variations::ActiveGroupId>& synthetic_trials,
 109       const std::string& trial_name,
 110       const std::string& trial_group) {
 111     uint32 trial_name_hash = HashName(trial_name);
 112     uint32 trial_group_hash = HashName(trial_group);
 113     for (const variations::ActiveGroupId& trial : synthetic_trials) {
 114       if (trial.name == trial_name_hash && trial.group == trial_group_hash)
 115         return true;
 116     }
 117     return false;
 118   }
 119
 120   // Finds a histogram with the specified |name_hash| in |histograms|.
 121   const base::HistogramBase* FindHistogram(
 122       const base::StatisticsRecorder::Histograms& histograms,
 123       uint64 name_hash) {
 124     for (const base::HistogramBase* histogram : histograms) {
 125       if (name_hash == HashMetricName(histogram->histogram_name()))
 126         return histogram;
 127     }
 128     return nullptr;
 129   }
 130
 131   // Checks whether |uma_log| contains any histograms that are not flagged
 132   // with kUmaStabilityHistogramFlag. Stability logs should only contain such
 133   // histograms.
 134   void CheckForNonStabilityHistograms(
 135       const ChromeUserMetricsExtension& uma_log) {
 136     const int kStabilityFlags = base::HistogramBase::kUmaStabilityHistogramFlag;
 137     base::StatisticsRecorder::Histograms histograms;
 138     base::StatisticsRecorder::GetHistograms(&histograms);
 139     for (int i = 0; i < uma_log.histogram_event_size(); ++i) {
 140       const uint64 hash = uma_log.histogram_event(i).name_hash();
 141
 142       const base::HistogramBase* histogram = FindHistogram(histograms, hash);
 143       EXPECT_TRUE(histogram) << hash;
 144
 145       EXPECT_EQ(kStabilityFlags, histogram->flags() & kStabilityFlags) << hash;
 146     }
 147   }
 148
 149  private:
 150   bool is_metrics_reporting_enabled() const {
 151     return is_metrics_reporting_enabled_;
 152   }
 153
 154   bool is_metrics_reporting_enabled_;
 155   TestingPrefServiceSimple testing_local_state_;
 156   scoped_ptr<MetricsStateManager> metrics_state_manager_;
 157   base::MessageLoop message_loop;
 158
 159   DISALLOW_COPY_AND_ASSIGN(MetricsServiceTest);
 160 };
 161
 162 }  // namespace
 163
 164 TEST_F(MetricsServiceTest, InitialStabilityLogAfterCleanShutDown) {
 165   EnableMetricsReporting();
 166   GetLocalState()->SetBoolean(prefs::kStabilityExitedCleanly, true);
 167
 168   TestMetricsServiceClient client;
 169   TestMetricsService service(
 170       GetMetricsStateManager(), &client, GetLocalState());
 171
 172   TestMetricsProvider* test_provider = new TestMetricsProvider();
 173   service.RegisterMetricsProvider(scoped_ptr<MetricsProvider>(test_provider));
 174
 175   service.InitializeMetricsRecordingState();
 176   // No initial stability log should be generated.
 177   EXPECT_FALSE(service.log_manager()->has_unsent_logs());
 178   EXPECT_FALSE(service.log_manager()->has_staged_log());
 179
 180   // The test provider should not have been called upon to provide initial
 181   // stability nor regular stability metrics.
 182   EXPECT_FALSE(test_provider->provide_initial_stability_metrics_called());
 183   EXPECT_FALSE(test_provider->provide_stability_metrics_called());
 184 }
 185
 186 TEST_F(MetricsServiceTest, InitialStabilityLogAtProviderRequest) {
 187   EnableMetricsReporting();
 188
 189   // Save an existing system profile to prefs, to correspond to what would be
 190   // saved from a previous session.
 191   TestMetricsServiceClient client;
 192   TestMetricsLog log("client", 1, &client, GetLocalState());
 193   log.RecordEnvironment(std::vector<MetricsProvider*>(),
 194                         std::vector<variations::ActiveGroupId>(), 0, 0);
 195
 196   // Record stability build time and version from previous session, so that
 197   // stability metrics (including exited cleanly flag) won't be cleared.
 198   GetLocalState()->SetInt64(prefs::kStabilityStatsBuildTime,
 199                             MetricsLog::GetBuildTime());
 200   GetLocalState()->SetString(prefs::kStabilityStatsVersion,
 201                              client.GetVersionString());
 202
 203   // Set the clean exit flag, as that will otherwise cause a stabilty
 204   // log to be produced, irrespective provider requests.
 205   GetLocalState()->SetBoolean(prefs::kStabilityExitedCleanly, true);
 206
 207   TestMetricsService service(
 208       GetMetricsStateManager(), &client, GetLocalState());
 209   // Add a metrics provider that requests a stability log.
 210   TestMetricsProvider* test_provider = new TestMetricsProvider();
 211   test_provider->set_has_initial_stability_metrics(true);
 212   service.RegisterMetricsProvider(
 213       scoped_ptr<MetricsProvider>(test_provider));
 214
 215   service.InitializeMetricsRecordingState();
 216
 217   // The initial stability log should be generated and persisted in unsent logs.
 218   MetricsLogManager* log_manager = service.log_manager();
 219   EXPECT_TRUE(log_manager->has_unsent_logs());
 220   EXPECT_FALSE(log_manager->has_staged_log());
 221
 222   // The test provider should have been called upon to provide initial
 223   // stability and regular stability metrics.
 224   EXPECT_TRUE(test_provider->provide_initial_stability_metrics_called());
 225   EXPECT_TRUE(test_provider->provide_stability_metrics_called());
 226
 227   // Stage the log and retrieve it.
 228   log_manager->StageNextLogForUpload();
 229   EXPECT_TRUE(log_manager->has_staged_log());
 230
 231   std::string uncompressed_log;
 232   EXPECT_TRUE(GzipUncompress(log_manager->staged_log(), &uncompressed_log));
 233
 234   ChromeUserMetricsExtension uma_log;
 235   EXPECT_TRUE(uma_log.ParseFromString(uncompressed_log));
 236
 237   EXPECT_TRUE(uma_log.has_client_id());
 238   EXPECT_TRUE(uma_log.has_session_id());
 239   EXPECT_TRUE(uma_log.has_system_profile());
 240   EXPECT_EQ(0, uma_log.user_action_event_size());
 241   EXPECT_EQ(0, uma_log.omnibox_event_size());
 242   EXPECT_EQ(0, uma_log.profiler_event_size());
 243   EXPECT_EQ(0, uma_log.perf_data_size());
 244   CheckForNonStabilityHistograms(uma_log);
 245
 246   // As there wasn't an unclean shutdown, this log has zero crash count.
 247   EXPECT_EQ(0, uma_log.system_profile().stability().crash_count());
 248 }
 249
 250 TEST_F(MetricsServiceTest, InitialStabilityLogAfterCrash) {
 251   EnableMetricsReporting();
 252   GetLocalState()->ClearPref(prefs::kStabilityExitedCleanly);
 253
 254   // Set up prefs to simulate restarting after a crash.
 255
 256   // Save an existing system profile to prefs, to correspond to what would be
 257   // saved from a previous session.
 258   TestMetricsServiceClient client;
 259   TestMetricsLog log("client", 1, &client, GetLocalState());
 260   log.RecordEnvironment(std::vector<MetricsProvider*>(),
 261                         std::vector<variations::ActiveGroupId>(), 0, 0);
 262
 263   // Record stability build time and version from previous session, so that
 264   // stability metrics (including exited cleanly flag) won't be cleared.
 265   GetLocalState()->SetInt64(prefs::kStabilityStatsBuildTime,
 266                             MetricsLog::GetBuildTime());
 267   GetLocalState()->SetString(prefs::kStabilityStatsVersion,
 268                              client.GetVersionString());
 269
 270   GetLocalState()->SetBoolean(prefs::kStabilityExitedCleanly, false);
 271
 272   TestMetricsService service(
 273       GetMetricsStateManager(), &client, GetLocalState());
 274   // Add a provider.
 275   TestMetricsProvider* test_provider = new TestMetricsProvider();
 276   service.RegisterMetricsProvider(scoped_ptr<MetricsProvider>(test_provider));
 277   service.InitializeMetricsRecordingState();
 278
 279   // The initial stability log should be generated and persisted in unsent logs.
 280   MetricsLogManager* log_manager = service.log_manager();
 281   EXPECT_TRUE(log_manager->has_unsent_logs());
 282   EXPECT_FALSE(log_manager->has_staged_log());
 283
 284   // The test provider should have been called upon to provide initial
 285   // stability and regular stability metrics.
 286   EXPECT_TRUE(test_provider->provide_initial_stability_metrics_called());
 287   EXPECT_TRUE(test_provider->provide_stability_metrics_called());
 288
 289   // Stage the log and retrieve it.
 290   log_manager->StageNextLogForUpload();
 291   EXPECT_TRUE(log_manager->has_staged_log());
 292
 293   std::string uncompressed_log;
 294   EXPECT_TRUE(GzipUncompress(log_manager->staged_log(), &uncompressed_log));
 295
 296   ChromeUserMetricsExtension uma_log;
 297   EXPECT_TRUE(uma_log.ParseFromString(uncompressed_log));
 298
 299   EXPECT_TRUE(uma_log.has_client_id());
 300   EXPECT_TRUE(uma_log.has_session_id());
 301   EXPECT_TRUE(uma_log.has_system_profile());
 302   EXPECT_EQ(0, uma_log.user_action_event_size());
 303   EXPECT_EQ(0, uma_log.omnibox_event_size());
 304   EXPECT_EQ(0, uma_log.profiler_event_size());
 305   EXPECT_EQ(0, uma_log.perf_data_size());
 306   CheckForNonStabilityHistograms(uma_log);
 307
 308   EXPECT_EQ(1, uma_log.system_profile().stability().crash_count());
 309 }
 310
 311 TEST_F(MetricsServiceTest, RegisterSyntheticTrial) {
 312   TestMetricsServiceClient client;
 313   MetricsService service(GetMetricsStateManager(), &client, GetLocalState());
 314
 315   // Add two synthetic trials and confirm that they show up in the list.
 316   SyntheticTrialGroup trial1(HashName("TestTrial1"), HashName("Group1"));
 317   service.RegisterSyntheticFieldTrial(trial1);
 318
 319   SyntheticTrialGroup trial2(HashName("TestTrial2"), HashName("Group2"));
 320   service.RegisterSyntheticFieldTrial(trial2);
 321   // Ensure that time has advanced by at least a tick before proceeding.
 322   WaitUntilTimeChanges(base::TimeTicks::Now());
 323
 324   service.log_manager_.BeginLoggingWithLog(scoped_ptr<MetricsLog>(
 325       new MetricsLog("clientID",
 326                      1,
 327                      MetricsLog::INITIAL_STABILITY_LOG,
 328                      &client,
 329                      GetLocalState())));
 330   // Save the time when the log was started (it's okay for this to be greater
 331   // than the time recorded by the above call since it's used to ensure the
 332   // value changes).
 333   const base::TimeTicks begin_log_time = base::TimeTicks::Now();
 334
 335   std::vector<variations::ActiveGroupId> synthetic_trials;
 336   service.GetCurrentSyntheticFieldTrials(&synthetic_trials);
 337   EXPECT_EQ(2U, synthetic_trials.size());
 338   EXPECT_TRUE(HasSyntheticTrial(synthetic_trials, "TestTrial1", "Group1"));
 339   EXPECT_TRUE(HasSyntheticTrial(synthetic_trials, "TestTrial2", "Group2"));
 340
 341   // Ensure that time has advanced by at least a tick before proceeding.
 342   WaitUntilTimeChanges(begin_log_time);
 343
 344   // Change the group for the first trial after the log started.
 345   SyntheticTrialGroup trial3(HashName("TestTrial1"), HashName("Group2"));
 346   service.RegisterSyntheticFieldTrial(trial3);
 347   service.GetCurrentSyntheticFieldTrials(&synthetic_trials);
 348   EXPECT_EQ(1U, synthetic_trials.size());
 349   EXPECT_TRUE(HasSyntheticTrial(synthetic_trials, "TestTrial2", "Group2"));
 350
 351   // Add a new trial after the log started and confirm that it doesn't show up.
 352   SyntheticTrialGroup trial4(HashName("TestTrial3"), HashName("Group3"));
 353   service.RegisterSyntheticFieldTrial(trial4);
 354   service.GetCurrentSyntheticFieldTrials(&synthetic_trials);
 355   EXPECT_EQ(1U, synthetic_trials.size());
 356   EXPECT_TRUE(HasSyntheticTrial(synthetic_trials, "TestTrial2", "Group2"));
 357
 358   // Ensure that time has advanced by at least a tick before proceeding.
 359   WaitUntilTimeChanges(base::TimeTicks::Now());
 360
 361   // Start a new log and ensure all three trials appear in it.
 362   service.log_manager_.FinishCurrentLog();
 363   service.log_manager_.BeginLoggingWithLog(
 364       scoped_ptr<MetricsLog>(new MetricsLog(
 365           "clientID", 1, MetricsLog::ONGOING_LOG, &client, GetLocalState())));
 366   service.GetCurrentSyntheticFieldTrials(&synthetic_trials);
 367   EXPECT_EQ(3U, synthetic_trials.size());
 368   EXPECT_TRUE(HasSyntheticTrial(synthetic_trials, "TestTrial1", "Group2"));
 369   EXPECT_TRUE(HasSyntheticTrial(synthetic_trials, "TestTrial2", "Group2"));
 370   EXPECT_TRUE(HasSyntheticTrial(synthetic_trials, "TestTrial3", "Group3"));
 371   service.log_manager_.FinishCurrentLog();
 372 }
 373
 374 }  // namespace metrics