diff options
Diffstat (limited to 'chromium/base/tracked_objects_unittest.cc')
| -rw-r--r-- | chromium/base/tracked_objects_unittest.cc | 968 |
1 files changed, 662 insertions, 306 deletions
diff --git a/chromium/base/tracked_objects_unittest.cc b/chromium/base/tracked_objects_unittest.cc index f19ba7b2c63..cdbf9ac7a6c 100644 --- a/chromium/base/tracked_objects_unittest.cc +++ b/chromium/base/tracked_objects_unittest.cc @@ -34,7 +34,7 @@ class TrackedObjectsTest : public testing::Test { ThreadData::now_function_is_time_ = true; } - virtual ~TrackedObjectsTest() { + ~TrackedObjectsTest() override { // We should not need to leak any structures we create, since we are // single threaded, and carefully accounting for items. ThreadData::ShutdownSingleThreadedCleanup(false); @@ -71,28 +71,35 @@ class TrackedObjectsTest : public testing::Test { int count, int run_ms, int queue_ms) { - ASSERT_EQ(1u, process_data.tasks.size()); + ASSERT_EQ(1u, process_data.phased_snapshots.size()); + auto it = process_data.phased_snapshots.find(0); + ASSERT_TRUE(it != process_data.phased_snapshots.end()); + const ProcessDataPhaseSnapshot& process_data_phase = it->second; - EXPECT_EQ(kFile, process_data.tasks[0].birth.location.file_name); + ASSERT_EQ(1u, process_data_phase.tasks.size()); + + EXPECT_EQ(kFile, process_data_phase.tasks[0].birth.location.file_name); EXPECT_EQ(function_name, - process_data.tasks[0].birth.location.function_name); - EXPECT_EQ(kLineNumber, process_data.tasks[0].birth.location.line_number); + process_data_phase.tasks[0].birth.location.function_name); + EXPECT_EQ(kLineNumber, + process_data_phase.tasks[0].birth.location.line_number); - EXPECT_EQ(birth_thread, process_data.tasks[0].birth.thread_name); + EXPECT_EQ(birth_thread, process_data_phase.tasks[0].birth.thread_name); - EXPECT_EQ(count, process_data.tasks[0].death_data.count); + EXPECT_EQ(count, process_data_phase.tasks[0].death_data.count); EXPECT_EQ(count * run_ms, - process_data.tasks[0].death_data.run_duration_sum); - EXPECT_EQ(run_ms, process_data.tasks[0].death_data.run_duration_max); - EXPECT_EQ(run_ms, process_data.tasks[0].death_data.run_duration_sample); + process_data_phase.tasks[0].death_data.run_duration_sum); + EXPECT_EQ(run_ms, process_data_phase.tasks[0].death_data.run_duration_max); + EXPECT_EQ(run_ms, + process_data_phase.tasks[0].death_data.run_duration_sample); EXPECT_EQ(count * queue_ms, - process_data.tasks[0].death_data.queue_duration_sum); - EXPECT_EQ(queue_ms, process_data.tasks[0].death_data.queue_duration_max); - EXPECT_EQ(queue_ms, process_data.tasks[0].death_data.queue_duration_sample); + process_data_phase.tasks[0].death_data.queue_duration_sum); + EXPECT_EQ(queue_ms, + process_data_phase.tasks[0].death_data.queue_duration_max); + EXPECT_EQ(queue_ms, + process_data_phase.tasks[0].death_data.queue_duration_sample); - EXPECT_EQ(death_thread, process_data.tasks[0].death_thread_name); - - EXPECT_EQ(0u, process_data.descendants.size()); + EXPECT_EQ(death_thread, process_data_phase.tasks[0].death_thread_name); EXPECT_EQ(base::GetCurrentProcId(), process_data.process_id); } @@ -112,10 +119,7 @@ class TrackedObjectsTest : public testing::Test { unsigned int TrackedObjectsTest::test_time_; TEST_F(TrackedObjectsTest, TaskStopwatchNoStartStop) { - if (!ThreadData::InitializeAndSetTrackingStatus( - ThreadData::PROFILING_CHILDREN_ACTIVE)) { - return; - } + ThreadData::InitializeAndSetTrackingStatus(ThreadData::PROFILING_ACTIVE); // Check that creating and destroying a stopwatch without starting it doesn't // crash. @@ -124,10 +128,7 @@ TEST_F(TrackedObjectsTest, TaskStopwatchNoStartStop) { TEST_F(TrackedObjectsTest, MinimalStartupShutdown) { // Minimal test doesn't even create any tasks. - if (!ThreadData::InitializeAndSetTrackingStatus( - ThreadData::PROFILING_CHILDREN_ACTIVE)) { - return; - } + ThreadData::InitializeAndSetTrackingStatus(ThreadData::PROFILING_ACTIVE); EXPECT_FALSE(ThreadData::first()); // No activity even on this thread. ThreadData* data = ThreadData::Get(); @@ -136,19 +137,16 @@ TEST_F(TrackedObjectsTest, MinimalStartupShutdown) { EXPECT_FALSE(data->next()); EXPECT_EQ(data, ThreadData::Get()); ThreadData::BirthMap birth_map; - ThreadData::DeathMap death_map; - ThreadData::ParentChildSet parent_child_set; - data->SnapshotMaps(false, &birth_map, &death_map, &parent_child_set); + ThreadData::DeathsSnapshot deaths; + data->SnapshotMaps(0, &birth_map, &deaths); EXPECT_EQ(0u, birth_map.size()); - EXPECT_EQ(0u, death_map.size()); - EXPECT_EQ(0u, parent_child_set.size()); + EXPECT_EQ(0u, deaths.size()); // Clean up with no leaking. Reset(); // Do it again, just to be sure we reset state completely. - EXPECT_TRUE(ThreadData::InitializeAndSetTrackingStatus( - ThreadData::PROFILING_CHILDREN_ACTIVE)); + ThreadData::InitializeAndSetTrackingStatus(ThreadData::PROFILING_ACTIVE); EXPECT_FALSE(ThreadData::first()); // No activity even on this thread. data = ThreadData::Get(); EXPECT_TRUE(ThreadData::first()); // Now class was constructed. @@ -156,42 +154,34 @@ TEST_F(TrackedObjectsTest, MinimalStartupShutdown) { EXPECT_FALSE(data->next()); EXPECT_EQ(data, ThreadData::Get()); birth_map.clear(); - death_map.clear(); - parent_child_set.clear(); - data->SnapshotMaps(false, &birth_map, &death_map, &parent_child_set); + deaths.clear(); + data->SnapshotMaps(0, &birth_map, &deaths); EXPECT_EQ(0u, birth_map.size()); - EXPECT_EQ(0u, death_map.size()); - EXPECT_EQ(0u, parent_child_set.size()); + EXPECT_EQ(0u, deaths.size()); } TEST_F(TrackedObjectsTest, TinyStartupShutdown) { - if (!ThreadData::InitializeAndSetTrackingStatus( - ThreadData::PROFILING_CHILDREN_ACTIVE)) { - return; - } + ThreadData::InitializeAndSetTrackingStatus(ThreadData::PROFILING_ACTIVE); // Instigate tracking on a single tracked object, on our thread. const char kFunction[] = "TinyStartupShutdown"; Location location(kFunction, kFile, kLineNumber, NULL); - Births* first_birth = ThreadData::TallyABirthIfActive(location); + ThreadData::TallyABirthIfActive(location); ThreadData* data = ThreadData::first(); ASSERT_TRUE(data); EXPECT_FALSE(data->next()); EXPECT_EQ(data, ThreadData::Get()); ThreadData::BirthMap birth_map; - ThreadData::DeathMap death_map; - ThreadData::ParentChildSet parent_child_set; - data->SnapshotMaps(false, &birth_map, &death_map, &parent_child_set); + ThreadData::DeathsSnapshot deaths; + data->SnapshotMaps(0, &birth_map, &deaths); EXPECT_EQ(1u, birth_map.size()); // 1 birth location. EXPECT_EQ(1, birth_map.begin()->second->birth_count()); // 1 birth. - EXPECT_EQ(0u, death_map.size()); // No deaths. - EXPECT_EQ(0u, parent_child_set.size()); // No children. + EXPECT_EQ(0u, deaths.size()); // No deaths. // Now instigate another birth, while we are timing the run of the first // execution. - ThreadData::PrepareForStartOfRun(first_birth); // Create a child (using the same birth location). // TrackingInfo will call TallyABirth() during construction. const int32 start_time = 1; @@ -209,74 +199,56 @@ TEST_F(TrackedObjectsTest, TinyStartupShutdown) { ThreadData::TallyRunOnNamedThreadIfTracking(pending_task, stopwatch); birth_map.clear(); - death_map.clear(); - parent_child_set.clear(); - data->SnapshotMaps(false, &birth_map, &death_map, &parent_child_set); + deaths.clear(); + data->SnapshotMaps(0, &birth_map, &deaths); EXPECT_EQ(1u, birth_map.size()); // 1 birth location. EXPECT_EQ(2, birth_map.begin()->second->birth_count()); // 2 births. - EXPECT_EQ(1u, death_map.size()); // 1 location. - EXPECT_EQ(1, death_map.begin()->second.count()); // 1 death. - if (ThreadData::TrackingParentChildStatus()) { - EXPECT_EQ(1u, parent_child_set.size()); // 1 child. - EXPECT_EQ(parent_child_set.begin()->first, - parent_child_set.begin()->second); - } else { - EXPECT_EQ(0u, parent_child_set.size()); // no stats. - } + EXPECT_EQ(1u, deaths.size()); // 1 location. + EXPECT_EQ(1, deaths.begin()->second.death_data.count); // 1 death. // The births were at the same location as the one known death. - EXPECT_EQ(birth_map.begin()->second, death_map.begin()->first); + EXPECT_EQ(birth_map.begin()->second, deaths.begin()->first); ProcessDataSnapshot process_data; - ThreadData::Snapshot(false, &process_data); - - ASSERT_EQ(1u, process_data.tasks.size()); - EXPECT_EQ(kFile, process_data.tasks[0].birth.location.file_name); - EXPECT_EQ(kFunction, process_data.tasks[0].birth.location.function_name); - EXPECT_EQ(kLineNumber, process_data.tasks[0].birth.location.line_number); - EXPECT_EQ(kWorkerThreadName, process_data.tasks[0].birth.thread_name); - EXPECT_EQ(1, process_data.tasks[0].death_data.count); - EXPECT_EQ(time_elapsed, process_data.tasks[0].death_data.run_duration_sum); - EXPECT_EQ(time_elapsed, process_data.tasks[0].death_data.run_duration_max); - EXPECT_EQ(time_elapsed, process_data.tasks[0].death_data.run_duration_sample); - EXPECT_EQ(0, process_data.tasks[0].death_data.queue_duration_sum); - EXPECT_EQ(0, process_data.tasks[0].death_data.queue_duration_max); - EXPECT_EQ(0, process_data.tasks[0].death_data.queue_duration_sample); - EXPECT_EQ(kWorkerThreadName, process_data.tasks[0].death_thread_name); - - if (ThreadData::TrackingParentChildStatus()) { - ASSERT_EQ(1u, process_data.descendants.size()); - EXPECT_EQ(kFile, process_data.descendants[0].parent.location.file_name); - EXPECT_EQ(kFunction, - process_data.descendants[0].parent.location.function_name); - EXPECT_EQ(kLineNumber, - process_data.descendants[0].parent.location.line_number); - EXPECT_EQ(kWorkerThreadName, - process_data.descendants[0].parent.thread_name); - EXPECT_EQ(kFile, process_data.descendants[0].child.location.file_name); - EXPECT_EQ(kFunction, - process_data.descendants[0].child.location.function_name); - EXPECT_EQ(kLineNumber, - process_data.descendants[0].child.location.line_number); - EXPECT_EQ(kWorkerThreadName, process_data.descendants[0].child.thread_name); - } else { - EXPECT_EQ(0u, process_data.descendants.size()); - } + ThreadData::Snapshot(0, &process_data); + + ASSERT_EQ(1u, process_data.phased_snapshots.size()); + auto it = process_data.phased_snapshots.find(0); + ASSERT_TRUE(it != process_data.phased_snapshots.end()); + const ProcessDataPhaseSnapshot& process_data_phase = it->second; + ASSERT_EQ(1u, process_data_phase.tasks.size()); + EXPECT_EQ(kFile, process_data_phase.tasks[0].birth.location.file_name); + EXPECT_EQ(kFunction, + process_data_phase.tasks[0].birth.location.function_name); + EXPECT_EQ(kLineNumber, + process_data_phase.tasks[0].birth.location.line_number); + EXPECT_EQ(kWorkerThreadName, process_data_phase.tasks[0].birth.thread_name); + EXPECT_EQ(1, process_data_phase.tasks[0].death_data.count); + EXPECT_EQ(time_elapsed, + process_data_phase.tasks[0].death_data.run_duration_sum); + EXPECT_EQ(time_elapsed, + process_data_phase.tasks[0].death_data.run_duration_max); + EXPECT_EQ(time_elapsed, + process_data_phase.tasks[0].death_data.run_duration_sample); + EXPECT_EQ(0, process_data_phase.tasks[0].death_data.queue_duration_sum); + EXPECT_EQ(0, process_data_phase.tasks[0].death_data.queue_duration_max); + EXPECT_EQ(0, process_data_phase.tasks[0].death_data.queue_duration_sample); + EXPECT_EQ(kWorkerThreadName, process_data_phase.tasks[0].death_thread_name); } -TEST_F(TrackedObjectsTest, DeathDataTest) { - if (!ThreadData::InitializeAndSetTrackingStatus( - ThreadData::PROFILING_CHILDREN_ACTIVE)) { - return; - } +TEST_F(TrackedObjectsTest, DeathDataTestRecordDeath) { + ThreadData::InitializeAndSetTrackingStatus(ThreadData::PROFILING_ACTIVE); scoped_ptr<DeathData> data(new DeathData()); ASSERT_NE(data, reinterpret_cast<DeathData*>(NULL)); EXPECT_EQ(data->run_duration_sum(), 0); + EXPECT_EQ(data->run_duration_max(), 0); EXPECT_EQ(data->run_duration_sample(), 0); EXPECT_EQ(data->queue_duration_sum(), 0); + EXPECT_EQ(data->queue_duration_max(), 0); EXPECT_EQ(data->queue_duration_sample(), 0); EXPECT_EQ(data->count(), 0); + EXPECT_EQ(nullptr, data->last_phase_snapshot()); int32 run_ms = 42; int32 queue_ms = 8; @@ -284,106 +256,199 @@ TEST_F(TrackedObjectsTest, DeathDataTest) { const int kUnrandomInt = 0; // Fake random int that ensure we sample data. data->RecordDeath(queue_ms, run_ms, kUnrandomInt); EXPECT_EQ(data->run_duration_sum(), run_ms); + EXPECT_EQ(data->run_duration_max(), run_ms); EXPECT_EQ(data->run_duration_sample(), run_ms); EXPECT_EQ(data->queue_duration_sum(), queue_ms); + EXPECT_EQ(data->queue_duration_max(), queue_ms); EXPECT_EQ(data->queue_duration_sample(), queue_ms); EXPECT_EQ(data->count(), 1); + EXPECT_EQ(nullptr, data->last_phase_snapshot()); + + data->RecordDeath(queue_ms, run_ms, kUnrandomInt); + EXPECT_EQ(data->run_duration_sum(), run_ms + run_ms); + EXPECT_EQ(data->run_duration_max(), run_ms); + EXPECT_EQ(data->run_duration_sample(), run_ms); + EXPECT_EQ(data->queue_duration_sum(), queue_ms + queue_ms); + EXPECT_EQ(data->queue_duration_max(), queue_ms); + EXPECT_EQ(data->queue_duration_sample(), queue_ms); + EXPECT_EQ(data->count(), 2); + EXPECT_EQ(nullptr, data->last_phase_snapshot()); +} + +TEST_F(TrackedObjectsTest, DeathDataTest2Phases) { + ThreadData::InitializeAndSetTrackingStatus(ThreadData::PROFILING_ACTIVE); + + scoped_ptr<DeathData> data(new DeathData()); + ASSERT_NE(data, reinterpret_cast<DeathData*>(NULL)); + + int32 run_ms = 42; + int32 queue_ms = 8; + const int kUnrandomInt = 0; // Fake random int that ensure we sample data. + data->RecordDeath(queue_ms, run_ms, kUnrandomInt); data->RecordDeath(queue_ms, run_ms, kUnrandomInt); + + data->OnProfilingPhaseCompleted(123); EXPECT_EQ(data->run_duration_sum(), run_ms + run_ms); + EXPECT_EQ(data->run_duration_max(), 0); EXPECT_EQ(data->run_duration_sample(), run_ms); EXPECT_EQ(data->queue_duration_sum(), queue_ms + queue_ms); + EXPECT_EQ(data->queue_duration_max(), 0); EXPECT_EQ(data->queue_duration_sample(), queue_ms); EXPECT_EQ(data->count(), 2); + ASSERT_NE(nullptr, data->last_phase_snapshot()); + EXPECT_EQ(123, data->last_phase_snapshot()->profiling_phase); + EXPECT_EQ(2, data->last_phase_snapshot()->death_data.count); + EXPECT_EQ(2 * run_ms, + data->last_phase_snapshot()->death_data.run_duration_sum); + EXPECT_EQ(run_ms, data->last_phase_snapshot()->death_data.run_duration_max); + EXPECT_EQ(run_ms, + data->last_phase_snapshot()->death_data.run_duration_sample); + EXPECT_EQ(2 * queue_ms, + data->last_phase_snapshot()->death_data.queue_duration_sum); + EXPECT_EQ(queue_ms, + data->last_phase_snapshot()->death_data.queue_duration_max); + EXPECT_EQ(queue_ms, + data->last_phase_snapshot()->death_data.queue_duration_sample); + EXPECT_EQ(nullptr, data->last_phase_snapshot()->prev); + + int32 run_ms1 = 21; + int32 queue_ms1 = 4; + + data->RecordDeath(queue_ms1, run_ms1, kUnrandomInt); + EXPECT_EQ(data->run_duration_sum(), run_ms + run_ms + run_ms1); + EXPECT_EQ(data->run_duration_max(), run_ms1); + EXPECT_EQ(data->run_duration_sample(), run_ms1); + EXPECT_EQ(data->queue_duration_sum(), queue_ms + queue_ms + queue_ms1); + EXPECT_EQ(data->queue_duration_max(), queue_ms1); + EXPECT_EQ(data->queue_duration_sample(), queue_ms1); + EXPECT_EQ(data->count(), 3); + ASSERT_NE(nullptr, data->last_phase_snapshot()); + EXPECT_EQ(123, data->last_phase_snapshot()->profiling_phase); + EXPECT_EQ(2, data->last_phase_snapshot()->death_data.count); + EXPECT_EQ(2 * run_ms, + data->last_phase_snapshot()->death_data.run_duration_sum); + EXPECT_EQ(run_ms, data->last_phase_snapshot()->death_data.run_duration_max); + EXPECT_EQ(run_ms, + data->last_phase_snapshot()->death_data.run_duration_sample); + EXPECT_EQ(2 * queue_ms, + data->last_phase_snapshot()->death_data.queue_duration_sum); + EXPECT_EQ(queue_ms, + data->last_phase_snapshot()->death_data.queue_duration_max); + EXPECT_EQ(queue_ms, + data->last_phase_snapshot()->death_data.queue_duration_sample); + EXPECT_EQ(nullptr, data->last_phase_snapshot()->prev); +} - DeathDataSnapshot snapshot(*data); - EXPECT_EQ(2, snapshot.count); - EXPECT_EQ(2 * run_ms, snapshot.run_duration_sum); - EXPECT_EQ(run_ms, snapshot.run_duration_max); - EXPECT_EQ(run_ms, snapshot.run_duration_sample); - EXPECT_EQ(2 * queue_ms, snapshot.queue_duration_sum); - EXPECT_EQ(queue_ms, snapshot.queue_duration_max); - EXPECT_EQ(queue_ms, snapshot.queue_duration_sample); +TEST_F(TrackedObjectsTest, Delta) { + ThreadData::InitializeAndSetTrackingStatus(ThreadData::PROFILING_ACTIVE); + + DeathDataSnapshot snapshot; + snapshot.count = 10; + snapshot.run_duration_sum = 100; + snapshot.run_duration_max = 50; + snapshot.run_duration_sample = 25; + snapshot.queue_duration_sum = 200; + snapshot.queue_duration_max = 101; + snapshot.queue_duration_sample = 26; + + DeathDataSnapshot older_snapshot; + older_snapshot.count = 2; + older_snapshot.run_duration_sum = 95; + older_snapshot.run_duration_max = 48; + older_snapshot.run_duration_sample = 22; + older_snapshot.queue_duration_sum = 190; + older_snapshot.queue_duration_max = 99; + older_snapshot.queue_duration_sample = 21; + + const DeathDataSnapshot& delta = snapshot.Delta(older_snapshot); + EXPECT_EQ(8, delta.count); + EXPECT_EQ(5, delta.run_duration_sum); + EXPECT_EQ(50, delta.run_duration_max); + EXPECT_EQ(25, delta.run_duration_sample); + EXPECT_EQ(10, delta.queue_duration_sum); + EXPECT_EQ(101, delta.queue_duration_max); + EXPECT_EQ(26, delta.queue_duration_sample); } TEST_F(TrackedObjectsTest, DeactivatedBirthOnlyToSnapshotWorkerThread) { // Start in the deactivated state. - if (!ThreadData::InitializeAndSetTrackingStatus(ThreadData::DEACTIVATED)) { - return; - } + ThreadData::InitializeAndSetTrackingStatus(ThreadData::DEACTIVATED); const char kFunction[] = "DeactivatedBirthOnlyToSnapshotWorkerThread"; Location location(kFunction, kFile, kLineNumber, NULL); TallyABirth(location, std::string()); ProcessDataSnapshot process_data; - ThreadData::Snapshot(false, &process_data); - EXPECT_EQ(0u, process_data.tasks.size()); - EXPECT_EQ(0u, process_data.descendants.size()); + ThreadData::Snapshot(0, &process_data); + + ASSERT_EQ(1u, process_data.phased_snapshots.size()); + + auto it = process_data.phased_snapshots.find(0); + ASSERT_TRUE(it != process_data.phased_snapshots.end()); + const ProcessDataPhaseSnapshot& process_data_phase = it->second; + + ASSERT_EQ(0u, process_data_phase.tasks.size()); + EXPECT_EQ(base::GetCurrentProcId(), process_data.process_id); } TEST_F(TrackedObjectsTest, DeactivatedBirthOnlyToSnapshotMainThread) { // Start in the deactivated state. - if (!ThreadData::InitializeAndSetTrackingStatus(ThreadData::DEACTIVATED)) { - return; - } + ThreadData::InitializeAndSetTrackingStatus(ThreadData::DEACTIVATED); const char kFunction[] = "DeactivatedBirthOnlyToSnapshotMainThread"; Location location(kFunction, kFile, kLineNumber, NULL); TallyABirth(location, kMainThreadName); ProcessDataSnapshot process_data; - ThreadData::Snapshot(false, &process_data); - EXPECT_EQ(0u, process_data.tasks.size()); - EXPECT_EQ(0u, process_data.descendants.size()); + ThreadData::Snapshot(0, &process_data); + + ASSERT_EQ(1u, process_data.phased_snapshots.size()); + + auto it = process_data.phased_snapshots.find(0); + ASSERT_TRUE(it != process_data.phased_snapshots.end()); + const ProcessDataPhaseSnapshot& process_data_phase = it->second; + + ASSERT_EQ(0u, process_data_phase.tasks.size()); + EXPECT_EQ(base::GetCurrentProcId(), process_data.process_id); } TEST_F(TrackedObjectsTest, BirthOnlyToSnapshotWorkerThread) { - if (!ThreadData::InitializeAndSetTrackingStatus( - ThreadData::PROFILING_CHILDREN_ACTIVE)) { - return; - } + ThreadData::InitializeAndSetTrackingStatus(ThreadData::PROFILING_ACTIVE); const char kFunction[] = "BirthOnlyToSnapshotWorkerThread"; Location location(kFunction, kFile, kLineNumber, NULL); TallyABirth(location, std::string()); ProcessDataSnapshot process_data; - ThreadData::Snapshot(false, &process_data); + ThreadData::Snapshot(0, &process_data); ExpectSimpleProcessData(process_data, kFunction, kWorkerThreadName, kStillAlive, 1, 0, 0); } TEST_F(TrackedObjectsTest, BirthOnlyToSnapshotMainThread) { - if (!ThreadData::InitializeAndSetTrackingStatus( - ThreadData::PROFILING_CHILDREN_ACTIVE)) { - return; - } + ThreadData::InitializeAndSetTrackingStatus(ThreadData::PROFILING_ACTIVE); const char kFunction[] = "BirthOnlyToSnapshotMainThread"; Location location(kFunction, kFile, kLineNumber, NULL); TallyABirth(location, kMainThreadName); ProcessDataSnapshot process_data; - ThreadData::Snapshot(false, &process_data); + ThreadData::Snapshot(0, &process_data); ExpectSimpleProcessData(process_data, kFunction, kMainThreadName, kStillAlive, 1, 0, 0); } TEST_F(TrackedObjectsTest, LifeCycleToSnapshotMainThread) { - if (!ThreadData::InitializeAndSetTrackingStatus( - ThreadData::PROFILING_CHILDREN_ACTIVE)) { - return; - } + ThreadData::InitializeAndSetTrackingStatus(ThreadData::PROFILING_ACTIVE); const char kFunction[] = "LifeCycleToSnapshotMainThread"; Location location(kFunction, kFile, kLineNumber, NULL); TallyABirth(location, kMainThreadName); - const base::TimeTicks kTimePosted = base::TimeTicks() + - base::TimeDelta::FromMilliseconds(1); + const TrackedTime kTimePosted = TrackedTime::FromMilliseconds(1); const base::TimeTicks kDelayedStartTime = base::TimeTicks(); // TrackingInfo will call TallyABirth() during construction. base::TrackingInfo pending_task(location, kDelayedStartTime); @@ -400,36 +465,24 @@ TEST_F(TrackedObjectsTest, LifeCycleToSnapshotMainThread) { ThreadData::TallyRunOnNamedThreadIfTracking(pending_task, stopwatch); ProcessDataSnapshot process_data; - ThreadData::Snapshot(false, &process_data); + ThreadData::Snapshot(0, &process_data); ExpectSimpleProcessData(process_data, kFunction, kMainThreadName, kMainThreadName, 1, 2, 4); } -// We will deactivate tracking after the birth, and before the death, and -// demonstrate that the lifecycle is completely tallied. This ensures that -// our tallied births are matched by tallied deaths (except for when the -// task is still running, or is queued). -TEST_F(TrackedObjectsTest, LifeCycleMidDeactivatedToSnapshotMainThread) { - if (!ThreadData::InitializeAndSetTrackingStatus( - ThreadData::PROFILING_CHILDREN_ACTIVE)) { - return; - } +TEST_F(TrackedObjectsTest, TwoPhases) { + ThreadData::InitializeAndSetTrackingStatus(ThreadData::PROFILING_ACTIVE); - const char kFunction[] = "LifeCycleMidDeactivatedToSnapshotMainThread"; + const char kFunction[] = "TwoPhases"; Location location(kFunction, kFile, kLineNumber, NULL); TallyABirth(location, kMainThreadName); - const base::TimeTicks kTimePosted = base::TimeTicks() + - base::TimeDelta::FromMilliseconds(1); + const TrackedTime kTimePosted = TrackedTime::FromMilliseconds(1); const base::TimeTicks kDelayedStartTime = base::TimeTicks(); // TrackingInfo will call TallyABirth() during construction. base::TrackingInfo pending_task(location, kDelayedStartTime); pending_task.time_posted = kTimePosted; // Overwrite implied Now(). - // Turn off tracking now that we have births. - EXPECT_TRUE(ThreadData::InitializeAndSetTrackingStatus( - ThreadData::DEACTIVATED)); - const unsigned int kStartOfRun = 5; const unsigned int kEndOfRun = 7; SetTestTime(kStartOfRun); @@ -440,26 +493,231 @@ TEST_F(TrackedObjectsTest, LifeCycleMidDeactivatedToSnapshotMainThread) { ThreadData::TallyRunOnNamedThreadIfTracking(pending_task, stopwatch); + ThreadData::OnProfilingPhaseCompleted(0); + + TallyABirth(location, kMainThreadName); + + const TrackedTime kTimePosted1 = TrackedTime::FromMilliseconds(9); + const base::TimeTicks kDelayedStartTime1 = base::TimeTicks(); + // TrackingInfo will call TallyABirth() during construction. + base::TrackingInfo pending_task1(location, kDelayedStartTime1); + pending_task1.time_posted = kTimePosted1; // Overwrite implied Now(). + + const unsigned int kStartOfRun1 = 11; + const unsigned int kEndOfRun1 = 21; + SetTestTime(kStartOfRun1); + TaskStopwatch stopwatch1; + stopwatch1.Start(); + SetTestTime(kEndOfRun1); + stopwatch1.Stop(); + + ThreadData::TallyRunOnNamedThreadIfTracking(pending_task1, stopwatch1); + ProcessDataSnapshot process_data; - ThreadData::Snapshot(false, &process_data); - ExpectSimpleProcessData(process_data, kFunction, kMainThreadName, - kMainThreadName, 1, 2, 4); + ThreadData::Snapshot(1, &process_data); + + ASSERT_EQ(2u, process_data.phased_snapshots.size()); + + auto it0 = process_data.phased_snapshots.find(0); + ASSERT_TRUE(it0 != process_data.phased_snapshots.end()); + const ProcessDataPhaseSnapshot& process_data_phase0 = it0->second; + + ASSERT_EQ(1u, process_data_phase0.tasks.size()); + + EXPECT_EQ(kFile, process_data_phase0.tasks[0].birth.location.file_name); + EXPECT_EQ(kFunction, + process_data_phase0.tasks[0].birth.location.function_name); + EXPECT_EQ(kLineNumber, + process_data_phase0.tasks[0].birth.location.line_number); + + EXPECT_EQ(kMainThreadName, process_data_phase0.tasks[0].birth.thread_name); + + EXPECT_EQ(1, process_data_phase0.tasks[0].death_data.count); + EXPECT_EQ(2, process_data_phase0.tasks[0].death_data.run_duration_sum); + EXPECT_EQ(2, process_data_phase0.tasks[0].death_data.run_duration_max); + EXPECT_EQ(2, process_data_phase0.tasks[0].death_data.run_duration_sample); + EXPECT_EQ(4, process_data_phase0.tasks[0].death_data.queue_duration_sum); + EXPECT_EQ(4, process_data_phase0.tasks[0].death_data.queue_duration_max); + EXPECT_EQ(4, process_data_phase0.tasks[0].death_data.queue_duration_sample); + + EXPECT_EQ(kMainThreadName, process_data_phase0.tasks[0].death_thread_name); + + auto it1 = process_data.phased_snapshots.find(1); + ASSERT_TRUE(it1 != process_data.phased_snapshots.end()); + const ProcessDataPhaseSnapshot& process_data_phase1 = it1->second; + + ASSERT_EQ(1u, process_data_phase1.tasks.size()); + + EXPECT_EQ(kFile, process_data_phase1.tasks[0].birth.location.file_name); + EXPECT_EQ(kFunction, + process_data_phase1.tasks[0].birth.location.function_name); + EXPECT_EQ(kLineNumber, + process_data_phase1.tasks[0].birth.location.line_number); + + EXPECT_EQ(kMainThreadName, process_data_phase1.tasks[0].birth.thread_name); + + EXPECT_EQ(1, process_data_phase1.tasks[0].death_data.count); + EXPECT_EQ(10, process_data_phase1.tasks[0].death_data.run_duration_sum); + EXPECT_EQ(10, process_data_phase1.tasks[0].death_data.run_duration_max); + EXPECT_EQ(10, process_data_phase1.tasks[0].death_data.run_duration_sample); + EXPECT_EQ(2, process_data_phase1.tasks[0].death_data.queue_duration_sum); + EXPECT_EQ(2, process_data_phase1.tasks[0].death_data.queue_duration_max); + EXPECT_EQ(2, process_data_phase1.tasks[0].death_data.queue_duration_sample); + + EXPECT_EQ(kMainThreadName, process_data_phase1.tasks[0].death_thread_name); + + EXPECT_EQ(base::GetCurrentProcId(), process_data.process_id); } -// We will deactivate tracking before starting a life cycle, and neither -// the birth nor the death will be recorded. -TEST_F(TrackedObjectsTest, LifeCyclePreDeactivatedToSnapshotMainThread) { - // Start in the deactivated state. - if (!ThreadData::InitializeAndSetTrackingStatus(ThreadData::DEACTIVATED)) { - return; +TEST_F(TrackedObjectsTest, ThreePhases) { + ThreadData::InitializeAndSetTrackingStatus(ThreadData::PROFILING_ACTIVE); + + const char kFunction[] = "ThreePhases"; + Location location(kFunction, kFile, kLineNumber, NULL); + + // Phase 0 + { + TallyABirth(location, kMainThreadName); + + // TrackingInfo will call TallyABirth() during construction. + SetTestTime(10); + base::TrackingInfo pending_task(location, base::TimeTicks()); + + SetTestTime(17); + TaskStopwatch stopwatch; + stopwatch.Start(); + SetTestTime(23); + stopwatch.Stop(); + + ThreadData::TallyRunOnNamedThreadIfTracking(pending_task, stopwatch); } - const char kFunction[] = "LifeCyclePreDeactivatedToSnapshotMainThread"; + ThreadData::OnProfilingPhaseCompleted(0); + + // Phase 1 + { + TallyABirth(location, kMainThreadName); + + SetTestTime(30); + base::TrackingInfo pending_task(location, base::TimeTicks()); + + SetTestTime(35); + TaskStopwatch stopwatch; + stopwatch.Start(); + SetTestTime(39); + stopwatch.Stop(); + + ThreadData::TallyRunOnNamedThreadIfTracking(pending_task, stopwatch); + } + + ThreadData::OnProfilingPhaseCompleted(1); + + // Phase 2 + { + TallyABirth(location, kMainThreadName); + + // TrackingInfo will call TallyABirth() during construction. + SetTestTime(40); + base::TrackingInfo pending_task(location, base::TimeTicks()); + + SetTestTime(43); + TaskStopwatch stopwatch; + stopwatch.Start(); + SetTestTime(45); + stopwatch.Stop(); + + ThreadData::TallyRunOnNamedThreadIfTracking(pending_task, stopwatch); + } + + // Snapshot and check results. + ProcessDataSnapshot process_data; + ThreadData::Snapshot(2, &process_data); + + ASSERT_EQ(3u, process_data.phased_snapshots.size()); + + auto it0 = process_data.phased_snapshots.find(0); + ASSERT_TRUE(it0 != process_data.phased_snapshots.end()); + const ProcessDataPhaseSnapshot& process_data_phase0 = it0->second; + + ASSERT_EQ(1u, process_data_phase0.tasks.size()); + + EXPECT_EQ(kFile, process_data_phase0.tasks[0].birth.location.file_name); + EXPECT_EQ(kFunction, + process_data_phase0.tasks[0].birth.location.function_name); + EXPECT_EQ(kLineNumber, + process_data_phase0.tasks[0].birth.location.line_number); + + EXPECT_EQ(kMainThreadName, process_data_phase0.tasks[0].birth.thread_name); + + EXPECT_EQ(1, process_data_phase0.tasks[0].death_data.count); + EXPECT_EQ(6, process_data_phase0.tasks[0].death_data.run_duration_sum); + EXPECT_EQ(6, process_data_phase0.tasks[0].death_data.run_duration_max); + EXPECT_EQ(6, process_data_phase0.tasks[0].death_data.run_duration_sample); + EXPECT_EQ(7, process_data_phase0.tasks[0].death_data.queue_duration_sum); + EXPECT_EQ(7, process_data_phase0.tasks[0].death_data.queue_duration_max); + EXPECT_EQ(7, process_data_phase0.tasks[0].death_data.queue_duration_sample); + + EXPECT_EQ(kMainThreadName, process_data_phase0.tasks[0].death_thread_name); + + auto it1 = process_data.phased_snapshots.find(1); + ASSERT_TRUE(it1 != process_data.phased_snapshots.end()); + const ProcessDataPhaseSnapshot& process_data_phase1 = it1->second; + + ASSERT_EQ(1u, process_data_phase1.tasks.size()); + + EXPECT_EQ(kFile, process_data_phase1.tasks[0].birth.location.file_name); + EXPECT_EQ(kFunction, + process_data_phase1.tasks[0].birth.location.function_name); + EXPECT_EQ(kLineNumber, + process_data_phase1.tasks[0].birth.location.line_number); + + EXPECT_EQ(kMainThreadName, process_data_phase1.tasks[0].birth.thread_name); + + EXPECT_EQ(1, process_data_phase1.tasks[0].death_data.count); + EXPECT_EQ(4, process_data_phase1.tasks[0].death_data.run_duration_sum); + EXPECT_EQ(4, process_data_phase1.tasks[0].death_data.run_duration_max); + EXPECT_EQ(4, process_data_phase1.tasks[0].death_data.run_duration_sample); + EXPECT_EQ(5, process_data_phase1.tasks[0].death_data.queue_duration_sum); + EXPECT_EQ(5, process_data_phase1.tasks[0].death_data.queue_duration_max); + EXPECT_EQ(5, process_data_phase1.tasks[0].death_data.queue_duration_sample); + + EXPECT_EQ(kMainThreadName, process_data_phase1.tasks[0].death_thread_name); + + auto it2 = process_data.phased_snapshots.find(2); + ASSERT_TRUE(it2 != process_data.phased_snapshots.end()); + const ProcessDataPhaseSnapshot& process_data_phase2 = it2->second; + + ASSERT_EQ(1u, process_data_phase2.tasks.size()); + + EXPECT_EQ(kFile, process_data_phase2.tasks[0].birth.location.file_name); + EXPECT_EQ(kFunction, + process_data_phase2.tasks[0].birth.location.function_name); + EXPECT_EQ(kLineNumber, + process_data_phase2.tasks[0].birth.location.line_number); + + EXPECT_EQ(kMainThreadName, process_data_phase2.tasks[0].birth.thread_name); + + EXPECT_EQ(1, process_data_phase2.tasks[0].death_data.count); + EXPECT_EQ(2, process_data_phase2.tasks[0].death_data.run_duration_sum); + EXPECT_EQ(2, process_data_phase2.tasks[0].death_data.run_duration_max); + EXPECT_EQ(2, process_data_phase2.tasks[0].death_data.run_duration_sample); + EXPECT_EQ(3, process_data_phase2.tasks[0].death_data.queue_duration_sum); + EXPECT_EQ(3, process_data_phase2.tasks[0].death_data.queue_duration_max); + EXPECT_EQ(3, process_data_phase2.tasks[0].death_data.queue_duration_sample); + + EXPECT_EQ(kMainThreadName, process_data_phase2.tasks[0].death_thread_name); + + EXPECT_EQ(base::GetCurrentProcId(), process_data.process_id); +} + +TEST_F(TrackedObjectsTest, TwoPhasesSecondEmpty) { + ThreadData::InitializeAndSetTrackingStatus(ThreadData::PROFILING_ACTIVE); + + const char kFunction[] = "TwoPhasesSecondEmpty"; Location location(kFunction, kFile, kLineNumber, NULL); - TallyABirth(location, kMainThreadName); + ThreadData::InitializeThreadContext(kMainThreadName); - const base::TimeTicks kTimePosted = base::TimeTicks() + - base::TimeDelta::FromMilliseconds(1); + const TrackedTime kTimePosted = TrackedTime::FromMilliseconds(1); const base::TimeTicks kDelayedStartTime = base::TimeTicks(); // TrackingInfo will call TallyABirth() during construction. base::TrackingInfo pending_task(location, kDelayedStartTime); @@ -475,26 +733,61 @@ TEST_F(TrackedObjectsTest, LifeCyclePreDeactivatedToSnapshotMainThread) { ThreadData::TallyRunOnNamedThreadIfTracking(pending_task, stopwatch); + ThreadData::OnProfilingPhaseCompleted(0); + ProcessDataSnapshot process_data; - ThreadData::Snapshot(false, &process_data); - EXPECT_EQ(0u, process_data.tasks.size()); - EXPECT_EQ(0u, process_data.descendants.size()); + ThreadData::Snapshot(1, &process_data); + + ASSERT_EQ(2u, process_data.phased_snapshots.size()); + + auto it0 = process_data.phased_snapshots.find(0); + ASSERT_TRUE(it0 != process_data.phased_snapshots.end()); + const ProcessDataPhaseSnapshot& process_data_phase0 = it0->second; + + ASSERT_EQ(1u, process_data_phase0.tasks.size()); + + EXPECT_EQ(kFile, process_data_phase0.tasks[0].birth.location.file_name); + EXPECT_EQ(kFunction, + process_data_phase0.tasks[0].birth.location.function_name); + EXPECT_EQ(kLineNumber, + process_data_phase0.tasks[0].birth.location.line_number); + + EXPECT_EQ(kMainThreadName, process_data_phase0.tasks[0].birth.thread_name); + + EXPECT_EQ(1, process_data_phase0.tasks[0].death_data.count); + EXPECT_EQ(2, process_data_phase0.tasks[0].death_data.run_duration_sum); + EXPECT_EQ(2, process_data_phase0.tasks[0].death_data.run_duration_max); + EXPECT_EQ(2, process_data_phase0.tasks[0].death_data.run_duration_sample); + EXPECT_EQ(4, process_data_phase0.tasks[0].death_data.queue_duration_sum); + EXPECT_EQ(4, process_data_phase0.tasks[0].death_data.queue_duration_max); + EXPECT_EQ(4, process_data_phase0.tasks[0].death_data.queue_duration_sample); + + EXPECT_EQ(kMainThreadName, process_data_phase0.tasks[0].death_thread_name); + + auto it1 = process_data.phased_snapshots.find(1); + ASSERT_TRUE(it1 != process_data.phased_snapshots.end()); + const ProcessDataPhaseSnapshot& process_data_phase1 = it1->second; + + ASSERT_EQ(0u, process_data_phase1.tasks.size()); + EXPECT_EQ(base::GetCurrentProcId(), process_data.process_id); } -TEST_F(TrackedObjectsTest, LifeCycleToSnapshotWorkerThread) { - if (!ThreadData::InitializeAndSetTrackingStatus( - ThreadData::PROFILING_CHILDREN_ACTIVE)) { - return; - } +TEST_F(TrackedObjectsTest, TwoPhasesFirstEmpty) { + ThreadData::InitializeAndSetTrackingStatus(ThreadData::PROFILING_ACTIVE); + + ThreadData::OnProfilingPhaseCompleted(0); - const char kFunction[] = "LifeCycleToSnapshotWorkerThread"; + const char kFunction[] = "TwoPhasesSecondEmpty"; Location location(kFunction, kFile, kLineNumber, NULL); - // Do not delete |birth|. We don't own it. - Births* birth = ThreadData::TallyABirthIfActive(location); - EXPECT_NE(reinterpret_cast<Births*>(NULL), birth); + ThreadData::InitializeThreadContext(kMainThreadName); + + const TrackedTime kTimePosted = TrackedTime::FromMilliseconds(1); + const base::TimeTicks kDelayedStartTime = base::TimeTicks(); + // TrackingInfo will call TallyABirth() during construction. + base::TrackingInfo pending_task(location, kDelayedStartTime); + pending_task.time_posted = kTimePosted; // Overwrite implied Now(). - const unsigned int kTimePosted = 1; const unsigned int kStartOfRun = 5; const unsigned int kEndOfRun = 7; SetTestTime(kStartOfRun); @@ -503,61 +796,124 @@ TEST_F(TrackedObjectsTest, LifeCycleToSnapshotWorkerThread) { SetTestTime(kEndOfRun); stopwatch.Stop(); - ThreadData::TallyRunOnWorkerThreadIfTracking( - birth, TrackedTime() + Duration::FromMilliseconds(kTimePosted), stopwatch); + ThreadData::TallyRunOnNamedThreadIfTracking(pending_task, stopwatch); - // Call for the ToSnapshot, but tell it to not reset the maxes after scanning. ProcessDataSnapshot process_data; - ThreadData::Snapshot(false, &process_data); - ExpectSimpleProcessData(process_data, kFunction, kWorkerThreadName, - kWorkerThreadName, 1, 2, 4); + ThreadData::Snapshot(1, &process_data); - // Call for the ToSnapshot, but tell it to reset the maxes after scanning. - // We'll still get the same values, but the data will be reset (which we'll - // see in a moment). - ProcessDataSnapshot process_data_pre_reset; - ThreadData::Snapshot(true, &process_data_pre_reset); - ExpectSimpleProcessData(process_data, kFunction, kWorkerThreadName, - kWorkerThreadName, 1, 2, 4); - - // Call for the ToSnapshot, and now we'll see the result of the last - // translation, as the max will have been pushed back to zero. - ProcessDataSnapshot process_data_post_reset; - ThreadData::Snapshot(true, &process_data_post_reset); - ASSERT_EQ(1u, process_data_post_reset.tasks.size()); - EXPECT_EQ(kFile, process_data_post_reset.tasks[0].birth.location.file_name); + ASSERT_EQ(1u, process_data.phased_snapshots.size()); + + auto it1 = process_data.phased_snapshots.find(1); + ASSERT_TRUE(it1 != process_data.phased_snapshots.end()); + const ProcessDataPhaseSnapshot& process_data_phase1 = it1->second; + + ASSERT_EQ(1u, process_data_phase1.tasks.size()); + + EXPECT_EQ(kFile, process_data_phase1.tasks[0].birth.location.file_name); EXPECT_EQ(kFunction, - process_data_post_reset.tasks[0].birth.location.function_name); + process_data_phase1.tasks[0].birth.location.function_name); EXPECT_EQ(kLineNumber, - process_data_post_reset.tasks[0].birth.location.line_number); - EXPECT_EQ(kWorkerThreadName, - process_data_post_reset.tasks[0].birth.thread_name); - EXPECT_EQ(1, process_data_post_reset.tasks[0].death_data.count); - EXPECT_EQ(2, process_data_post_reset.tasks[0].death_data.run_duration_sum); - EXPECT_EQ(0, process_data_post_reset.tasks[0].death_data.run_duration_max); - EXPECT_EQ(2, process_data_post_reset.tasks[0].death_data.run_duration_sample); - EXPECT_EQ(4, process_data_post_reset.tasks[0].death_data.queue_duration_sum); - EXPECT_EQ(0, process_data_post_reset.tasks[0].death_data.queue_duration_max); - EXPECT_EQ(4, - process_data_post_reset.tasks[0].death_data.queue_duration_sample); - EXPECT_EQ(kWorkerThreadName, - process_data_post_reset.tasks[0].death_thread_name); - EXPECT_EQ(0u, process_data_post_reset.descendants.size()); - EXPECT_EQ(base::GetCurrentProcId(), process_data_post_reset.process_id); + process_data_phase1.tasks[0].birth.location.line_number); + + EXPECT_EQ(kMainThreadName, process_data_phase1.tasks[0].birth.thread_name); + + EXPECT_EQ(1, process_data_phase1.tasks[0].death_data.count); + EXPECT_EQ(2, process_data_phase1.tasks[0].death_data.run_duration_sum); + EXPECT_EQ(2, process_data_phase1.tasks[0].death_data.run_duration_max); + EXPECT_EQ(2, process_data_phase1.tasks[0].death_data.run_duration_sample); + EXPECT_EQ(4, process_data_phase1.tasks[0].death_data.queue_duration_sum); + EXPECT_EQ(4, process_data_phase1.tasks[0].death_data.queue_duration_max); + EXPECT_EQ(4, process_data_phase1.tasks[0].death_data.queue_duration_sample); + + EXPECT_EQ(kMainThreadName, process_data_phase1.tasks[0].death_thread_name); + + EXPECT_EQ(base::GetCurrentProcId(), process_data.process_id); +} + +// We will deactivate tracking after the birth, and before the death, and +// demonstrate that the lifecycle is completely tallied. This ensures that +// our tallied births are matched by tallied deaths (except for when the +// task is still running, or is queued). +TEST_F(TrackedObjectsTest, LifeCycleMidDeactivatedToSnapshotMainThread) { + ThreadData::InitializeAndSetTrackingStatus(ThreadData::PROFILING_ACTIVE); + + const char kFunction[] = "LifeCycleMidDeactivatedToSnapshotMainThread"; + Location location(kFunction, kFile, kLineNumber, NULL); + TallyABirth(location, kMainThreadName); + + const TrackedTime kTimePosted = TrackedTime::FromMilliseconds(1); + const base::TimeTicks kDelayedStartTime = base::TimeTicks(); + // TrackingInfo will call TallyABirth() during construction. + base::TrackingInfo pending_task(location, kDelayedStartTime); + pending_task.time_posted = kTimePosted; // Overwrite implied Now(). + + // Turn off tracking now that we have births. + ThreadData::InitializeAndSetTrackingStatus(ThreadData::DEACTIVATED); + + const unsigned int kStartOfRun = 5; + const unsigned int kEndOfRun = 7; + SetTestTime(kStartOfRun); + TaskStopwatch stopwatch; + stopwatch.Start(); + SetTestTime(kEndOfRun); + stopwatch.Stop(); + + ThreadData::TallyRunOnNamedThreadIfTracking(pending_task, stopwatch); + + ProcessDataSnapshot process_data; + ThreadData::Snapshot(0, &process_data); + ExpectSimpleProcessData(process_data, kFunction, kMainThreadName, + kMainThreadName, 1, 2, 4); +} + +// We will deactivate tracking before starting a life cycle, and neither +// the birth nor the death will be recorded. +TEST_F(TrackedObjectsTest, LifeCyclePreDeactivatedToSnapshotMainThread) { + // Start in the deactivated state. + ThreadData::InitializeAndSetTrackingStatus(ThreadData::DEACTIVATED); + + const char kFunction[] = "LifeCyclePreDeactivatedToSnapshotMainThread"; + Location location(kFunction, kFile, kLineNumber, NULL); + TallyABirth(location, kMainThreadName); + + const TrackedTime kTimePosted = TrackedTime::FromMilliseconds(1); + const base::TimeTicks kDelayedStartTime = base::TimeTicks(); + // TrackingInfo will call TallyABirth() during construction. + base::TrackingInfo pending_task(location, kDelayedStartTime); + pending_task.time_posted = kTimePosted; // Overwrite implied Now(). + + const unsigned int kStartOfRun = 5; + const unsigned int kEndOfRun = 7; + SetTestTime(kStartOfRun); + TaskStopwatch stopwatch; + stopwatch.Start(); + SetTestTime(kEndOfRun); + stopwatch.Stop(); + + ThreadData::TallyRunOnNamedThreadIfTracking(pending_task, stopwatch); + + ProcessDataSnapshot process_data; + ThreadData::Snapshot(0, &process_data); + + ASSERT_EQ(1u, process_data.phased_snapshots.size()); + + auto it = process_data.phased_snapshots.find(0); + ASSERT_TRUE(it != process_data.phased_snapshots.end()); + const ProcessDataPhaseSnapshot& process_data_phase = it->second; + + ASSERT_EQ(0u, process_data_phase.tasks.size()); + + EXPECT_EQ(base::GetCurrentProcId(), process_data.process_id); } TEST_F(TrackedObjectsTest, TwoLives) { - if (!ThreadData::InitializeAndSetTrackingStatus( - ThreadData::PROFILING_CHILDREN_ACTIVE)) { - return; - } + ThreadData::InitializeAndSetTrackingStatus(ThreadData::PROFILING_ACTIVE); const char kFunction[] = "TwoLives"; Location location(kFunction, kFile, kLineNumber, NULL); TallyABirth(location, kMainThreadName); - const base::TimeTicks kTimePosted = base::TimeTicks() + - base::TimeDelta::FromMilliseconds(1); + const TrackedTime kTimePosted = TrackedTime::FromMilliseconds(1); const base::TimeTicks kDelayedStartTime = base::TimeTicks(); // TrackingInfo will call TallyABirth() during construction. base::TrackingInfo pending_task(location, kDelayedStartTime); @@ -585,24 +941,20 @@ TEST_F(TrackedObjectsTest, TwoLives) { ThreadData::TallyRunOnNamedThreadIfTracking(pending_task2, stopwatch2); ProcessDataSnapshot process_data; - ThreadData::Snapshot(false, &process_data); + ThreadData::Snapshot(0, &process_data); ExpectSimpleProcessData(process_data, kFunction, kMainThreadName, kMainThreadName, 2, 2, 4); } TEST_F(TrackedObjectsTest, DifferentLives) { - if (!ThreadData::InitializeAndSetTrackingStatus( - ThreadData::PROFILING_CHILDREN_ACTIVE)) { - return; - } + ThreadData::InitializeAndSetTrackingStatus(ThreadData::PROFILING_ACTIVE); // Use a well named thread. ThreadData::InitializeThreadContext(kMainThreadName); const char kFunction[] = "DifferentLives"; Location location(kFunction, kFile, kLineNumber, NULL); - const base::TimeTicks kTimePosted = base::TimeTicks() + - base::TimeDelta::FromMilliseconds(1); + const TrackedTime kTimePosted = TrackedTime::FromMilliseconds(1); const base::TimeTicks kDelayedStartTime = base::TimeTicks(); // TrackingInfo will call TallyABirth() during construction. base::TrackingInfo pending_task(location, kDelayedStartTime); @@ -626,50 +978,54 @@ TEST_F(TrackedObjectsTest, DifferentLives) { pending_task2.time_posted = kTimePosted; // Overwrite implied Now(). ProcessDataSnapshot process_data; - ThreadData::Snapshot(false, &process_data); - ASSERT_EQ(2u, process_data.tasks.size()); - - EXPECT_EQ(kFile, process_data.tasks[0].birth.location.file_name); - EXPECT_EQ(kFunction, process_data.tasks[0].birth.location.function_name); - EXPECT_EQ(kLineNumber, process_data.tasks[0].birth.location.line_number); - EXPECT_EQ(kMainThreadName, process_data.tasks[0].birth.thread_name); - EXPECT_EQ(1, process_data.tasks[0].death_data.count); - EXPECT_EQ(2, process_data.tasks[0].death_data.run_duration_sum); - EXPECT_EQ(2, process_data.tasks[0].death_data.run_duration_max); - EXPECT_EQ(2, process_data.tasks[0].death_data.run_duration_sample); - EXPECT_EQ(4, process_data.tasks[0].death_data.queue_duration_sum); - EXPECT_EQ(4, process_data.tasks[0].death_data.queue_duration_max); - EXPECT_EQ(4, process_data.tasks[0].death_data.queue_duration_sample); - EXPECT_EQ(kMainThreadName, process_data.tasks[0].death_thread_name); - EXPECT_EQ(kFile, process_data.tasks[1].birth.location.file_name); - EXPECT_EQ(kFunction, process_data.tasks[1].birth.location.function_name); + ThreadData::Snapshot(0, &process_data); + + ASSERT_EQ(1u, process_data.phased_snapshots.size()); + auto it = process_data.phased_snapshots.find(0); + ASSERT_TRUE(it != process_data.phased_snapshots.end()); + const ProcessDataPhaseSnapshot& process_data_phase = it->second; + + ASSERT_EQ(2u, process_data_phase.tasks.size()); + + EXPECT_EQ(kFile, process_data_phase.tasks[0].birth.location.file_name); + EXPECT_EQ(kFunction, + process_data_phase.tasks[0].birth.location.function_name); + EXPECT_EQ(kLineNumber, + process_data_phase.tasks[0].birth.location.line_number); + EXPECT_EQ(kMainThreadName, process_data_phase.tasks[0].birth.thread_name); + EXPECT_EQ(1, process_data_phase.tasks[0].death_data.count); + EXPECT_EQ(2, process_data_phase.tasks[0].death_data.run_duration_sum); + EXPECT_EQ(2, process_data_phase.tasks[0].death_data.run_duration_max); + EXPECT_EQ(2, process_data_phase.tasks[0].death_data.run_duration_sample); + EXPECT_EQ(4, process_data_phase.tasks[0].death_data.queue_duration_sum); + EXPECT_EQ(4, process_data_phase.tasks[0].death_data.queue_duration_max); + EXPECT_EQ(4, process_data_phase.tasks[0].death_data.queue_duration_sample); + EXPECT_EQ(kMainThreadName, process_data_phase.tasks[0].death_thread_name); + EXPECT_EQ(kFile, process_data_phase.tasks[1].birth.location.file_name); + EXPECT_EQ(kFunction, + process_data_phase.tasks[1].birth.location.function_name); EXPECT_EQ(kSecondFakeLineNumber, - process_data.tasks[1].birth.location.line_number); - EXPECT_EQ(kMainThreadName, process_data.tasks[1].birth.thread_name); - EXPECT_EQ(1, process_data.tasks[1].death_data.count); - EXPECT_EQ(0, process_data.tasks[1].death_data.run_duration_sum); - EXPECT_EQ(0, process_data.tasks[1].death_data.run_duration_max); - EXPECT_EQ(0, process_data.tasks[1].death_data.run_duration_sample); - EXPECT_EQ(0, process_data.tasks[1].death_data.queue_duration_sum); - EXPECT_EQ(0, process_data.tasks[1].death_data.queue_duration_max); - EXPECT_EQ(0, process_data.tasks[1].death_data.queue_duration_sample); - EXPECT_EQ(kStillAlive, process_data.tasks[1].death_thread_name); - EXPECT_EQ(0u, process_data.descendants.size()); + process_data_phase.tasks[1].birth.location.line_number); + EXPECT_EQ(kMainThreadName, process_data_phase.tasks[1].birth.thread_name); + EXPECT_EQ(1, process_data_phase.tasks[1].death_data.count); + EXPECT_EQ(0, process_data_phase.tasks[1].death_data.run_duration_sum); + EXPECT_EQ(0, process_data_phase.tasks[1].death_data.run_duration_max); + EXPECT_EQ(0, process_data_phase.tasks[1].death_data.run_duration_sample); + EXPECT_EQ(0, process_data_phase.tasks[1].death_data.queue_duration_sum); + EXPECT_EQ(0, process_data_phase.tasks[1].death_data.queue_duration_max); + EXPECT_EQ(0, process_data_phase.tasks[1].death_data.queue_duration_sample); + EXPECT_EQ(kStillAlive, process_data_phase.tasks[1].death_thread_name); EXPECT_EQ(base::GetCurrentProcId(), process_data.process_id); } TEST_F(TrackedObjectsTest, TaskWithNestedExclusion) { - if (!ThreadData::InitializeAndSetTrackingStatus( - ThreadData::PROFILING_CHILDREN_ACTIVE)) { - return; - } + ThreadData::InitializeAndSetTrackingStatus(ThreadData::PROFILING_ACTIVE); const char kFunction[] = "TaskWithNestedExclusion"; Location location(kFunction, kFile, kLineNumber, NULL); TallyABirth(location, kMainThreadName); - const base::TimeTicks kTimePosted = base::TimeTicks() + - base::TimeDelta::FromMilliseconds(1); + const TrackedTime kTimePosted = TrackedTime::FromMilliseconds(1); const base::TimeTicks kDelayedStartTime = base::TimeTicks(); // TrackingInfo will call TallyABirth() during construction. base::TrackingInfo pending_task(location, kDelayedStartTime); @@ -691,23 +1047,19 @@ TEST_F(TrackedObjectsTest, TaskWithNestedExclusion) { ThreadData::TallyRunOnNamedThreadIfTracking(pending_task, task_stopwatch); ProcessDataSnapshot process_data; - ThreadData::Snapshot(false, &process_data); + ThreadData::Snapshot(0, &process_data); ExpectSimpleProcessData(process_data, kFunction, kMainThreadName, kMainThreadName, 1, 6, 4); } TEST_F(TrackedObjectsTest, TaskWith2NestedExclusions) { - if (!ThreadData::InitializeAndSetTrackingStatus( - ThreadData::PROFILING_CHILDREN_ACTIVE)) { - return; - } + ThreadData::InitializeAndSetTrackingStatus(ThreadData::PROFILING_ACTIVE); const char kFunction[] = "TaskWith2NestedExclusions"; Location location(kFunction, kFile, kLineNumber, NULL); TallyABirth(location, kMainThreadName); - const base::TimeTicks kTimePosted = base::TimeTicks() + - base::TimeDelta::FromMilliseconds(1); + const TrackedTime kTimePosted = TrackedTime::FromMilliseconds(1); const base::TimeTicks kDelayedStartTime = base::TimeTicks(); // TrackingInfo will call TallyABirth() during construction. base::TrackingInfo pending_task(location, kDelayedStartTime); @@ -735,16 +1087,13 @@ TEST_F(TrackedObjectsTest, TaskWith2NestedExclusions) { ThreadData::TallyRunOnNamedThreadIfTracking(pending_task, task_stopwatch); ProcessDataSnapshot process_data; - ThreadData::Snapshot(false, &process_data); + ThreadData::Snapshot(0, &process_data); ExpectSimpleProcessData(process_data, kFunction, kMainThreadName, kMainThreadName, 1, 13, 4); } TEST_F(TrackedObjectsTest, TaskWithNestedExclusionWithNestedTask) { - if (!ThreadData::InitializeAndSetTrackingStatus( - ThreadData::PROFILING_CHILDREN_ACTIVE)) { - return; - } + ThreadData::InitializeAndSetTrackingStatus(ThreadData::PROFILING_ACTIVE); const char kFunction[] = "TaskWithNestedExclusionWithNestedTask"; Location location(kFunction, kFile, kLineNumber, NULL); @@ -753,8 +1102,7 @@ TEST_F(TrackedObjectsTest, TaskWithNestedExclusionWithNestedTask) { TallyABirth(location, kMainThreadName); - const base::TimeTicks kTimePosted = base::TimeTicks() + - base::TimeDelta::FromMilliseconds(1); + const TrackedTime kTimePosted = TrackedTime::FromMilliseconds(1); const base::TimeTicks kDelayedStartTime = base::TimeTicks(); // TrackingInfo will call TallyABirth() during construction. base::TrackingInfo pending_task(location, kDelayedStartTime); @@ -771,8 +1119,7 @@ TEST_F(TrackedObjectsTest, TaskWithNestedExclusionWithNestedTask) { Location second_location(kFunction, kFile, kSecondFakeLineNumber, NULL); base::TrackingInfo nested_task(second_location, kDelayedStartTime); // Overwrite implied Now(). - nested_task.time_posted = - base::TimeTicks() + base::TimeDelta::FromMilliseconds(8); + nested_task.time_posted = TrackedTime::FromMilliseconds(8); SetTestTime(9); TaskStopwatch nested_task_stopwatch; nested_task_stopwatch.Start(); @@ -790,40 +1137,49 @@ TEST_F(TrackedObjectsTest, TaskWithNestedExclusionWithNestedTask) { ThreadData::TallyRunOnNamedThreadIfTracking(pending_task, task_stopwatch); ProcessDataSnapshot process_data; - ThreadData::Snapshot(false, &process_data); + ThreadData::Snapshot(0, &process_data); + + ASSERT_EQ(1u, process_data.phased_snapshots.size()); + auto it = process_data.phased_snapshots.find(0); + ASSERT_TRUE(it != process_data.phased_snapshots.end()); + const ProcessDataPhaseSnapshot& process_data_phase = it->second; // The order in which the two task follow is platform-dependent. - int t0 = (process_data.tasks[0].birth.location.line_number == kLineNumber) ? - 0 : 1; + int t0 = + (process_data_phase.tasks[0].birth.location.line_number == kLineNumber) + ? 0 + : 1; int t1 = 1 - t0; - ASSERT_EQ(2u, process_data.tasks.size()); - EXPECT_EQ(kFile, process_data.tasks[t0].birth.location.file_name); - EXPECT_EQ(kFunction, process_data.tasks[t0].birth.location.function_name); - EXPECT_EQ(kLineNumber, process_data.tasks[t0].birth.location.line_number); - EXPECT_EQ(kMainThreadName, process_data.tasks[t0].birth.thread_name); - EXPECT_EQ(1, process_data.tasks[t0].death_data.count); - EXPECT_EQ(6, process_data.tasks[t0].death_data.run_duration_sum); - EXPECT_EQ(6, process_data.tasks[t0].death_data.run_duration_max); - EXPECT_EQ(6, process_data.tasks[t0].death_data.run_duration_sample); - EXPECT_EQ(4, process_data.tasks[t0].death_data.queue_duration_sum); - EXPECT_EQ(4, process_data.tasks[t0].death_data.queue_duration_max); - EXPECT_EQ(4, process_data.tasks[t0].death_data.queue_duration_sample); - EXPECT_EQ(kMainThreadName, process_data.tasks[t0].death_thread_name); - EXPECT_EQ(kFile, process_data.tasks[t1].birth.location.file_name); - EXPECT_EQ(kFunction, process_data.tasks[t1].birth.location.function_name); + ASSERT_EQ(2u, process_data_phase.tasks.size()); + EXPECT_EQ(kFile, process_data_phase.tasks[t0].birth.location.file_name); + EXPECT_EQ(kFunction, + process_data_phase.tasks[t0].birth.location.function_name); + EXPECT_EQ(kLineNumber, + process_data_phase.tasks[t0].birth.location.line_number); + EXPECT_EQ(kMainThreadName, process_data_phase.tasks[t0].birth.thread_name); + EXPECT_EQ(1, process_data_phase.tasks[t0].death_data.count); + EXPECT_EQ(6, process_data_phase.tasks[t0].death_data.run_duration_sum); + EXPECT_EQ(6, process_data_phase.tasks[t0].death_data.run_duration_max); + EXPECT_EQ(6, process_data_phase.tasks[t0].death_data.run_duration_sample); + EXPECT_EQ(4, process_data_phase.tasks[t0].death_data.queue_duration_sum); + EXPECT_EQ(4, process_data_phase.tasks[t0].death_data.queue_duration_max); + EXPECT_EQ(4, process_data_phase.tasks[t0].death_data.queue_duration_sample); + EXPECT_EQ(kMainThreadName, process_data_phase.tasks[t0].death_thread_name); + EXPECT_EQ(kFile, process_data_phase.tasks[t1].birth.location.file_name); + EXPECT_EQ(kFunction, + process_data_phase.tasks[t1].birth.location.function_name); EXPECT_EQ(kSecondFakeLineNumber, - process_data.tasks[t1].birth.location.line_number); - EXPECT_EQ(kMainThreadName, process_data.tasks[t1].birth.thread_name); - EXPECT_EQ(1, process_data.tasks[t1].death_data.count); - EXPECT_EQ(2, process_data.tasks[t1].death_data.run_duration_sum); - EXPECT_EQ(2, process_data.tasks[t1].death_data.run_duration_max); - EXPECT_EQ(2, process_data.tasks[t1].death_data.run_duration_sample); - EXPECT_EQ(1, process_data.tasks[t1].death_data.queue_duration_sum); - EXPECT_EQ(1, process_data.tasks[t1].death_data.queue_duration_max); - EXPECT_EQ(1, process_data.tasks[t1].death_data.queue_duration_sample); - EXPECT_EQ(kMainThreadName, process_data.tasks[t1].death_thread_name); - EXPECT_EQ(0u, process_data.descendants.size()); + process_data_phase.tasks[t1].birth.location.line_number); + EXPECT_EQ(kMainThreadName, process_data_phase.tasks[t1].birth.thread_name); + EXPECT_EQ(1, process_data_phase.tasks[t1].death_data.count); + EXPECT_EQ(2, process_data_phase.tasks[t1].death_data.run_duration_sum); + EXPECT_EQ(2, process_data_phase.tasks[t1].death_data.run_duration_max); + EXPECT_EQ(2, process_data_phase.tasks[t1].death_data.run_duration_sample); + EXPECT_EQ(1, process_data_phase.tasks[t1].death_data.queue_duration_sum); + EXPECT_EQ(1, process_data_phase.tasks[t1].death_data.queue_duration_max); + EXPECT_EQ(1, process_data_phase.tasks[t1].death_data.queue_duration_sample); + EXPECT_EQ(kMainThreadName, process_data_phase.tasks[t1].death_thread_name); EXPECT_EQ(base::GetCurrentProcId(), process_data.process_id); } |