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