1 // Copyright (c) 2012 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 <string> 6 7 #include "base/basictypes.h" 8 #include "base/message_loop/message_loop.h" 9 #include "base/port.h" 10 #include "base/prefs/pref_service.h" 11 #include "base/prefs/testing_pref_service.h" 12 #include "base/strings/string_number_conversions.h" 13 #include "base/strings/string_util.h" 14 #include "base/strings/stringprintf.h" 15 #include "base/threading/sequenced_worker_pool.h" 16 #include "base/time/time.h" 17 #include "base/tracked_objects.h" 18 #include "chrome/browser/google/google_util.h" 19 #include "chrome/browser/metrics/metrics_log.h" 20 #include "chrome/browser/prefs/browser_prefs.h" 21 #include "chrome/common/metrics/proto/profiler_event.pb.h" 22 #include "chrome/common/metrics/proto/system_profile.pb.h" 23 #include "chrome/common/metrics/variations/variations_util.h" 24 #include "chrome/common/pref_names.h" 25 #include "chrome/installer/util/google_update_settings.h" 26 #include "content/public/browser/browser_thread.h" 27 #include "content/public/common/process_type.h" 28 #include "content/public/common/webplugininfo.h" 29 #include "content/public/test/test_utils.h" 30 #include "testing/gtest/include/gtest/gtest.h" 31 #include "ui/gfx/size.h" 32 #include "url/gurl.h" 33 34 #if defined(OS_CHROMEOS) 35 #include "chromeos/dbus/mock_dbus_thread_manager_without_gmock.h" 36 #endif // OS_CHROMEOS 37 38 using base::TimeDelta; 39 using metrics::ProfilerEventProto; 40 using tracked_objects::ProcessDataSnapshot; 41 using tracked_objects::TaskSnapshot; 42 43 namespace { 44 45 const char kClientId[] = "bogus client ID"; 46 const int64 kInstallDate = 1373051956; 47 const int64 kEnabledDate = 1373001211; 48 const int kSessionId = 127; 49 const int kScreenWidth = 1024; 50 const int kScreenHeight = 768; 51 const int kScreenCount = 3; 52 const float kScreenScaleFactor = 2; 53 const char kBrandForTesting[] = "brand_for_testing"; 54 const chrome_variations::ActiveGroupId kFieldTrialIds[] = { 55 {37, 43}, 56 {13, 47}, 57 {23, 17} 58 }; 59 60 class TestMetricsLog : public MetricsLog { 61 public: 62 TestMetricsLog(const std::string& client_id, int session_id) 63 : MetricsLog(client_id, session_id), 64 brand_for_testing_(kBrandForTesting) { 65 chrome::RegisterLocalState(prefs_.registry()); 66 67 prefs_.SetInt64(prefs::kInstallDate, kInstallDate); 68 prefs_.SetString(prefs::kMetricsClientIDTimestamp, 69 base::Int64ToString(kEnabledDate)); 70 #if defined(OS_CHROMEOS) 71 prefs_.SetInteger(prefs::kStabilityChildProcessCrashCount, 10); 72 prefs_.SetInteger(prefs::kStabilityOtherUserCrashCount, 11); 73 prefs_.SetInteger(prefs::kStabilityKernelCrashCount, 12); 74 prefs_.SetInteger(prefs::kStabilitySystemUncleanShutdownCount, 13); 75 #endif // OS_CHROMEOS 76 } 77 virtual ~TestMetricsLog() {} 78 79 virtual PrefService* GetPrefService() OVERRIDE { 80 return &prefs_; 81 } 82 83 const metrics::ChromeUserMetricsExtension& uma_proto() const { 84 return *MetricsLog::uma_proto(); 85 } 86 87 const metrics::SystemProfileProto& system_profile() const { 88 return uma_proto().system_profile(); 89 } 90 91 private: 92 virtual void GetFieldTrialIds( 93 std::vector<chrome_variations::ActiveGroupId>* field_trial_ids) const 94 OVERRIDE { 95 ASSERT_TRUE(field_trial_ids->empty()); 96 97 for (size_t i = 0; i < arraysize(kFieldTrialIds); ++i) { 98 field_trial_ids->push_back(kFieldTrialIds[i]); 99 } 100 } 101 102 virtual gfx::Size GetScreenSize() const OVERRIDE { 103 return gfx::Size(kScreenWidth, kScreenHeight); 104 } 105 106 virtual float GetScreenDeviceScaleFactor() const OVERRIDE { 107 return kScreenScaleFactor; 108 } 109 110 virtual int GetScreenCount() const OVERRIDE { 111 return kScreenCount; 112 } 113 114 TestingPrefServiceSimple prefs_; 115 116 google_util::BrandForTesting brand_for_testing_; 117 118 DISALLOW_COPY_AND_ASSIGN(TestMetricsLog); 119 }; 120 121 } // namespace 122 123 class MetricsLogTest : public testing::Test { 124 public: 125 MetricsLogTest() : message_loop_(base::MessageLoop::TYPE_IO) {} 126 127 protected: 128 void TestRecordEnvironment(bool proto_only) { 129 TestMetricsLog log(kClientId, kSessionId); 130 131 std::vector<content::WebPluginInfo> plugins; 132 GoogleUpdateMetrics google_update_metrics; 133 if (proto_only) 134 log.RecordEnvironmentProto(plugins, google_update_metrics); 135 else 136 log.RecordEnvironment(plugins, google_update_metrics); 137 138 // Computed from original time of 1373051956. 139 EXPECT_EQ(1373050800, log.system_profile().install_date()); 140 141 // Computed from original time of 1373001211. 142 EXPECT_EQ(1373000400, log.system_profile().uma_enabled_date()); 143 144 const metrics::SystemProfileProto& system_profile = log.system_profile(); 145 ASSERT_EQ(arraysize(kFieldTrialIds), 146 static_cast<size_t>(system_profile.field_trial_size())); 147 for (size_t i = 0; i < arraysize(kFieldTrialIds); ++i) { 148 const metrics::SystemProfileProto::FieldTrial& field_trial = 149 system_profile.field_trial(i); 150 EXPECT_EQ(kFieldTrialIds[i].name, field_trial.name_id()); 151 EXPECT_EQ(kFieldTrialIds[i].group, field_trial.group_id()); 152 } 153 154 EXPECT_EQ(kBrandForTesting, system_profile.brand_code()); 155 156 const metrics::SystemProfileProto::Hardware& hardware = 157 system_profile.hardware(); 158 EXPECT_EQ(kScreenWidth, hardware.primary_screen_width()); 159 EXPECT_EQ(kScreenHeight, hardware.primary_screen_height()); 160 EXPECT_EQ(kScreenScaleFactor, hardware.primary_screen_scale_factor()); 161 EXPECT_EQ(kScreenCount, hardware.screen_count()); 162 163 EXPECT_TRUE(hardware.has_cpu()); 164 EXPECT_TRUE(hardware.cpu().has_vendor_name()); 165 EXPECT_TRUE(hardware.cpu().has_signature()); 166 167 // TODO(isherman): Verify other data written into the protobuf as a result 168 // of this call. 169 } 170 171 virtual void SetUp() OVERRIDE { 172 #if defined(OS_CHROMEOS) 173 mock_dbus_thread_manager_ = 174 new chromeos::MockDBusThreadManagerWithoutGMock(); 175 chromeos::DBusThreadManager::InitializeForTesting( 176 mock_dbus_thread_manager_); 177 #endif // OS_CHROMEOS 178 } 179 180 virtual void TearDown() OVERRIDE { 181 // Drain the blocking pool from PostTaskAndReply executed by 182 // MetrticsLog.network_observer_. 183 content::BrowserThread::GetBlockingPool()->FlushForTesting(); 184 content::RunAllPendingInMessageLoop(); 185 186 #if defined(OS_CHROMEOS) 187 chromeos::DBusThreadManager::Shutdown(); 188 #endif // OS_CHROMEOS 189 } 190 191 private: 192 // This is necessary because eventually some tests call base::RepeatingTimer 193 // functions and a message loop is required for that. 194 base::MessageLoop message_loop_; 195 196 #if defined(OS_CHROMEOS) 197 chromeos::MockDBusThreadManagerWithoutGMock* mock_dbus_thread_manager_; 198 #endif // OS_CHROMEOS 199 }; 200 201 TEST_F(MetricsLogTest, RecordEnvironment) { 202 // Test that recording the environment works via both of the public methods 203 // RecordEnvironment() and RecordEnvironmentProto(). 204 TestRecordEnvironment(false); 205 TestRecordEnvironment(true); 206 } 207 208 // Test that we properly write profiler data to the log. 209 TEST_F(MetricsLogTest, RecordProfilerData) { 210 TestMetricsLog log(kClientId, kSessionId); 211 EXPECT_EQ(0, log.uma_proto().profiler_event_size()); 212 213 { 214 ProcessDataSnapshot process_data; 215 process_data.process_id = 177; 216 process_data.tasks.push_back(TaskSnapshot()); 217 process_data.tasks.back().birth.location.file_name = "file"; 218 process_data.tasks.back().birth.location.function_name = "function"; 219 process_data.tasks.back().birth.location.line_number = 1337; 220 process_data.tasks.back().birth.thread_name = "birth_thread"; 221 process_data.tasks.back().death_data.count = 37; 222 process_data.tasks.back().death_data.run_duration_sum = 31; 223 process_data.tasks.back().death_data.run_duration_max = 17; 224 process_data.tasks.back().death_data.run_duration_sample = 13; 225 process_data.tasks.back().death_data.queue_duration_sum = 8; 226 process_data.tasks.back().death_data.queue_duration_max = 5; 227 process_data.tasks.back().death_data.queue_duration_sample = 3; 228 process_data.tasks.back().death_thread_name = "Still_Alive"; 229 process_data.tasks.push_back(TaskSnapshot()); 230 process_data.tasks.back().birth.location.file_name = "file2"; 231 process_data.tasks.back().birth.location.function_name = "function2"; 232 process_data.tasks.back().birth.location.line_number = 1773; 233 process_data.tasks.back().birth.thread_name = "birth_thread2"; 234 process_data.tasks.back().death_data.count = 19; 235 process_data.tasks.back().death_data.run_duration_sum = 23; 236 process_data.tasks.back().death_data.run_duration_max = 11; 237 process_data.tasks.back().death_data.run_duration_sample = 7; 238 process_data.tasks.back().death_data.queue_duration_sum = 0; 239 process_data.tasks.back().death_data.queue_duration_max = 0; 240 process_data.tasks.back().death_data.queue_duration_sample = 0; 241 process_data.tasks.back().death_thread_name = "death_thread"; 242 243 log.RecordProfilerData(process_data, content::PROCESS_TYPE_BROWSER); 244 ASSERT_EQ(1, log.uma_proto().profiler_event_size()); 245 EXPECT_EQ(ProfilerEventProto::STARTUP_PROFILE, 246 log.uma_proto().profiler_event(0).profile_type()); 247 EXPECT_EQ(ProfilerEventProto::WALL_CLOCK_TIME, 248 log.uma_proto().profiler_event(0).time_source()); 249 250 ASSERT_EQ(2, log.uma_proto().profiler_event(0).tracked_object_size()); 251 252 const ProfilerEventProto::TrackedObject* tracked_object = 253 &log.uma_proto().profiler_event(0).tracked_object(0); 254 EXPECT_EQ(GG_UINT64_C(10123486280357988687), 255 tracked_object->source_file_name_hash()); 256 EXPECT_EQ(GG_UINT64_C(13962325592283560029), 257 tracked_object->source_function_name_hash()); 258 EXPECT_EQ(1337, tracked_object->source_line_number()); 259 EXPECT_EQ(GG_UINT64_C(3400908935414830400), 260 tracked_object->birth_thread_name_hash()); 261 EXPECT_EQ(37, tracked_object->exec_count()); 262 EXPECT_EQ(31, tracked_object->exec_time_total()); 263 EXPECT_EQ(13, tracked_object->exec_time_sampled()); 264 EXPECT_EQ(8, tracked_object->queue_time_total()); 265 EXPECT_EQ(3, tracked_object->queue_time_sampled()); 266 EXPECT_EQ(GG_UINT64_C(10151977472163283085), 267 tracked_object->exec_thread_name_hash()); 268 EXPECT_EQ(177U, tracked_object->process_id()); 269 EXPECT_EQ(ProfilerEventProto::TrackedObject::BROWSER, 270 tracked_object->process_type()); 271 272 tracked_object = &log.uma_proto().profiler_event(0).tracked_object(1); 273 EXPECT_EQ(GG_UINT64_C(2025659946535236365), 274 tracked_object->source_file_name_hash()); 275 EXPECT_EQ(GG_UINT64_C(55232426147951219), 276 tracked_object->source_function_name_hash()); 277 EXPECT_EQ(1773, tracked_object->source_line_number()); 278 EXPECT_EQ(GG_UINT64_C(15727396632046120663), 279 tracked_object->birth_thread_name_hash()); 280 EXPECT_EQ(19, tracked_object->exec_count()); 281 EXPECT_EQ(23, tracked_object->exec_time_total()); 282 EXPECT_EQ(7, tracked_object->exec_time_sampled()); 283 EXPECT_EQ(0, tracked_object->queue_time_total()); 284 EXPECT_EQ(0, tracked_object->queue_time_sampled()); 285 EXPECT_EQ(GG_UINT64_C(14275151213201158253), 286 tracked_object->exec_thread_name_hash()); 287 EXPECT_EQ(177U, tracked_object->process_id()); 288 EXPECT_EQ(ProfilerEventProto::TrackedObject::BROWSER, 289 tracked_object->process_type()); 290 } 291 292 { 293 ProcessDataSnapshot process_data; 294 process_data.process_id = 1177; 295 process_data.tasks.push_back(TaskSnapshot()); 296 process_data.tasks.back().birth.location.file_name = "file3"; 297 process_data.tasks.back().birth.location.function_name = "function3"; 298 process_data.tasks.back().birth.location.line_number = 7331; 299 process_data.tasks.back().birth.thread_name = "birth_thread3"; 300 process_data.tasks.back().death_data.count = 137; 301 process_data.tasks.back().death_data.run_duration_sum = 131; 302 process_data.tasks.back().death_data.run_duration_max = 117; 303 process_data.tasks.back().death_data.run_duration_sample = 113; 304 process_data.tasks.back().death_data.queue_duration_sum = 108; 305 process_data.tasks.back().death_data.queue_duration_max = 105; 306 process_data.tasks.back().death_data.queue_duration_sample = 103; 307 process_data.tasks.back().death_thread_name = "death_thread3"; 308 309 log.RecordProfilerData(process_data, content::PROCESS_TYPE_RENDERER); 310 ASSERT_EQ(1, log.uma_proto().profiler_event_size()); 311 EXPECT_EQ(ProfilerEventProto::STARTUP_PROFILE, 312 log.uma_proto().profiler_event(0).profile_type()); 313 EXPECT_EQ(ProfilerEventProto::WALL_CLOCK_TIME, 314 log.uma_proto().profiler_event(0).time_source()); 315 ASSERT_EQ(3, log.uma_proto().profiler_event(0).tracked_object_size()); 316 317 const ProfilerEventProto::TrackedObject* tracked_object = 318 &log.uma_proto().profiler_event(0).tracked_object(2); 319 EXPECT_EQ(GG_UINT64_C(2686523203278102732), 320 tracked_object->source_file_name_hash()); 321 EXPECT_EQ(GG_UINT64_C(5081672290546182009), 322 tracked_object->source_function_name_hash()); 323 EXPECT_EQ(7331, tracked_object->source_line_number()); 324 EXPECT_EQ(GG_UINT64_C(8768512930949373716), 325 tracked_object->birth_thread_name_hash()); 326 EXPECT_EQ(137, tracked_object->exec_count()); 327 EXPECT_EQ(131, tracked_object->exec_time_total()); 328 EXPECT_EQ(113, tracked_object->exec_time_sampled()); 329 EXPECT_EQ(108, tracked_object->queue_time_total()); 330 EXPECT_EQ(103, tracked_object->queue_time_sampled()); 331 EXPECT_EQ(GG_UINT64_C(7246674144371406371), 332 tracked_object->exec_thread_name_hash()); 333 EXPECT_EQ(1177U, tracked_object->process_id()); 334 EXPECT_EQ(ProfilerEventProto::TrackedObject::RENDERER, 335 tracked_object->process_type()); 336 } 337 } 338
