// On entry, leak any database structures in case they are still in use by
// prior threads.
ThreadData::ShutdownSingleThreadedCleanup(true);
+
+ test_time_ = 0;
+ ThreadData::SetAlternateTimeSource(&TrackedObjectsTest::GetTestTime);
+ ThreadData::now_function_is_time_ = true;
}
virtual ~TrackedObjectsTest() {
// Reset the profiler state.
void Reset() {
ThreadData::ShutdownSingleThreadedCleanup(false);
+ test_time_ = 0;
}
// Simulate a birth on the thread named |thread_name|, at the given
EXPECT_EQ(base::GetCurrentProcId(), process_data.process_id);
}
+
+ // Sets time that will be returned by ThreadData::Now().
+ static void SetTestTime(unsigned int test_time) { test_time_ = test_time; }
+
+ private:
+ // Returns test time in milliseconds.
+ static unsigned int GetTestTime() { return test_time_; }
+
+ // Test time in milliseconds.
+ static unsigned int test_time_;
};
+// static
+unsigned int TrackedObjectsTest::test_time_;
+
+
TEST_F(TrackedObjectsTest, MinimalStartupShutdown) {
// Minimal test doesn't even create any tasks.
if (!ThreadData::InitializeAndSetTrackingStatus(
- ThreadData::PROFILING_CHILDREN_ACTIVE))
+ ThreadData::PROFILING_CHILDREN_ACTIVE)) {
return;
+ }
EXPECT_FALSE(ThreadData::first()); // No activity even on this thread.
ThreadData* data = ThreadData::Get();
TEST_F(TrackedObjectsTest, TinyStartupShutdown) {
if (!ThreadData::InitializeAndSetTrackingStatus(
- ThreadData::PROFILING_CHILDREN_ACTIVE))
+ ThreadData::PROFILING_CHILDREN_ACTIVE)) {
return;
+ }
// Instigate tracking on a single tracked object, on our thread.
const char kFunction[] = "TinyStartupShutdown";
// Now instigate another birth, while we are timing the run of the first
// execution.
- ThreadData::NowForStartOfRun(first_birth);
+ ThreadData::PrepareForStartOfRun(first_birth);
// Create a child (using the same birth location).
// TrackingInfo will call TallyABirth() during construction.
- base::TimeTicks kBogusBirthTime;
+ const int32 start_time = 1;
+ base::TimeTicks kBogusBirthTime = base::TimeTicks() +
+ base::TimeDelta::FromMilliseconds(start_time);
base::TrackingInfo pending_task(location, kBogusBirthTime);
- TrackedTime start_time(pending_task.time_posted);
+ SetTestTime(1);
+ TaskStopwatch stopwatch;
// Finally conclude the outer run.
- TrackedTime end_time = ThreadData::NowForEndOfRun();
- ThreadData::TallyRunOnNamedThreadIfTracking(pending_task, start_time,
- end_time);
+ const int32 time_elapsed = 1000;
+ SetTestTime(start_time + time_elapsed);
+ stopwatch.Stop();
+
+ ThreadData::TallyRunOnNamedThreadIfTracking(pending_task, stopwatch);
birth_map.clear();
death_map.clear();
ProcessDataSnapshot process_data;
ThreadData::Snapshot(false, &process_data);
- const int32 time_elapsed = (end_time - start_time).InMilliseconds();
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);
TEST_F(TrackedObjectsTest, DeathDataTest) {
if (!ThreadData::InitializeAndSetTrackingStatus(
- ThreadData::PROFILING_CHILDREN_ACTIVE))
+ ThreadData::PROFILING_CHILDREN_ACTIVE)) {
return;
+ }
scoped_ptr<DeathData> data(new DeathData());
ASSERT_NE(data, reinterpret_cast<DeathData*>(NULL));
TEST_F(TrackedObjectsTest, DeactivatedBirthOnlyToSnapshotWorkerThread) {
// Start in the deactivated state.
- if (!ThreadData::InitializeAndSetTrackingStatus(ThreadData::DEACTIVATED))
+ if (!ThreadData::InitializeAndSetTrackingStatus(ThreadData::DEACTIVATED)) {
return;
+ }
const char kFunction[] = "DeactivatedBirthOnlyToSnapshotWorkerThread";
Location location(kFunction, kFile, kLineNumber, NULL);
TEST_F(TrackedObjectsTest, DeactivatedBirthOnlyToSnapshotMainThread) {
// Start in the deactivated state.
- if (!ThreadData::InitializeAndSetTrackingStatus(ThreadData::DEACTIVATED))
+ if (!ThreadData::InitializeAndSetTrackingStatus(ThreadData::DEACTIVATED)) {
return;
+ }
const char kFunction[] = "DeactivatedBirthOnlyToSnapshotMainThread";
Location location(kFunction, kFile, kLineNumber, NULL);
TEST_F(TrackedObjectsTest, BirthOnlyToSnapshotWorkerThread) {
if (!ThreadData::InitializeAndSetTrackingStatus(
- ThreadData::PROFILING_CHILDREN_ACTIVE))
+ ThreadData::PROFILING_CHILDREN_ACTIVE)) {
return;
+ }
const char kFunction[] = "BirthOnlyToSnapshotWorkerThread";
Location location(kFunction, kFile, kLineNumber, NULL);
TEST_F(TrackedObjectsTest, BirthOnlyToSnapshotMainThread) {
if (!ThreadData::InitializeAndSetTrackingStatus(
- ThreadData::PROFILING_CHILDREN_ACTIVE))
+ ThreadData::PROFILING_CHILDREN_ACTIVE)) {
return;
+ }
const char kFunction[] = "BirthOnlyToSnapshotMainThread";
Location location(kFunction, kFile, kLineNumber, NULL);
TEST_F(TrackedObjectsTest, LifeCycleToSnapshotMainThread) {
if (!ThreadData::InitializeAndSetTrackingStatus(
- ThreadData::PROFILING_CHILDREN_ACTIVE))
+ ThreadData::PROFILING_CHILDREN_ACTIVE)) {
return;
+ }
const char kFunction[] = "LifeCycleToSnapshotMainThread";
Location location(kFunction, kFile, kLineNumber, NULL);
base::TrackingInfo pending_task(location, kDelayedStartTime);
pending_task.time_posted = kTimePosted; // Overwrite implied Now().
- const TrackedTime kStartOfRun = TrackedTime() +
- Duration::FromMilliseconds(5);
- const TrackedTime kEndOfRun = TrackedTime() + Duration::FromMilliseconds(7);
- ThreadData::TallyRunOnNamedThreadIfTracking(pending_task,
- kStartOfRun, kEndOfRun);
+ const unsigned int kStartOfRun = 5;
+ const unsigned int kEndOfRun = 7;
+ SetTestTime(kStartOfRun);
+ TaskStopwatch stopwatch;
+ SetTestTime(kEndOfRun);
+ stopwatch.Stop();
+
+ ThreadData::TallyRunOnNamedThreadIfTracking(pending_task, stopwatch);
ProcessDataSnapshot process_data;
ThreadData::Snapshot(false, &process_data);
// task is still running, or is queued).
TEST_F(TrackedObjectsTest, LifeCycleMidDeactivatedToSnapshotMainThread) {
if (!ThreadData::InitializeAndSetTrackingStatus(
- ThreadData::PROFILING_CHILDREN_ACTIVE))
+ ThreadData::PROFILING_CHILDREN_ACTIVE)) {
return;
+ }
const char kFunction[] = "LifeCycleMidDeactivatedToSnapshotMainThread";
Location location(kFunction, kFile, kLineNumber, NULL);
EXPECT_TRUE(ThreadData::InitializeAndSetTrackingStatus(
ThreadData::DEACTIVATED));
- const TrackedTime kStartOfRun = TrackedTime() +
- Duration::FromMilliseconds(5);
- const TrackedTime kEndOfRun = TrackedTime() + Duration::FromMilliseconds(7);
- ThreadData::TallyRunOnNamedThreadIfTracking(pending_task,
- kStartOfRun, kEndOfRun);
+ const unsigned int kStartOfRun = 5;
+ const unsigned int kEndOfRun = 7;
+ SetTestTime(kStartOfRun);
+ TaskStopwatch stopwatch;
+ SetTestTime(kEndOfRun);
+ stopwatch.Stop();
+
+ ThreadData::TallyRunOnNamedThreadIfTracking(pending_task, stopwatch);
ProcessDataSnapshot process_data;
ThreadData::Snapshot(false, &process_data);
// the birth nor the death will be recorded.
TEST_F(TrackedObjectsTest, LifeCyclePreDeactivatedToSnapshotMainThread) {
// Start in the deactivated state.
- if (!ThreadData::InitializeAndSetTrackingStatus(ThreadData::DEACTIVATED))
+ if (!ThreadData::InitializeAndSetTrackingStatus(ThreadData::DEACTIVATED)) {
return;
+ }
const char kFunction[] = "LifeCyclePreDeactivatedToSnapshotMainThread";
Location location(kFunction, kFile, kLineNumber, NULL);
base::TrackingInfo pending_task(location, kDelayedStartTime);
pending_task.time_posted = kTimePosted; // Overwrite implied Now().
- const TrackedTime kStartOfRun = TrackedTime() +
- Duration::FromMilliseconds(5);
- const TrackedTime kEndOfRun = TrackedTime() + Duration::FromMilliseconds(7);
- ThreadData::TallyRunOnNamedThreadIfTracking(pending_task,
- kStartOfRun, kEndOfRun);
+ const unsigned int kStartOfRun = 5;
+ const unsigned int kEndOfRun = 7;
+ SetTestTime(kStartOfRun);
+ TaskStopwatch stopwatch;
+ SetTestTime(kEndOfRun);
+ stopwatch.Stop();
+
+ ThreadData::TallyRunOnNamedThreadIfTracking(pending_task, stopwatch);
ProcessDataSnapshot process_data;
ThreadData::Snapshot(false, &process_data);
TEST_F(TrackedObjectsTest, LifeCycleToSnapshotWorkerThread) {
if (!ThreadData::InitializeAndSetTrackingStatus(
- ThreadData::PROFILING_CHILDREN_ACTIVE))
+ ThreadData::PROFILING_CHILDREN_ACTIVE)) {
return;
+ }
const char kFunction[] = "LifeCycleToSnapshotWorkerThread";
Location location(kFunction, kFile, kLineNumber, NULL);
Births* birth = ThreadData::TallyABirthIfActive(location);
EXPECT_NE(reinterpret_cast<Births*>(NULL), birth);
- const TrackedTime kTimePosted = TrackedTime() + Duration::FromMilliseconds(1);
- const TrackedTime kStartOfRun = TrackedTime() +
- Duration::FromMilliseconds(5);
- const TrackedTime kEndOfRun = TrackedTime() + Duration::FromMilliseconds(7);
- ThreadData::TallyRunOnWorkerThreadIfTracking(birth, kTimePosted,
- kStartOfRun, kEndOfRun);
+ const unsigned int kTimePosted = 1;
+ const unsigned int kStartOfRun = 5;
+ const unsigned int kEndOfRun = 7;
+ SetTestTime(kStartOfRun);
+ TaskStopwatch stopwatch;
+ SetTestTime(kEndOfRun);
+ stopwatch.Stop();
+
+ ThreadData::TallyRunOnWorkerThreadIfTracking(
+ birth, TrackedTime() + Duration::FromMilliseconds(kTimePosted), stopwatch);
// Call for the ToSnapshot, but tell it to not reset the maxes after scanning.
ProcessDataSnapshot process_data;
TEST_F(TrackedObjectsTest, TwoLives) {
if (!ThreadData::InitializeAndSetTrackingStatus(
- ThreadData::PROFILING_CHILDREN_ACTIVE))
+ ThreadData::PROFILING_CHILDREN_ACTIVE)) {
return;
+ }
const char kFunction[] = "TwoLives";
Location location(kFunction, kFile, kLineNumber, NULL);
base::TrackingInfo pending_task(location, kDelayedStartTime);
pending_task.time_posted = kTimePosted; // Overwrite implied Now().
- const TrackedTime kStartOfRun = TrackedTime() +
- Duration::FromMilliseconds(5);
- const TrackedTime kEndOfRun = TrackedTime() + Duration::FromMilliseconds(7);
- ThreadData::TallyRunOnNamedThreadIfTracking(pending_task,
- kStartOfRun, kEndOfRun);
+ const unsigned int kStartOfRun = 5;
+ const unsigned int kEndOfRun = 7;
+ SetTestTime(kStartOfRun);
+ TaskStopwatch stopwatch;
+ SetTestTime(kEndOfRun);
+ stopwatch.Stop();
+
+ ThreadData::TallyRunOnNamedThreadIfTracking(pending_task, stopwatch);
// TrackingInfo will call TallyABirth() during construction.
base::TrackingInfo pending_task2(location, kDelayedStartTime);
pending_task2.time_posted = kTimePosted; // Overwrite implied Now().
+ SetTestTime(kStartOfRun);
+ TaskStopwatch stopwatch2;
+ SetTestTime(kEndOfRun);
+ stopwatch2.Stop();
- ThreadData::TallyRunOnNamedThreadIfTracking(pending_task2,
- kStartOfRun, kEndOfRun);
+ ThreadData::TallyRunOnNamedThreadIfTracking(pending_task2, stopwatch2);
ProcessDataSnapshot process_data;
ThreadData::Snapshot(false, &process_data);
TEST_F(TrackedObjectsTest, DifferentLives) {
if (!ThreadData::InitializeAndSetTrackingStatus(
- ThreadData::PROFILING_CHILDREN_ACTIVE))
+ ThreadData::PROFILING_CHILDREN_ACTIVE)) {
return;
+ }
// Use a well named thread.
ThreadData::InitializeThreadContext(kMainThreadName);
base::TrackingInfo pending_task(location, kDelayedStartTime);
pending_task.time_posted = kTimePosted; // Overwrite implied Now().
- const TrackedTime kStartOfRun = TrackedTime() +
- Duration::FromMilliseconds(5);
- const TrackedTime kEndOfRun = TrackedTime() + Duration::FromMilliseconds(7);
- ThreadData::TallyRunOnNamedThreadIfTracking(pending_task,
- kStartOfRun, kEndOfRun);
+ const unsigned int kStartOfRun = 5;
+ const unsigned int kEndOfRun = 7;
+ SetTestTime(kStartOfRun);
+ TaskStopwatch stopwatch;
+ SetTestTime(kEndOfRun);
+ stopwatch.Stop();
+
+ ThreadData::TallyRunOnNamedThreadIfTracking(pending_task, stopwatch);
const int kSecondFakeLineNumber = 999;
Location second_location(kFunction, kFile, kSecondFakeLineNumber, NULL);
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(base::GetCurrentProcId(), process_data.process_id);
}
+TEST_F(TrackedObjectsTest, TaskWithNestedExclusion) {
+ if (!ThreadData::InitializeAndSetTrackingStatus(
+ ThreadData::PROFILING_CHILDREN_ACTIVE)) {
+ return;
+ }
+
+ const char kFunction[] = "TaskWithNestedExclusion";
+ Location location(kFunction, kFile, kLineNumber, NULL);
+ TallyABirth(location, kMainThreadName);
+
+ const base::TimeTicks kTimePosted = base::TimeTicks() +
+ base::TimeDelta::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().
+
+ SetTestTime(5);
+ TaskStopwatch task_stopwatch;
+ {
+ SetTestTime(8);
+ TaskStopwatch exclusion_stopwatch;
+ SetTestTime(12);
+ exclusion_stopwatch.Stop();
+ }
+ SetTestTime(15);
+ task_stopwatch.Stop();
+
+ ThreadData::TallyRunOnNamedThreadIfTracking(pending_task, task_stopwatch);
+
+ ProcessDataSnapshot process_data;
+ ThreadData::Snapshot(false, &process_data);
+ ExpectSimpleProcessData(process_data, kFunction, kMainThreadName,
+ kMainThreadName, 1, 6, 4);
+}
+
+TEST_F(TrackedObjectsTest, TaskWith2NestedExclusions) {
+ if (!ThreadData::InitializeAndSetTrackingStatus(
+ ThreadData::PROFILING_CHILDREN_ACTIVE)) {
+ return;
+ }
+
+ const char kFunction[] = "TaskWith2NestedExclusions";
+ Location location(kFunction, kFile, kLineNumber, NULL);
+ TallyABirth(location, kMainThreadName);
+
+ const base::TimeTicks kTimePosted = base::TimeTicks() +
+ base::TimeDelta::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().
+
+ SetTestTime(5);
+ TaskStopwatch task_stopwatch;
+ {
+ SetTestTime(8);
+ TaskStopwatch exclusion_stopwatch;
+ SetTestTime(12);
+ exclusion_stopwatch.Stop();
+
+ SetTestTime(15);
+ TaskStopwatch exclusion_stopwatch2;
+ SetTestTime(18);
+ exclusion_stopwatch2.Stop();
+ }
+ SetTestTime(25);
+ task_stopwatch.Stop();
+
+ ThreadData::TallyRunOnNamedThreadIfTracking(pending_task, task_stopwatch);
+
+ ProcessDataSnapshot process_data;
+ ThreadData::Snapshot(false, &process_data);
+ ExpectSimpleProcessData(process_data, kFunction, kMainThreadName,
+ kMainThreadName, 1, 13, 4);
+}
+
+TEST_F(TrackedObjectsTest, TaskWithNestedExclusionWithNestedTask) {
+ if (!ThreadData::InitializeAndSetTrackingStatus(
+ ThreadData::PROFILING_CHILDREN_ACTIVE)) {
+ return;
+ }
+
+ const char kFunction[] = "TaskWithNestedExclusionWithNestedTask";
+ Location location(kFunction, kFile, kLineNumber, NULL);
+
+ const int kSecondFakeLineNumber = 999;
+
+ TallyABirth(location, kMainThreadName);
+
+ const base::TimeTicks kTimePosted = base::TimeTicks() +
+ base::TimeDelta::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().
+
+ SetTestTime(5);
+ TaskStopwatch task_stopwatch;
+ {
+ SetTestTime(8);
+ TaskStopwatch exclusion_stopwatch;
+ {
+ 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);
+ SetTestTime(9);
+ TaskStopwatch nested_task_stopwatch;
+ SetTestTime(11);
+ nested_task_stopwatch.Stop();
+ ThreadData::TallyRunOnNamedThreadIfTracking(
+ nested_task, nested_task_stopwatch);
+ }
+ SetTestTime(12);
+ exclusion_stopwatch.Stop();
+ }
+ SetTestTime(15);
+ task_stopwatch.Stop();
+
+ ThreadData::TallyRunOnNamedThreadIfTracking(pending_task, task_stopwatch);
+
+ ProcessDataSnapshot process_data;
+ ThreadData::Snapshot(false, &process_data);
+
+ // 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 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);
+ 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());
+ EXPECT_EQ(base::GetCurrentProcId(), process_data.process_id);
+}
+
} // namespace tracked_objects