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: 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 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. 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|. 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. 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(). 101 static void SetTestTime(unsigned int test_time) { test_time_ = test_time; } 102 103 private: 104 // Returns test time in milliseconds. 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 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 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 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 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 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 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 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 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). 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. 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 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 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 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 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 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 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
