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 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(false, &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(false, &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(false, &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, LifeCycleToSnapshotWorkerThread) {
 483   if (!ThreadData::InitializeAndSetTrackingStatus(
 484           ThreadData::PROFILING_CHILDREN_ACTIVE)) {
 485     return;
 486   }
 487
 488   const char kFunction[] = "LifeCycleToSnapshotWorkerThread";
 489   Location location(kFunction, kFile, kLineNumber, NULL);
 490   // Do not delete |birth|.  We don't own it.
 491   Births* birth = ThreadData::TallyABirthIfActive(location);
 492   EXPECT_NE(reinterpret_cast<Births*>(NULL), birth);
 493
 494   const unsigned int kTimePosted = 1;
 495   const unsigned int kStartOfRun = 5;
 496   const unsigned int kEndOfRun = 7;
 497   SetTestTime(kStartOfRun);
 498   TaskStopwatch stopwatch;
 499   stopwatch.Start();
 500   SetTestTime(kEndOfRun);
 501   stopwatch.Stop();
 502
 503   ThreadData::TallyRunOnWorkerThreadIfTracking(
 504   birth, TrackedTime() + Duration::FromMilliseconds(kTimePosted), stopwatch);
 505
 506   // Call for the ToSnapshot, but tell it to not reset the maxes after scanning.
 507   ProcessDataSnapshot process_data;
 508   ThreadData::Snapshot(false, &process_data);
 509   ExpectSimpleProcessData(process_data, kFunction, kWorkerThreadName,
 510                           kWorkerThreadName, 1, 2, 4);
 511
 512   // Call for the ToSnapshot, but tell it to reset the maxes after scanning.
 513   // We'll still get the same values, but the data will be reset (which we'll
 514   // see in a moment).
 515   ProcessDataSnapshot process_data_pre_reset;
 516   ThreadData::Snapshot(true, &process_data_pre_reset);
 517   ExpectSimpleProcessData(process_data, kFunction, kWorkerThreadName,
 518                           kWorkerThreadName, 1, 2, 4);
 519
 520   // Call for the ToSnapshot, and now we'll see the result of the last
 521   // translation, as the max will have been pushed back to zero.
 522   ProcessDataSnapshot process_data_post_reset;
 523   ThreadData::Snapshot(true, &process_data_post_reset);
 524   ASSERT_EQ(1u, process_data_post_reset.tasks.size());
 525   EXPECT_EQ(kFile, process_data_post_reset.tasks[0].birth.location.file_name);
 526   EXPECT_EQ(kFunction,
 527             process_data_post_reset.tasks[0].birth.location.function_name);
 528   EXPECT_EQ(kLineNumber,
 529             process_data_post_reset.tasks[0].birth.location.line_number);
 530   EXPECT_EQ(kWorkerThreadName,
 531             process_data_post_reset.tasks[0].birth.thread_name);
 532   EXPECT_EQ(1, process_data_post_reset.tasks[0].death_data.count);
 533   EXPECT_EQ(2, process_data_post_reset.tasks[0].death_data.run_duration_sum);
 534   EXPECT_EQ(0, process_data_post_reset.tasks[0].death_data.run_duration_max);
 535   EXPECT_EQ(2, process_data_post_reset.tasks[0].death_data.run_duration_sample);
 536   EXPECT_EQ(4, process_data_post_reset.tasks[0].death_data.queue_duration_sum);
 537   EXPECT_EQ(0, process_data_post_reset.tasks[0].death_data.queue_duration_max);
 538   EXPECT_EQ(4,
 539             process_data_post_reset.tasks[0].death_data.queue_duration_sample);
 540   EXPECT_EQ(kWorkerThreadName,
 541             process_data_post_reset.tasks[0].death_thread_name);
 542   EXPECT_EQ(0u, process_data_post_reset.descendants.size());
 543   EXPECT_EQ(base::GetCurrentProcId(), process_data_post_reset.process_id);
 544 }
 545
 546 TEST_F(TrackedObjectsTest, TwoLives) {
 547   if (!ThreadData::InitializeAndSetTrackingStatus(
 548           ThreadData::PROFILING_CHILDREN_ACTIVE)) {
 549     return;
 550   }
 551
 552   const char kFunction[] = "TwoLives";
 553   Location location(kFunction, kFile, kLineNumber, NULL);
 554   TallyABirth(location, kMainThreadName);
 555
 556   const TrackedTime kTimePosted = TrackedTime::FromMilliseconds(1);
 557   const base::TimeTicks kDelayedStartTime = base::TimeTicks();
 558   // TrackingInfo will call TallyABirth() during construction.
 559   base::TrackingInfo pending_task(location, kDelayedStartTime);
 560   pending_task.time_posted = kTimePosted;  // Overwrite implied Now().
 561
 562   const unsigned int kStartOfRun = 5;
 563   const unsigned int kEndOfRun = 7;
 564   SetTestTime(kStartOfRun);
 565   TaskStopwatch stopwatch;
 566   stopwatch.Start();
 567   SetTestTime(kEndOfRun);
 568   stopwatch.Stop();
 569
 570   ThreadData::TallyRunOnNamedThreadIfTracking(pending_task, stopwatch);
 571
 572   // TrackingInfo will call TallyABirth() during construction.
 573   base::TrackingInfo pending_task2(location, kDelayedStartTime);
 574   pending_task2.time_posted = kTimePosted;  // Overwrite implied Now().
 575   SetTestTime(kStartOfRun);
 576   TaskStopwatch stopwatch2;
 577   stopwatch2.Start();
 578   SetTestTime(kEndOfRun);
 579   stopwatch2.Stop();
 580
 581   ThreadData::TallyRunOnNamedThreadIfTracking(pending_task2, stopwatch2);
 582
 583   ProcessDataSnapshot process_data;
 584   ThreadData::Snapshot(false, &process_data);
 585   ExpectSimpleProcessData(process_data, kFunction, kMainThreadName,
 586                           kMainThreadName, 2, 2, 4);
 587 }
 588
 589 TEST_F(TrackedObjectsTest, DifferentLives) {
 590   if (!ThreadData::InitializeAndSetTrackingStatus(
 591           ThreadData::PROFILING_CHILDREN_ACTIVE)) {
 592     return;
 593   }
 594
 595   // Use a well named thread.
 596   ThreadData::InitializeThreadContext(kMainThreadName);
 597   const char kFunction[] = "DifferentLives";
 598   Location location(kFunction, kFile, kLineNumber, NULL);
 599
 600   const TrackedTime kTimePosted = TrackedTime::FromMilliseconds(1);
 601   const base::TimeTicks kDelayedStartTime = base::TimeTicks();
 602   // TrackingInfo will call TallyABirth() during construction.
 603   base::TrackingInfo pending_task(location, kDelayedStartTime);
 604   pending_task.time_posted = kTimePosted;  // Overwrite implied Now().
 605
 606   const unsigned int kStartOfRun = 5;
 607   const unsigned int kEndOfRun = 7;
 608   SetTestTime(kStartOfRun);
 609   TaskStopwatch stopwatch;
 610   stopwatch.Start();
 611   SetTestTime(kEndOfRun);
 612   stopwatch.Stop();
 613
 614   ThreadData::TallyRunOnNamedThreadIfTracking(pending_task, stopwatch);
 615
 616   const int kSecondFakeLineNumber = 999;
 617   Location second_location(kFunction, kFile, kSecondFakeLineNumber, NULL);
 618
 619   // TrackingInfo will call TallyABirth() during construction.
 620   base::TrackingInfo pending_task2(second_location, kDelayedStartTime);
 621   pending_task2.time_posted = kTimePosted;  // Overwrite implied Now().
 622
 623   ProcessDataSnapshot process_data;
 624   ThreadData::Snapshot(false, &process_data);
 625   ASSERT_EQ(2u, process_data.tasks.size());
 626
 627   EXPECT_EQ(kFile, process_data.tasks[0].birth.location.file_name);
 628   EXPECT_EQ(kFunction, process_data.tasks[0].birth.location.function_name);
 629   EXPECT_EQ(kLineNumber, process_data.tasks[0].birth.location.line_number);
 630   EXPECT_EQ(kMainThreadName, process_data.tasks[0].birth.thread_name);
 631   EXPECT_EQ(1, process_data.tasks[0].death_data.count);
 632   EXPECT_EQ(2, process_data.tasks[0].death_data.run_duration_sum);
 633   EXPECT_EQ(2, process_data.tasks[0].death_data.run_duration_max);
 634   EXPECT_EQ(2, process_data.tasks[0].death_data.run_duration_sample);
 635   EXPECT_EQ(4, process_data.tasks[0].death_data.queue_duration_sum);
 636   EXPECT_EQ(4, process_data.tasks[0].death_data.queue_duration_max);
 637   EXPECT_EQ(4, process_data.tasks[0].death_data.queue_duration_sample);
 638   EXPECT_EQ(kMainThreadName, process_data.tasks[0].death_thread_name);
 639   EXPECT_EQ(kFile, process_data.tasks[1].birth.location.file_name);
 640   EXPECT_EQ(kFunction, process_data.tasks[1].birth.location.function_name);
 641   EXPECT_EQ(kSecondFakeLineNumber,
 642             process_data.tasks[1].birth.location.line_number);
 643   EXPECT_EQ(kMainThreadName, process_data.tasks[1].birth.thread_name);
 644   EXPECT_EQ(1, process_data.tasks[1].death_data.count);
 645   EXPECT_EQ(0, process_data.tasks[1].death_data.run_duration_sum);
 646   EXPECT_EQ(0, process_data.tasks[1].death_data.run_duration_max);
 647   EXPECT_EQ(0, process_data.tasks[1].death_data.run_duration_sample);
 648   EXPECT_EQ(0, process_data.tasks[1].death_data.queue_duration_sum);
 649   EXPECT_EQ(0, process_data.tasks[1].death_data.queue_duration_max);
 650   EXPECT_EQ(0, process_data.tasks[1].death_data.queue_duration_sample);
 651   EXPECT_EQ(kStillAlive, process_data.tasks[1].death_thread_name);
 652   EXPECT_EQ(0u, process_data.descendants.size());
 653   EXPECT_EQ(base::GetCurrentProcId(), process_data.process_id);
 654 }
 655
 656 TEST_F(TrackedObjectsTest, TaskWithNestedExclusion) {
 657   if (!ThreadData::InitializeAndSetTrackingStatus(
 658           ThreadData::PROFILING_CHILDREN_ACTIVE)) {
 659     return;
 660   }
 661
 662   const char kFunction[] = "TaskWithNestedExclusion";
 663   Location location(kFunction, kFile, kLineNumber, NULL);
 664   TallyABirth(location, kMainThreadName);
 665
 666   const TrackedTime kTimePosted = TrackedTime::FromMilliseconds(1);
 667   const base::TimeTicks kDelayedStartTime = base::TimeTicks();
 668   // TrackingInfo will call TallyABirth() during construction.
 669   base::TrackingInfo pending_task(location, kDelayedStartTime);
 670   pending_task.time_posted = kTimePosted;  // Overwrite implied Now().
 671
 672   SetTestTime(5);
 673   TaskStopwatch task_stopwatch;
 674   task_stopwatch.Start();
 675   {
 676     SetTestTime(8);
 677     TaskStopwatch exclusion_stopwatch;
 678     exclusion_stopwatch.Start();
 679     SetTestTime(12);
 680     exclusion_stopwatch.Stop();
 681   }
 682   SetTestTime(15);
 683   task_stopwatch.Stop();
 684
 685   ThreadData::TallyRunOnNamedThreadIfTracking(pending_task, task_stopwatch);
 686
 687   ProcessDataSnapshot process_data;
 688   ThreadData::Snapshot(false, &process_data);
 689   ExpectSimpleProcessData(process_data, kFunction, kMainThreadName,
 690                           kMainThreadName, 1, 6, 4);
 691 }
 692
 693 TEST_F(TrackedObjectsTest, TaskWith2NestedExclusions) {
 694   if (!ThreadData::InitializeAndSetTrackingStatus(
 695           ThreadData::PROFILING_CHILDREN_ACTIVE)) {
 696     return;
 697   }
 698
 699   const char kFunction[] = "TaskWith2NestedExclusions";
 700   Location location(kFunction, kFile, kLineNumber, NULL);
 701   TallyABirth(location, kMainThreadName);
 702
 703   const TrackedTime kTimePosted = TrackedTime::FromMilliseconds(1);
 704   const base::TimeTicks kDelayedStartTime = base::TimeTicks();
 705   // TrackingInfo will call TallyABirth() during construction.
 706   base::TrackingInfo pending_task(location, kDelayedStartTime);
 707   pending_task.time_posted = kTimePosted;  // Overwrite implied Now().
 708
 709   SetTestTime(5);
 710   TaskStopwatch task_stopwatch;
 711   task_stopwatch.Start();
 712   {
 713     SetTestTime(8);
 714     TaskStopwatch exclusion_stopwatch;
 715     exclusion_stopwatch.Start();
 716     SetTestTime(12);
 717     exclusion_stopwatch.Stop();
 718
 719     SetTestTime(15);
 720     TaskStopwatch exclusion_stopwatch2;
 721     exclusion_stopwatch2.Start();
 722     SetTestTime(18);
 723     exclusion_stopwatch2.Stop();
 724   }
 725   SetTestTime(25);
 726   task_stopwatch.Stop();
 727
 728   ThreadData::TallyRunOnNamedThreadIfTracking(pending_task, task_stopwatch);
 729
 730   ProcessDataSnapshot process_data;
 731   ThreadData::Snapshot(false, &process_data);
 732   ExpectSimpleProcessData(process_data, kFunction, kMainThreadName,
 733                           kMainThreadName, 1, 13, 4);
 734 }
 735
 736 TEST_F(TrackedObjectsTest, TaskWithNestedExclusionWithNestedTask) {
 737   if (!ThreadData::InitializeAndSetTrackingStatus(
 738           ThreadData::PROFILING_CHILDREN_ACTIVE)) {
 739     return;
 740   }
 741
 742   const char kFunction[] = "TaskWithNestedExclusionWithNestedTask";
 743   Location location(kFunction, kFile, kLineNumber, NULL);
 744
 745   const int kSecondFakeLineNumber = 999;
 746
 747   TallyABirth(location, kMainThreadName);
 748
 749   const TrackedTime kTimePosted = TrackedTime::FromMilliseconds(1);
 750   const base::TimeTicks kDelayedStartTime = base::TimeTicks();
 751   // TrackingInfo will call TallyABirth() during construction.
 752   base::TrackingInfo pending_task(location, kDelayedStartTime);
 753   pending_task.time_posted = kTimePosted;  // Overwrite implied Now().
 754
 755   SetTestTime(5);
 756   TaskStopwatch task_stopwatch;
 757   task_stopwatch.Start();
 758   {
 759     SetTestTime(8);
 760     TaskStopwatch exclusion_stopwatch;
 761     exclusion_stopwatch.Start();
 762     {
 763       Location second_location(kFunction, kFile, kSecondFakeLineNumber, NULL);
 764       base::TrackingInfo nested_task(second_location, kDelayedStartTime);
 765        // Overwrite implied Now().
 766       nested_task.time_posted = TrackedTime::FromMilliseconds(8);
 767       SetTestTime(9);
 768       TaskStopwatch nested_task_stopwatch;
 769       nested_task_stopwatch.Start();
 770       SetTestTime(11);
 771       nested_task_stopwatch.Stop();
 772       ThreadData::TallyRunOnNamedThreadIfTracking(
 773           nested_task, nested_task_stopwatch);
 774     }
 775     SetTestTime(12);
 776     exclusion_stopwatch.Stop();
 777   }
 778   SetTestTime(15);
 779   task_stopwatch.Stop();
 780
 781   ThreadData::TallyRunOnNamedThreadIfTracking(pending_task, task_stopwatch);
 782
 783   ProcessDataSnapshot process_data;
 784   ThreadData::Snapshot(false, &process_data);
 785
 786   // The order in which the two task follow is platform-dependent.
 787   int t0 = (process_data.tasks[0].birth.location.line_number == kLineNumber) ?
 788       0 : 1;
 789   int t1 = 1 - t0;
 790
 791   ASSERT_EQ(2u, process_data.tasks.size());
 792   EXPECT_EQ(kFile, process_data.tasks[t0].birth.location.file_name);
 793   EXPECT_EQ(kFunction, process_data.tasks[t0].birth.location.function_name);
 794   EXPECT_EQ(kLineNumber, process_data.tasks[t0].birth.location.line_number);
 795   EXPECT_EQ(kMainThreadName, process_data.tasks[t0].birth.thread_name);
 796   EXPECT_EQ(1, process_data.tasks[t0].death_data.count);
 797   EXPECT_EQ(6, process_data.tasks[t0].death_data.run_duration_sum);
 798   EXPECT_EQ(6, process_data.tasks[t0].death_data.run_duration_max);
 799   EXPECT_EQ(6, process_data.tasks[t0].death_data.run_duration_sample);
 800   EXPECT_EQ(4, process_data.tasks[t0].death_data.queue_duration_sum);
 801   EXPECT_EQ(4, process_data.tasks[t0].death_data.queue_duration_max);
 802   EXPECT_EQ(4, process_data.tasks[t0].death_data.queue_duration_sample);
 803   EXPECT_EQ(kMainThreadName, process_data.tasks[t0].death_thread_name);
 804   EXPECT_EQ(kFile, process_data.tasks[t1].birth.location.file_name);
 805   EXPECT_EQ(kFunction, process_data.tasks[t1].birth.location.function_name);
 806   EXPECT_EQ(kSecondFakeLineNumber,
 807             process_data.tasks[t1].birth.location.line_number);
 808   EXPECT_EQ(kMainThreadName, process_data.tasks[t1].birth.thread_name);
 809   EXPECT_EQ(1, process_data.tasks[t1].death_data.count);
 810   EXPECT_EQ(2, process_data.tasks[t1].death_data.run_duration_sum);
 811   EXPECT_EQ(2, process_data.tasks[t1].death_data.run_duration_max);
 812   EXPECT_EQ(2, process_data.tasks[t1].death_data.run_duration_sample);
 813   EXPECT_EQ(1, process_data.tasks[t1].death_data.queue_duration_sum);
 814   EXPECT_EQ(1, process_data.tasks[t1].death_data.queue_duration_max);
 815   EXPECT_EQ(1, process_data.tasks[t1].death_data.queue_duration_sample);
 816   EXPECT_EQ(kMainThreadName, process_data.tasks[t1].death_thread_name);
 817   EXPECT_EQ(0u, process_data.descendants.size());
 818   EXPECT_EQ(base::GetCurrentProcId(), process_data.process_id);
 819 }
 820
 821 }  // namespace tracked_objects