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
3 // found in the LICENSE file.
4
5 // Test of classes in the tracked_objects.h classes.
6
7 #include "base/tracked_objects.h"
8
9 #include <stddef.h>
10
11 #include "base/memory/scoped_ptr.h"
12 #include "base/process/process_handle.h"
13 #include "base/time/time.h"
14 #include "base/tracking_info.h"
15 #include "testing/gtest/include/gtest/gtest.h"
16
17 const int kLineNumber = 1776;
18 const char kFile[] = "FixedUnitTestFileName";
19 const char kWorkerThreadName[] = "WorkerThread-1";
20 const char kMainThreadName[] = "SomeMainThreadName";
21 const char kStillAlive[] = "Still_Alive";
22
23 namespace tracked_objects {
24
25 class TrackedObjectsTest : public testing::Test {
26 protected:
TrackedObjectsTest()27 TrackedObjectsTest() {
28 // On entry, leak any database structures in case they are still in use by
29 // prior threads.
30 ThreadData::ShutdownSingleThreadedCleanup(true);
31
32 test_time_ = 0;
33 ThreadData::SetAlternateTimeSource(&TrackedObjectsTest::GetTestTime);
34 ThreadData::now_function_is_time_ = true;
35 }
36
~TrackedObjectsTest()37 virtual ~TrackedObjectsTest() {
38 // We should not need to leak any structures we create, since we are
39 // single threaded, and carefully accounting for items.
40 ThreadData::ShutdownSingleThreadedCleanup(false);
41 }
42
43 // Reset the profiler state.
Reset()44 void Reset() {
45 ThreadData::ShutdownSingleThreadedCleanup(false);
46 test_time_ = 0;
47 }
48
49 // Simulate a birth on the thread named |thread_name|, at the given
50 // |location|.
TallyABirth(const Location & location,const std::string & thread_name)51 void TallyABirth(const Location& location, const std::string& thread_name) {
52 // If the |thread_name| is empty, we don't initialize system with a thread
53 // name, so we're viewed as a worker thread.
54 if (!thread_name.empty())
55 ThreadData::InitializeThreadContext(kMainThreadName);
56
57 // Do not delete |birth|. We don't own it.
58 Births* birth = ThreadData::TallyABirthIfActive(location);
59
60 if (ThreadData::status() == ThreadData::DEACTIVATED)
61 EXPECT_EQ(reinterpret_cast<Births*>(NULL), birth);
62 else
63 EXPECT_NE(reinterpret_cast<Births*>(NULL), birth);
64 }
65
66 // Helper function to verify the most common test expectations.
ExpectSimpleProcessData(const ProcessDataSnapshot & process_data,const std::string & function_name,const std::string & birth_thread,const std::string & death_thread,int count,int run_ms,int queue_ms)67 void ExpectSimpleProcessData(const ProcessDataSnapshot& process_data,
68 const std::string& function_name,
69 const std::string& birth_thread,
70 const std::string& death_thread,
71 int count,
72 int run_ms,
73 int queue_ms) {
74 ASSERT_EQ(1u, process_data.tasks.size());
75
76 EXPECT_EQ(kFile, process_data.tasks[0].birth.location.file_name);
77 EXPECT_EQ(function_name,
78 process_data.tasks[0].birth.location.function_name);
79 EXPECT_EQ(kLineNumber, process_data.tasks[0].birth.location.line_number);
80
81 EXPECT_EQ(birth_thread, process_data.tasks[0].birth.thread_name);
82
83 EXPECT_EQ(count, process_data.tasks[0].death_data.count);
84 EXPECT_EQ(count * run_ms,
85 process_data.tasks[0].death_data.run_duration_sum);
86 EXPECT_EQ(run_ms, process_data.tasks[0].death_data.run_duration_max);
87 EXPECT_EQ(run_ms, process_data.tasks[0].death_data.run_duration_sample);
88 EXPECT_EQ(count * queue_ms,
89 process_data.tasks[0].death_data.queue_duration_sum);
90 EXPECT_EQ(queue_ms, process_data.tasks[0].death_data.queue_duration_max);
91 EXPECT_EQ(queue_ms, process_data.tasks[0].death_data.queue_duration_sample);
92
93 EXPECT_EQ(death_thread, process_data.tasks[0].death_thread_name);
94
95 EXPECT_EQ(0u, process_data.descendants.size());
96
97 EXPECT_EQ(base::GetCurrentProcId(), process_data.process_id);
98 }
99
100 // Sets time that will be returned by ThreadData::Now().
SetTestTime(unsigned int test_time)101 static void SetTestTime(unsigned int test_time) { test_time_ = test_time; }
102
103 private:
104 // Returns test time in milliseconds.
GetTestTime()105 static unsigned int GetTestTime() { return test_time_; }
106
107 // Test time in milliseconds.
108 static unsigned int test_time_;
109 };
110
111 // static
112 unsigned int TrackedObjectsTest::test_time_;
113
114
TEST_F(TrackedObjectsTest,MinimalStartupShutdown)115 TEST_F(TrackedObjectsTest, MinimalStartupShutdown) {
116 // Minimal test doesn't even create any tasks.
117 if (!ThreadData::InitializeAndSetTrackingStatus(
118 ThreadData::PROFILING_CHILDREN_ACTIVE)) {
119 return;
120 }
121
122 EXPECT_FALSE(ThreadData::first()); // No activity even on this thread.
123 ThreadData* data = ThreadData::Get();
124 EXPECT_TRUE(ThreadData::first()); // Now class was constructed.
125 ASSERT_TRUE(data);
126 EXPECT_FALSE(data->next());
127 EXPECT_EQ(data, ThreadData::Get());
128 ThreadData::BirthMap birth_map;
129 ThreadData::DeathMap death_map;
130 ThreadData::ParentChildSet parent_child_set;
131 data->SnapshotMaps(false, &birth_map, &death_map, &parent_child_set);
132 EXPECT_EQ(0u, birth_map.size());
133 EXPECT_EQ(0u, death_map.size());
134 EXPECT_EQ(0u, parent_child_set.size());
135
136 // Clean up with no leaking.
137 Reset();
138
139 // Do it again, just to be sure we reset state completely.
140 EXPECT_TRUE(ThreadData::InitializeAndSetTrackingStatus(
141 ThreadData::PROFILING_CHILDREN_ACTIVE));
142 EXPECT_FALSE(ThreadData::first()); // No activity even on this thread.
143 data = ThreadData::Get();
144 EXPECT_TRUE(ThreadData::first()); // Now class was constructed.
145 ASSERT_TRUE(data);
146 EXPECT_FALSE(data->next());
147 EXPECT_EQ(data, ThreadData::Get());
148 birth_map.clear();
149 death_map.clear();
150 parent_child_set.clear();
151 data->SnapshotMaps(false, &birth_map, &death_map, &parent_child_set);
152 EXPECT_EQ(0u, birth_map.size());
153 EXPECT_EQ(0u, death_map.size());
154 EXPECT_EQ(0u, parent_child_set.size());
155 }
156
TEST_F(TrackedObjectsTest,TinyStartupShutdown)157 TEST_F(TrackedObjectsTest, TinyStartupShutdown) {
158 if (!ThreadData::InitializeAndSetTrackingStatus(
159 ThreadData::PROFILING_CHILDREN_ACTIVE)) {
160 return;
161 }
162
163 // Instigate tracking on a single tracked object, on our thread.
164 const char kFunction[] = "TinyStartupShutdown";
165 Location location(kFunction, kFile, kLineNumber, NULL);
166 Births* first_birth = ThreadData::TallyABirthIfActive(location);
167
168 ThreadData* data = ThreadData::first();
169 ASSERT_TRUE(data);
170 EXPECT_FALSE(data->next());
171 EXPECT_EQ(data, ThreadData::Get());
172 ThreadData::BirthMap birth_map;
173 ThreadData::DeathMap death_map;
174 ThreadData::ParentChildSet parent_child_set;
175 data->SnapshotMaps(false, &birth_map, &death_map, &parent_child_set);
176 EXPECT_EQ(1u, birth_map.size()); // 1 birth location.
177 EXPECT_EQ(1, birth_map.begin()->second->birth_count()); // 1 birth.
178 EXPECT_EQ(0u, death_map.size()); // No deaths.
179 EXPECT_EQ(0u, parent_child_set.size()); // No children.
180
181
182 // Now instigate another birth, while we are timing the run of the first
183 // execution.
184 ThreadData::PrepareForStartOfRun(first_birth);
185 // Create a child (using the same birth location).
186 // TrackingInfo will call TallyABirth() during construction.
187 const int32 start_time = 1;
188 base::TimeTicks kBogusBirthTime = base::TimeTicks() +
189 base::TimeDelta::FromMilliseconds(start_time);
190 base::TrackingInfo pending_task(location, kBogusBirthTime);
191 SetTestTime(1);
192 TaskStopwatch stopwatch;
193 // Finally conclude the outer run.
194 const int32 time_elapsed = 1000;
195 SetTestTime(start_time + time_elapsed);
196 stopwatch.Stop();
197
198 ThreadData::TallyRunOnNamedThreadIfTracking(pending_task, stopwatch);
199
200 birth_map.clear();
201 death_map.clear();
202 parent_child_set.clear();
203 data->SnapshotMaps(false, &birth_map, &death_map, &parent_child_set);
204 EXPECT_EQ(1u, birth_map.size()); // 1 birth location.
205 EXPECT_EQ(2, birth_map.begin()->second->birth_count()); // 2 births.
206 EXPECT_EQ(1u, death_map.size()); // 1 location.
207 EXPECT_EQ(1, death_map.begin()->second.count()); // 1 death.
208 if (ThreadData::TrackingParentChildStatus()) {
209 EXPECT_EQ(1u, parent_child_set.size()); // 1 child.
210 EXPECT_EQ(parent_child_set.begin()->first,
211 parent_child_set.begin()->second);
212 } else {
213 EXPECT_EQ(0u, parent_child_set.size()); // no stats.
214 }
215
216 // The births were at the same location as the one known death.
217 EXPECT_EQ(birth_map.begin()->second, death_map.begin()->first);
218
219 ProcessDataSnapshot process_data;
220 ThreadData::Snapshot(false, &process_data);
221
222 ASSERT_EQ(1u, process_data.tasks.size());
223 EXPECT_EQ(kFile, process_data.tasks[0].birth.location.file_name);
224 EXPECT_EQ(kFunction, process_data.tasks[0].birth.location.function_name);
225 EXPECT_EQ(kLineNumber, process_data.tasks[0].birth.location.line_number);
226 EXPECT_EQ(kWorkerThreadName, process_data.tasks[0].birth.thread_name);
227 EXPECT_EQ(1, process_data.tasks[0].death_data.count);
228 EXPECT_EQ(time_elapsed, process_data.tasks[0].death_data.run_duration_sum);
229 EXPECT_EQ(time_elapsed, process_data.tasks[0].death_data.run_duration_max);
230 EXPECT_EQ(time_elapsed, process_data.tasks[0].death_data.run_duration_sample);
231 EXPECT_EQ(0, process_data.tasks[0].death_data.queue_duration_sum);
232 EXPECT_EQ(0, process_data.tasks[0].death_data.queue_duration_max);
233 EXPECT_EQ(0, process_data.tasks[0].death_data.queue_duration_sample);
234 EXPECT_EQ(kWorkerThreadName, process_data.tasks[0].death_thread_name);
235
236 if (ThreadData::TrackingParentChildStatus()) {
237 ASSERT_EQ(1u, process_data.descendants.size());
238 EXPECT_EQ(kFile, process_data.descendants[0].parent.location.file_name);
239 EXPECT_EQ(kFunction,
240 process_data.descendants[0].parent.location.function_name);
241 EXPECT_EQ(kLineNumber,
242 process_data.descendants[0].parent.location.line_number);
243 EXPECT_EQ(kWorkerThreadName,
244 process_data.descendants[0].parent.thread_name);
245 EXPECT_EQ(kFile, process_data.descendants[0].child.location.file_name);
246 EXPECT_EQ(kFunction,
247 process_data.descendants[0].child.location.function_name);
248 EXPECT_EQ(kLineNumber,
249 process_data.descendants[0].child.location.line_number);
250 EXPECT_EQ(kWorkerThreadName, process_data.descendants[0].child.thread_name);
251 } else {
252 EXPECT_EQ(0u, process_data.descendants.size());
253 }
254 }
255
TEST_F(TrackedObjectsTest,DeathDataTest)256 TEST_F(TrackedObjectsTest, DeathDataTest) {
257 if (!ThreadData::InitializeAndSetTrackingStatus(
258 ThreadData::PROFILING_CHILDREN_ACTIVE)) {
259 return;
260 }
261
262 scoped_ptr<DeathData> data(new DeathData());
263 ASSERT_NE(data, reinterpret_cast<DeathData*>(NULL));
264 EXPECT_EQ(data->run_duration_sum(), 0);
265 EXPECT_EQ(data->run_duration_sample(), 0);
266 EXPECT_EQ(data->queue_duration_sum(), 0);
267 EXPECT_EQ(data->queue_duration_sample(), 0);
268 EXPECT_EQ(data->count(), 0);
269
270 int32 run_ms = 42;
271 int32 queue_ms = 8;
272
273 const int kUnrandomInt = 0; // Fake random int that ensure we sample data.
274 data->RecordDeath(queue_ms, run_ms, kUnrandomInt);
275 EXPECT_EQ(data->run_duration_sum(), run_ms);
276 EXPECT_EQ(data->run_duration_sample(), run_ms);
277 EXPECT_EQ(data->queue_duration_sum(), queue_ms);
278 EXPECT_EQ(data->queue_duration_sample(), queue_ms);
279 EXPECT_EQ(data->count(), 1);
280
281 data->RecordDeath(queue_ms, run_ms, kUnrandomInt);
282 EXPECT_EQ(data->run_duration_sum(), run_ms + run_ms);
283 EXPECT_EQ(data->run_duration_sample(), run_ms);
284 EXPECT_EQ(data->queue_duration_sum(), queue_ms + queue_ms);
285 EXPECT_EQ(data->queue_duration_sample(), queue_ms);
286 EXPECT_EQ(data->count(), 2);
287
288 DeathDataSnapshot snapshot(*data);
289 EXPECT_EQ(2, snapshot.count);
290 EXPECT_EQ(2 * run_ms, snapshot.run_duration_sum);
291 EXPECT_EQ(run_ms, snapshot.run_duration_max);
292 EXPECT_EQ(run_ms, snapshot.run_duration_sample);
293 EXPECT_EQ(2 * queue_ms, snapshot.queue_duration_sum);
294 EXPECT_EQ(queue_ms, snapshot.queue_duration_max);
295 EXPECT_EQ(queue_ms, snapshot.queue_duration_sample);
296 }
297
TEST_F(TrackedObjectsTest,DeactivatedBirthOnlyToSnapshotWorkerThread)298 TEST_F(TrackedObjectsTest, DeactivatedBirthOnlyToSnapshotWorkerThread) {
299 // Start in the deactivated state.
300 if (!ThreadData::InitializeAndSetTrackingStatus(ThreadData::DEACTIVATED)) {
301 return;
302 }
303
304 const char kFunction[] = "DeactivatedBirthOnlyToSnapshotWorkerThread";
305 Location location(kFunction, kFile, kLineNumber, NULL);
306 TallyABirth(location, std::string());
307
308 ProcessDataSnapshot process_data;
309 ThreadData::Snapshot(false, &process_data);
310 EXPECT_EQ(0u, process_data.tasks.size());
311 EXPECT_EQ(0u, process_data.descendants.size());
312 EXPECT_EQ(base::GetCurrentProcId(), process_data.process_id);
313 }
314
TEST_F(TrackedObjectsTest,DeactivatedBirthOnlyToSnapshotMainThread)315 TEST_F(TrackedObjectsTest, DeactivatedBirthOnlyToSnapshotMainThread) {
316 // Start in the deactivated state.
317 if (!ThreadData::InitializeAndSetTrackingStatus(ThreadData::DEACTIVATED)) {
318 return;
319 }
320
321 const char kFunction[] = "DeactivatedBirthOnlyToSnapshotMainThread";
322 Location location(kFunction, kFile, kLineNumber, NULL);
323 TallyABirth(location, kMainThreadName);
324
325 ProcessDataSnapshot process_data;
326 ThreadData::Snapshot(false, &process_data);
327 EXPECT_EQ(0u, process_data.tasks.size());
328 EXPECT_EQ(0u, process_data.descendants.size());
329 EXPECT_EQ(base::GetCurrentProcId(), process_data.process_id);
330 }
331
TEST_F(TrackedObjectsTest,BirthOnlyToSnapshotWorkerThread)332 TEST_F(TrackedObjectsTest, BirthOnlyToSnapshotWorkerThread) {
333 if (!ThreadData::InitializeAndSetTrackingStatus(
334 ThreadData::PROFILING_CHILDREN_ACTIVE)) {
335 return;
336 }
337
338 const char kFunction[] = "BirthOnlyToSnapshotWorkerThread";
339 Location location(kFunction, kFile, kLineNumber, NULL);
340 TallyABirth(location, std::string());
341
342 ProcessDataSnapshot process_data;
343 ThreadData::Snapshot(false, &process_data);
344 ExpectSimpleProcessData(process_data, kFunction, kWorkerThreadName,
345 kStillAlive, 1, 0, 0);
346 }
347
TEST_F(TrackedObjectsTest,BirthOnlyToSnapshotMainThread)348 TEST_F(TrackedObjectsTest, BirthOnlyToSnapshotMainThread) {
349 if (!ThreadData::InitializeAndSetTrackingStatus(
350 ThreadData::PROFILING_CHILDREN_ACTIVE)) {
351 return;
352 }
353
354 const char kFunction[] = "BirthOnlyToSnapshotMainThread";
355 Location location(kFunction, kFile, kLineNumber, NULL);
356 TallyABirth(location, kMainThreadName);
357
358 ProcessDataSnapshot process_data;
359 ThreadData::Snapshot(false, &process_data);
360 ExpectSimpleProcessData(process_data, kFunction, kMainThreadName, kStillAlive,
361 1, 0, 0);
362 }
363
TEST_F(TrackedObjectsTest,LifeCycleToSnapshotMainThread)364 TEST_F(TrackedObjectsTest, LifeCycleToSnapshotMainThread) {
365 if (!ThreadData::InitializeAndSetTrackingStatus(
366 ThreadData::PROFILING_CHILDREN_ACTIVE)) {
367 return;
368 }
369
370 const char kFunction[] = "LifeCycleToSnapshotMainThread";
371 Location location(kFunction, kFile, kLineNumber, NULL);
372 TallyABirth(location, kMainThreadName);
373
374 const base::TimeTicks kTimePosted = base::TimeTicks() +
375 base::TimeDelta::FromMilliseconds(1);
376 const base::TimeTicks kDelayedStartTime = base::TimeTicks();
377 // TrackingInfo will call TallyABirth() during construction.
378 base::TrackingInfo pending_task(location, kDelayedStartTime);
379 pending_task.time_posted = kTimePosted; // Overwrite implied Now().
380
381 const unsigned int kStartOfRun = 5;
382 const unsigned int kEndOfRun = 7;
383 SetTestTime(kStartOfRun);
384 TaskStopwatch stopwatch;
385 SetTestTime(kEndOfRun);
386 stopwatch.Stop();
387
388 ThreadData::TallyRunOnNamedThreadIfTracking(pending_task, stopwatch);
389
390 ProcessDataSnapshot process_data;
391 ThreadData::Snapshot(false, &process_data);
392 ExpectSimpleProcessData(process_data, kFunction, kMainThreadName,
393 kMainThreadName, 1, 2, 4);
394 }
395
396 // We will deactivate tracking after the birth, and before the death, and
397 // demonstrate that the lifecycle is completely tallied. This ensures that
398 // our tallied births are matched by tallied deaths (except for when the
399 // task is still running, or is queued).
TEST_F(TrackedObjectsTest,LifeCycleMidDeactivatedToSnapshotMainThread)400 TEST_F(TrackedObjectsTest, LifeCycleMidDeactivatedToSnapshotMainThread) {
401 if (!ThreadData::InitializeAndSetTrackingStatus(
402 ThreadData::PROFILING_CHILDREN_ACTIVE)) {
403 return;
404 }
405
406 const char kFunction[] = "LifeCycleMidDeactivatedToSnapshotMainThread";
407 Location location(kFunction, kFile, kLineNumber, NULL);
408 TallyABirth(location, kMainThreadName);
409
410 const base::TimeTicks kTimePosted = base::TimeTicks() +
411 base::TimeDelta::FromMilliseconds(1);
412 const base::TimeTicks kDelayedStartTime = base::TimeTicks();
413 // TrackingInfo will call TallyABirth() during construction.
414 base::TrackingInfo pending_task(location, kDelayedStartTime);
415 pending_task.time_posted = kTimePosted; // Overwrite implied Now().
416
417 // Turn off tracking now that we have births.
418 EXPECT_TRUE(ThreadData::InitializeAndSetTrackingStatus(
419 ThreadData::DEACTIVATED));
420
421 const unsigned int kStartOfRun = 5;
422 const unsigned int kEndOfRun = 7;
423 SetTestTime(kStartOfRun);
424 TaskStopwatch stopwatch;
425 SetTestTime(kEndOfRun);
426 stopwatch.Stop();
427
428 ThreadData::TallyRunOnNamedThreadIfTracking(pending_task, stopwatch);
429
430 ProcessDataSnapshot process_data;
431 ThreadData::Snapshot(false, &process_data);
432 ExpectSimpleProcessData(process_data, kFunction, kMainThreadName,
433 kMainThreadName, 1, 2, 4);
434 }
435
436 // We will deactivate tracking before starting a life cycle, and neither
437 // the birth nor the death will be recorded.
TEST_F(TrackedObjectsTest,LifeCyclePreDeactivatedToSnapshotMainThread)438 TEST_F(TrackedObjectsTest, LifeCyclePreDeactivatedToSnapshotMainThread) {
439 // Start in the deactivated state.
440 if (!ThreadData::InitializeAndSetTrackingStatus(ThreadData::DEACTIVATED)) {
441 return;
442 }
443
444 const char kFunction[] = "LifeCyclePreDeactivatedToSnapshotMainThread";
445 Location location(kFunction, kFile, kLineNumber, NULL);
446 TallyABirth(location, kMainThreadName);
447
448 const base::TimeTicks kTimePosted = base::TimeTicks() +
449 base::TimeDelta::FromMilliseconds(1);
450 const base::TimeTicks kDelayedStartTime = base::TimeTicks();
451 // TrackingInfo will call TallyABirth() during construction.
452 base::TrackingInfo pending_task(location, kDelayedStartTime);
453 pending_task.time_posted = kTimePosted; // Overwrite implied Now().
454
455 const unsigned int kStartOfRun = 5;
456 const unsigned int kEndOfRun = 7;
457 SetTestTime(kStartOfRun);
458 TaskStopwatch stopwatch;
459 SetTestTime(kEndOfRun);
460 stopwatch.Stop();
461
462 ThreadData::TallyRunOnNamedThreadIfTracking(pending_task, stopwatch);
463
464 ProcessDataSnapshot process_data;
465 ThreadData::Snapshot(false, &process_data);
466 EXPECT_EQ(0u, process_data.tasks.size());
467 EXPECT_EQ(0u, process_data.descendants.size());
468 EXPECT_EQ(base::GetCurrentProcId(), process_data.process_id);
469 }
470
TEST_F(TrackedObjectsTest,LifeCycleToSnapshotWorkerThread)471 TEST_F(TrackedObjectsTest, LifeCycleToSnapshotWorkerThread) {
472 if (!ThreadData::InitializeAndSetTrackingStatus(
473 ThreadData::PROFILING_CHILDREN_ACTIVE)) {
474 return;
475 }
476
477 const char kFunction[] = "LifeCycleToSnapshotWorkerThread";
478 Location location(kFunction, kFile, kLineNumber, NULL);
479 // Do not delete |birth|. We don't own it.
480 Births* birth = ThreadData::TallyABirthIfActive(location);
481 EXPECT_NE(reinterpret_cast<Births*>(NULL), birth);
482
483 const unsigned int kTimePosted = 1;
484 const unsigned int kStartOfRun = 5;
485 const unsigned int kEndOfRun = 7;
486 SetTestTime(kStartOfRun);
487 TaskStopwatch stopwatch;
488 SetTestTime(kEndOfRun);
489 stopwatch.Stop();
490
491 ThreadData::TallyRunOnWorkerThreadIfTracking(
492 birth, TrackedTime() + Duration::FromMilliseconds(kTimePosted), stopwatch);
493
494 // Call for the ToSnapshot, but tell it to not reset the maxes after scanning.
495 ProcessDataSnapshot process_data;
496 ThreadData::Snapshot(false, &process_data);
497 ExpectSimpleProcessData(process_data, kFunction, kWorkerThreadName,
498 kWorkerThreadName, 1, 2, 4);
499
500 // Call for the ToSnapshot, but tell it to reset the maxes after scanning.
501 // We'll still get the same values, but the data will be reset (which we'll
502 // see in a moment).
503 ProcessDataSnapshot process_data_pre_reset;
504 ThreadData::Snapshot(true, &process_data_pre_reset);
505 ExpectSimpleProcessData(process_data, kFunction, kWorkerThreadName,
506 kWorkerThreadName, 1, 2, 4);
507
508 // Call for the ToSnapshot, and now we'll see the result of the last
509 // translation, as the max will have been pushed back to zero.
510 ProcessDataSnapshot process_data_post_reset;
511 ThreadData::Snapshot(true, &process_data_post_reset);
512 ASSERT_EQ(1u, process_data_post_reset.tasks.size());
513 EXPECT_EQ(kFile, process_data_post_reset.tasks[0].birth.location.file_name);
514 EXPECT_EQ(kFunction,
515 process_data_post_reset.tasks[0].birth.location.function_name);
516 EXPECT_EQ(kLineNumber,
517 process_data_post_reset.tasks[0].birth.location.line_number);
518 EXPECT_EQ(kWorkerThreadName,
519 process_data_post_reset.tasks[0].birth.thread_name);
520 EXPECT_EQ(1, process_data_post_reset.tasks[0].death_data.count);
521 EXPECT_EQ(2, process_data_post_reset.tasks[0].death_data.run_duration_sum);
522 EXPECT_EQ(0, process_data_post_reset.tasks[0].death_data.run_duration_max);
523 EXPECT_EQ(2, process_data_post_reset.tasks[0].death_data.run_duration_sample);
524 EXPECT_EQ(4, process_data_post_reset.tasks[0].death_data.queue_duration_sum);
525 EXPECT_EQ(0, process_data_post_reset.tasks[0].death_data.queue_duration_max);
526 EXPECT_EQ(4,
527 process_data_post_reset.tasks[0].death_data.queue_duration_sample);
528 EXPECT_EQ(kWorkerThreadName,
529 process_data_post_reset.tasks[0].death_thread_name);
530 EXPECT_EQ(0u, process_data_post_reset.descendants.size());
531 EXPECT_EQ(base::GetCurrentProcId(), process_data_post_reset.process_id);
532 }
533
TEST_F(TrackedObjectsTest,TwoLives)534 TEST_F(TrackedObjectsTest, TwoLives) {
535 if (!ThreadData::InitializeAndSetTrackingStatus(
536 ThreadData::PROFILING_CHILDREN_ACTIVE)) {
537 return;
538 }
539
540 const char kFunction[] = "TwoLives";
541 Location location(kFunction, kFile, kLineNumber, NULL);
542 TallyABirth(location, kMainThreadName);
543
544 const base::TimeTicks kTimePosted = base::TimeTicks() +
545 base::TimeDelta::FromMilliseconds(1);
546 const base::TimeTicks kDelayedStartTime = base::TimeTicks();
547 // TrackingInfo will call TallyABirth() during construction.
548 base::TrackingInfo pending_task(location, kDelayedStartTime);
549 pending_task.time_posted = kTimePosted; // Overwrite implied Now().
550
551 const unsigned int kStartOfRun = 5;
552 const unsigned int kEndOfRun = 7;
553 SetTestTime(kStartOfRun);
554 TaskStopwatch stopwatch;
555 SetTestTime(kEndOfRun);
556 stopwatch.Stop();
557
558 ThreadData::TallyRunOnNamedThreadIfTracking(pending_task, stopwatch);
559
560 // TrackingInfo will call TallyABirth() during construction.
561 base::TrackingInfo pending_task2(location, kDelayedStartTime);
562 pending_task2.time_posted = kTimePosted; // Overwrite implied Now().
563 SetTestTime(kStartOfRun);
564 TaskStopwatch stopwatch2;
565 SetTestTime(kEndOfRun);
566 stopwatch2.Stop();
567
568 ThreadData::TallyRunOnNamedThreadIfTracking(pending_task2, stopwatch2);
569
570 ProcessDataSnapshot process_data;
571 ThreadData::Snapshot(false, &process_data);
572 ExpectSimpleProcessData(process_data, kFunction, kMainThreadName,
573 kMainThreadName, 2, 2, 4);
574 }
575
TEST_F(TrackedObjectsTest,DifferentLives)576 TEST_F(TrackedObjectsTest, DifferentLives) {
577 if (!ThreadData::InitializeAndSetTrackingStatus(
578 ThreadData::PROFILING_CHILDREN_ACTIVE)) {
579 return;
580 }
581
582 // Use a well named thread.
583 ThreadData::InitializeThreadContext(kMainThreadName);
584 const char kFunction[] = "DifferentLives";
585 Location location(kFunction, kFile, kLineNumber, NULL);
586
587 const base::TimeTicks kTimePosted = base::TimeTicks() +
588 base::TimeDelta::FromMilliseconds(1);
589 const base::TimeTicks kDelayedStartTime = base::TimeTicks();
590 // TrackingInfo will call TallyABirth() during construction.
591 base::TrackingInfo pending_task(location, kDelayedStartTime);
592 pending_task.time_posted = kTimePosted; // Overwrite implied Now().
593
594 const unsigned int kStartOfRun = 5;
595 const unsigned int kEndOfRun = 7;
596 SetTestTime(kStartOfRun);
597 TaskStopwatch stopwatch;
598 SetTestTime(kEndOfRun);
599 stopwatch.Stop();
600
601 ThreadData::TallyRunOnNamedThreadIfTracking(pending_task, stopwatch);
602
603 const int kSecondFakeLineNumber = 999;
604 Location second_location(kFunction, kFile, kSecondFakeLineNumber, NULL);
605
606 // TrackingInfo will call TallyABirth() during construction.
607 base::TrackingInfo pending_task2(second_location, kDelayedStartTime);
608 pending_task2.time_posted = kTimePosted; // Overwrite implied Now().
609
610 ProcessDataSnapshot process_data;
611 ThreadData::Snapshot(false, &process_data);
612 ASSERT_EQ(2u, process_data.tasks.size());
613
614 EXPECT_EQ(kFile, process_data.tasks[0].birth.location.file_name);
615 EXPECT_EQ(kFunction, process_data.tasks[0].birth.location.function_name);
616 EXPECT_EQ(kLineNumber, process_data.tasks[0].birth.location.line_number);
617 EXPECT_EQ(kMainThreadName, process_data.tasks[0].birth.thread_name);
618 EXPECT_EQ(1, process_data.tasks[0].death_data.count);
619 EXPECT_EQ(2, process_data.tasks[0].death_data.run_duration_sum);
620 EXPECT_EQ(2, process_data.tasks[0].death_data.run_duration_max);
621 EXPECT_EQ(2, process_data.tasks[0].death_data.run_duration_sample);
622 EXPECT_EQ(4, process_data.tasks[0].death_data.queue_duration_sum);
623 EXPECT_EQ(4, process_data.tasks[0].death_data.queue_duration_max);
624 EXPECT_EQ(4, process_data.tasks[0].death_data.queue_duration_sample);
625 EXPECT_EQ(kMainThreadName, process_data.tasks[0].death_thread_name);
626 EXPECT_EQ(kFile, process_data.tasks[1].birth.location.file_name);
627 EXPECT_EQ(kFunction, process_data.tasks[1].birth.location.function_name);
628 EXPECT_EQ(kSecondFakeLineNumber,
629 process_data.tasks[1].birth.location.line_number);
630 EXPECT_EQ(kMainThreadName, process_data.tasks[1].birth.thread_name);
631 EXPECT_EQ(1, process_data.tasks[1].death_data.count);
632 EXPECT_EQ(0, process_data.tasks[1].death_data.run_duration_sum);
633 EXPECT_EQ(0, process_data.tasks[1].death_data.run_duration_max);
634 EXPECT_EQ(0, process_data.tasks[1].death_data.run_duration_sample);
635 EXPECT_EQ(0, process_data.tasks[1].death_data.queue_duration_sum);
636 EXPECT_EQ(0, process_data.tasks[1].death_data.queue_duration_max);
637 EXPECT_EQ(0, process_data.tasks[1].death_data.queue_duration_sample);
638 EXPECT_EQ(kStillAlive, process_data.tasks[1].death_thread_name);
639 EXPECT_EQ(0u, process_data.descendants.size());
640 EXPECT_EQ(base::GetCurrentProcId(), process_data.process_id);
641 }
642
TEST_F(TrackedObjectsTest,TaskWithNestedExclusion)643 TEST_F(TrackedObjectsTest, TaskWithNestedExclusion) {
644 if (!ThreadData::InitializeAndSetTrackingStatus(
645 ThreadData::PROFILING_CHILDREN_ACTIVE)) {
646 return;
647 }
648
649 const char kFunction[] = "TaskWithNestedExclusion";
650 Location location(kFunction, kFile, kLineNumber, NULL);
651 TallyABirth(location, kMainThreadName);
652
653 const base::TimeTicks kTimePosted = base::TimeTicks() +
654 base::TimeDelta::FromMilliseconds(1);
655 const base::TimeTicks kDelayedStartTime = base::TimeTicks();
656 // TrackingInfo will call TallyABirth() during construction.
657 base::TrackingInfo pending_task(location, kDelayedStartTime);
658 pending_task.time_posted = kTimePosted; // Overwrite implied Now().
659
660 SetTestTime(5);
661 TaskStopwatch task_stopwatch;
662 {
663 SetTestTime(8);
664 TaskStopwatch exclusion_stopwatch;
665 SetTestTime(12);
666 exclusion_stopwatch.Stop();
667 }
668 SetTestTime(15);
669 task_stopwatch.Stop();
670
671 ThreadData::TallyRunOnNamedThreadIfTracking(pending_task, task_stopwatch);
672
673 ProcessDataSnapshot process_data;
674 ThreadData::Snapshot(false, &process_data);
675 ExpectSimpleProcessData(process_data, kFunction, kMainThreadName,
676 kMainThreadName, 1, 6, 4);
677 }
678
TEST_F(TrackedObjectsTest,TaskWith2NestedExclusions)679 TEST_F(TrackedObjectsTest, TaskWith2NestedExclusions) {
680 if (!ThreadData::InitializeAndSetTrackingStatus(
681 ThreadData::PROFILING_CHILDREN_ACTIVE)) {
682 return;
683 }
684
685 const char kFunction[] = "TaskWith2NestedExclusions";
686 Location location(kFunction, kFile, kLineNumber, NULL);
687 TallyABirth(location, kMainThreadName);
688
689 const base::TimeTicks kTimePosted = base::TimeTicks() +
690 base::TimeDelta::FromMilliseconds(1);
691 const base::TimeTicks kDelayedStartTime = base::TimeTicks();
692 // TrackingInfo will call TallyABirth() during construction.
693 base::TrackingInfo pending_task(location, kDelayedStartTime);
694 pending_task.time_posted = kTimePosted; // Overwrite implied Now().
695
696 SetTestTime(5);
697 TaskStopwatch task_stopwatch;
698 {
699 SetTestTime(8);
700 TaskStopwatch exclusion_stopwatch;
701 SetTestTime(12);
702 exclusion_stopwatch.Stop();
703
704 SetTestTime(15);
705 TaskStopwatch exclusion_stopwatch2;
706 SetTestTime(18);
707 exclusion_stopwatch2.Stop();
708 }
709 SetTestTime(25);
710 task_stopwatch.Stop();
711
712 ThreadData::TallyRunOnNamedThreadIfTracking(pending_task, task_stopwatch);
713
714 ProcessDataSnapshot process_data;
715 ThreadData::Snapshot(false, &process_data);
716 ExpectSimpleProcessData(process_data, kFunction, kMainThreadName,
717 kMainThreadName, 1, 13, 4);
718 }
719
TEST_F(TrackedObjectsTest,TaskWithNestedExclusionWithNestedTask)720 TEST_F(TrackedObjectsTest, TaskWithNestedExclusionWithNestedTask) {
721 if (!ThreadData::InitializeAndSetTrackingStatus(
722 ThreadData::PROFILING_CHILDREN_ACTIVE)) {
723 return;
724 }
725
726 const char kFunction[] = "TaskWithNestedExclusionWithNestedTask";
727 Location location(kFunction, kFile, kLineNumber, NULL);
728
729 const int kSecondFakeLineNumber = 999;
730
731 TallyABirth(location, kMainThreadName);
732
733 const base::TimeTicks kTimePosted = base::TimeTicks() +
734 base::TimeDelta::FromMilliseconds(1);
735 const base::TimeTicks kDelayedStartTime = base::TimeTicks();
736 // TrackingInfo will call TallyABirth() during construction.
737 base::TrackingInfo pending_task(location, kDelayedStartTime);
738 pending_task.time_posted = kTimePosted; // Overwrite implied Now().
739
740 SetTestTime(5);
741 TaskStopwatch task_stopwatch;
742 {
743 SetTestTime(8);
744 TaskStopwatch exclusion_stopwatch;
745 {
746 Location second_location(kFunction, kFile, kSecondFakeLineNumber, NULL);
747 base::TrackingInfo nested_task(second_location, kDelayedStartTime);
748 // Overwrite implied Now().
749 nested_task.time_posted =
750 base::TimeTicks() + base::TimeDelta::FromMilliseconds(8);
751 SetTestTime(9);
752 TaskStopwatch nested_task_stopwatch;
753 SetTestTime(11);
754 nested_task_stopwatch.Stop();
755 ThreadData::TallyRunOnNamedThreadIfTracking(
756 nested_task, nested_task_stopwatch);
757 }
758 SetTestTime(12);
759 exclusion_stopwatch.Stop();
760 }
761 SetTestTime(15);
762 task_stopwatch.Stop();
763
764 ThreadData::TallyRunOnNamedThreadIfTracking(pending_task, task_stopwatch);
765
766 ProcessDataSnapshot process_data;
767 ThreadData::Snapshot(false, &process_data);
768
769 // The order in which the two task follow is platform-dependent.
770 int t0 = (process_data.tasks[0].birth.location.line_number == kLineNumber) ?
771 0 : 1;
772 int t1 = 1 - t0;
773
774 ASSERT_EQ(2u, process_data.tasks.size());
775 EXPECT_EQ(kFile, process_data.tasks[t0].birth.location.file_name);
776 EXPECT_EQ(kFunction, process_data.tasks[t0].birth.location.function_name);
777 EXPECT_EQ(kLineNumber, process_data.tasks[t0].birth.location.line_number);
778 EXPECT_EQ(kMainThreadName, process_data.tasks[t0].birth.thread_name);
779 EXPECT_EQ(1, process_data.tasks[t0].death_data.count);
780 EXPECT_EQ(6, process_data.tasks[t0].death_data.run_duration_sum);
781 EXPECT_EQ(6, process_data.tasks[t0].death_data.run_duration_max);
782 EXPECT_EQ(6, process_data.tasks[t0].death_data.run_duration_sample);
783 EXPECT_EQ(4, process_data.tasks[t0].death_data.queue_duration_sum);
784 EXPECT_EQ(4, process_data.tasks[t0].death_data.queue_duration_max);
785 EXPECT_EQ(4, process_data.tasks[t0].death_data.queue_duration_sample);
786 EXPECT_EQ(kMainThreadName, process_data.tasks[t0].death_thread_name);
787 EXPECT_EQ(kFile, process_data.tasks[t1].birth.location.file_name);
788 EXPECT_EQ(kFunction, process_data.tasks[t1].birth.location.function_name);
789 EXPECT_EQ(kSecondFakeLineNumber,
790 process_data.tasks[t1].birth.location.line_number);
791 EXPECT_EQ(kMainThreadName, process_data.tasks[t1].birth.thread_name);
792 EXPECT_EQ(1, process_data.tasks[t1].death_data.count);
793 EXPECT_EQ(2, process_data.tasks[t1].death_data.run_duration_sum);
794 EXPECT_EQ(2, process_data.tasks[t1].death_data.run_duration_max);
795 EXPECT_EQ(2, process_data.tasks[t1].death_data.run_duration_sample);
796 EXPECT_EQ(1, process_data.tasks[t1].death_data.queue_duration_sum);
797 EXPECT_EQ(1, process_data.tasks[t1].death_data.queue_duration_max);
798 EXPECT_EQ(1, process_data.tasks[t1].death_data.queue_duration_sample);
799 EXPECT_EQ(kMainThreadName, process_data.tasks[t1].death_thread_name);
800 EXPECT_EQ(0u, process_data.descendants.size());
801 EXPECT_EQ(base::GetCurrentProcId(), process_data.process_id);
802 }
803
804 } // namespace tracked_objects
805