base/tracked_objects_unittest.cc

   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   ~TrackedObjectsTest() override {
  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 TEST_F(TrackedObjectsTest, TaskStopwatchNoStartStop) {
 115   if (!ThreadData::InitializeAndSetTrackingStatus(
 116           ThreadData::PROFILING_CHILDREN_ACTIVE)) {
 117     return;
 118   }
 119
 120   // Check that creating and destroying a stopwatch without starting it doesn't
 121   // crash.
 122   TaskStopwatch stopwatch;
 123 }
 124
 125 TEST_F(TrackedObjectsTest, MinimalStartupShutdown) {
 126   // Minimal test doesn't even create any tasks.
 127   if (!ThreadData::InitializeAndSetTrackingStatus(
 128           ThreadData::PROFILING_CHILDREN_ACTIVE)) {
 129     return;
 130   }
 131
 132   EXPECT_FALSE(ThreadData::first());  // No activity even on this thread.
 133   ThreadData* data = ThreadData::Get();
 134   EXPECT_TRUE(ThreadData::first());  // Now class was constructed.
 135   ASSERT_TRUE(data);
 136   EXPECT_FALSE(data->next());
 137   EXPECT_EQ(data, ThreadData::Get());
 138   ThreadData::BirthMap birth_map;
 139   ThreadData::DeathMap death_map;
 140   ThreadData::ParentChildSet parent_child_set;
 141   data->SnapshotMaps(&birth_map, &death_map, &parent_child_set);
 142   EXPECT_EQ(0u, birth_map.size());
 143   EXPECT_EQ(0u, death_map.size());
 144   EXPECT_EQ(0u, parent_child_set.size());
 145
 146   // Clean up with no leaking.
 147   Reset();
 148
 149   // Do it again, just to be sure we reset state completely.
 150   EXPECT_TRUE(ThreadData::InitializeAndSetTrackingStatus(
 151       ThreadData::PROFILING_CHILDREN_ACTIVE));
 152   EXPECT_FALSE(ThreadData::first());  // No activity even on this thread.
 153   data = ThreadData::Get();
 154   EXPECT_TRUE(ThreadData::first());  // Now class was constructed.
 155   ASSERT_TRUE(data);
 156   EXPECT_FALSE(data->next());
 157   EXPECT_EQ(data, ThreadData::Get());
 158   birth_map.clear();
 159   death_map.clear();
 160   parent_child_set.clear();
 161   data->SnapshotMaps(&birth_map, &death_map, &parent_child_set);
 162   EXPECT_EQ(0u, birth_map.size());
 163   EXPECT_EQ(0u, death_map.size());
 164   EXPECT_EQ(0u, parent_child_set.size());
 165 }
 166
 167 TEST_F(TrackedObjectsTest, TinyStartupShutdown) {
 168   if (!ThreadData::InitializeAndSetTrackingStatus(
 169           ThreadData::PROFILING_CHILDREN_ACTIVE)) {
 170     return;
 171   }
 172
 173   // Instigate tracking on a single tracked object, on our thread.
 174   const char kFunction[] = "TinyStartupShutdown";
 175   Location location(kFunction, kFile, kLineNumber, NULL);
 176   Births* first_birth = ThreadData::TallyABirthIfActive(location);
 177
 178   ThreadData* data = ThreadData::first();
 179   ASSERT_TRUE(data);
 180   EXPECT_FALSE(data->next());
 181   EXPECT_EQ(data, ThreadData::Get());
 182   ThreadData::BirthMap birth_map;
 183   ThreadData::DeathMap death_map;
 184   ThreadData::ParentChildSet parent_child_set;
 185   data->SnapshotMaps(&birth_map, &death_map, &parent_child_set);
 186   EXPECT_EQ(1u, birth_map.size());                         // 1 birth location.
 187   EXPECT_EQ(1, birth_map.begin()->second->birth_count());  // 1 birth.
 188   EXPECT_EQ(0u, death_map.size());                         // No deaths.
 189   EXPECT_EQ(0u, parent_child_set.size());                  // No children.
 190
 191
 192   // Now instigate another birth, while we are timing the run of the first
 193   // execution.
 194   ThreadData::PrepareForStartOfRun(first_birth);
 195   // Create a child (using the same birth location).
 196   // TrackingInfo will call TallyABirth() during construction.
 197   const int32 start_time = 1;
 198   base::TimeTicks kBogusBirthTime = base::TimeTicks() +
 199       base::TimeDelta::FromMilliseconds(start_time);
 200   base::TrackingInfo pending_task(location, kBogusBirthTime);
 201   SetTestTime(1);
 202   TaskStopwatch stopwatch;
 203   stopwatch.Start();
 204   // Finally conclude the outer run.
 205   const int32 time_elapsed = 1000;
 206   SetTestTime(start_time + time_elapsed);
 207   stopwatch.Stop();
 208
 209   ThreadData::TallyRunOnNamedThreadIfTracking(pending_task, stopwatch);
 210
 211   birth_map.clear();
 212   death_map.clear();
 213   parent_child_set.clear();
 214   data->SnapshotMaps(&birth_map, &death_map, &parent_child_set);
 215   EXPECT_EQ(1u, birth_map.size());                         // 1 birth location.
 216   EXPECT_EQ(2, birth_map.begin()->second->birth_count());  // 2 births.
 217   EXPECT_EQ(1u, death_map.size());                         // 1 location.
 218   EXPECT_EQ(1, death_map.begin()->second.count());         // 1 death.
 219   if (ThreadData::TrackingParentChildStatus()) {
 220     EXPECT_EQ(1u, parent_child_set.size());                  // 1 child.
 221     EXPECT_EQ(parent_child_set.begin()->first,
 222               parent_child_set.begin()->second);
 223   } else {
 224     EXPECT_EQ(0u, parent_child_set.size());                  // no stats.
 225   }
 226
 227   // The births were at the same location as the one known death.
 228   EXPECT_EQ(birth_map.begin()->second, death_map.begin()->first);
 229
 230   ProcessDataSnapshot process_data;
 231   ThreadData::Snapshot(&process_data);
 232
 233   ASSERT_EQ(1u, process_data.tasks.size());
 234   EXPECT_EQ(kFile, process_data.tasks[0].birth.location.file_name);
 235   EXPECT_EQ(kFunction, process_data.tasks[0].birth.location.function_name);
 236   EXPECT_EQ(kLineNumber, process_data.tasks[0].birth.location.line_number);
 237   EXPECT_EQ(kWorkerThreadName, process_data.tasks[0].birth.thread_name);
 238   EXPECT_EQ(1, process_data.tasks[0].death_data.count);
 239   EXPECT_EQ(time_elapsed, process_data.tasks[0].death_data.run_duration_sum);
 240   EXPECT_EQ(time_elapsed, process_data.tasks[0].death_data.run_duration_max);
 241   EXPECT_EQ(time_elapsed, process_data.tasks[0].death_data.run_duration_sample);
 242   EXPECT_EQ(0, process_data.tasks[0].death_data.queue_duration_sum);
 243   EXPECT_EQ(0, process_data.tasks[0].death_data.queue_duration_max);
 244   EXPECT_EQ(0, process_data.tasks[0].death_data.queue_duration_sample);
 245   EXPECT_EQ(kWorkerThreadName, process_data.tasks[0].death_thread_name);
 246
 247   if (ThreadData::TrackingParentChildStatus()) {
 248     ASSERT_EQ(1u, process_data.descendants.size());
 249     EXPECT_EQ(kFile, process_data.descendants[0].parent.location.file_name);
 250     EXPECT_EQ(kFunction,
 251               process_data.descendants[0].parent.location.function_name);
 252     EXPECT_EQ(kLineNumber,
 253               process_data.descendants[0].parent.location.line_number);
 254     EXPECT_EQ(kWorkerThreadName,
 255               process_data.descendants[0].parent.thread_name);
 256     EXPECT_EQ(kFile, process_data.descendants[0].child.location.file_name);
 257     EXPECT_EQ(kFunction,
 258               process_data.descendants[0].child.location.function_name);
 259     EXPECT_EQ(kLineNumber,
 260               process_data.descendants[0].child.location.line_number);
 261     EXPECT_EQ(kWorkerThreadName, process_data.descendants[0].child.thread_name);
 262   } else {
 263     EXPECT_EQ(0u, process_data.descendants.size());
 264   }
 265 }
 266
 267 TEST_F(TrackedObjectsTest, DeathDataTest) {
 268   if (!ThreadData::InitializeAndSetTrackingStatus(
 269           ThreadData::PROFILING_CHILDREN_ACTIVE)) {
 270     return;
 271   }
 272
 273   scoped_ptr<DeathData> data(new DeathData());
 274   ASSERT_NE(data, reinterpret_cast<DeathData*>(NULL));
 275   EXPECT_EQ(data->run_duration_sum(), 0);
 276   EXPECT_EQ(data->run_duration_sample(), 0);
 277   EXPECT_EQ(data->queue_duration_sum(), 0);
 278   EXPECT_EQ(data->queue_duration_sample(), 0);
 279   EXPECT_EQ(data->count(), 0);
 280
 281   int32 run_ms = 42;
 282   int32 queue_ms = 8;
 283
 284   const int kUnrandomInt = 0;  // Fake random int that ensure we sample data.
 285   data->RecordDeath(queue_ms, run_ms, kUnrandomInt);
 286   EXPECT_EQ(data->run_duration_sum(), run_ms);
 287   EXPECT_EQ(data->run_duration_sample(), run_ms);
 288   EXPECT_EQ(data->queue_duration_sum(), queue_ms);
 289   EXPECT_EQ(data->queue_duration_sample(), queue_ms);
 290   EXPECT_EQ(data->count(), 1);
 291
 292   data->RecordDeath(queue_ms, run_ms, kUnrandomInt);
 293   EXPECT_EQ(data->run_duration_sum(), run_ms + run_ms);
 294   EXPECT_EQ(data->run_duration_sample(), run_ms);
 295   EXPECT_EQ(data->queue_duration_sum(), queue_ms + queue_ms);
 296   EXPECT_EQ(data->queue_duration_sample(), queue_ms);
 297   EXPECT_EQ(data->count(), 2);
 298
 299   DeathDataSnapshot snapshot(*data);
 300   EXPECT_EQ(2, snapshot.count);
 301   EXPECT_EQ(2 * run_ms, snapshot.run_duration_sum);
 302   EXPECT_EQ(run_ms, snapshot.run_duration_max);
 303   EXPECT_EQ(run_ms, snapshot.run_duration_sample);
 304   EXPECT_EQ(2 * queue_ms, snapshot.queue_duration_sum);
 305   EXPECT_EQ(queue_ms, snapshot.queue_duration_max);
 306   EXPECT_EQ(queue_ms, snapshot.queue_duration_sample);
 307 }
 308
 309 TEST_F(TrackedObjectsTest, DeactivatedBirthOnlyToSnapshotWorkerThread) {
 310   // Start in the deactivated state.
 311   if (!ThreadData::InitializeAndSetTrackingStatus(ThreadData::DEACTIVATED)) {
 312     return;
 313   }
 314
 315   const char kFunction[] = "DeactivatedBirthOnlyToSnapshotWorkerThread";
 316   Location location(kFunction, kFile, kLineNumber, NULL);
 317   TallyABirth(location, std::string());
 318
 319   ProcessDataSnapshot process_data;
 320   ThreadData::Snapshot(&process_data);
 321   EXPECT_EQ(0u, process_data.tasks.size());
 322   EXPECT_EQ(0u, process_data.descendants.size());
 323   EXPECT_EQ(base::GetCurrentProcId(), process_data.process_id);
 324 }
 325
 326 TEST_F(TrackedObjectsTest, DeactivatedBirthOnlyToSnapshotMainThread) {
 327   // Start in the deactivated state.
 328   if (!ThreadData::InitializeAndSetTrackingStatus(ThreadData::DEACTIVATED)) {
 329     return;
 330   }
 331
 332   const char kFunction[] = "DeactivatedBirthOnlyToSnapshotMainThread";
 333   Location location(kFunction, kFile, kLineNumber, NULL);
 334   TallyABirth(location, kMainThreadName);
 335
 336   ProcessDataSnapshot process_data;
 337   ThreadData::Snapshot(&process_data);
 338   EXPECT_EQ(0u, process_data.tasks.size());
 339   EXPECT_EQ(0u, process_data.descendants.size());
 340   EXPECT_EQ(base::GetCurrentProcId(), process_data.process_id);
 341 }
 342
 343 TEST_F(TrackedObjectsTest, BirthOnlyToSnapshotWorkerThread) {
 344   if (!ThreadData::InitializeAndSetTrackingStatus(
 345           ThreadData::PROFILING_CHILDREN_ACTIVE)) {
 346     return;
 347   }
 348
 349   const char kFunction[] = "BirthOnlyToSnapshotWorkerThread";
 350   Location location(kFunction, kFile, kLineNumber, NULL);
 351   TallyABirth(location, std::string());
 352
 353   ProcessDataSnapshot process_data;
 354   ThreadData::Snapshot(&process_data);
 355   ExpectSimpleProcessData(process_data, kFunction, kWorkerThreadName,
 356                           kStillAlive, 1, 0, 0);
 357 }
 358
 359 TEST_F(TrackedObjectsTest, BirthOnlyToSnapshotMainThread) {
 360   if (!ThreadData::InitializeAndSetTrackingStatus(
 361           ThreadData::PROFILING_CHILDREN_ACTIVE)) {
 362     return;
 363   }
 364
 365   const char kFunction[] = "BirthOnlyToSnapshotMainThread";
 366   Location location(kFunction, kFile, kLineNumber, NULL);
 367   TallyABirth(location, kMainThreadName);
 368
 369   ProcessDataSnapshot process_data;
 370   ThreadData::Snapshot(&process_data);
 371   ExpectSimpleProcessData(process_data, kFunction, kMainThreadName, kStillAlive,
 372                           1, 0, 0);
 373 }
 374
 375 TEST_F(TrackedObjectsTest, LifeCycleToSnapshotMainThread) {
 376   if (!ThreadData::InitializeAndSetTrackingStatus(
 377           ThreadData::PROFILING_CHILDREN_ACTIVE)) {
 378     return;
 379   }
 380
 381   const char kFunction[] = "LifeCycleToSnapshotMainThread";
 382   Location location(kFunction, kFile, kLineNumber, NULL);
 383   TallyABirth(location, kMainThreadName);
 384
 385   const TrackedTime kTimePosted = TrackedTime::FromMilliseconds(1);
 386   const base::TimeTicks kDelayedStartTime = base::TimeTicks();
 387   // TrackingInfo will call TallyABirth() during construction.
 388   base::TrackingInfo pending_task(location, kDelayedStartTime);
 389   pending_task.time_posted = kTimePosted;  // Overwrite implied Now().
 390
 391   const unsigned int kStartOfRun = 5;
 392   const unsigned int kEndOfRun = 7;
 393   SetTestTime(kStartOfRun);
 394   TaskStopwatch stopwatch;
 395   stopwatch.Start();
 396   SetTestTime(kEndOfRun);
 397   stopwatch.Stop();
 398
 399   ThreadData::TallyRunOnNamedThreadIfTracking(pending_task, stopwatch);
 400
 401   ProcessDataSnapshot process_data;
 402   ThreadData::Snapshot(&process_data);
 403   ExpectSimpleProcessData(process_data, kFunction, kMainThreadName,
 404                           kMainThreadName, 1, 2, 4);
 405 }
 406
 407 // We will deactivate tracking after the birth, and before the death, and
 408 // demonstrate that the lifecycle is completely tallied. This ensures that
 409 // our tallied births are matched by tallied deaths (except for when the
 410 // task is still running, or is queued).
 411 TEST_F(TrackedObjectsTest, LifeCycleMidDeactivatedToSnapshotMainThread) {
 412   if (!ThreadData::InitializeAndSetTrackingStatus(
 413           ThreadData::PROFILING_CHILDREN_ACTIVE)) {
 414     return;
 415   }
 416
 417   const char kFunction[] = "LifeCycleMidDeactivatedToSnapshotMainThread";
 418   Location location(kFunction, kFile, kLineNumber, NULL);
 419   TallyABirth(location, kMainThreadName);
 420
 421   const TrackedTime kTimePosted = TrackedTime::FromMilliseconds(1);
 422   const base::TimeTicks kDelayedStartTime = base::TimeTicks();
 423   // TrackingInfo will call TallyABirth() during construction.
 424   base::TrackingInfo pending_task(location, kDelayedStartTime);
 425   pending_task.time_posted = kTimePosted;  // Overwrite implied Now().
 426
 427   // Turn off tracking now that we have births.
 428   EXPECT_TRUE(ThreadData::InitializeAndSetTrackingStatus(
 429       ThreadData::DEACTIVATED));
 430
 431   const unsigned int kStartOfRun = 5;
 432   const unsigned int kEndOfRun = 7;
 433   SetTestTime(kStartOfRun);
 434   TaskStopwatch stopwatch;
 435   stopwatch.Start();
 436   SetTestTime(kEndOfRun);
 437   stopwatch.Stop();
 438
 439   ThreadData::TallyRunOnNamedThreadIfTracking(pending_task, stopwatch);
 440
 441   ProcessDataSnapshot process_data;
 442   ThreadData::Snapshot(&process_data);
 443   ExpectSimpleProcessData(process_data, kFunction, kMainThreadName,
 444                           kMainThreadName, 1, 2, 4);
 445 }
 446
 447 // We will deactivate tracking before starting a life cycle, and neither
 448 // the birth nor the death will be recorded.
 449 TEST_F(TrackedObjectsTest, LifeCyclePreDeactivatedToSnapshotMainThread) {
 450   // Start in the deactivated state.
 451   if (!ThreadData::InitializeAndSetTrackingStatus(ThreadData::DEACTIVATED)) {
 452     return;
 453   }
 454
 455   const char kFunction[] = "LifeCyclePreDeactivatedToSnapshotMainThread";
 456   Location location(kFunction, kFile, kLineNumber, NULL);
 457   TallyABirth(location, kMainThreadName);
 458
 459   const TrackedTime kTimePosted = TrackedTime::FromMilliseconds(1);
 460   const base::TimeTicks kDelayedStartTime = base::TimeTicks();
 461   // TrackingInfo will call TallyABirth() during construction.
 462   base::TrackingInfo pending_task(location, kDelayedStartTime);
 463   pending_task.time_posted = kTimePosted;  // Overwrite implied Now().
 464
 465   const unsigned int kStartOfRun = 5;
 466   const unsigned int kEndOfRun = 7;
 467   SetTestTime(kStartOfRun);
 468   TaskStopwatch stopwatch;
 469   stopwatch.Start();
 470   SetTestTime(kEndOfRun);
 471   stopwatch.Stop();
 472
 473   ThreadData::TallyRunOnNamedThreadIfTracking(pending_task, stopwatch);
 474
 475   ProcessDataSnapshot process_data;
 476   ThreadData::Snapshot(&process_data);
 477   EXPECT_EQ(0u, process_data.tasks.size());
 478   EXPECT_EQ(0u, process_data.descendants.size());
 479   EXPECT_EQ(base::GetCurrentProcId(), process_data.process_id);
 480 }
 481
 482 TEST_F(TrackedObjectsTest, TwoLives) {
 483   if (!ThreadData::InitializeAndSetTrackingStatus(
 484           ThreadData::PROFILING_CHILDREN_ACTIVE)) {
 485     return;
 486   }
 487
 488   const char kFunction[] = "TwoLives";
 489   Location location(kFunction, kFile, kLineNumber, NULL);
 490   TallyABirth(location, kMainThreadName);
 491
 492   const TrackedTime kTimePosted = TrackedTime::FromMilliseconds(1);
 493   const base::TimeTicks kDelayedStartTime = base::TimeTicks();
 494   // TrackingInfo will call TallyABirth() during construction.
 495   base::TrackingInfo pending_task(location, kDelayedStartTime);
 496   pending_task.time_posted = kTimePosted;  // Overwrite implied Now().
 497
 498   const unsigned int kStartOfRun = 5;
 499   const unsigned int kEndOfRun = 7;
 500   SetTestTime(kStartOfRun);
 501   TaskStopwatch stopwatch;
 502   stopwatch.Start();
 503   SetTestTime(kEndOfRun);
 504   stopwatch.Stop();
 505
 506   ThreadData::TallyRunOnNamedThreadIfTracking(pending_task, stopwatch);
 507
 508   // TrackingInfo will call TallyABirth() during construction.
 509   base::TrackingInfo pending_task2(location, kDelayedStartTime);
 510   pending_task2.time_posted = kTimePosted;  // Overwrite implied Now().
 511   SetTestTime(kStartOfRun);
 512   TaskStopwatch stopwatch2;
 513   stopwatch2.Start();
 514   SetTestTime(kEndOfRun);
 515   stopwatch2.Stop();
 516
 517   ThreadData::TallyRunOnNamedThreadIfTracking(pending_task2, stopwatch2);
 518
 519   ProcessDataSnapshot process_data;
 520   ThreadData::Snapshot(&process_data);
 521   ExpectSimpleProcessData(process_data, kFunction, kMainThreadName,
 522                           kMainThreadName, 2, 2, 4);
 523 }
 524
 525 TEST_F(TrackedObjectsTest, DifferentLives) {
 526   if (!ThreadData::InitializeAndSetTrackingStatus(
 527           ThreadData::PROFILING_CHILDREN_ACTIVE)) {
 528     return;
 529   }
 530
 531   // Use a well named thread.
 532   ThreadData::InitializeThreadContext(kMainThreadName);
 533   const char kFunction[] = "DifferentLives";
 534   Location location(kFunction, kFile, kLineNumber, NULL);
 535
 536   const TrackedTime kTimePosted = TrackedTime::FromMilliseconds(1);
 537   const base::TimeTicks kDelayedStartTime = base::TimeTicks();
 538   // TrackingInfo will call TallyABirth() during construction.
 539   base::TrackingInfo pending_task(location, kDelayedStartTime);
 540   pending_task.time_posted = kTimePosted;  // Overwrite implied Now().
 541
 542   const unsigned int kStartOfRun = 5;
 543   const unsigned int kEndOfRun = 7;
 544   SetTestTime(kStartOfRun);
 545   TaskStopwatch stopwatch;
 546   stopwatch.Start();
 547   SetTestTime(kEndOfRun);
 548   stopwatch.Stop();
 549
 550   ThreadData::TallyRunOnNamedThreadIfTracking(pending_task, stopwatch);
 551
 552   const int kSecondFakeLineNumber = 999;
 553   Location second_location(kFunction, kFile, kSecondFakeLineNumber, NULL);
 554
 555   // TrackingInfo will call TallyABirth() during construction.
 556   base::TrackingInfo pending_task2(second_location, kDelayedStartTime);
 557   pending_task2.time_posted = kTimePosted;  // Overwrite implied Now().
 558
 559   ProcessDataSnapshot process_data;
 560   ThreadData::Snapshot(&process_data);
 561   ASSERT_EQ(2u, process_data.tasks.size());
 562
 563   EXPECT_EQ(kFile, process_data.tasks[0].birth.location.file_name);
 564   EXPECT_EQ(kFunction, process_data.tasks[0].birth.location.function_name);
 565   EXPECT_EQ(kLineNumber, process_data.tasks[0].birth.location.line_number);
 566   EXPECT_EQ(kMainThreadName, process_data.tasks[0].birth.thread_name);
 567   EXPECT_EQ(1, process_data.tasks[0].death_data.count);
 568   EXPECT_EQ(2, process_data.tasks[0].death_data.run_duration_sum);
 569   EXPECT_EQ(2, process_data.tasks[0].death_data.run_duration_max);
 570   EXPECT_EQ(2, process_data.tasks[0].death_data.run_duration_sample);
 571   EXPECT_EQ(4, process_data.tasks[0].death_data.queue_duration_sum);
 572   EXPECT_EQ(4, process_data.tasks[0].death_data.queue_duration_max);
 573   EXPECT_EQ(4, process_data.tasks[0].death_data.queue_duration_sample);
 574   EXPECT_EQ(kMainThreadName, process_data.tasks[0].death_thread_name);
 575   EXPECT_EQ(kFile, process_data.tasks[1].birth.location.file_name);
 576   EXPECT_EQ(kFunction, process_data.tasks[1].birth.location.function_name);
 577   EXPECT_EQ(kSecondFakeLineNumber,
 578             process_data.tasks[1].birth.location.line_number);
 579   EXPECT_EQ(kMainThreadName, process_data.tasks[1].birth.thread_name);
 580   EXPECT_EQ(1, process_data.tasks[1].death_data.count);
 581   EXPECT_EQ(0, process_data.tasks[1].death_data.run_duration_sum);
 582   EXPECT_EQ(0, process_data.tasks[1].death_data.run_duration_max);
 583   EXPECT_EQ(0, process_data.tasks[1].death_data.run_duration_sample);
 584   EXPECT_EQ(0, process_data.tasks[1].death_data.queue_duration_sum);
 585   EXPECT_EQ(0, process_data.tasks[1].death_data.queue_duration_max);
 586   EXPECT_EQ(0, process_data.tasks[1].death_data.queue_duration_sample);
 587   EXPECT_EQ(kStillAlive, process_data.tasks[1].death_thread_name);
 588   EXPECT_EQ(0u, process_data.descendants.size());
 589   EXPECT_EQ(base::GetCurrentProcId(), process_data.process_id);
 590 }
 591
 592 TEST_F(TrackedObjectsTest, TaskWithNestedExclusion) {
 593   if (!ThreadData::InitializeAndSetTrackingStatus(
 594           ThreadData::PROFILING_CHILDREN_ACTIVE)) {
 595     return;
 596   }
 597
 598   const char kFunction[] = "TaskWithNestedExclusion";
 599   Location location(kFunction, kFile, kLineNumber, NULL);
 600   TallyABirth(location, kMainThreadName);
 601
 602   const TrackedTime kTimePosted = TrackedTime::FromMilliseconds(1);
 603   const base::TimeTicks kDelayedStartTime = base::TimeTicks();
 604   // TrackingInfo will call TallyABirth() during construction.
 605   base::TrackingInfo pending_task(location, kDelayedStartTime);
 606   pending_task.time_posted = kTimePosted;  // Overwrite implied Now().
 607
 608   SetTestTime(5);
 609   TaskStopwatch task_stopwatch;
 610   task_stopwatch.Start();
 611   {
 612     SetTestTime(8);
 613     TaskStopwatch exclusion_stopwatch;
 614     exclusion_stopwatch.Start();
 615     SetTestTime(12);
 616     exclusion_stopwatch.Stop();
 617   }
 618   SetTestTime(15);
 619   task_stopwatch.Stop();
 620
 621   ThreadData::TallyRunOnNamedThreadIfTracking(pending_task, task_stopwatch);
 622
 623   ProcessDataSnapshot process_data;
 624   ThreadData::Snapshot(&process_data);
 625   ExpectSimpleProcessData(process_data, kFunction, kMainThreadName,
 626                           kMainThreadName, 1, 6, 4);
 627 }
 628
 629 TEST_F(TrackedObjectsTest, TaskWith2NestedExclusions) {
 630   if (!ThreadData::InitializeAndSetTrackingStatus(
 631           ThreadData::PROFILING_CHILDREN_ACTIVE)) {
 632     return;
 633   }
 634
 635   const char kFunction[] = "TaskWith2NestedExclusions";
 636   Location location(kFunction, kFile, kLineNumber, NULL);
 637   TallyABirth(location, kMainThreadName);
 638
 639   const TrackedTime kTimePosted = TrackedTime::FromMilliseconds(1);
 640   const base::TimeTicks kDelayedStartTime = base::TimeTicks();
 641   // TrackingInfo will call TallyABirth() during construction.
 642   base::TrackingInfo pending_task(location, kDelayedStartTime);
 643   pending_task.time_posted = kTimePosted;  // Overwrite implied Now().
 644
 645   SetTestTime(5);
 646   TaskStopwatch task_stopwatch;
 647   task_stopwatch.Start();
 648   {
 649     SetTestTime(8);
 650     TaskStopwatch exclusion_stopwatch;
 651     exclusion_stopwatch.Start();
 652     SetTestTime(12);
 653     exclusion_stopwatch.Stop();
 654
 655     SetTestTime(15);
 656     TaskStopwatch exclusion_stopwatch2;
 657     exclusion_stopwatch2.Start();
 658     SetTestTime(18);
 659     exclusion_stopwatch2.Stop();
 660   }
 661   SetTestTime(25);
 662   task_stopwatch.Stop();
 663
 664   ThreadData::TallyRunOnNamedThreadIfTracking(pending_task, task_stopwatch);
 665
 666   ProcessDataSnapshot process_data;
 667   ThreadData::Snapshot(&process_data);
 668   ExpectSimpleProcessData(process_data, kFunction, kMainThreadName,
 669                           kMainThreadName, 1, 13, 4);
 670 }
 671
 672 TEST_F(TrackedObjectsTest, TaskWithNestedExclusionWithNestedTask) {
 673   if (!ThreadData::InitializeAndSetTrackingStatus(
 674           ThreadData::PROFILING_CHILDREN_ACTIVE)) {
 675     return;
 676   }
 677
 678   const char kFunction[] = "TaskWithNestedExclusionWithNestedTask";
 679   Location location(kFunction, kFile, kLineNumber, NULL);
 680
 681   const int kSecondFakeLineNumber = 999;
 682
 683   TallyABirth(location, kMainThreadName);
 684
 685   const TrackedTime kTimePosted = TrackedTime::FromMilliseconds(1);
 686   const base::TimeTicks kDelayedStartTime = base::TimeTicks();
 687   // TrackingInfo will call TallyABirth() during construction.
 688   base::TrackingInfo pending_task(location, kDelayedStartTime);
 689   pending_task.time_posted = kTimePosted;  // Overwrite implied Now().
 690
 691   SetTestTime(5);
 692   TaskStopwatch task_stopwatch;
 693   task_stopwatch.Start();
 694   {
 695     SetTestTime(8);
 696     TaskStopwatch exclusion_stopwatch;
 697     exclusion_stopwatch.Start();
 698     {
 699       Location second_location(kFunction, kFile, kSecondFakeLineNumber, NULL);
 700       base::TrackingInfo nested_task(second_location, kDelayedStartTime);
 701        // Overwrite implied Now().
 702       nested_task.time_posted = TrackedTime::FromMilliseconds(8);
 703       SetTestTime(9);
 704       TaskStopwatch nested_task_stopwatch;
 705       nested_task_stopwatch.Start();
 706       SetTestTime(11);
 707       nested_task_stopwatch.Stop();
 708       ThreadData::TallyRunOnNamedThreadIfTracking(
 709           nested_task, nested_task_stopwatch);
 710     }
 711     SetTestTime(12);
 712     exclusion_stopwatch.Stop();
 713   }
 714   SetTestTime(15);
 715   task_stopwatch.Stop();
 716
 717   ThreadData::TallyRunOnNamedThreadIfTracking(pending_task, task_stopwatch);
 718
 719   ProcessDataSnapshot process_data;
 720   ThreadData::Snapshot(&process_data);
 721
 722   // The order in which the two task follow is platform-dependent.
 723   int t0 = (process_data.tasks[0].birth.location.line_number == kLineNumber) ?
 724       0 : 1;
 725   int t1 = 1 - t0;
 726
 727   ASSERT_EQ(2u, process_data.tasks.size());
 728   EXPECT_EQ(kFile, process_data.tasks[t0].birth.location.file_name);
 729   EXPECT_EQ(kFunction, process_data.tasks[t0].birth.location.function_name);
 730   EXPECT_EQ(kLineNumber, process_data.tasks[t0].birth.location.line_number);
 731   EXPECT_EQ(kMainThreadName, process_data.tasks[t0].birth.thread_name);
 732   EXPECT_EQ(1, process_data.tasks[t0].death_data.count);
 733   EXPECT_EQ(6, process_data.tasks[t0].death_data.run_duration_sum);
 734   EXPECT_EQ(6, process_data.tasks[t0].death_data.run_duration_max);
 735   EXPECT_EQ(6, process_data.tasks[t0].death_data.run_duration_sample);
 736   EXPECT_EQ(4, process_data.tasks[t0].death_data.queue_duration_sum);
 737   EXPECT_EQ(4, process_data.tasks[t0].death_data.queue_duration_max);
 738   EXPECT_EQ(4, process_data.tasks[t0].death_data.queue_duration_sample);
 739   EXPECT_EQ(kMainThreadName, process_data.tasks[t0].death_thread_name);
 740   EXPECT_EQ(kFile, process_data.tasks[t1].birth.location.file_name);
 741   EXPECT_EQ(kFunction, process_data.tasks[t1].birth.location.function_name);
 742   EXPECT_EQ(kSecondFakeLineNumber,
 743             process_data.tasks[t1].birth.location.line_number);
 744   EXPECT_EQ(kMainThreadName, process_data.tasks[t1].birth.thread_name);
 745   EXPECT_EQ(1, process_data.tasks[t1].death_data.count);
 746   EXPECT_EQ(2, process_data.tasks[t1].death_data.run_duration_sum);
 747   EXPECT_EQ(2, process_data.tasks[t1].death_data.run_duration_max);
 748   EXPECT_EQ(2, process_data.tasks[t1].death_data.run_duration_sample);
 749   EXPECT_EQ(1, process_data.tasks[t1].death_data.queue_duration_sum);
 750   EXPECT_EQ(1, process_data.tasks[t1].death_data.queue_duration_max);
 751   EXPECT_EQ(1, process_data.tasks[t1].death_data.queue_duration_sample);
 752   EXPECT_EQ(kMainThreadName, process_data.tasks[t1].death_thread_name);
 753   EXPECT_EQ(0u, process_data.descendants.size());
 754   EXPECT_EQ(base::GetCurrentProcId(), process_data.process_id);
 755 }
 756
 757 }  // namespace tracked_objects