| 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 "base/debug/trace_event_unittest.h" | 5 #include "base/debug/trace_event_unittest.h" |
| 6 | 6 |
| 7 #include "base/bind.h" | 7 #include "base/bind.h" |
| 8 #include "base/command_line.h" | 8 #include "base/command_line.h" |
| 9 #include "base/debug/trace_event.h" | 9 #include "base/debug/trace_event.h" |
| 10 #include "base/json/json_reader.h" | 10 #include "base/json/json_reader.h" |
| (...skipping 28 matching lines...) Expand all Loading... |
| 39 CompareOp op; | 39 CompareOp op; |
| 40 }; | 40 }; |
| 41 | 41 |
| 42 class TraceEventTestFixture : public testing::Test { | 42 class TraceEventTestFixture : public testing::Test { |
| 43 public: | 43 public: |
| 44 // This fixture does not use SetUp() because the fixture must be manually set | 44 // This fixture does not use SetUp() because the fixture must be manually set |
| 45 // up multiple times when testing AtExit. Use ManualTestSetUp for this. | 45 // up multiple times when testing AtExit. Use ManualTestSetUp for this. |
| 46 void ManualTestSetUp(); | 46 void ManualTestSetUp(); |
| 47 void OnTraceDataCollected( | 47 void OnTraceDataCollected( |
| 48 const scoped_refptr<base::RefCountedString>& events_str); | 48 const scoped_refptr<base::RefCountedString>& events_str); |
| 49 void OnTraceNotification(int notification) { |
| 50 if (notification & TraceLog::EVENT_WATCH_NOTIFICATION) |
| 51 ++event_watch_notification_; |
| 52 } |
| 49 DictionaryValue* FindMatchingTraceEntry(const JsonKeyValue* key_values); | 53 DictionaryValue* FindMatchingTraceEntry(const JsonKeyValue* key_values); |
| 50 DictionaryValue* FindNamePhase(const char* name, const char* phase); | 54 DictionaryValue* FindNamePhase(const char* name, const char* phase); |
| 51 DictionaryValue* FindNamePhaseKeyValue(const char* name, | 55 DictionaryValue* FindNamePhaseKeyValue(const char* name, |
| 52 const char* phase, | 56 const char* phase, |
| 53 const char* key, | 57 const char* key, |
| 54 const char* value); | 58 const char* value); |
| 55 bool FindMatchingValue(const char* key, | 59 bool FindMatchingValue(const char* key, |
| 56 const char* value); | 60 const char* value); |
| 57 bool FindNonMatchingValue(const char* key, | 61 bool FindNonMatchingValue(const char* key, |
| 58 const char* value); | 62 const char* value); |
| 59 void Clear() { | 63 void Clear() { |
| 60 trace_parsed_.Clear(); | 64 trace_parsed_.Clear(); |
| 61 json_output_.json_output.clear(); | 65 json_output_.json_output.clear(); |
| 62 } | 66 } |
| 63 | 67 |
| 68 void BeginTrace() { |
| 69 event_watch_notification_ = 0; |
| 70 TraceLog::GetInstance()->SetEnabled("*"); |
| 71 } |
| 72 |
| 73 void EndTraceAndFlush() { |
| 74 TraceLog::GetInstance()->SetDisabled(); |
| 75 TraceLog::GetInstance()->Flush( |
| 76 base::Bind(&TraceEventTestFixture::OnTraceDataCollected, |
| 77 base::Unretained(this))); |
| 78 } |
| 79 |
| 64 virtual void SetUp() OVERRIDE { | 80 virtual void SetUp() OVERRIDE { |
| 65 old_thread_name_ = PlatformThread::GetName(); | 81 old_thread_name_ = PlatformThread::GetName(); |
| 66 } | 82 } |
| 67 virtual void TearDown() OVERRIDE { | 83 virtual void TearDown() OVERRIDE { |
| 68 if (TraceLog::GetInstance()) | 84 if (TraceLog::GetInstance()) |
| 69 EXPECT_FALSE(TraceLog::GetInstance()->IsEnabled()); | 85 EXPECT_FALSE(TraceLog::GetInstance()->IsEnabled()); |
| 70 PlatformThread::SetName(old_thread_name_ ? old_thread_name_ : ""); | 86 PlatformThread::SetName(old_thread_name_ ? old_thread_name_ : ""); |
| 71 } | 87 } |
| 72 | 88 |
| 73 const char* old_thread_name_; | 89 const char* old_thread_name_; |
| 74 ListValue trace_parsed_; | 90 ListValue trace_parsed_; |
| 75 base::debug::TraceResultBuffer trace_buffer_; | 91 base::debug::TraceResultBuffer trace_buffer_; |
| 76 base::debug::TraceResultBuffer::SimpleOutput json_output_; | 92 base::debug::TraceResultBuffer::SimpleOutput json_output_; |
| 93 int event_watch_notification_; |
| 77 | 94 |
| 78 private: | 95 private: |
| 79 // We want our singleton torn down after each test. | 96 // We want our singleton torn down after each test. |
| 80 ShadowingAtExitManager at_exit_manager_; | 97 ShadowingAtExitManager at_exit_manager_; |
| 81 Lock lock_; | 98 Lock lock_; |
| 82 }; | 99 }; |
| 83 | 100 |
| 84 void TraceEventTestFixture::ManualTestSetUp() { | 101 void TraceEventTestFixture::ManualTestSetUp() { |
| 85 TraceLog::DeleteForTesting(); | 102 TraceLog::DeleteForTesting(); |
| 86 TraceLog::Resurrect(); | 103 TraceLog::Resurrect(); |
| 87 TraceLog* tracelog = TraceLog::GetInstance(); | 104 TraceLog* tracelog = TraceLog::GetInstance(); |
| 88 ASSERT_TRUE(tracelog); | 105 ASSERT_TRUE(tracelog); |
| 89 ASSERT_FALSE(tracelog->IsEnabled()); | 106 ASSERT_FALSE(tracelog->IsEnabled()); |
| 90 tracelog->SetOutputCallback( | 107 tracelog->SetNotificationCallback( |
| 91 base::Bind(&TraceEventTestFixture::OnTraceDataCollected, | 108 base::Bind(&TraceEventTestFixture::OnTraceNotification, |
| 92 base::Unretained(this))); | 109 base::Unretained(this))); |
| 93 trace_buffer_.SetOutputCallback(json_output_.GetCallback()); | 110 trace_buffer_.SetOutputCallback(json_output_.GetCallback()); |
| 94 } | 111 } |
| 95 | 112 |
| 96 void TraceEventTestFixture::OnTraceDataCollected( | 113 void TraceEventTestFixture::OnTraceDataCollected( |
| 97 const scoped_refptr<base::RefCountedString>& events_str) { | 114 const scoped_refptr<base::RefCountedString>& events_str) { |
| 98 AutoLock lock(lock_); | 115 AutoLock lock(lock_); |
| 99 json_output_.json_output.clear(); | 116 json_output_.json_output.clear(); |
| 100 trace_buffer_.Start(); | 117 trace_buffer_.Start(); |
| 101 trace_buffer_.AddFragment(events_str->data()); | 118 trace_buffer_.AddFragment(events_str->data()); |
| (...skipping 541 matching lines...) Expand 10 before | Expand all | Expand 10 after Loading... |
| 643 } while (base::TimeTicks::HighResNow() < end_time); | 660 } while (base::TimeTicks::HighResNow() < end_time); |
| 644 } | 661 } |
| 645 | 662 |
| 646 // Simple Test for emitting data and validating it was received. | 663 // Simple Test for emitting data and validating it was received. |
| 647 TEST_F(TraceEventTestFixture, DataCaptured) { | 664 TEST_F(TraceEventTestFixture, DataCaptured) { |
| 648 ManualTestSetUp(); | 665 ManualTestSetUp(); |
| 649 TraceLog::GetInstance()->SetEnabled(true); | 666 TraceLog::GetInstance()->SetEnabled(true); |
| 650 | 667 |
| 651 TraceWithAllMacroVariants(NULL); | 668 TraceWithAllMacroVariants(NULL); |
| 652 | 669 |
| 653 TraceLog::GetInstance()->SetEnabled(false); | 670 EndTraceAndFlush(); |
| 654 | 671 |
| 655 ValidateAllTraceMacrosCreatedData(trace_parsed_); | 672 ValidateAllTraceMacrosCreatedData(trace_parsed_); |
| 656 } | 673 } |
| 657 | 674 |
| 658 class MockEnabledStateChangedObserver : | 675 class MockEnabledStateChangedObserver : |
| 659 public base::debug::TraceLog::EnabledStateChangedObserver { | 676 public base::debug::TraceLog::EnabledStateChangedObserver { |
| 660 public: | 677 public: |
| 661 MOCK_METHOD0(OnTraceLogWillEnable, void()); | 678 MOCK_METHOD0(OnTraceLogWillEnable, void()); |
| 662 MOCK_METHOD0(OnTraceLogWillDisable, void()); | 679 MOCK_METHOD0(OnTraceLogWillDisable, void()); |
| 663 }; | 680 }; |
| (...skipping 70 matching lines...) Expand 10 before | Expand all | Expand 10 after Loading... |
| 734 } | 751 } |
| 735 | 752 |
| 736 // Test that categories work. | 753 // Test that categories work. |
| 737 TEST_F(TraceEventTestFixture, Categories) { | 754 TEST_F(TraceEventTestFixture, Categories) { |
| 738 ManualTestSetUp(); | 755 ManualTestSetUp(); |
| 739 | 756 |
| 740 // Test that categories that are used can be retrieved whether trace was | 757 // Test that categories that are used can be retrieved whether trace was |
| 741 // enabled or disabled when the trace event was encountered. | 758 // enabled or disabled when the trace event was encountered. |
| 742 TRACE_EVENT_INSTANT0("c1", "name"); | 759 TRACE_EVENT_INSTANT0("c1", "name"); |
| 743 TRACE_EVENT_INSTANT0("c2", "name"); | 760 TRACE_EVENT_INSTANT0("c2", "name"); |
| 744 TraceLog::GetInstance()->SetEnabled(true); | 761 BeginTrace(); |
| 745 TRACE_EVENT_INSTANT0("c3", "name"); | 762 TRACE_EVENT_INSTANT0("c3", "name"); |
| 746 TRACE_EVENT_INSTANT0("c4", "name"); | 763 TRACE_EVENT_INSTANT0("c4", "name"); |
| 747 TraceLog::GetInstance()->SetEnabled(false); | 764 EndTraceAndFlush(); |
| 748 std::vector<std::string> cats; | 765 std::vector<std::string> cats; |
| 749 TraceLog::GetInstance()->GetKnownCategories(&cats); | 766 TraceLog::GetInstance()->GetKnownCategories(&cats); |
| 750 EXPECT_TRUE(std::find(cats.begin(), cats.end(), "c1") != cats.end()); | 767 EXPECT_TRUE(std::find(cats.begin(), cats.end(), "c1") != cats.end()); |
| 751 EXPECT_TRUE(std::find(cats.begin(), cats.end(), "c2") != cats.end()); | 768 EXPECT_TRUE(std::find(cats.begin(), cats.end(), "c2") != cats.end()); |
| 752 EXPECT_TRUE(std::find(cats.begin(), cats.end(), "c3") != cats.end()); | 769 EXPECT_TRUE(std::find(cats.begin(), cats.end(), "c3") != cats.end()); |
| 753 EXPECT_TRUE(std::find(cats.begin(), cats.end(), "c4") != cats.end()); | 770 EXPECT_TRUE(std::find(cats.begin(), cats.end(), "c4") != cats.end()); |
| 754 | 771 |
| 755 const std::vector<std::string> empty_categories; | 772 const std::vector<std::string> empty_categories; |
| 756 std::vector<std::string> included_categories; | 773 std::vector<std::string> included_categories; |
| 757 std::vector<std::string> excluded_categories; | 774 std::vector<std::string> excluded_categories; |
| 758 | 775 |
| 759 // Test that category filtering works. | 776 // Test that category filtering works. |
| 760 | 777 |
| 761 // Include nonexistent category -> no events | 778 // Include nonexistent category -> no events |
| 762 Clear(); | 779 Clear(); |
| 763 included_categories.clear(); | 780 included_categories.clear(); |
| 764 included_categories.push_back("not_found823564786"); | 781 included_categories.push_back("not_found823564786"); |
| 765 TraceLog::GetInstance()->SetEnabled(included_categories, empty_categories); | 782 TraceLog::GetInstance()->SetEnabled(included_categories, empty_categories); |
| 766 TRACE_EVENT_INSTANT0("cat1", "name"); | 783 TRACE_EVENT_INSTANT0("cat1", "name"); |
| 767 TRACE_EVENT_INSTANT0("cat2", "name"); | 784 TRACE_EVENT_INSTANT0("cat2", "name"); |
| 768 TraceLog::GetInstance()->SetDisabled(); | 785 EndTraceAndFlush(); |
| 769 EXPECT_TRUE(trace_parsed_.empty()); | 786 EXPECT_TRUE(trace_parsed_.empty()); |
| 770 | 787 |
| 771 // Include existent category -> only events of that category | 788 // Include existent category -> only events of that category |
| 772 Clear(); | 789 Clear(); |
| 773 included_categories.clear(); | 790 included_categories.clear(); |
| 774 included_categories.push_back("inc"); | 791 included_categories.push_back("inc"); |
| 775 TraceLog::GetInstance()->SetEnabled(included_categories, empty_categories); | 792 TraceLog::GetInstance()->SetEnabled(included_categories, empty_categories); |
| 776 TRACE_EVENT_INSTANT0("inc", "name"); | 793 TRACE_EVENT_INSTANT0("inc", "name"); |
| 777 TRACE_EVENT_INSTANT0("inc2", "name"); | 794 TRACE_EVENT_INSTANT0("inc2", "name"); |
| 778 TraceLog::GetInstance()->SetDisabled(); | 795 EndTraceAndFlush(); |
| 779 EXPECT_TRUE(FindMatchingValue("cat", "inc")); | 796 EXPECT_TRUE(FindMatchingValue("cat", "inc")); |
| 780 EXPECT_FALSE(FindNonMatchingValue("cat", "inc")); | 797 EXPECT_FALSE(FindNonMatchingValue("cat", "inc")); |
| 781 | 798 |
| 782 // Include existent wildcard -> all categories matching wildcard | 799 // Include existent wildcard -> all categories matching wildcard |
| 783 Clear(); | 800 Clear(); |
| 784 included_categories.clear(); | 801 included_categories.clear(); |
| 785 included_categories.push_back("inc_wildcard_*"); | 802 included_categories.push_back("inc_wildcard_*"); |
| 786 included_categories.push_back("inc_wildchar_?_end"); | 803 included_categories.push_back("inc_wildchar_?_end"); |
| 787 TraceLog::GetInstance()->SetEnabled(included_categories, empty_categories); | 804 TraceLog::GetInstance()->SetEnabled(included_categories, empty_categories); |
| 788 TRACE_EVENT_INSTANT0("inc_wildcard_abc", "included"); | 805 TRACE_EVENT_INSTANT0("inc_wildcard_abc", "included"); |
| 789 TRACE_EVENT_INSTANT0("inc_wildcard_", "included"); | 806 TRACE_EVENT_INSTANT0("inc_wildcard_", "included"); |
| 790 TRACE_EVENT_INSTANT0("inc_wildchar_x_end", "included"); | 807 TRACE_EVENT_INSTANT0("inc_wildchar_x_end", "included"); |
| 791 TRACE_EVENT_INSTANT0("inc_wildchar_bla_end", "not_inc"); | 808 TRACE_EVENT_INSTANT0("inc_wildchar_bla_end", "not_inc"); |
| 792 TRACE_EVENT_INSTANT0("cat1", "not_inc"); | 809 TRACE_EVENT_INSTANT0("cat1", "not_inc"); |
| 793 TRACE_EVENT_INSTANT0("cat2", "not_inc"); | 810 TRACE_EVENT_INSTANT0("cat2", "not_inc"); |
| 794 TraceLog::GetInstance()->SetDisabled(); | 811 EndTraceAndFlush(); |
| 795 EXPECT_TRUE(FindMatchingValue("cat", "inc_wildcard_abc")); | 812 EXPECT_TRUE(FindMatchingValue("cat", "inc_wildcard_abc")); |
| 796 EXPECT_TRUE(FindMatchingValue("cat", "inc_wildcard_")); | 813 EXPECT_TRUE(FindMatchingValue("cat", "inc_wildcard_")); |
| 797 EXPECT_TRUE(FindMatchingValue("cat", "inc_wildchar_x_end")); | 814 EXPECT_TRUE(FindMatchingValue("cat", "inc_wildchar_x_end")); |
| 798 EXPECT_FALSE(FindMatchingValue("name", "not_inc")); | 815 EXPECT_FALSE(FindMatchingValue("name", "not_inc")); |
| 799 | 816 |
| 800 included_categories.clear(); | 817 included_categories.clear(); |
| 801 | 818 |
| 802 // Exclude nonexistent category -> all events | 819 // Exclude nonexistent category -> all events |
| 803 Clear(); | 820 Clear(); |
| 804 excluded_categories.clear(); | 821 excluded_categories.clear(); |
| 805 excluded_categories.push_back("not_found823564786"); | 822 excluded_categories.push_back("not_found823564786"); |
| 806 TraceLog::GetInstance()->SetEnabled(empty_categories, excluded_categories); | 823 TraceLog::GetInstance()->SetEnabled(empty_categories, excluded_categories); |
| 807 TRACE_EVENT_INSTANT0("cat1", "name"); | 824 TRACE_EVENT_INSTANT0("cat1", "name"); |
| 808 TRACE_EVENT_INSTANT0("cat2", "name"); | 825 TRACE_EVENT_INSTANT0("cat2", "name"); |
| 809 TraceLog::GetInstance()->SetDisabled(); | 826 EndTraceAndFlush(); |
| 810 EXPECT_TRUE(FindMatchingValue("cat", "cat1")); | 827 EXPECT_TRUE(FindMatchingValue("cat", "cat1")); |
| 811 EXPECT_TRUE(FindMatchingValue("cat", "cat2")); | 828 EXPECT_TRUE(FindMatchingValue("cat", "cat2")); |
| 812 | 829 |
| 813 // Exclude existent category -> only events of other categories | 830 // Exclude existent category -> only events of other categories |
| 814 Clear(); | 831 Clear(); |
| 815 excluded_categories.clear(); | 832 excluded_categories.clear(); |
| 816 excluded_categories.push_back("inc"); | 833 excluded_categories.push_back("inc"); |
| 817 TraceLog::GetInstance()->SetEnabled(empty_categories, excluded_categories); | 834 TraceLog::GetInstance()->SetEnabled(empty_categories, excluded_categories); |
| 818 TRACE_EVENT_INSTANT0("inc", "name"); | 835 TRACE_EVENT_INSTANT0("inc", "name"); |
| 819 TRACE_EVENT_INSTANT0("inc2", "name"); | 836 TRACE_EVENT_INSTANT0("inc2", "name"); |
| 820 TraceLog::GetInstance()->SetDisabled(); | 837 EndTraceAndFlush(); |
| 821 EXPECT_TRUE(FindMatchingValue("cat", "inc2")); | 838 EXPECT_TRUE(FindMatchingValue("cat", "inc2")); |
| 822 EXPECT_FALSE(FindMatchingValue("cat", "inc")); | 839 EXPECT_FALSE(FindMatchingValue("cat", "inc")); |
| 823 | 840 |
| 824 // Exclude existent wildcard -> all categories not matching wildcard | 841 // Exclude existent wildcard -> all categories not matching wildcard |
| 825 Clear(); | 842 Clear(); |
| 826 excluded_categories.clear(); | 843 excluded_categories.clear(); |
| 827 excluded_categories.push_back("inc_wildcard_*"); | 844 excluded_categories.push_back("inc_wildcard_*"); |
| 828 excluded_categories.push_back("inc_wildchar_?_end"); | 845 excluded_categories.push_back("inc_wildchar_?_end"); |
| 829 TraceLog::GetInstance()->SetEnabled(empty_categories, excluded_categories); | 846 TraceLog::GetInstance()->SetEnabled(empty_categories, excluded_categories); |
| 830 TRACE_EVENT_INSTANT0("inc_wildcard_abc", "not_inc"); | 847 TRACE_EVENT_INSTANT0("inc_wildcard_abc", "not_inc"); |
| 831 TRACE_EVENT_INSTANT0("inc_wildcard_", "not_inc"); | 848 TRACE_EVENT_INSTANT0("inc_wildcard_", "not_inc"); |
| 832 TRACE_EVENT_INSTANT0("inc_wildchar_x_end", "not_inc"); | 849 TRACE_EVENT_INSTANT0("inc_wildchar_x_end", "not_inc"); |
| 833 TRACE_EVENT_INSTANT0("inc_wildchar_bla_end", "included"); | 850 TRACE_EVENT_INSTANT0("inc_wildchar_bla_end", "included"); |
| 834 TRACE_EVENT_INSTANT0("cat1", "included"); | 851 TRACE_EVENT_INSTANT0("cat1", "included"); |
| 835 TRACE_EVENT_INSTANT0("cat2", "included"); | 852 TRACE_EVENT_INSTANT0("cat2", "included"); |
| 836 TraceLog::GetInstance()->SetDisabled(); | 853 EndTraceAndFlush(); |
| 837 EXPECT_TRUE(FindMatchingValue("cat", "inc_wildchar_bla_end")); | 854 EXPECT_TRUE(FindMatchingValue("cat", "inc_wildchar_bla_end")); |
| 838 EXPECT_TRUE(FindMatchingValue("cat", "cat1")); | 855 EXPECT_TRUE(FindMatchingValue("cat", "cat1")); |
| 839 EXPECT_TRUE(FindMatchingValue("cat", "cat2")); | 856 EXPECT_TRUE(FindMatchingValue("cat", "cat2")); |
| 840 EXPECT_FALSE(FindMatchingValue("name", "not_inc")); | 857 EXPECT_FALSE(FindMatchingValue("name", "not_inc")); |
| 841 } | 858 } |
| 842 | 859 |
| 843 // Simple Test for time threshold events. | 860 // Simple Test for time threshold events. |
| 844 TEST_F(TraceEventTestFixture, DataCapturedThreshold) { | 861 TEST_F(TraceEventTestFixture, DataCapturedThreshold) { |
| 845 ManualTestSetUp(); | 862 ManualTestSetUp(); |
| 846 TraceLog::GetInstance()->SetEnabled(true); | 863 BeginTrace(); |
| 847 | 864 |
| 848 // Test that events at the same level are properly filtered by threshold. | 865 // Test that events at the same level are properly filtered by threshold. |
| 849 { | 866 { |
| 850 TRACE_EVENT_IF_LONGER_THAN0(100, "time", "threshold 100"); | 867 TRACE_EVENT_IF_LONGER_THAN0(100, "time", "threshold 100"); |
| 851 TRACE_EVENT_IF_LONGER_THAN0(1000, "time", "threshold 1000"); | 868 TRACE_EVENT_IF_LONGER_THAN0(1000, "time", "threshold 1000"); |
| 852 TRACE_EVENT_IF_LONGER_THAN0(10000, "time", "threshold 10000"); | 869 TRACE_EVENT_IF_LONGER_THAN0(10000, "time", "threshold 10000"); |
| 853 // 100+ seconds to avoid flakiness. | 870 // 100+ seconds to avoid flakiness. |
| 854 TRACE_EVENT_IF_LONGER_THAN0(100000000, "time", "threshold long1"); | 871 TRACE_EVENT_IF_LONGER_THAN0(100000000, "time", "threshold long1"); |
| 855 TRACE_EVENT_IF_LONGER_THAN0(200000000, "time", "threshold long2"); | 872 TRACE_EVENT_IF_LONGER_THAN0(200000000, "time", "threshold long2"); |
| 856 HighResSleepForTraceTest(base::TimeDelta::FromMilliseconds(20)); | 873 HighResSleepForTraceTest(base::TimeDelta::FromMilliseconds(20)); |
| (...skipping 46 matching lines...) Expand 10 before | Expand all | Expand 10 after Loading... |
| 903 TRACE_EVENT_IF_LONGER_THAN0(200000000, "time", | 920 TRACE_EVENT_IF_LONGER_THAN0(200000000, "time", |
| 904 "4thresholdlong2"); | 921 "4thresholdlong2"); |
| 905 HighResSleepForTraceTest(base::TimeDelta::FromMilliseconds(20)); | 922 HighResSleepForTraceTest(base::TimeDelta::FromMilliseconds(20)); |
| 906 } | 923 } |
| 907 } | 924 } |
| 908 } | 925 } |
| 909 } | 926 } |
| 910 } | 927 } |
| 911 } | 928 } |
| 912 | 929 |
| 913 TraceLog::GetInstance()->SetEnabled(false); | 930 EndTraceAndFlush(); |
| 914 | 931 |
| 915 #define EXPECT_FIND_BE_(str) \ | 932 #define EXPECT_FIND_BE_(str) \ |
| 916 EXPECT_TRUE(FindNamePhase(str, "B")); \ | 933 EXPECT_TRUE(FindNamePhase(str, "B")); \ |
| 917 EXPECT_TRUE(FindNamePhase(str, "E")) | 934 EXPECT_TRUE(FindNamePhase(str, "E")) |
| 918 #define EXPECT_NOT_FIND_BE_(str) \ | 935 #define EXPECT_NOT_FIND_BE_(str) \ |
| 919 EXPECT_FALSE(FindNamePhase(str, "B")); \ | 936 EXPECT_FALSE(FindNamePhase(str, "B")); \ |
| 920 EXPECT_FALSE(FindNamePhase(str, "E")) | 937 EXPECT_FALSE(FindNamePhase(str, "E")) |
| 921 | 938 |
| 922 EXPECT_FIND_BE_("threshold 100"); | 939 EXPECT_FIND_BE_("threshold 100"); |
| 923 EXPECT_FIND_BE_("threshold 1000"); | 940 EXPECT_FIND_BE_("threshold 1000"); |
| (...skipping 12 matching lines...) Expand all Loading... |
| 936 EXPECT_NOT_FIND_BE_("3thresholdlong2"); | 953 EXPECT_NOT_FIND_BE_("3thresholdlong2"); |
| 937 | 954 |
| 938 EXPECT_FIND_BE_("nonthreshold4"); | 955 EXPECT_FIND_BE_("nonthreshold4"); |
| 939 EXPECT_FIND_BE_("4threshold100"); | 956 EXPECT_FIND_BE_("4threshold100"); |
| 940 EXPECT_FIND_BE_("4threshold1000"); | 957 EXPECT_FIND_BE_("4threshold1000"); |
| 941 EXPECT_FIND_BE_("4threshold10000"); | 958 EXPECT_FIND_BE_("4threshold10000"); |
| 942 EXPECT_NOT_FIND_BE_("4thresholdlong1"); | 959 EXPECT_NOT_FIND_BE_("4thresholdlong1"); |
| 943 EXPECT_NOT_FIND_BE_("4thresholdlong2"); | 960 EXPECT_NOT_FIND_BE_("4thresholdlong2"); |
| 944 } | 961 } |
| 945 | 962 |
| 963 // Test EVENT_WATCH_NOTIFICATION |
| 964 TEST_F(TraceEventTestFixture, EventWatchNotification) { |
| 965 ManualTestSetUp(); |
| 966 |
| 967 // Basic one occurrence. |
| 968 BeginTrace(); |
| 969 TraceLog::GetInstance()->SetWatchEvent("cat", "event"); |
| 970 TRACE_EVENT_INSTANT0("cat", "event"); |
| 971 EndTraceAndFlush(); |
| 972 EXPECT_EQ(event_watch_notification_, 1); |
| 973 |
| 974 // Basic one occurrence before Set. |
| 975 BeginTrace(); |
| 976 TRACE_EVENT_INSTANT0("cat", "event"); |
| 977 TraceLog::GetInstance()->SetWatchEvent("cat", "event"); |
| 978 EndTraceAndFlush(); |
| 979 EXPECT_EQ(event_watch_notification_, 1); |
| 980 |
| 981 // Auto-reset after end trace. |
| 982 BeginTrace(); |
| 983 TraceLog::GetInstance()->SetWatchEvent("cat", "event"); |
| 984 EndTraceAndFlush(); |
| 985 BeginTrace(); |
| 986 TRACE_EVENT_INSTANT0("cat", "event"); |
| 987 EndTraceAndFlush(); |
| 988 EXPECT_EQ(event_watch_notification_, 0); |
| 989 |
| 990 // Multiple occurrence. |
| 991 BeginTrace(); |
| 992 int num_occurrences = 5; |
| 993 TraceLog::GetInstance()->SetWatchEvent("cat", "event"); |
| 994 for (int i = 0; i < num_occurrences; ++i) |
| 995 TRACE_EVENT_INSTANT0("cat", "event"); |
| 996 EndTraceAndFlush(); |
| 997 EXPECT_EQ(event_watch_notification_, num_occurrences); |
| 998 |
| 999 // Wrong category. |
| 1000 BeginTrace(); |
| 1001 TraceLog::GetInstance()->SetWatchEvent("cat", "event"); |
| 1002 TRACE_EVENT_INSTANT0("wrong_cat", "event"); |
| 1003 EndTraceAndFlush(); |
| 1004 EXPECT_EQ(event_watch_notification_, 0); |
| 1005 |
| 1006 // Wrong name. |
| 1007 BeginTrace(); |
| 1008 TraceLog::GetInstance()->SetWatchEvent("cat", "event"); |
| 1009 TRACE_EVENT_INSTANT0("cat", "wrong_event"); |
| 1010 EndTraceAndFlush(); |
| 1011 EXPECT_EQ(event_watch_notification_, 0); |
| 1012 |
| 1013 // Canceled. |
| 1014 BeginTrace(); |
| 1015 TraceLog::GetInstance()->SetWatchEvent("cat", "event"); |
| 1016 TraceLog::GetInstance()->CancelWatchEvent(); |
| 1017 TRACE_EVENT_INSTANT0("cat", "event"); |
| 1018 EndTraceAndFlush(); |
| 1019 EXPECT_EQ(event_watch_notification_, 0); |
| 1020 } |
| 1021 |
| 946 // Test ASYNC_BEGIN/END events | 1022 // Test ASYNC_BEGIN/END events |
| 947 TEST_F(TraceEventTestFixture, AsyncBeginEndEvents) { | 1023 TEST_F(TraceEventTestFixture, AsyncBeginEndEvents) { |
| 948 ManualTestSetUp(); | 1024 ManualTestSetUp(); |
| 949 TraceLog::GetInstance()->SetEnabled(true); | 1025 BeginTrace(); |
| 950 | 1026 |
| 951 unsigned long long id = 0xfeedbeeffeedbeefull; | 1027 unsigned long long id = 0xfeedbeeffeedbeefull; |
| 952 TRACE_EVENT_ASYNC_BEGIN0( "cat", "name1", id); | 1028 TRACE_EVENT_ASYNC_BEGIN0( "cat", "name1", id); |
| 953 TRACE_EVENT_ASYNC_BEGIN_STEP0( "cat", "name1", id, "step1"); | 1029 TRACE_EVENT_ASYNC_BEGIN_STEP0( "cat", "name1", id, "step1"); |
| 954 TRACE_EVENT_ASYNC_END0("cat", "name1", id); | 1030 TRACE_EVENT_ASYNC_END0("cat", "name1", id); |
| 955 TRACE_EVENT_BEGIN0( "cat", "name2"); | 1031 TRACE_EVENT_BEGIN0( "cat", "name2"); |
| 956 TRACE_EVENT_ASYNC_BEGIN0( "cat", "name3", 0); | 1032 TRACE_EVENT_ASYNC_BEGIN0( "cat", "name3", 0); |
| 957 | 1033 |
| 958 TraceLog::GetInstance()->SetEnabled(false); | 1034 EndTraceAndFlush(); |
| 959 | 1035 |
| 960 EXPECT_TRUE(FindNamePhase("name1", "S")); | 1036 EXPECT_TRUE(FindNamePhase("name1", "S")); |
| 961 EXPECT_TRUE(FindNamePhase("name1", "T")); | 1037 EXPECT_TRUE(FindNamePhase("name1", "T")); |
| 962 EXPECT_TRUE(FindNamePhase("name1", "F")); | 1038 EXPECT_TRUE(FindNamePhase("name1", "F")); |
| 963 | 1039 |
| 964 std::string id_str; | 1040 std::string id_str; |
| 965 StringAppendF(&id_str, "%llx", id); | 1041 StringAppendF(&id_str, "%llx", id); |
| 966 | 1042 |
| 967 EXPECT_TRUE(FindNamePhaseKeyValue("name1", "S", "id", id_str.c_str())); | 1043 EXPECT_TRUE(FindNamePhaseKeyValue("name1", "S", "id", id_str.c_str())); |
| 968 EXPECT_TRUE(FindNamePhaseKeyValue("name1", "T", "id", id_str.c_str())); | 1044 EXPECT_TRUE(FindNamePhaseKeyValue("name1", "T", "id", id_str.c_str())); |
| 969 EXPECT_TRUE(FindNamePhaseKeyValue("name1", "F", "id", id_str.c_str())); | 1045 EXPECT_TRUE(FindNamePhaseKeyValue("name1", "F", "id", id_str.c_str())); |
| 970 EXPECT_TRUE(FindNamePhaseKeyValue("name3", "S", "id", "0")); | 1046 EXPECT_TRUE(FindNamePhaseKeyValue("name3", "S", "id", "0")); |
| 971 | 1047 |
| 972 // BEGIN events should not have id | 1048 // BEGIN events should not have id |
| 973 EXPECT_FALSE(FindNamePhaseKeyValue("name2", "B", "id", "0")); | 1049 EXPECT_FALSE(FindNamePhaseKeyValue("name2", "B", "id", "0")); |
| 974 } | 1050 } |
| 975 | 1051 |
| 976 // Test ASYNC_BEGIN/END events | 1052 // Test ASYNC_BEGIN/END events |
| 977 TEST_F(TraceEventTestFixture, AsyncBeginEndPointerMangling) { | 1053 TEST_F(TraceEventTestFixture, AsyncBeginEndPointerMangling) { |
| 978 ManualTestSetUp(); | 1054 ManualTestSetUp(); |
| 979 | 1055 |
| 980 void* ptr = this; | 1056 void* ptr = this; |
| 981 | 1057 |
| 982 TraceLog::GetInstance()->SetProcessID(100); | 1058 TraceLog::GetInstance()->SetProcessID(100); |
| 983 TraceLog::GetInstance()->SetEnabled(true); | 1059 BeginTrace(); |
| 984 TRACE_EVENT_ASYNC_BEGIN0( "cat", "name1", ptr); | 1060 TRACE_EVENT_ASYNC_BEGIN0( "cat", "name1", ptr); |
| 985 TRACE_EVENT_ASYNC_BEGIN0( "cat", "name2", ptr); | 1061 TRACE_EVENT_ASYNC_BEGIN0( "cat", "name2", ptr); |
| 986 TraceLog::GetInstance()->SetEnabled(false); | 1062 EndTraceAndFlush(); |
| 987 | 1063 |
| 988 TraceLog::GetInstance()->SetProcessID(200); | 1064 TraceLog::GetInstance()->SetProcessID(200); |
| 989 TraceLog::GetInstance()->SetEnabled(true); | 1065 BeginTrace(); |
| 990 TRACE_EVENT_ASYNC_END0( "cat", "name1", ptr); | 1066 TRACE_EVENT_ASYNC_END0( "cat", "name1", ptr); |
| 991 TraceLog::GetInstance()->SetEnabled(false); | 1067 EndTraceAndFlush(); |
| 992 | 1068 |
| 993 DictionaryValue* async_begin = FindNamePhase("name1", "S"); | 1069 DictionaryValue* async_begin = FindNamePhase("name1", "S"); |
| 994 DictionaryValue* async_begin2 = FindNamePhase("name2", "S"); | 1070 DictionaryValue* async_begin2 = FindNamePhase("name2", "S"); |
| 995 DictionaryValue* async_end = FindNamePhase("name1", "F"); | 1071 DictionaryValue* async_end = FindNamePhase("name1", "F"); |
| 996 EXPECT_TRUE(async_begin); | 1072 EXPECT_TRUE(async_begin); |
| 997 EXPECT_TRUE(async_begin2); | 1073 EXPECT_TRUE(async_begin2); |
| 998 EXPECT_TRUE(async_end); | 1074 EXPECT_TRUE(async_end); |
| 999 | 1075 |
| 1000 Value* value = NULL; | 1076 Value* value = NULL; |
| 1001 std::string async_begin_id_str; | 1077 std::string async_begin_id_str; |
| 1002 std::string async_begin2_id_str; | 1078 std::string async_begin2_id_str; |
| 1003 std::string async_end_id_str; | 1079 std::string async_end_id_str; |
| 1004 ASSERT_TRUE(async_begin->Get("id", &value)); | 1080 ASSERT_TRUE(async_begin->Get("id", &value)); |
| 1005 ASSERT_TRUE(value->GetAsString(&async_begin_id_str)); | 1081 ASSERT_TRUE(value->GetAsString(&async_begin_id_str)); |
| 1006 ASSERT_TRUE(async_begin2->Get("id", &value)); | 1082 ASSERT_TRUE(async_begin2->Get("id", &value)); |
| 1007 ASSERT_TRUE(value->GetAsString(&async_begin2_id_str)); | 1083 ASSERT_TRUE(value->GetAsString(&async_begin2_id_str)); |
| 1008 ASSERT_TRUE(async_end->Get("id", &value)); | 1084 ASSERT_TRUE(async_end->Get("id", &value)); |
| 1009 ASSERT_TRUE(value->GetAsString(&async_end_id_str)); | 1085 ASSERT_TRUE(value->GetAsString(&async_end_id_str)); |
| 1010 | 1086 |
| 1011 EXPECT_STREQ(async_begin_id_str.c_str(), async_begin2_id_str.c_str()); | 1087 EXPECT_STREQ(async_begin_id_str.c_str(), async_begin2_id_str.c_str()); |
| 1012 EXPECT_STRNE(async_begin_id_str.c_str(), async_end_id_str.c_str()); | 1088 EXPECT_STRNE(async_begin_id_str.c_str(), async_end_id_str.c_str()); |
| 1013 } | 1089 } |
| 1014 | 1090 |
| 1015 // Test that static strings are not copied. | 1091 // Test that static strings are not copied. |
| 1016 TEST_F(TraceEventTestFixture, StaticStringVsString) { | 1092 TEST_F(TraceEventTestFixture, StaticStringVsString) { |
| 1017 ManualTestSetUp(); | 1093 ManualTestSetUp(); |
| 1018 TraceLog* tracer = TraceLog::GetInstance(); | 1094 TraceLog* tracer = TraceLog::GetInstance(); |
| 1019 // Make sure old events are flushed: | 1095 // Make sure old events are flushed: |
| 1020 tracer->SetEnabled(false); | 1096 EndTraceAndFlush(); |
| 1021 EXPECT_EQ(0u, tracer->GetEventsSize()); | 1097 EXPECT_EQ(0u, tracer->GetEventsSize()); |
| 1022 | 1098 |
| 1023 { | 1099 { |
| 1024 tracer->SetEnabled(true); | 1100 BeginTrace(); |
| 1025 // Test that string arguments are copied. | 1101 // Test that string arguments are copied. |
| 1026 TRACE_EVENT2("cat", "name1", | 1102 TRACE_EVENT2("cat", "name1", |
| 1027 "arg1", std::string("argval"), "arg2", std::string("argval")); | 1103 "arg1", std::string("argval"), "arg2", std::string("argval")); |
| 1028 // Test that static TRACE_STR_COPY string arguments are copied. | 1104 // Test that static TRACE_STR_COPY string arguments are copied. |
| 1029 TRACE_EVENT2("cat", "name2", | 1105 TRACE_EVENT2("cat", "name2", |
| 1030 "arg1", TRACE_STR_COPY("argval"), | 1106 "arg1", TRACE_STR_COPY("argval"), |
| 1031 "arg2", TRACE_STR_COPY("argval")); | 1107 "arg2", TRACE_STR_COPY("argval")); |
| 1032 size_t num_events = tracer->GetEventsSize(); | 1108 size_t num_events = tracer->GetEventsSize(); |
| 1033 EXPECT_GT(num_events, 1u); | 1109 EXPECT_GT(num_events, 1u); |
| 1034 const TraceEvent& event1 = tracer->GetEventAt(num_events - 2); | 1110 const TraceEvent& event1 = tracer->GetEventAt(num_events - 2); |
| 1035 const TraceEvent& event2 = tracer->GetEventAt(num_events - 1); | 1111 const TraceEvent& event2 = tracer->GetEventAt(num_events - 1); |
| 1036 EXPECT_STREQ("name1", event1.name()); | 1112 EXPECT_STREQ("name1", event1.name()); |
| 1037 EXPECT_STREQ("name2", event2.name()); | 1113 EXPECT_STREQ("name2", event2.name()); |
| 1038 EXPECT_TRUE(event1.parameter_copy_storage() != NULL); | 1114 EXPECT_TRUE(event1.parameter_copy_storage() != NULL); |
| 1039 EXPECT_TRUE(event2.parameter_copy_storage() != NULL); | 1115 EXPECT_TRUE(event2.parameter_copy_storage() != NULL); |
| 1040 EXPECT_GT(event1.parameter_copy_storage()->size(), 0u); | 1116 EXPECT_GT(event1.parameter_copy_storage()->size(), 0u); |
| 1041 EXPECT_GT(event2.parameter_copy_storage()->size(), 0u); | 1117 EXPECT_GT(event2.parameter_copy_storage()->size(), 0u); |
| 1042 tracer->SetEnabled(false); | 1118 EndTraceAndFlush(); |
| 1043 } | 1119 } |
| 1044 | 1120 |
| 1045 { | 1121 { |
| 1046 tracer->SetEnabled(true); | 1122 BeginTrace(); |
| 1047 // Test that static literal string arguments are not copied. | 1123 // Test that static literal string arguments are not copied. |
| 1048 TRACE_EVENT2("cat", "name1", | 1124 TRACE_EVENT2("cat", "name1", |
| 1049 "arg1", "argval", "arg2", "argval"); | 1125 "arg1", "argval", "arg2", "argval"); |
| 1050 // Test that static TRACE_STR_COPY NULL string arguments are not copied. | 1126 // Test that static TRACE_STR_COPY NULL string arguments are not copied. |
| 1051 const char* str1 = NULL; | 1127 const char* str1 = NULL; |
| 1052 const char* str2 = NULL; | 1128 const char* str2 = NULL; |
| 1053 TRACE_EVENT2("cat", "name2", | 1129 TRACE_EVENT2("cat", "name2", |
| 1054 "arg1", TRACE_STR_COPY(str1), | 1130 "arg1", TRACE_STR_COPY(str1), |
| 1055 "arg2", TRACE_STR_COPY(str2)); | 1131 "arg2", TRACE_STR_COPY(str2)); |
| 1056 size_t num_events = tracer->GetEventsSize(); | 1132 size_t num_events = tracer->GetEventsSize(); |
| 1057 EXPECT_GT(num_events, 1u); | 1133 EXPECT_GT(num_events, 1u); |
| 1058 const TraceEvent& event1 = tracer->GetEventAt(num_events - 2); | 1134 const TraceEvent& event1 = tracer->GetEventAt(num_events - 2); |
| 1059 const TraceEvent& event2 = tracer->GetEventAt(num_events - 1); | 1135 const TraceEvent& event2 = tracer->GetEventAt(num_events - 1); |
| 1060 EXPECT_STREQ("name1", event1.name()); | 1136 EXPECT_STREQ("name1", event1.name()); |
| 1061 EXPECT_STREQ("name2", event2.name()); | 1137 EXPECT_STREQ("name2", event2.name()); |
| 1062 EXPECT_TRUE(event1.parameter_copy_storage() == NULL); | 1138 EXPECT_TRUE(event1.parameter_copy_storage() == NULL); |
| 1063 EXPECT_TRUE(event2.parameter_copy_storage() == NULL); | 1139 EXPECT_TRUE(event2.parameter_copy_storage() == NULL); |
| 1064 tracer->SetEnabled(false); | 1140 EndTraceAndFlush(); |
| 1065 } | 1141 } |
| 1066 } | 1142 } |
| 1067 | 1143 |
| 1068 // Test that data sent from other threads is gathered | 1144 // Test that data sent from other threads is gathered |
| 1069 TEST_F(TraceEventTestFixture, DataCapturedOnThread) { | 1145 TEST_F(TraceEventTestFixture, DataCapturedOnThread) { |
| 1070 ManualTestSetUp(); | 1146 ManualTestSetUp(); |
| 1071 TraceLog::GetInstance()->SetEnabled(true); | 1147 BeginTrace(); |
| 1072 | 1148 |
| 1073 Thread thread("1"); | 1149 Thread thread("1"); |
| 1074 WaitableEvent task_complete_event(false, false); | 1150 WaitableEvent task_complete_event(false, false); |
| 1075 thread.Start(); | 1151 thread.Start(); |
| 1076 | 1152 |
| 1077 thread.message_loop()->PostTask( | 1153 thread.message_loop()->PostTask( |
| 1078 FROM_HERE, base::Bind(&TraceWithAllMacroVariants, &task_complete_event)); | 1154 FROM_HERE, base::Bind(&TraceWithAllMacroVariants, &task_complete_event)); |
| 1079 task_complete_event.Wait(); | 1155 task_complete_event.Wait(); |
| 1080 thread.Stop(); | 1156 thread.Stop(); |
| 1081 | 1157 |
| 1082 TraceLog::GetInstance()->SetEnabled(false); | 1158 EndTraceAndFlush(); |
| 1083 ValidateAllTraceMacrosCreatedData(trace_parsed_); | 1159 ValidateAllTraceMacrosCreatedData(trace_parsed_); |
| 1084 } | 1160 } |
| 1085 | 1161 |
| 1086 // Test that data sent from multiple threads is gathered | 1162 // Test that data sent from multiple threads is gathered |
| 1087 TEST_F(TraceEventTestFixture, DataCapturedManyThreads) { | 1163 TEST_F(TraceEventTestFixture, DataCapturedManyThreads) { |
| 1088 ManualTestSetUp(); | 1164 ManualTestSetUp(); |
| 1089 TraceLog::GetInstance()->SetEnabled(true); | 1165 BeginTrace(); |
| 1090 | 1166 |
| 1091 const int num_threads = 4; | 1167 const int num_threads = 4; |
| 1092 const int num_events = 4000; | 1168 const int num_events = 4000; |
| 1093 Thread* threads[num_threads]; | 1169 Thread* threads[num_threads]; |
| 1094 WaitableEvent* task_complete_events[num_threads]; | 1170 WaitableEvent* task_complete_events[num_threads]; |
| 1095 for (int i = 0; i < num_threads; i++) { | 1171 for (int i = 0; i < num_threads; i++) { |
| 1096 threads[i] = new Thread(StringPrintf("Thread %d", i).c_str()); | 1172 threads[i] = new Thread(StringPrintf("Thread %d", i).c_str()); |
| 1097 task_complete_events[i] = new WaitableEvent(false, false); | 1173 task_complete_events[i] = new WaitableEvent(false, false); |
| 1098 threads[i]->Start(); | 1174 threads[i]->Start(); |
| 1099 threads[i]->message_loop()->PostTask( | 1175 threads[i]->message_loop()->PostTask( |
| 1100 FROM_HERE, base::Bind(&TraceManyInstantEvents, | 1176 FROM_HERE, base::Bind(&TraceManyInstantEvents, |
| 1101 i, num_events, task_complete_events[i])); | 1177 i, num_events, task_complete_events[i])); |
| 1102 } | 1178 } |
| 1103 | 1179 |
| 1104 for (int i = 0; i < num_threads; i++) { | 1180 for (int i = 0; i < num_threads; i++) { |
| 1105 task_complete_events[i]->Wait(); | 1181 task_complete_events[i]->Wait(); |
| 1106 } | 1182 } |
| 1107 | 1183 |
| 1108 for (int i = 0; i < num_threads; i++) { | 1184 for (int i = 0; i < num_threads; i++) { |
| 1109 threads[i]->Stop(); | 1185 threads[i]->Stop(); |
| 1110 delete threads[i]; | 1186 delete threads[i]; |
| 1111 delete task_complete_events[i]; | 1187 delete task_complete_events[i]; |
| 1112 } | 1188 } |
| 1113 | 1189 |
| 1114 TraceLog::GetInstance()->SetEnabled(false); | 1190 EndTraceAndFlush(); |
| 1115 | 1191 |
| 1116 ValidateInstantEventPresentOnEveryThread(trace_parsed_, | 1192 ValidateInstantEventPresentOnEveryThread(trace_parsed_, |
| 1117 num_threads, num_events); | 1193 num_threads, num_events); |
| 1118 } | 1194 } |
| 1119 | 1195 |
| 1120 // Test that thread and process names show up in the trace | 1196 // Test that thread and process names show up in the trace |
| 1121 TEST_F(TraceEventTestFixture, ThreadNames) { | 1197 TEST_F(TraceEventTestFixture, ThreadNames) { |
| 1122 ManualTestSetUp(); | 1198 ManualTestSetUp(); |
| 1123 | 1199 |
| 1124 // Create threads before we enable tracing to make sure | 1200 // Create threads before we enable tracing to make sure |
| 1125 // that tracelog still captures them. | 1201 // that tracelog still captures them. |
| 1126 const int num_threads = 4; | 1202 const int num_threads = 4; |
| 1127 const int num_events = 10; | 1203 const int num_events = 10; |
| 1128 Thread* threads[num_threads]; | 1204 Thread* threads[num_threads]; |
| 1129 PlatformThreadId thread_ids[num_threads]; | 1205 PlatformThreadId thread_ids[num_threads]; |
| 1130 for (int i = 0; i < num_threads; i++) | 1206 for (int i = 0; i < num_threads; i++) |
| 1131 threads[i] = new Thread(StringPrintf("Thread %d", i).c_str()); | 1207 threads[i] = new Thread(StringPrintf("Thread %d", i).c_str()); |
| 1132 | 1208 |
| 1133 // Enable tracing. | 1209 // Enable tracing. |
| 1134 TraceLog::GetInstance()->SetEnabled(true); | 1210 BeginTrace(); |
| 1135 | 1211 |
| 1136 // Now run some trace code on these threads. | 1212 // Now run some trace code on these threads. |
| 1137 WaitableEvent* task_complete_events[num_threads]; | 1213 WaitableEvent* task_complete_events[num_threads]; |
| 1138 for (int i = 0; i < num_threads; i++) { | 1214 for (int i = 0; i < num_threads; i++) { |
| 1139 task_complete_events[i] = new WaitableEvent(false, false); | 1215 task_complete_events[i] = new WaitableEvent(false, false); |
| 1140 threads[i]->Start(); | 1216 threads[i]->Start(); |
| 1141 thread_ids[i] = threads[i]->thread_id(); | 1217 thread_ids[i] = threads[i]->thread_id(); |
| 1142 threads[i]->message_loop()->PostTask( | 1218 threads[i]->message_loop()->PostTask( |
| 1143 FROM_HERE, base::Bind(&TraceManyInstantEvents, | 1219 FROM_HERE, base::Bind(&TraceManyInstantEvents, |
| 1144 i, num_events, task_complete_events[i])); | 1220 i, num_events, task_complete_events[i])); |
| 1145 } | 1221 } |
| 1146 for (int i = 0; i < num_threads; i++) { | 1222 for (int i = 0; i < num_threads; i++) { |
| 1147 task_complete_events[i]->Wait(); | 1223 task_complete_events[i]->Wait(); |
| 1148 } | 1224 } |
| 1149 | 1225 |
| 1150 // Shut things down. | 1226 // Shut things down. |
| 1151 for (int i = 0; i < num_threads; i++) { | 1227 for (int i = 0; i < num_threads; i++) { |
| 1152 threads[i]->Stop(); | 1228 threads[i]->Stop(); |
| 1153 delete threads[i]; | 1229 delete threads[i]; |
| 1154 delete task_complete_events[i]; | 1230 delete task_complete_events[i]; |
| 1155 } | 1231 } |
| 1156 | 1232 |
| 1157 TraceLog::GetInstance()->SetEnabled(false); | 1233 EndTraceAndFlush(); |
| 1158 | 1234 |
| 1159 std::string tmp; | 1235 std::string tmp; |
| 1160 int tmp_int; | 1236 int tmp_int; |
| 1161 const DictionaryValue* item; | 1237 const DictionaryValue* item; |
| 1162 | 1238 |
| 1163 // Make sure we get thread name metadata. | 1239 // Make sure we get thread name metadata. |
| 1164 // Note, the test suite may have created a ton of threads. | 1240 // Note, the test suite may have created a ton of threads. |
| 1165 // So, we'll have thread names for threads we didn't create. | 1241 // So, we'll have thread names for threads we didn't create. |
| 1166 std::vector<const DictionaryValue*> items = | 1242 std::vector<const DictionaryValue*> items = |
| 1167 FindTraceEntries(trace_parsed_, "thread_name"); | 1243 FindTraceEntries(trace_parsed_, "thread_name"); |
| (...skipping 15 matching lines...) Expand all Loading... |
| 1183 // a comma-separated list of thread names, so look for a substring. | 1259 // a comma-separated list of thread names, so look for a substring. |
| 1184 EXPECT_TRUE(item->GetString("args.name", &tmp) && | 1260 EXPECT_TRUE(item->GetString("args.name", &tmp) && |
| 1185 tmp.find(expected_name) != std::string::npos); | 1261 tmp.find(expected_name) != std::string::npos); |
| 1186 } | 1262 } |
| 1187 } | 1263 } |
| 1188 } | 1264 } |
| 1189 | 1265 |
| 1190 TEST_F(TraceEventTestFixture, ThreadNameChanges) { | 1266 TEST_F(TraceEventTestFixture, ThreadNameChanges) { |
| 1191 ManualTestSetUp(); | 1267 ManualTestSetUp(); |
| 1192 | 1268 |
| 1193 TraceLog::GetInstance()->SetEnabled(true); | 1269 BeginTrace(); |
| 1194 | 1270 |
| 1195 PlatformThread::SetName(""); | 1271 PlatformThread::SetName(""); |
| 1196 TRACE_EVENT_INSTANT0("drink", "water"); | 1272 TRACE_EVENT_INSTANT0("drink", "water"); |
| 1197 | 1273 |
| 1198 PlatformThread::SetName("cafe"); | 1274 PlatformThread::SetName("cafe"); |
| 1199 TRACE_EVENT_INSTANT0("drink", "coffee"); | 1275 TRACE_EVENT_INSTANT0("drink", "coffee"); |
| 1200 | 1276 |
| 1201 PlatformThread::SetName("shop"); | 1277 PlatformThread::SetName("shop"); |
| 1202 // No event here, so won't appear in combined name. | 1278 // No event here, so won't appear in combined name. |
| 1203 | 1279 |
| 1204 PlatformThread::SetName("pub"); | 1280 PlatformThread::SetName("pub"); |
| 1205 TRACE_EVENT_INSTANT0("drink", "beer"); | 1281 TRACE_EVENT_INSTANT0("drink", "beer"); |
| 1206 TRACE_EVENT_INSTANT0("drink", "wine"); | 1282 TRACE_EVENT_INSTANT0("drink", "wine"); |
| 1207 | 1283 |
| 1208 PlatformThread::SetName(" bar"); | 1284 PlatformThread::SetName(" bar"); |
| 1209 TRACE_EVENT_INSTANT0("drink", "whisky"); | 1285 TRACE_EVENT_INSTANT0("drink", "whisky"); |
| 1210 | 1286 |
| 1211 TraceLog::GetInstance()->SetEnabled(false); | 1287 EndTraceAndFlush(); |
| 1212 | 1288 |
| 1213 std::vector<const DictionaryValue*> items = | 1289 std::vector<const DictionaryValue*> items = |
| 1214 FindTraceEntries(trace_parsed_, "thread_name"); | 1290 FindTraceEntries(trace_parsed_, "thread_name"); |
| 1215 EXPECT_EQ(1u, items.size()); | 1291 EXPECT_EQ(1u, items.size()); |
| 1216 ASSERT_GT(items.size(), 0u); | 1292 ASSERT_GT(items.size(), 0u); |
| 1217 const DictionaryValue* item = items[0]; | 1293 const DictionaryValue* item = items[0]; |
| 1218 ASSERT_TRUE(item); | 1294 ASSERT_TRUE(item); |
| 1219 int tid; | 1295 int tid; |
| 1220 EXPECT_TRUE(item->GetInteger("tid", &tid)); | 1296 EXPECT_TRUE(item->GetInteger("tid", &tid)); |
| 1221 EXPECT_EQ(PlatformThread::CurrentId(), static_cast<PlatformThreadId>(tid)); | 1297 EXPECT_EQ(PlatformThread::CurrentId(), static_cast<PlatformThreadId>(tid)); |
| (...skipping 18 matching lines...) Expand all Loading... |
| 1240 // Scope to contain the then destroy the TraceLog singleton. | 1316 // Scope to contain the then destroy the TraceLog singleton. |
| 1241 { | 1317 { |
| 1242 base::ShadowingAtExitManager exit_manager_will_destroy_singletons; | 1318 base::ShadowingAtExitManager exit_manager_will_destroy_singletons; |
| 1243 | 1319 |
| 1244 // Setup TraceLog singleton inside this test's exit manager scope | 1320 // Setup TraceLog singleton inside this test's exit manager scope |
| 1245 // so that it will be destroyed when this scope closes. | 1321 // so that it will be destroyed when this scope closes. |
| 1246 ManualTestSetUp(); | 1322 ManualTestSetUp(); |
| 1247 | 1323 |
| 1248 TRACE_EVENT_INSTANT0("all", "not recorded; system not enabled"); | 1324 TRACE_EVENT_INSTANT0("all", "not recorded; system not enabled"); |
| 1249 | 1325 |
| 1250 TraceLog::GetInstance()->SetEnabled(true); | 1326 BeginTrace(); |
| 1251 | 1327 |
| 1252 TRACE_EVENT_INSTANT0("all", "is recorded 1; system has been enabled"); | 1328 TRACE_EVENT_INSTANT0("all", "is recorded 1; system has been enabled"); |
| 1253 // Trace calls that will cache pointers to categories; they're valid here | 1329 // Trace calls that will cache pointers to categories; they're valid here |
| 1254 TraceCallsWithCachedCategoryPointersPointers( | 1330 TraceCallsWithCachedCategoryPointersPointers( |
| 1255 "is recorded 2; system has been enabled"); | 1331 "is recorded 2; system has been enabled"); |
| 1256 | 1332 |
| 1257 TraceLog::GetInstance()->SetEnabled(false); | 1333 EndTraceAndFlush(); |
| 1258 } // scope to destroy singleton | 1334 } // scope to destroy singleton |
| 1259 ASSERT_FALSE(TraceLog::GetInstance()); | 1335 ASSERT_FALSE(TraceLog::GetInstance()); |
| 1260 | 1336 |
| 1261 // Now that singleton is destroyed, check what trace events were recorded | 1337 // Now that singleton is destroyed, check what trace events were recorded |
| 1262 const DictionaryValue* item = NULL; | 1338 const DictionaryValue* item = NULL; |
| 1263 ListValue& trace_parsed = trace_parsed_; | 1339 ListValue& trace_parsed = trace_parsed_; |
| 1264 EXPECT_FIND_("is recorded 1"); | 1340 EXPECT_FIND_("is recorded 1"); |
| 1265 EXPECT_FIND_("is recorded 2"); | 1341 EXPECT_FIND_("is recorded 2"); |
| 1266 EXPECT_NOT_FIND_("not recorded"); | 1342 EXPECT_NOT_FIND_("not recorded"); |
| 1267 | 1343 |
| (...skipping 20 matching lines...) Expand all Loading... |
| 1288 } | 1364 } |
| 1289 | 1365 |
| 1290 TEST_F(TraceEventTestFixture, NormallyNoDeepCopy) { | 1366 TEST_F(TraceEventTestFixture, NormallyNoDeepCopy) { |
| 1291 // Test that the TRACE_EVENT macros do not deep-copy their string. If they | 1367 // Test that the TRACE_EVENT macros do not deep-copy their string. If they |
| 1292 // do so it may indicate a performance regression, but more-over it would | 1368 // do so it may indicate a performance regression, but more-over it would |
| 1293 // make the DEEP_COPY overloads redundant. | 1369 // make the DEEP_COPY overloads redundant. |
| 1294 ManualTestSetUp(); | 1370 ManualTestSetUp(); |
| 1295 | 1371 |
| 1296 std::string name_string("event name"); | 1372 std::string name_string("event name"); |
| 1297 | 1373 |
| 1298 TraceLog::GetInstance()->SetEnabled(true); | 1374 BeginTrace(); |
| 1299 TRACE_EVENT_INSTANT0("category", name_string.c_str()); | 1375 TRACE_EVENT_INSTANT0("category", name_string.c_str()); |
| 1300 | 1376 |
| 1301 // Modify the string in place (a wholesale reassignment may leave the old | 1377 // Modify the string in place (a wholesale reassignment may leave the old |
| 1302 // string intact on the heap). | 1378 // string intact on the heap). |
| 1303 name_string[0] = '@'; | 1379 name_string[0] = '@'; |
| 1304 | 1380 |
| 1305 TraceLog::GetInstance()->SetEnabled(false); | 1381 EndTraceAndFlush(); |
| 1306 | 1382 |
| 1307 EXPECT_FALSE(FindTraceEntry(trace_parsed_, "event name")); | 1383 EXPECT_FALSE(FindTraceEntry(trace_parsed_, "event name")); |
| 1308 EXPECT_TRUE(FindTraceEntry(trace_parsed_, name_string.c_str())); | 1384 EXPECT_TRUE(FindTraceEntry(trace_parsed_, name_string.c_str())); |
| 1309 } | 1385 } |
| 1310 | 1386 |
| 1311 TEST_F(TraceEventTestFixture, DeepCopy) { | 1387 TEST_F(TraceEventTestFixture, DeepCopy) { |
| 1312 ManualTestSetUp(); | 1388 ManualTestSetUp(); |
| 1313 | 1389 |
| 1314 static const char kOriginalName1[] = "name1"; | 1390 static const char kOriginalName1[] = "name1"; |
| 1315 static const char kOriginalName2[] = "name2"; | 1391 static const char kOriginalName2[] = "name2"; |
| 1316 static const char kOriginalName3[] = "name3"; | 1392 static const char kOriginalName3[] = "name3"; |
| 1317 std::string name1(kOriginalName1); | 1393 std::string name1(kOriginalName1); |
| 1318 std::string name2(kOriginalName2); | 1394 std::string name2(kOriginalName2); |
| 1319 std::string name3(kOriginalName3); | 1395 std::string name3(kOriginalName3); |
| 1320 std::string arg1("arg1"); | 1396 std::string arg1("arg1"); |
| 1321 std::string arg2("arg2"); | 1397 std::string arg2("arg2"); |
| 1322 std::string val1("val1"); | 1398 std::string val1("val1"); |
| 1323 std::string val2("val2"); | 1399 std::string val2("val2"); |
| 1324 | 1400 |
| 1325 TraceLog::GetInstance()->SetEnabled(true); | 1401 BeginTrace(); |
| 1326 TRACE_EVENT_COPY_INSTANT0("category", name1.c_str()); | 1402 TRACE_EVENT_COPY_INSTANT0("category", name1.c_str()); |
| 1327 TRACE_EVENT_COPY_BEGIN1("category", name2.c_str(), | 1403 TRACE_EVENT_COPY_BEGIN1("category", name2.c_str(), |
| 1328 arg1.c_str(), 5); | 1404 arg1.c_str(), 5); |
| 1329 TRACE_EVENT_COPY_END2("category", name3.c_str(), | 1405 TRACE_EVENT_COPY_END2("category", name3.c_str(), |
| 1330 arg1.c_str(), val1, | 1406 arg1.c_str(), val1, |
| 1331 arg2.c_str(), val2); | 1407 arg2.c_str(), val2); |
| 1332 | 1408 |
| 1333 // As per NormallyNoDeepCopy, modify the strings in place. | 1409 // As per NormallyNoDeepCopy, modify the strings in place. |
| 1334 name1[0] = name2[0] = name3[0] = arg1[0] = arg2[0] = val1[0] = val2[0] = '@'; | 1410 name1[0] = name2[0] = name3[0] = arg1[0] = arg2[0] = val1[0] = val2[0] = '@'; |
| 1335 | 1411 |
| 1336 TraceLog::GetInstance()->SetEnabled(false); | 1412 EndTraceAndFlush(); |
| 1337 | 1413 |
| 1338 EXPECT_FALSE(FindTraceEntry(trace_parsed_, name1.c_str())); | 1414 EXPECT_FALSE(FindTraceEntry(trace_parsed_, name1.c_str())); |
| 1339 EXPECT_FALSE(FindTraceEntry(trace_parsed_, name2.c_str())); | 1415 EXPECT_FALSE(FindTraceEntry(trace_parsed_, name2.c_str())); |
| 1340 EXPECT_FALSE(FindTraceEntry(trace_parsed_, name3.c_str())); | 1416 EXPECT_FALSE(FindTraceEntry(trace_parsed_, name3.c_str())); |
| 1341 | 1417 |
| 1342 const DictionaryValue* entry1 = FindTraceEntry(trace_parsed_, kOriginalName1); | 1418 const DictionaryValue* entry1 = FindTraceEntry(trace_parsed_, kOriginalName1); |
| 1343 const DictionaryValue* entry2 = FindTraceEntry(trace_parsed_, kOriginalName2); | 1419 const DictionaryValue* entry2 = FindTraceEntry(trace_parsed_, kOriginalName2); |
| 1344 const DictionaryValue* entry3 = FindTraceEntry(trace_parsed_, kOriginalName3); | 1420 const DictionaryValue* entry3 = FindTraceEntry(trace_parsed_, kOriginalName3); |
| 1345 ASSERT_TRUE(entry1); | 1421 ASSERT_TRUE(entry1); |
| 1346 ASSERT_TRUE(entry2); | 1422 ASSERT_TRUE(entry2); |
| (...skipping 28 matching lines...) Expand all Loading... |
| 1375 Clear(); | 1451 Clear(); |
| 1376 | 1452 |
| 1377 trace_buffer_.Start(); | 1453 trace_buffer_.Start(); |
| 1378 trace_buffer_.AddFragment("bla1,bla2,bla3,bla4"); | 1454 trace_buffer_.AddFragment("bla1,bla2,bla3,bla4"); |
| 1379 trace_buffer_.Finish(); | 1455 trace_buffer_.Finish(); |
| 1380 EXPECT_STREQ(json_output_.json_output.c_str(), "[bla1,bla2,bla3,bla4]"); | 1456 EXPECT_STREQ(json_output_.json_output.c_str(), "[bla1,bla2,bla3,bla4]"); |
| 1381 } | 1457 } |
| 1382 | 1458 |
| 1383 } // namespace debug | 1459 } // namespace debug |
| 1384 } // namespace base | 1460 } // namespace base |
| OLD | NEW |