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