OLD | NEW |
1 // Copyright (c) 2012 The Chromium Authors. All rights reserved. | 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 | 2 // Use of this source code is governed by a BSD-style license that can be |
3 // found in the LICENSE file. | 3 // found in the LICENSE file. |
4 | 4 |
5 #include "chrome/browser/metrics/metrics_log.h" | 5 #include "chrome/browser/metrics/metrics_log.h" |
6 | 6 |
7 #include <string> | 7 #include <string> |
8 | 8 |
9 #include "base/base64.h" | 9 #include "base/base64.h" |
10 #include "base/basictypes.h" | 10 #include "base/basictypes.h" |
11 #include "base/command_line.h" | 11 #include "base/command_line.h" |
12 #include "base/port.h" | 12 #include "base/port.h" |
13 #include "base/prefs/pref_service.h" | 13 #include "base/prefs/pref_service.h" |
14 #include "base/prefs/testing_pref_service.h" | 14 #include "base/prefs/testing_pref_service.h" |
15 #include "base/strings/string_number_conversions.h" | 15 #include "base/strings/string_number_conversions.h" |
16 #include "base/strings/string_util.h" | 16 #include "base/strings/string_util.h" |
17 #include "base/strings/stringprintf.h" | 17 #include "base/strings/stringprintf.h" |
18 #include "base/threading/sequenced_worker_pool.h" | 18 #include "base/threading/sequenced_worker_pool.h" |
19 #include "base/time/time.h" | 19 #include "base/time/time.h" |
20 #include "base/tracked_objects.h" | |
21 #include "chrome/browser/google/google_util.h" | 20 #include "chrome/browser/google/google_util.h" |
22 #include "chrome/browser/metrics/metrics_service.h" | 21 #include "chrome/browser/metrics/metrics_service.h" |
23 #include "chrome/browser/prefs/browser_prefs.h" | 22 #include "chrome/browser/prefs/browser_prefs.h" |
24 #include "chrome/common/chrome_version_info.h" | 23 #include "chrome/common/chrome_version_info.h" |
25 #include "chrome/common/pref_names.h" | 24 #include "chrome/common/pref_names.h" |
26 #include "components/metrics/metrics_hashes.h" | 25 #include "components/metrics/metrics_hashes.h" |
27 #include "components/metrics/metrics_provider.h" | 26 #include "components/metrics/metrics_provider.h" |
28 #include "components/metrics/proto/profiler_event.pb.h" | 27 #include "components/metrics/proto/profiler_event.pb.h" |
29 #include "components/metrics/proto/system_profile.pb.h" | 28 #include "components/metrics/proto/system_profile.pb.h" |
30 #include "components/metrics/test_metrics_service_client.h" | 29 #include "components/metrics/test_metrics_service_client.h" |
31 #include "components/variations/active_field_trials.h" | 30 #include "components/variations/active_field_trials.h" |
32 #include "content/public/browser/browser_thread.h" | 31 #include "content/public/browser/browser_thread.h" |
33 #include "content/public/common/process_type.h" | |
34 #include "content/public/test/test_browser_thread_bundle.h" | 32 #include "content/public/test/test_browser_thread_bundle.h" |
35 #include "content/public/test/test_utils.h" | 33 #include "content/public/test/test_utils.h" |
36 #include "testing/gtest/include/gtest/gtest.h" | 34 #include "testing/gtest/include/gtest/gtest.h" |
37 #include "url/gurl.h" | 35 #include "url/gurl.h" |
38 | 36 |
39 #if defined(OS_CHROMEOS) | 37 #if defined(OS_CHROMEOS) |
40 #include "chromeos/login/login_state.h" | 38 #include "chromeos/login/login_state.h" |
41 #endif // defined(OS_CHROMEOS) | 39 #endif // defined(OS_CHROMEOS) |
42 | 40 |
43 using base::TimeDelta; | 41 using base::TimeDelta; |
44 using metrics::ProfilerEventProto; | |
45 using tracked_objects::ProcessDataSnapshot; | |
46 using tracked_objects::TaskSnapshot; | |
47 | 42 |
48 namespace { | 43 namespace { |
49 | 44 |
50 const char kClientId[] = "bogus client ID"; | 45 const char kClientId[] = "bogus client ID"; |
51 const int64 kInstallDate = 1373051956; | 46 const int64 kInstallDate = 1373051956; |
52 const int64 kInstallDateExpected = 1373050800; // Computed from kInstallDate. | 47 const int64 kInstallDateExpected = 1373050800; // Computed from kInstallDate. |
53 const int64 kEnabledDate = 1373001211; | 48 const int64 kEnabledDate = 1373001211; |
54 const int64 kEnabledDateExpected = 1373000400; // Computed from kEnabledDate. | 49 const int64 kEnabledDateExpected = 1373000400; // Computed from kEnabledDate. |
55 const int kSessionId = 127; | 50 const int kSessionId = 127; |
56 const variations::ActiveGroupId kFieldTrialIds[] = { | 51 const variations::ActiveGroupId kFieldTrialIds[] = { |
(...skipping 243 matching lines...) Expand 10 before | Expand all | Expand 10 after Loading... |
300 EXPECT_TRUE(stability.has_launch_count()); | 295 EXPECT_TRUE(stability.has_launch_count()); |
301 EXPECT_TRUE(stability.has_crash_count()); | 296 EXPECT_TRUE(stability.has_crash_count()); |
302 // Initial log metrics: | 297 // Initial log metrics: |
303 EXPECT_FALSE(stability.has_incomplete_shutdown_count()); | 298 EXPECT_FALSE(stability.has_incomplete_shutdown_count()); |
304 EXPECT_FALSE(stability.has_breakpad_registration_success_count()); | 299 EXPECT_FALSE(stability.has_breakpad_registration_success_count()); |
305 EXPECT_FALSE(stability.has_breakpad_registration_failure_count()); | 300 EXPECT_FALSE(stability.has_breakpad_registration_failure_count()); |
306 EXPECT_FALSE(stability.has_debugger_present_count()); | 301 EXPECT_FALSE(stability.has_debugger_present_count()); |
307 EXPECT_FALSE(stability.has_debugger_not_present_count()); | 302 EXPECT_FALSE(stability.has_debugger_not_present_count()); |
308 } | 303 } |
309 | 304 |
310 // Test that we properly write profiler data to the log. | |
311 TEST_F(MetricsLogTest, RecordProfilerData) { | |
312 // WARNING: If you broke the below check, you've modified how | |
313 // metrics::HashMetricName works. Please also modify all server-side code that | |
314 // relies on the existing way of hashing. | |
315 EXPECT_EQ(GG_UINT64_C(1518842999910132863), | |
316 metrics::HashMetricName("birth_thread*")); | |
317 | |
318 metrics::TestMetricsServiceClient client; | |
319 TestMetricsLog log( | |
320 kClientId, kSessionId, MetricsLog::ONGOING_LOG, &client, &prefs_); | |
321 EXPECT_EQ(0, log.uma_proto().profiler_event_size()); | |
322 | |
323 { | |
324 ProcessDataSnapshot process_data; | |
325 process_data.process_id = 177; | |
326 process_data.tasks.push_back(TaskSnapshot()); | |
327 process_data.tasks.back().birth.location.file_name = "a/b/file.h"; | |
328 process_data.tasks.back().birth.location.function_name = "function"; | |
329 process_data.tasks.back().birth.location.line_number = 1337; | |
330 process_data.tasks.back().birth.thread_name = "birth_thread"; | |
331 process_data.tasks.back().death_data.count = 37; | |
332 process_data.tasks.back().death_data.run_duration_sum = 31; | |
333 process_data.tasks.back().death_data.run_duration_max = 17; | |
334 process_data.tasks.back().death_data.run_duration_sample = 13; | |
335 process_data.tasks.back().death_data.queue_duration_sum = 8; | |
336 process_data.tasks.back().death_data.queue_duration_max = 5; | |
337 process_data.tasks.back().death_data.queue_duration_sample = 3; | |
338 process_data.tasks.back().death_thread_name = "Still_Alive"; | |
339 process_data.tasks.push_back(TaskSnapshot()); | |
340 process_data.tasks.back().birth.location.file_name = "c\\d\\file2"; | |
341 process_data.tasks.back().birth.location.function_name = "function2"; | |
342 process_data.tasks.back().birth.location.line_number = 1773; | |
343 process_data.tasks.back().birth.thread_name = "birth_thread2"; | |
344 process_data.tasks.back().death_data.count = 19; | |
345 process_data.tasks.back().death_data.run_duration_sum = 23; | |
346 process_data.tasks.back().death_data.run_duration_max = 11; | |
347 process_data.tasks.back().death_data.run_duration_sample = 7; | |
348 process_data.tasks.back().death_data.queue_duration_sum = 0; | |
349 process_data.tasks.back().death_data.queue_duration_max = 0; | |
350 process_data.tasks.back().death_data.queue_duration_sample = 0; | |
351 process_data.tasks.back().death_thread_name = "death_thread"; | |
352 | |
353 log.RecordProfilerData(process_data, content::PROCESS_TYPE_BROWSER); | |
354 ASSERT_EQ(1, log.uma_proto().profiler_event_size()); | |
355 EXPECT_EQ(ProfilerEventProto::STARTUP_PROFILE, | |
356 log.uma_proto().profiler_event(0).profile_type()); | |
357 EXPECT_EQ(ProfilerEventProto::WALL_CLOCK_TIME, | |
358 log.uma_proto().profiler_event(0).time_source()); | |
359 | |
360 ASSERT_EQ(2, log.uma_proto().profiler_event(0).tracked_object_size()); | |
361 | |
362 const ProfilerEventProto::TrackedObject* tracked_object = | |
363 &log.uma_proto().profiler_event(0).tracked_object(0); | |
364 EXPECT_EQ(metrics::HashMetricName("file.h"), | |
365 tracked_object->source_file_name_hash()); | |
366 EXPECT_EQ(metrics::HashMetricName("function"), | |
367 tracked_object->source_function_name_hash()); | |
368 EXPECT_EQ(1337, tracked_object->source_line_number()); | |
369 EXPECT_EQ(metrics::HashMetricName("birth_thread"), | |
370 tracked_object->birth_thread_name_hash()); | |
371 EXPECT_EQ(37, tracked_object->exec_count()); | |
372 EXPECT_EQ(31, tracked_object->exec_time_total()); | |
373 EXPECT_EQ(13, tracked_object->exec_time_sampled()); | |
374 EXPECT_EQ(8, tracked_object->queue_time_total()); | |
375 EXPECT_EQ(3, tracked_object->queue_time_sampled()); | |
376 EXPECT_EQ(metrics::HashMetricName("Still_Alive"), | |
377 tracked_object->exec_thread_name_hash()); | |
378 EXPECT_EQ(177U, tracked_object->process_id()); | |
379 EXPECT_EQ(ProfilerEventProto::TrackedObject::BROWSER, | |
380 tracked_object->process_type()); | |
381 | |
382 tracked_object = &log.uma_proto().profiler_event(0).tracked_object(1); | |
383 EXPECT_EQ(metrics::HashMetricName("file2"), | |
384 tracked_object->source_file_name_hash()); | |
385 EXPECT_EQ(metrics::HashMetricName("function2"), | |
386 tracked_object->source_function_name_hash()); | |
387 EXPECT_EQ(1773, tracked_object->source_line_number()); | |
388 EXPECT_EQ(metrics::HashMetricName("birth_thread*"), | |
389 tracked_object->birth_thread_name_hash()); | |
390 EXPECT_EQ(19, tracked_object->exec_count()); | |
391 EXPECT_EQ(23, tracked_object->exec_time_total()); | |
392 EXPECT_EQ(7, tracked_object->exec_time_sampled()); | |
393 EXPECT_EQ(0, tracked_object->queue_time_total()); | |
394 EXPECT_EQ(0, tracked_object->queue_time_sampled()); | |
395 EXPECT_EQ(metrics::HashMetricName("death_thread"), | |
396 tracked_object->exec_thread_name_hash()); | |
397 EXPECT_EQ(177U, tracked_object->process_id()); | |
398 EXPECT_EQ(ProfilerEventProto::TrackedObject::BROWSER, | |
399 tracked_object->process_type()); | |
400 } | |
401 | |
402 { | |
403 ProcessDataSnapshot process_data; | |
404 process_data.process_id = 1177; | |
405 process_data.tasks.push_back(TaskSnapshot()); | |
406 process_data.tasks.back().birth.location.file_name = "file3"; | |
407 process_data.tasks.back().birth.location.function_name = "function3"; | |
408 process_data.tasks.back().birth.location.line_number = 7331; | |
409 process_data.tasks.back().birth.thread_name = "birth_thread3"; | |
410 process_data.tasks.back().death_data.count = 137; | |
411 process_data.tasks.back().death_data.run_duration_sum = 131; | |
412 process_data.tasks.back().death_data.run_duration_max = 117; | |
413 process_data.tasks.back().death_data.run_duration_sample = 113; | |
414 process_data.tasks.back().death_data.queue_duration_sum = 108; | |
415 process_data.tasks.back().death_data.queue_duration_max = 105; | |
416 process_data.tasks.back().death_data.queue_duration_sample = 103; | |
417 process_data.tasks.back().death_thread_name = "death_thread3"; | |
418 process_data.tasks.push_back(TaskSnapshot()); | |
419 process_data.tasks.back().birth.location.file_name = ""; | |
420 process_data.tasks.back().birth.location.function_name = ""; | |
421 process_data.tasks.back().birth.location.line_number = 7332; | |
422 process_data.tasks.back().birth.thread_name = ""; | |
423 process_data.tasks.back().death_data.count = 138; | |
424 process_data.tasks.back().death_data.run_duration_sum = 132; | |
425 process_data.tasks.back().death_data.run_duration_max = 118; | |
426 process_data.tasks.back().death_data.run_duration_sample = 114; | |
427 process_data.tasks.back().death_data.queue_duration_sum = 109; | |
428 process_data.tasks.back().death_data.queue_duration_max = 106; | |
429 process_data.tasks.back().death_data.queue_duration_sample = 104; | |
430 process_data.tasks.back().death_thread_name = ""; | |
431 | |
432 log.RecordProfilerData(process_data, content::PROCESS_TYPE_RENDERER); | |
433 ASSERT_EQ(1, log.uma_proto().profiler_event_size()); | |
434 EXPECT_EQ(ProfilerEventProto::STARTUP_PROFILE, | |
435 log.uma_proto().profiler_event(0).profile_type()); | |
436 EXPECT_EQ(ProfilerEventProto::WALL_CLOCK_TIME, | |
437 log.uma_proto().profiler_event(0).time_source()); | |
438 ASSERT_EQ(4, log.uma_proto().profiler_event(0).tracked_object_size()); | |
439 | |
440 const ProfilerEventProto::TrackedObject* tracked_object = | |
441 &log.uma_proto().profiler_event(0).tracked_object(2); | |
442 EXPECT_EQ(metrics::HashMetricName("file3"), | |
443 tracked_object->source_file_name_hash()); | |
444 EXPECT_EQ(metrics::HashMetricName("function3"), | |
445 tracked_object->source_function_name_hash()); | |
446 EXPECT_EQ(7331, tracked_object->source_line_number()); | |
447 EXPECT_EQ(metrics::HashMetricName("birth_thread*"), | |
448 tracked_object->birth_thread_name_hash()); | |
449 EXPECT_EQ(137, tracked_object->exec_count()); | |
450 EXPECT_EQ(131, tracked_object->exec_time_total()); | |
451 EXPECT_EQ(113, tracked_object->exec_time_sampled()); | |
452 EXPECT_EQ(108, tracked_object->queue_time_total()); | |
453 EXPECT_EQ(103, tracked_object->queue_time_sampled()); | |
454 EXPECT_EQ(metrics::HashMetricName("death_thread*"), | |
455 tracked_object->exec_thread_name_hash()); | |
456 EXPECT_EQ(1177U, tracked_object->process_id()); | |
457 EXPECT_EQ(ProfilerEventProto::TrackedObject::RENDERER, | |
458 tracked_object->process_type()); | |
459 | |
460 tracked_object = &log.uma_proto().profiler_event(0).tracked_object(3); | |
461 EXPECT_EQ(metrics::HashMetricName(""), | |
462 tracked_object->source_file_name_hash()); | |
463 EXPECT_EQ(metrics::HashMetricName(""), | |
464 tracked_object->source_function_name_hash()); | |
465 EXPECT_EQ(7332, tracked_object->source_line_number()); | |
466 EXPECT_EQ(metrics::HashMetricName(""), | |
467 tracked_object->birth_thread_name_hash()); | |
468 EXPECT_EQ(138, tracked_object->exec_count()); | |
469 EXPECT_EQ(132, tracked_object->exec_time_total()); | |
470 EXPECT_EQ(114, tracked_object->exec_time_sampled()); | |
471 EXPECT_EQ(109, tracked_object->queue_time_total()); | |
472 EXPECT_EQ(104, tracked_object->queue_time_sampled()); | |
473 EXPECT_EQ(metrics::HashMetricName(""), | |
474 tracked_object->exec_thread_name_hash()); | |
475 EXPECT_EQ(ProfilerEventProto::TrackedObject::RENDERER, | |
476 tracked_object->process_type()); | |
477 } | |
478 } | |
479 | |
480 TEST_F(MetricsLogTest, ChromeChannelWrittenToProtobuf) { | 305 TEST_F(MetricsLogTest, ChromeChannelWrittenToProtobuf) { |
481 metrics::TestMetricsServiceClient client; | 306 metrics::TestMetricsServiceClient client; |
482 TestMetricsLog log( | 307 TestMetricsLog log( |
483 "user@test.com", kSessionId, MetricsLog::ONGOING_LOG, &client, &prefs_); | 308 "user@test.com", kSessionId, MetricsLog::ONGOING_LOG, &client, &prefs_); |
484 EXPECT_TRUE(log.uma_proto().system_profile().has_channel()); | 309 EXPECT_TRUE(log.uma_proto().system_profile().has_channel()); |
485 } | 310 } |
OLD | NEW |