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(false, &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(false, &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(false, &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(false, &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(false, &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(false, &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(false, &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(false, &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(false, &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 base::TimeTicks kTimePosted = base::TimeTicks() +
 386       base::TimeDelta::FromMilliseconds(1);
 387   const base::TimeTicks kDelayedStartTime = base::TimeTicks();
 388   // TrackingInfo will call TallyABirth() during construction.
 389   base::TrackingInfo pending_task(location, kDelayedStartTime);
 390   pending_task.time_posted = kTimePosted;  // Overwrite implied Now().
 391
 392   const unsigned int kStartOfRun = 5;
 393   const unsigned int kEndOfRun = 7;
 394   SetTestTime(kStartOfRun);
 395   TaskStopwatch stopwatch;
 396   stopwatch.Start();
 397   SetTestTime(kEndOfRun);
 398   stopwatch.Stop();
 399
 400   ThreadData::TallyRunOnNamedThreadIfTracking(pending_task, stopwatch);
 401
 402   ProcessDataSnapshot process_data;
 403   ThreadData::Snapshot(false, &process_data);
 404   ExpectSimpleProcessData(process_data, kFunction, kMainThreadName,
 405                           kMainThreadName, 1, 2, 4);
 406 }
 407
 408 // We will deactivate tracking after the birth, and before the death, and
 409 // demonstrate that the lifecycle is completely tallied. This ensures that
 410 // our tallied births are matched by tallied deaths (except for when the
 411 // task is still running, or is queued).
 412 TEST_F(TrackedObjectsTest, LifeCycleMidDeactivatedToSnapshotMainThread) {
 413   if (!ThreadData::InitializeAndSetTrackingStatus(
 414           ThreadData::PROFILING_CHILDREN_ACTIVE)) {
 415     return;
 416   }
 417
 418   const char kFunction[] = "LifeCycleMidDeactivatedToSnapshotMainThread";
 419   Location location(kFunction, kFile, kLineNumber, NULL);
 420   TallyABirth(location, kMainThreadName);
 421
 422   const base::TimeTicks kTimePosted = base::TimeTicks() +
 423       base::TimeDelta::FromMilliseconds(1);
 424   const base::TimeTicks kDelayedStartTime = base::TimeTicks();
 425   // TrackingInfo will call TallyABirth() during construction.
 426   base::TrackingInfo pending_task(location, kDelayedStartTime);
 427   pending_task.time_posted = kTimePosted;  // Overwrite implied Now().
 428
 429   // Turn off tracking now that we have births.
 430   EXPECT_TRUE(ThreadData::InitializeAndSetTrackingStatus(
 431       ThreadData::DEACTIVATED));
 432
 433   const unsigned int kStartOfRun = 5;
 434   const unsigned int kEndOfRun = 7;
 435   SetTestTime(kStartOfRun);
 436   TaskStopwatch stopwatch;
 437   stopwatch.Start();
 438   SetTestTime(kEndOfRun);
 439   stopwatch.Stop();
 440
 441   ThreadData::TallyRunOnNamedThreadIfTracking(pending_task, stopwatch);
 442
 443   ProcessDataSnapshot process_data;
 444   ThreadData::Snapshot(false, &process_data);
 445   ExpectSimpleProcessData(process_data, kFunction, kMainThreadName,
 446                           kMainThreadName, 1, 2, 4);
 447 }
 448
 449 // We will deactivate tracking before starting a life cycle, and neither
 450 // the birth nor the death will be recorded.
 451 TEST_F(TrackedObjectsTest, LifeCyclePreDeactivatedToSnapshotMainThread) {
 452   // Start in the deactivated state.
 453   if (!ThreadData::InitializeAndSetTrackingStatus(ThreadData::DEACTIVATED)) {
 454     return;
 455   }
 456
 457   const char kFunction[] = "LifeCyclePreDeactivatedToSnapshotMainThread";
 458   Location location(kFunction, kFile, kLineNumber, NULL);
 459   TallyABirth(location, kMainThreadName);
 460
 461   const base::TimeTicks kTimePosted = base::TimeTicks() +
 462       base::TimeDelta::FromMilliseconds(1);
 463   const base::TimeTicks kDelayedStartTime = base::TimeTicks();
 464   // TrackingInfo will call TallyABirth() during construction.
 465   base::TrackingInfo pending_task(location, kDelayedStartTime);
 466   pending_task.time_posted = kTimePosted;  // Overwrite implied Now().
 467
 468   const unsigned int kStartOfRun = 5;
 469   const unsigned int kEndOfRun = 7;
 470   SetTestTime(kStartOfRun);
 471   TaskStopwatch stopwatch;
 472   stopwatch.Start();
 473   SetTestTime(kEndOfRun);
 474   stopwatch.Stop();
 475
 476   ThreadData::TallyRunOnNamedThreadIfTracking(pending_task, stopwatch);
 477
 478   ProcessDataSnapshot process_data;
 479   ThreadData::Snapshot(false, &process_data);
 480   EXPECT_EQ(0u, process_data.tasks.size());
 481   EXPECT_EQ(0u, process_data.descendants.size());
 482   EXPECT_EQ(base::GetCurrentProcId(), process_data.process_id);
 483 }
 484
 485 TEST_F(TrackedObjectsTest, LifeCycleToSnapshotWorkerThread) {
 486   if (!ThreadData::InitializeAndSetTrackingStatus(
 487           ThreadData::PROFILING_CHILDREN_ACTIVE)) {
 488     return;
 489   }
 490
 491   const char kFunction[] = "LifeCycleToSnapshotWorkerThread";
 492   Location location(kFunction, kFile, kLineNumber, NULL);
 493   // Do not delete |birth|.  We don't own it.
 494   Births* birth = ThreadData::TallyABirthIfActive(location);
 495   EXPECT_NE(reinterpret_cast<Births*>(NULL), birth);
 496
 497   const unsigned int kTimePosted = 1;
 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::TallyRunOnWorkerThreadIfTracking(
 507   birth, TrackedTime() + Duration::FromMilliseconds(kTimePosted), stopwatch);
 508
 509   // Call for the ToSnapshot, but tell it to not reset the maxes after scanning.
 510   ProcessDataSnapshot process_data;
 511   ThreadData::Snapshot(false, &process_data);
 512   ExpectSimpleProcessData(process_data, kFunction, kWorkerThreadName,
 513                           kWorkerThreadName, 1, 2, 4);
 514
 515   // Call for the ToSnapshot, but tell it to reset the maxes after scanning.
 516   // We'll still get the same values, but the data will be reset (which we'll
 517   // see in a moment).
 518   ProcessDataSnapshot process_data_pre_reset;
 519   ThreadData::Snapshot(true, &process_data_pre_reset);
 520   ExpectSimpleProcessData(process_data, kFunction, kWorkerThreadName,
 521                           kWorkerThreadName, 1, 2, 4);
 522
 523   // Call for the ToSnapshot, and now we'll see the result of the last
 524   // translation, as the max will have been pushed back to zero.
 525   ProcessDataSnapshot process_data_post_reset;
 526   ThreadData::Snapshot(true, &process_data_post_reset);
 527   ASSERT_EQ(1u, process_data_post_reset.tasks.size());
 528   EXPECT_EQ(kFile, process_data_post_reset.tasks[0].birth.location.file_name);
 529   EXPECT_EQ(kFunction,
 530             process_data_post_reset.tasks[0].birth.location.function_name);
 531   EXPECT_EQ(kLineNumber,
 532             process_data_post_reset.tasks[0].birth.location.line_number);
 533   EXPECT_EQ(kWorkerThreadName,
 534             process_data_post_reset.tasks[0].birth.thread_name);
 535   EXPECT_EQ(1, process_data_post_reset.tasks[0].death_data.count);
 536   EXPECT_EQ(2, process_data_post_reset.tasks[0].death_data.run_duration_sum);
 537   EXPECT_EQ(0, process_data_post_reset.tasks[0].death_data.run_duration_max);
 538   EXPECT_EQ(2, process_data_post_reset.tasks[0].death_data.run_duration_sample);
 539   EXPECT_EQ(4, process_data_post_reset.tasks[0].death_data.queue_duration_sum);
 540   EXPECT_EQ(0, process_data_post_reset.tasks[0].death_data.queue_duration_max);
 541   EXPECT_EQ(4,
 542             process_data_post_reset.tasks[0].death_data.queue_duration_sample);
 543   EXPECT_EQ(kWorkerThreadName,
 544             process_data_post_reset.tasks[0].death_thread_name);
 545   EXPECT_EQ(0u, process_data_post_reset.descendants.size());
 546   EXPECT_EQ(base::GetCurrentProcId(), process_data_post_reset.process_id);
 547 }
 548
 549 TEST_F(TrackedObjectsTest, TwoLives) {
 550   if (!ThreadData::InitializeAndSetTrackingStatus(
 551           ThreadData::PROFILING_CHILDREN_ACTIVE)) {
 552     return;
 553   }
 554
 555   const char kFunction[] = "TwoLives";
 556   Location location(kFunction, kFile, kLineNumber, NULL);
 557   TallyABirth(location, kMainThreadName);
 558
 559   const base::TimeTicks kTimePosted = base::TimeTicks() +
 560       base::TimeDelta::FromMilliseconds(1);
 561   const base::TimeTicks kDelayedStartTime = base::TimeTicks();
 562   // TrackingInfo will call TallyABirth() during construction.
 563   base::TrackingInfo pending_task(location, kDelayedStartTime);
 564   pending_task.time_posted = kTimePosted;  // Overwrite implied Now().
 565
 566   const unsigned int kStartOfRun = 5;
 567   const unsigned int kEndOfRun = 7;
 568   SetTestTime(kStartOfRun);
 569   TaskStopwatch stopwatch;
 570   stopwatch.Start();
 571   SetTestTime(kEndOfRun);
 572   stopwatch.Stop();
 573
 574   ThreadData::TallyRunOnNamedThreadIfTracking(pending_task, stopwatch);
 575
 576   // TrackingInfo will call TallyABirth() during construction.
 577   base::TrackingInfo pending_task2(location, kDelayedStartTime);
 578   pending_task2.time_posted = kTimePosted;  // Overwrite implied Now().
 579   SetTestTime(kStartOfRun);
 580   TaskStopwatch stopwatch2;
 581   stopwatch2.Start();
 582   SetTestTime(kEndOfRun);
 583   stopwatch2.Stop();
 584
 585   ThreadData::TallyRunOnNamedThreadIfTracking(pending_task2, stopwatch2);
 586
 587   ProcessDataSnapshot process_data;
 588   ThreadData::Snapshot(false, &process_data);
 589   ExpectSimpleProcessData(process_data, kFunction, kMainThreadName,
 590                           kMainThreadName, 2, 2, 4);
 591 }
 592
 593 TEST_F(TrackedObjectsTest, DifferentLives) {
 594   if (!ThreadData::InitializeAndSetTrackingStatus(
 595           ThreadData::PROFILING_CHILDREN_ACTIVE)) {
 596     return;
 597   }
 598
 599   // Use a well named thread.
 600   ThreadData::InitializeThreadContext(kMainThreadName);
 601   const char kFunction[] = "DifferentLives";
 602   Location location(kFunction, kFile, kLineNumber, NULL);
 603
 604   const base::TimeTicks kTimePosted = base::TimeTicks() +
 605       base::TimeDelta::FromMilliseconds(1);
 606   const base::TimeTicks kDelayedStartTime = base::TimeTicks();
 607   // TrackingInfo will call TallyABirth() during construction.
 608   base::TrackingInfo pending_task(location, kDelayedStartTime);
 609   pending_task.time_posted = kTimePosted;  // Overwrite implied Now().
 610
 611   const unsigned int kStartOfRun = 5;
 612   const unsigned int kEndOfRun = 7;
 613   SetTestTime(kStartOfRun);
 614   TaskStopwatch stopwatch;
 615   stopwatch.Start();
 616   SetTestTime(kEndOfRun);
 617   stopwatch.Stop();
 618
 619   ThreadData::TallyRunOnNamedThreadIfTracking(pending_task, stopwatch);
 620
 621   const int kSecondFakeLineNumber = 999;
 622   Location second_location(kFunction, kFile, kSecondFakeLineNumber, NULL);
 623
 624   // TrackingInfo will call TallyABirth() during construction.
 625   base::TrackingInfo pending_task2(second_location, kDelayedStartTime);
 626   pending_task2.time_posted = kTimePosted;  // Overwrite implied Now().
 627
 628   ProcessDataSnapshot process_data;
 629   ThreadData::Snapshot(false, &process_data);
 630   ASSERT_EQ(2u, process_data.tasks.size());
 631
 632   EXPECT_EQ(kFile, process_data.tasks[0].birth.location.file_name);
 633   EXPECT_EQ(kFunction, process_data.tasks[0].birth.location.function_name);
 634   EXPECT_EQ(kLineNumber, process_data.tasks[0].birth.location.line_number);
 635   EXPECT_EQ(kMainThreadName, process_data.tasks[0].birth.thread_name);
 636   EXPECT_EQ(1, process_data.tasks[0].death_data.count);
 637   EXPECT_EQ(2, process_data.tasks[0].death_data.run_duration_sum);
 638   EXPECT_EQ(2, process_data.tasks[0].death_data.run_duration_max);
 639   EXPECT_EQ(2, process_data.tasks[0].death_data.run_duration_sample);
 640   EXPECT_EQ(4, process_data.tasks[0].death_data.queue_duration_sum);
 641   EXPECT_EQ(4, process_data.tasks[0].death_data.queue_duration_max);
 642   EXPECT_EQ(4, process_data.tasks[0].death_data.queue_duration_sample);
 643   EXPECT_EQ(kMainThreadName, process_data.tasks[0].death_thread_name);
 644   EXPECT_EQ(kFile, process_data.tasks[1].birth.location.file_name);
 645   EXPECT_EQ(kFunction, process_data.tasks[1].birth.location.function_name);
 646   EXPECT_EQ(kSecondFakeLineNumber,
 647             process_data.tasks[1].birth.location.line_number);
 648   EXPECT_EQ(kMainThreadName, process_data.tasks[1].birth.thread_name);
 649   EXPECT_EQ(1, process_data.tasks[1].death_data.count);
 650   EXPECT_EQ(0, process_data.tasks[1].death_data.run_duration_sum);
 651   EXPECT_EQ(0, process_data.tasks[1].death_data.run_duration_max);
 652   EXPECT_EQ(0, process_data.tasks[1].death_data.run_duration_sample);
 653   EXPECT_EQ(0, process_data.tasks[1].death_data.queue_duration_sum);
 654   EXPECT_EQ(0, process_data.tasks[1].death_data.queue_duration_max);
 655   EXPECT_EQ(0, process_data.tasks[1].death_data.queue_duration_sample);
 656   EXPECT_EQ(kStillAlive, process_data.tasks[1].death_thread_name);
 657   EXPECT_EQ(0u, process_data.descendants.size());
 658   EXPECT_EQ(base::GetCurrentProcId(), process_data.process_id);
 659 }
 660
 661 TEST_F(TrackedObjectsTest, TaskWithNestedExclusion) {
 662   if (!ThreadData::InitializeAndSetTrackingStatus(
 663           ThreadData::PROFILING_CHILDREN_ACTIVE)) {
 664     return;
 665   }
 666
 667   const char kFunction[] = "TaskWithNestedExclusion";
 668   Location location(kFunction, kFile, kLineNumber, NULL);
 669   TallyABirth(location, kMainThreadName);
 670
 671   const base::TimeTicks kTimePosted = base::TimeTicks() +
 672       base::TimeDelta::FromMilliseconds(1);
 673   const base::TimeTicks kDelayedStartTime = base::TimeTicks();
 674   // TrackingInfo will call TallyABirth() during construction.
 675   base::TrackingInfo pending_task(location, kDelayedStartTime);
 676   pending_task.time_posted = kTimePosted;  // Overwrite implied Now().
 677
 678   SetTestTime(5);
 679   TaskStopwatch task_stopwatch;
 680   task_stopwatch.Start();
 681   {
 682     SetTestTime(8);
 683     TaskStopwatch exclusion_stopwatch;
 684     exclusion_stopwatch.Start();
 685     SetTestTime(12);
 686     exclusion_stopwatch.Stop();
 687   }
 688   SetTestTime(15);
 689   task_stopwatch.Stop();
 690
 691   ThreadData::TallyRunOnNamedThreadIfTracking(pending_task, task_stopwatch);
 692
 693   ProcessDataSnapshot process_data;
 694   ThreadData::Snapshot(false, &process_data);
 695   ExpectSimpleProcessData(process_data, kFunction, kMainThreadName,
 696                           kMainThreadName, 1, 6, 4);
 697 }
 698
 699 TEST_F(TrackedObjectsTest, TaskWith2NestedExclusions) {
 700   if (!ThreadData::InitializeAndSetTrackingStatus(
 701           ThreadData::PROFILING_CHILDREN_ACTIVE)) {
 702     return;
 703   }
 704
 705   const char kFunction[] = "TaskWith2NestedExclusions";
 706   Location location(kFunction, kFile, kLineNumber, NULL);
 707   TallyABirth(location, kMainThreadName);
 708
 709   const base::TimeTicks kTimePosted = base::TimeTicks() +
 710       base::TimeDelta::FromMilliseconds(1);
 711   const base::TimeTicks kDelayedStartTime = base::TimeTicks();
 712   // TrackingInfo will call TallyABirth() during construction.
 713   base::TrackingInfo pending_task(location, kDelayedStartTime);
 714   pending_task.time_posted = kTimePosted;  // Overwrite implied Now().
 715
 716   SetTestTime(5);
 717   TaskStopwatch task_stopwatch;
 718   task_stopwatch.Start();
 719   {
 720     SetTestTime(8);
 721     TaskStopwatch exclusion_stopwatch;
 722     exclusion_stopwatch.Start();
 723     SetTestTime(12);
 724     exclusion_stopwatch.Stop();
 725
 726     SetTestTime(15);
 727     TaskStopwatch exclusion_stopwatch2;
 728     exclusion_stopwatch2.Start();
 729     SetTestTime(18);
 730     exclusion_stopwatch2.Stop();
 731   }
 732   SetTestTime(25);
 733   task_stopwatch.Stop();
 734
 735   ThreadData::TallyRunOnNamedThreadIfTracking(pending_task, task_stopwatch);
 736
 737   ProcessDataSnapshot process_data;
 738   ThreadData::Snapshot(false, &process_data);
 739   ExpectSimpleProcessData(process_data, kFunction, kMainThreadName,
 740                           kMainThreadName, 1, 13, 4);
 741 }
 742
 743 TEST_F(TrackedObjectsTest, TaskWithNestedExclusionWithNestedTask) {
 744   if (!ThreadData::InitializeAndSetTrackingStatus(
 745           ThreadData::PROFILING_CHILDREN_ACTIVE)) {
 746     return;
 747   }
 748
 749   const char kFunction[] = "TaskWithNestedExclusionWithNestedTask";
 750   Location location(kFunction, kFile, kLineNumber, NULL);
 751
 752   const int kSecondFakeLineNumber = 999;
 753
 754   TallyABirth(location, kMainThreadName);
 755
 756   const base::TimeTicks kTimePosted = base::TimeTicks() +
 757       base::TimeDelta::FromMilliseconds(1);
 758   const base::TimeTicks kDelayedStartTime = base::TimeTicks();
 759   // TrackingInfo will call TallyABirth() during construction.
 760   base::TrackingInfo pending_task(location, kDelayedStartTime);
 761   pending_task.time_posted = kTimePosted;  // Overwrite implied Now().
 762
 763   SetTestTime(5);
 764   TaskStopwatch task_stopwatch;
 765   task_stopwatch.Start();
 766   {
 767     SetTestTime(8);
 768     TaskStopwatch exclusion_stopwatch;
 769     exclusion_stopwatch.Start();
 770     {
 771       Location second_location(kFunction, kFile, kSecondFakeLineNumber, NULL);
 772       base::TrackingInfo nested_task(second_location, kDelayedStartTime);
 773        // Overwrite implied Now().
 774       nested_task.time_posted =
 775           base::TimeTicks() + base::TimeDelta::FromMilliseconds(8);
 776       SetTestTime(9);
 777       TaskStopwatch nested_task_stopwatch;
 778       nested_task_stopwatch.Start();
 779       SetTestTime(11);
 780       nested_task_stopwatch.Stop();
 781       ThreadData::TallyRunOnNamedThreadIfTracking(
 782           nested_task, nested_task_stopwatch);
 783     }
 784     SetTestTime(12);
 785     exclusion_stopwatch.Stop();
 786   }
 787   SetTestTime(15);
 788   task_stopwatch.Stop();
 789
 790   ThreadData::TallyRunOnNamedThreadIfTracking(pending_task, task_stopwatch);
 791
 792   ProcessDataSnapshot process_data;
 793   ThreadData::Snapshot(false, &process_data);
 794
 795   // The order in which the two task follow is platform-dependent.
 796   int t0 = (process_data.tasks[0].birth.location.line_number == kLineNumber) ?
 797       0 : 1;
 798   int t1 = 1 - t0;
 799
 800   ASSERT_EQ(2u, process_data.tasks.size());
 801   EXPECT_EQ(kFile, process_data.tasks[t0].birth.location.file_name);
 802   EXPECT_EQ(kFunction, process_data.tasks[t0].birth.location.function_name);
 803   EXPECT_EQ(kLineNumber, process_data.tasks[t0].birth.location.line_number);
 804   EXPECT_EQ(kMainThreadName, process_data.tasks[t0].birth.thread_name);
 805   EXPECT_EQ(1, process_data.tasks[t0].death_data.count);
 806   EXPECT_EQ(6, process_data.tasks[t0].death_data.run_duration_sum);
 807   EXPECT_EQ(6, process_data.tasks[t0].death_data.run_duration_max);
 808   EXPECT_EQ(6, process_data.tasks[t0].death_data.run_duration_sample);
 809   EXPECT_EQ(4, process_data.tasks[t0].death_data.queue_duration_sum);
 810   EXPECT_EQ(4, process_data.tasks[t0].death_data.queue_duration_max);
 811   EXPECT_EQ(4, process_data.tasks[t0].death_data.queue_duration_sample);
 812   EXPECT_EQ(kMainThreadName, process_data.tasks[t0].death_thread_name);
 813   EXPECT_EQ(kFile, process_data.tasks[t1].birth.location.file_name);
 814   EXPECT_EQ(kFunction, process_data.tasks[t1].birth.location.function_name);
 815   EXPECT_EQ(kSecondFakeLineNumber,
 816             process_data.tasks[t1].birth.location.line_number);
 817   EXPECT_EQ(kMainThreadName, process_data.tasks[t1].birth.thread_name);
 818   EXPECT_EQ(1, process_data.tasks[t1].death_data.count);
 819   EXPECT_EQ(2, process_data.tasks[t1].death_data.run_duration_sum);
 820   EXPECT_EQ(2, process_data.tasks[t1].death_data.run_duration_max);
 821   EXPECT_EQ(2, process_data.tasks[t1].death_data.run_duration_sample);
 822   EXPECT_EQ(1, process_data.tasks[t1].death_data.queue_duration_sum);
 823   EXPECT_EQ(1, process_data.tasks[t1].death_data.queue_duration_max);
 824   EXPECT_EQ(1, process_data.tasks[t1].death_data.queue_duration_sample);
 825   EXPECT_EQ(kMainThreadName, process_data.tasks[t1].death_thread_name);
 826   EXPECT_EQ(0u, process_data.descendants.size());
 827   EXPECT_EQ(base::GetCurrentProcId(), process_data.process_id);
 828 }
 829
 830 }  // namespace tracked_objects