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