| 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/trace_event/trace_event.h" | 5 #include "base/trace_event/trace_event.h" |
| 6 | 6 |
| 7 #include <math.h> | 7 #include <math.h> |
| 8 #include <stddef.h> | 8 #include <stddef.h> |
| 9 #include <stdint.h> | 9 #include <stdint.h> |
| 10 | 10 |
| (...skipping 2512 matching lines...) Expand 10 before | Expand all | Expand 10 after Loading... |
| 2523 dict->GetDictionary("args", &args_dict); | 2523 dict->GetDictionary("args", &args_dict); |
| 2524 ASSERT_TRUE(args_dict); | 2524 ASSERT_TRUE(args_dict); |
| 2525 | 2525 |
| 2526 EXPECT_TRUE(args_dict->GetString("granular_arg_whitelisted", &args_string)); | 2526 EXPECT_TRUE(args_dict->GetString("granular_arg_whitelisted", &args_string)); |
| 2527 EXPECT_EQ(args_string, "whitelisted_value"); | 2527 EXPECT_EQ(args_string, "whitelisted_value"); |
| 2528 | 2528 |
| 2529 EXPECT_TRUE(args_dict->GetString("granular_arg_blacklisted", &args_string)); | 2529 EXPECT_TRUE(args_dict->GetString("granular_arg_blacklisted", &args_string)); |
| 2530 EXPECT_EQ(args_string, "__stripped__"); | 2530 EXPECT_EQ(args_string, "__stripped__"); |
| 2531 } | 2531 } |
| 2532 | 2532 |
| 2533 class TraceEventCallbackTest : public TraceEventTestFixture { | |
| 2534 public: | |
| 2535 void SetUp() override { | |
| 2536 TraceEventTestFixture::SetUp(); | |
| 2537 ASSERT_EQ(NULL, s_instance); | |
| 2538 s_instance = this; | |
| 2539 } | |
| 2540 void TearDown() override { | |
| 2541 TraceLog::GetInstance()->SetDisabled(); | |
| 2542 ASSERT_TRUE(s_instance); | |
| 2543 s_instance = NULL; | |
| 2544 TraceEventTestFixture::TearDown(); | |
| 2545 } | |
| 2546 | |
| 2547 protected: | |
| 2548 // For TraceEventCallbackAndRecordingX tests. | |
| 2549 void VerifyCallbackAndRecordedEvents(size_t expected_callback_count, | |
| 2550 size_t expected_recorded_count) { | |
| 2551 // Callback events. | |
| 2552 EXPECT_EQ(expected_callback_count, collected_events_names_.size()); | |
| 2553 for (size_t i = 0; i < collected_events_names_.size(); ++i) { | |
| 2554 EXPECT_EQ("callback", collected_events_categories_[i]); | |
| 2555 EXPECT_EQ("yes", collected_events_names_[i]); | |
| 2556 } | |
| 2557 | |
| 2558 // Recorded events. | |
| 2559 EXPECT_EQ(expected_recorded_count, trace_parsed_.GetSize()); | |
| 2560 EXPECT_TRUE(FindTraceEntry(trace_parsed_, "recording")); | |
| 2561 EXPECT_FALSE(FindTraceEntry(trace_parsed_, "callback")); | |
| 2562 EXPECT_TRUE(FindTraceEntry(trace_parsed_, "yes")); | |
| 2563 EXPECT_FALSE(FindTraceEntry(trace_parsed_, "no")); | |
| 2564 } | |
| 2565 | |
| 2566 void VerifyCollectedEvent(size_t i, | |
| 2567 unsigned phase, | |
| 2568 const std::string& category, | |
| 2569 const std::string& name) { | |
| 2570 EXPECT_EQ(phase, collected_events_phases_[i]); | |
| 2571 EXPECT_EQ(category, collected_events_categories_[i]); | |
| 2572 EXPECT_EQ(name, collected_events_names_[i]); | |
| 2573 } | |
| 2574 | |
| 2575 std::vector<std::string> collected_events_categories_; | |
| 2576 std::vector<std::string> collected_events_names_; | |
| 2577 std::vector<unsigned char> collected_events_phases_; | |
| 2578 std::vector<TimeTicks> collected_events_timestamps_; | |
| 2579 | |
| 2580 static TraceEventCallbackTest* s_instance; | |
| 2581 static void Callback(TimeTicks timestamp, | |
| 2582 char phase, | |
| 2583 const unsigned char* category_group_enabled, | |
| 2584 const char* name, | |
| 2585 const char* scope, | |
| 2586 unsigned long long id, | |
| 2587 int num_args, | |
| 2588 const char* const arg_names[], | |
| 2589 const unsigned char arg_types[], | |
| 2590 const unsigned long long arg_values[], | |
| 2591 unsigned int flags) { | |
| 2592 s_instance->collected_events_phases_.push_back(phase); | |
| 2593 s_instance->collected_events_categories_.push_back( | |
| 2594 TraceLog::GetCategoryGroupName(category_group_enabled)); | |
| 2595 s_instance->collected_events_names_.push_back(name); | |
| 2596 s_instance->collected_events_timestamps_.push_back(timestamp); | |
| 2597 } | |
| 2598 }; | |
| 2599 | |
| 2600 TraceEventCallbackTest* TraceEventCallbackTest::s_instance; | |
| 2601 | |
| 2602 TEST_F(TraceEventCallbackTest, TraceEventCallback) { | |
| 2603 TRACE_EVENT_INSTANT0("all", "before enable", TRACE_EVENT_SCOPE_THREAD); | |
| 2604 TraceLog::GetInstance()->SetEventCallbackEnabled( | |
| 2605 TraceConfig(kRecordAllCategoryFilter, ""), Callback); | |
| 2606 TRACE_EVENT_INSTANT0("all", "event1", TRACE_EVENT_SCOPE_GLOBAL); | |
| 2607 TRACE_EVENT_INSTANT0("all", "event2", TRACE_EVENT_SCOPE_GLOBAL); | |
| 2608 { | |
| 2609 TRACE_EVENT0("all", "duration"); | |
| 2610 TRACE_EVENT_INSTANT0("all", "event3", TRACE_EVENT_SCOPE_GLOBAL); | |
| 2611 } | |
| 2612 TraceLog::GetInstance()->SetEventCallbackDisabled(); | |
| 2613 TRACE_EVENT_INSTANT0("all", "after callback removed", | |
| 2614 TRACE_EVENT_SCOPE_GLOBAL); | |
| 2615 ASSERT_EQ(5u, collected_events_names_.size()); | |
| 2616 EXPECT_EQ("event1", collected_events_names_[0]); | |
| 2617 EXPECT_EQ(TRACE_EVENT_PHASE_INSTANT, collected_events_phases_[0]); | |
| 2618 EXPECT_EQ("event2", collected_events_names_[1]); | |
| 2619 EXPECT_EQ(TRACE_EVENT_PHASE_INSTANT, collected_events_phases_[1]); | |
| 2620 EXPECT_EQ("duration", collected_events_names_[2]); | |
| 2621 EXPECT_EQ(TRACE_EVENT_PHASE_BEGIN, collected_events_phases_[2]); | |
| 2622 EXPECT_EQ("event3", collected_events_names_[3]); | |
| 2623 EXPECT_EQ(TRACE_EVENT_PHASE_INSTANT, collected_events_phases_[3]); | |
| 2624 EXPECT_EQ("duration", collected_events_names_[4]); | |
| 2625 EXPECT_EQ(TRACE_EVENT_PHASE_END, collected_events_phases_[4]); | |
| 2626 for (size_t i = 1; i < collected_events_timestamps_.size(); i++) { | |
| 2627 EXPECT_LE(collected_events_timestamps_[i - 1], | |
| 2628 collected_events_timestamps_[i]); | |
| 2629 } | |
| 2630 } | |
| 2631 | |
| 2632 TEST_F(TraceEventCallbackTest, TraceEventCallbackWhileFull) { | |
| 2633 TraceLog::GetInstance()->SetEnabled(TraceConfig(kRecordAllCategoryFilter, ""), | |
| 2634 TraceLog::RECORDING_MODE); | |
| 2635 do { | |
| 2636 TRACE_EVENT_INSTANT0("all", "badger badger", TRACE_EVENT_SCOPE_GLOBAL); | |
| 2637 } while (!TraceLog::GetInstance()->BufferIsFull()); | |
| 2638 TraceLog::GetInstance()->SetEventCallbackEnabled( | |
| 2639 TraceConfig(kRecordAllCategoryFilter, ""), Callback); | |
| 2640 TRACE_EVENT_INSTANT0("all", "a snake", TRACE_EVENT_SCOPE_GLOBAL); | |
| 2641 TraceLog::GetInstance()->SetEventCallbackDisabled(); | |
| 2642 ASSERT_EQ(1u, collected_events_names_.size()); | |
| 2643 EXPECT_EQ("a snake", collected_events_names_[0]); | |
| 2644 } | |
| 2645 | |
| 2646 // 1: Enable callback, enable recording, disable callback, disable recording. | |
| 2647 TEST_F(TraceEventCallbackTest, TraceEventCallbackAndRecording1) { | |
| 2648 TRACE_EVENT_INSTANT0("recording", "no", TRACE_EVENT_SCOPE_GLOBAL); | |
| 2649 TRACE_EVENT_INSTANT0("callback", "no", TRACE_EVENT_SCOPE_GLOBAL); | |
| 2650 TraceLog::GetInstance()->SetEventCallbackEnabled(TraceConfig("callback", ""), | |
| 2651 Callback); | |
| 2652 TRACE_EVENT_INSTANT0("recording", "no", TRACE_EVENT_SCOPE_GLOBAL); | |
| 2653 TRACE_EVENT_INSTANT0("callback", "yes", TRACE_EVENT_SCOPE_GLOBAL); | |
| 2654 TraceLog::GetInstance()->SetEnabled(TraceConfig("recording", ""), | |
| 2655 TraceLog::RECORDING_MODE); | |
| 2656 TRACE_EVENT_INSTANT0("recording", "yes", TRACE_EVENT_SCOPE_GLOBAL); | |
| 2657 TRACE_EVENT_INSTANT0("callback", "yes", TRACE_EVENT_SCOPE_GLOBAL); | |
| 2658 TraceLog::GetInstance()->SetEventCallbackDisabled(); | |
| 2659 TRACE_EVENT_INSTANT0("recording", "yes", TRACE_EVENT_SCOPE_GLOBAL); | |
| 2660 TRACE_EVENT_INSTANT0("callback", "no", TRACE_EVENT_SCOPE_GLOBAL); | |
| 2661 EndTraceAndFlush(); | |
| 2662 TRACE_EVENT_INSTANT0("recording", "no", TRACE_EVENT_SCOPE_GLOBAL); | |
| 2663 TRACE_EVENT_INSTANT0("callback", "no", TRACE_EVENT_SCOPE_GLOBAL); | |
| 2664 | |
| 2665 DropTracedMetadataRecords(); | |
| 2666 VerifyCallbackAndRecordedEvents(2, 2); | |
| 2667 } | |
| 2668 | |
| 2669 // 2: Enable callback, enable recording, disable recording, disable callback. | |
| 2670 TEST_F(TraceEventCallbackTest, TraceEventCallbackAndRecording2) { | |
| 2671 TRACE_EVENT_INSTANT0("recording", "no", TRACE_EVENT_SCOPE_GLOBAL); | |
| 2672 TRACE_EVENT_INSTANT0("callback", "no", TRACE_EVENT_SCOPE_GLOBAL); | |
| 2673 TraceLog::GetInstance()->SetEventCallbackEnabled(TraceConfig("callback", ""), | |
| 2674 Callback); | |
| 2675 TRACE_EVENT_INSTANT0("recording", "no", TRACE_EVENT_SCOPE_GLOBAL); | |
| 2676 TRACE_EVENT_INSTANT0("callback", "yes", TRACE_EVENT_SCOPE_GLOBAL); | |
| 2677 TraceLog::GetInstance()->SetEnabled(TraceConfig("recording", ""), | |
| 2678 TraceLog::RECORDING_MODE); | |
| 2679 TRACE_EVENT_INSTANT0("recording", "yes", TRACE_EVENT_SCOPE_GLOBAL); | |
| 2680 TRACE_EVENT_INSTANT0("callback", "yes", TRACE_EVENT_SCOPE_GLOBAL); | |
| 2681 EndTraceAndFlush(); | |
| 2682 TRACE_EVENT_INSTANT0("recording", "no", TRACE_EVENT_SCOPE_GLOBAL); | |
| 2683 TRACE_EVENT_INSTANT0("callback", "yes", TRACE_EVENT_SCOPE_GLOBAL); | |
| 2684 TraceLog::GetInstance()->SetEventCallbackDisabled(); | |
| 2685 TRACE_EVENT_INSTANT0("recording", "no", TRACE_EVENT_SCOPE_GLOBAL); | |
| 2686 TRACE_EVENT_INSTANT0("callback", "no", TRACE_EVENT_SCOPE_GLOBAL); | |
| 2687 | |
| 2688 DropTracedMetadataRecords(); | |
| 2689 VerifyCallbackAndRecordedEvents(3, 1); | |
| 2690 } | |
| 2691 | |
| 2692 // 3: Enable recording, enable callback, disable callback, disable recording. | |
| 2693 TEST_F(TraceEventCallbackTest, TraceEventCallbackAndRecording3) { | |
| 2694 TRACE_EVENT_INSTANT0("recording", "no", TRACE_EVENT_SCOPE_GLOBAL); | |
| 2695 TRACE_EVENT_INSTANT0("callback", "no", TRACE_EVENT_SCOPE_GLOBAL); | |
| 2696 TraceLog::GetInstance()->SetEnabled(TraceConfig("recording", ""), | |
| 2697 TraceLog::RECORDING_MODE); | |
| 2698 TRACE_EVENT_INSTANT0("recording", "yes", TRACE_EVENT_SCOPE_GLOBAL); | |
| 2699 TRACE_EVENT_INSTANT0("callback", "no", TRACE_EVENT_SCOPE_GLOBAL); | |
| 2700 TraceLog::GetInstance()->SetEventCallbackEnabled(TraceConfig("callback", ""), | |
| 2701 Callback); | |
| 2702 TRACE_EVENT_INSTANT0("recording", "yes", TRACE_EVENT_SCOPE_GLOBAL); | |
| 2703 TRACE_EVENT_INSTANT0("callback", "yes", TRACE_EVENT_SCOPE_GLOBAL); | |
| 2704 TraceLog::GetInstance()->SetEventCallbackDisabled(); | |
| 2705 TRACE_EVENT_INSTANT0("recording", "yes", TRACE_EVENT_SCOPE_GLOBAL); | |
| 2706 TRACE_EVENT_INSTANT0("callback", "no", TRACE_EVENT_SCOPE_GLOBAL); | |
| 2707 EndTraceAndFlush(); | |
| 2708 TRACE_EVENT_INSTANT0("recording", "no", TRACE_EVENT_SCOPE_GLOBAL); | |
| 2709 TRACE_EVENT_INSTANT0("callback", "no", TRACE_EVENT_SCOPE_GLOBAL); | |
| 2710 | |
| 2711 DropTracedMetadataRecords(); | |
| 2712 VerifyCallbackAndRecordedEvents(1, 3); | |
| 2713 } | |
| 2714 | |
| 2715 // 4: Enable recording, enable callback, disable recording, disable callback. | |
| 2716 TEST_F(TraceEventCallbackTest, TraceEventCallbackAndRecording4) { | |
| 2717 TRACE_EVENT_INSTANT0("recording", "no", TRACE_EVENT_SCOPE_GLOBAL); | |
| 2718 TRACE_EVENT_INSTANT0("callback", "no", TRACE_EVENT_SCOPE_GLOBAL); | |
| 2719 TraceLog::GetInstance()->SetEnabled(TraceConfig("recording", ""), | |
| 2720 TraceLog::RECORDING_MODE); | |
| 2721 TRACE_EVENT_INSTANT0("recording", "yes", TRACE_EVENT_SCOPE_GLOBAL); | |
| 2722 TRACE_EVENT_INSTANT0("callback", "no", TRACE_EVENT_SCOPE_GLOBAL); | |
| 2723 TraceLog::GetInstance()->SetEventCallbackEnabled(TraceConfig("callback", ""), | |
| 2724 Callback); | |
| 2725 TRACE_EVENT_INSTANT0("recording", "yes", TRACE_EVENT_SCOPE_GLOBAL); | |
| 2726 TRACE_EVENT_INSTANT0("callback", "yes", TRACE_EVENT_SCOPE_GLOBAL); | |
| 2727 EndTraceAndFlush(); | |
| 2728 TRACE_EVENT_INSTANT0("recording", "no", TRACE_EVENT_SCOPE_GLOBAL); | |
| 2729 TRACE_EVENT_INSTANT0("callback", "yes", TRACE_EVENT_SCOPE_GLOBAL); | |
| 2730 TraceLog::GetInstance()->SetEventCallbackDisabled(); | |
| 2731 TRACE_EVENT_INSTANT0("recording", "no", TRACE_EVENT_SCOPE_GLOBAL); | |
| 2732 TRACE_EVENT_INSTANT0("callback", "no", TRACE_EVENT_SCOPE_GLOBAL); | |
| 2733 | |
| 2734 DropTracedMetadataRecords(); | |
| 2735 VerifyCallbackAndRecordedEvents(2, 2); | |
| 2736 } | |
| 2737 | |
| 2738 TEST_F(TraceEventCallbackTest, TraceEventCallbackAndRecordingDuration) { | |
| 2739 TraceLog::GetInstance()->SetEventCallbackEnabled( | |
| 2740 TraceConfig(kRecordAllCategoryFilter, ""), Callback); | |
| 2741 { | |
| 2742 TRACE_EVENT0("callback", "duration1"); | |
| 2743 TraceLog::GetInstance()->SetEnabled( | |
| 2744 TraceConfig(kRecordAllCategoryFilter, ""), TraceLog::RECORDING_MODE); | |
| 2745 TRACE_EVENT0("callback", "duration2"); | |
| 2746 EndTraceAndFlush(); | |
| 2747 TRACE_EVENT0("callback", "duration3"); | |
| 2748 } | |
| 2749 TraceLog::GetInstance()->SetEventCallbackDisabled(); | |
| 2750 | |
| 2751 ASSERT_EQ(6u, collected_events_names_.size()); | |
| 2752 VerifyCollectedEvent(0, TRACE_EVENT_PHASE_BEGIN, "callback", "duration1"); | |
| 2753 VerifyCollectedEvent(1, TRACE_EVENT_PHASE_BEGIN, "callback", "duration2"); | |
| 2754 VerifyCollectedEvent(2, TRACE_EVENT_PHASE_BEGIN, "callback", "duration3"); | |
| 2755 VerifyCollectedEvent(3, TRACE_EVENT_PHASE_END, "callback", "duration3"); | |
| 2756 VerifyCollectedEvent(4, TRACE_EVENT_PHASE_END, "callback", "duration2"); | |
| 2757 VerifyCollectedEvent(5, TRACE_EVENT_PHASE_END, "callback", "duration1"); | |
| 2758 } | |
| 2759 | |
| 2760 TEST_F(TraceEventTestFixture, TraceBufferVectorReportFull) { | 2533 TEST_F(TraceEventTestFixture, TraceBufferVectorReportFull) { |
| 2761 TraceLog* trace_log = TraceLog::GetInstance(); | 2534 TraceLog* trace_log = TraceLog::GetInstance(); |
| 2762 trace_log->SetEnabled( | 2535 trace_log->SetEnabled( |
| 2763 TraceConfig(kRecordAllCategoryFilter, ""), TraceLog::RECORDING_MODE); | 2536 TraceConfig(kRecordAllCategoryFilter, ""), TraceLog::RECORDING_MODE); |
| 2764 trace_log->logged_events_.reset( | 2537 trace_log->logged_events_.reset( |
| 2765 TraceBuffer::CreateTraceBufferVectorOfSize(100)); | 2538 TraceBuffer::CreateTraceBufferVectorOfSize(100)); |
| 2766 do { | 2539 do { |
| 2767 TRACE_EVENT_BEGIN_WITH_ID_TID_AND_TIMESTAMP0( | 2540 TRACE_EVENT_BEGIN_WITH_ID_TID_AND_TIMESTAMP0( |
| 2768 "all", "with_timestamp", 0, 0, TimeTicks::Now()); | 2541 "all", "with_timestamp", 0, 0, TimeTicks::Now()); |
| 2769 TRACE_EVENT_END_WITH_ID_TID_AND_TIMESTAMP0( | 2542 TRACE_EVENT_END_WITH_ID_TID_AND_TIMESTAMP0( |
| (...skipping 680 matching lines...) Expand 10 before | Expand all | Expand 10 after Loading... |
| 3450 | 3223 |
| 3451 TEST_F(TraceEventTestFixture, ClockSyncEventsAreAlwaysAddedToTrace) { | 3224 TEST_F(TraceEventTestFixture, ClockSyncEventsAreAlwaysAddedToTrace) { |
| 3452 BeginSpecificTrace("-*"); | 3225 BeginSpecificTrace("-*"); |
| 3453 TRACE_EVENT_CLOCK_SYNC_RECEIVER(1); | 3226 TRACE_EVENT_CLOCK_SYNC_RECEIVER(1); |
| 3454 EndTraceAndFlush(); | 3227 EndTraceAndFlush(); |
| 3455 EXPECT_TRUE(FindNamePhase("clock_sync", "c")); | 3228 EXPECT_TRUE(FindNamePhase("clock_sync", "c")); |
| 3456 } | 3229 } |
| 3457 | 3230 |
| 3458 } // namespace trace_event | 3231 } // namespace trace_event |
| 3459 } // namespace base | 3232 } // namespace base |
| OLD | NEW |