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.phased_snapshots.size());
  75     auto it = process_data.phased_snapshots.find(0);
  76     ASSERT_TRUE(it != process_data.phased_snapshots.end());
  77     const ProcessDataPhaseSnapshot& process_data_phase = it->second;
  78
  79     ASSERT_EQ(1u, process_data_phase.tasks.size());
  80
  81     EXPECT_EQ(kFile, process_data_phase.tasks[0].birth.location.file_name);
  82     EXPECT_EQ(function_name,
  83               process_data_phase.tasks[0].birth.location.function_name);
  84     EXPECT_EQ(kLineNumber,
  85               process_data_phase.tasks[0].birth.location.line_number);
  86
  87     EXPECT_EQ(birth_thread, process_data_phase.tasks[0].birth.thread_name);
  88
  89     EXPECT_EQ(count, process_data_phase.tasks[0].death_data.count);
  90     EXPECT_EQ(count * run_ms,
  91               process_data_phase.tasks[0].death_data.run_duration_sum);
  92     EXPECT_EQ(run_ms, process_data_phase.tasks[0].death_data.run_duration_max);
  93     EXPECT_EQ(run_ms,
  94               process_data_phase.tasks[0].death_data.run_duration_sample);
  95     EXPECT_EQ(count * queue_ms,
  96               process_data_phase.tasks[0].death_data.queue_duration_sum);
  97     EXPECT_EQ(queue_ms,
  98               process_data_phase.tasks[0].death_data.queue_duration_max);
  99     EXPECT_EQ(queue_ms,
 100               process_data_phase.tasks[0].death_data.queue_duration_sample);
 101
 102     EXPECT_EQ(death_thread, process_data_phase.tasks[0].death_thread_name);
 103
 104     EXPECT_EQ(0u, process_data_phase.descendants.size());
 105
 106     EXPECT_EQ(base::GetCurrentProcId(), process_data.process_id);
 107   }
 108
 109   // Sets time that will be returned by ThreadData::Now().
 110   static void SetTestTime(unsigned int test_time) { test_time_ = test_time; }
 111
 112  private:
 113   // Returns test time in milliseconds.
 114   static unsigned int GetTestTime() { return test_time_; }
 115
 116   // Test time in milliseconds.
 117   static unsigned int test_time_;
 118 };
 119
 120 // static
 121 unsigned int TrackedObjectsTest::test_time_;
 122
 123 TEST_F(TrackedObjectsTest, TaskStopwatchNoStartStop) {
 124   if (!ThreadData::InitializeAndSetTrackingStatus(
 125           ThreadData::PROFILING_CHILDREN_ACTIVE)) {
 126     // Don't run the test if task tracking is not compiled in.
 127     return;
 128   }
 129
 130   // Check that creating and destroying a stopwatch without starting it doesn't
 131   // crash.
 132   TaskStopwatch stopwatch;
 133 }
 134
 135 TEST_F(TrackedObjectsTest, MinimalStartupShutdown) {
 136   // Minimal test doesn't even create any tasks.
 137   if (!ThreadData::InitializeAndSetTrackingStatus(
 138           ThreadData::PROFILING_CHILDREN_ACTIVE)) {
 139     // Don't run the test if task tracking is not compiled in.
 140     return;
 141   }
 142
 143   EXPECT_FALSE(ThreadData::first());  // No activity even on this thread.
 144   ThreadData* data = ThreadData::Get();
 145   EXPECT_TRUE(ThreadData::first());  // Now class was constructed.
 146   ASSERT_TRUE(data);
 147   EXPECT_FALSE(data->next());
 148   EXPECT_EQ(data, ThreadData::Get());
 149   ThreadData::BirthMap birth_map;
 150   ThreadData::DeathsSnapshot deaths;
 151   ThreadData::ParentChildSet parent_child_set;
 152   data->SnapshotMaps(0, &birth_map, &deaths, &parent_child_set);
 153   EXPECT_EQ(0u, birth_map.size());
 154   EXPECT_EQ(0u, deaths.size());
 155   EXPECT_EQ(0u, parent_child_set.size());
 156
 157   // Clean up with no leaking.
 158   Reset();
 159
 160   // Do it again, just to be sure we reset state completely.
 161   EXPECT_TRUE(ThreadData::InitializeAndSetTrackingStatus(
 162       ThreadData::PROFILING_CHILDREN_ACTIVE));
 163   EXPECT_FALSE(ThreadData::first());  // No activity even on this thread.
 164   data = ThreadData::Get();
 165   EXPECT_TRUE(ThreadData::first());  // Now class was constructed.
 166   ASSERT_TRUE(data);
 167   EXPECT_FALSE(data->next());
 168   EXPECT_EQ(data, ThreadData::Get());
 169   birth_map.clear();
 170   deaths.clear();
 171   parent_child_set.clear();
 172   data->SnapshotMaps(0, &birth_map, &deaths, &parent_child_set);
 173   EXPECT_EQ(0u, birth_map.size());
 174   EXPECT_EQ(0u, deaths.size());
 175   EXPECT_EQ(0u, parent_child_set.size());
 176 }
 177
 178 TEST_F(TrackedObjectsTest, TinyStartupShutdown) {
 179   if (!ThreadData::InitializeAndSetTrackingStatus(
 180           ThreadData::PROFILING_CHILDREN_ACTIVE)) {
 181     // Don't run the test if task tracking is not compiled in.
 182     return;
 183   }
 184
 185   // Instigate tracking on a single tracked object, on our thread.
 186   const char kFunction[] = "TinyStartupShutdown";
 187   Location location(kFunction, kFile, kLineNumber, NULL);
 188   Births* first_birth = ThreadData::TallyABirthIfActive(location);
 189
 190   ThreadData* data = ThreadData::first();
 191   ASSERT_TRUE(data);
 192   EXPECT_FALSE(data->next());
 193   EXPECT_EQ(data, ThreadData::Get());
 194   ThreadData::BirthMap birth_map;
 195   ThreadData::DeathsSnapshot deaths;
 196   ThreadData::ParentChildSet parent_child_set;
 197   data->SnapshotMaps(0, &birth_map, &deaths, &parent_child_set);
 198   EXPECT_EQ(1u, birth_map.size());                         // 1 birth location.
 199   EXPECT_EQ(1, birth_map.begin()->second->birth_count());  // 1 birth.
 200   EXPECT_EQ(0u, deaths.size());                            // No deaths.
 201   EXPECT_EQ(0u, parent_child_set.size());                  // No children.
 202
 203
 204   // Now instigate another birth, while we are timing the run of the first
 205   // execution.
 206   ThreadData::PrepareForStartOfRun(first_birth);
 207   // Create a child (using the same birth location).
 208   // TrackingInfo will call TallyABirth() during construction.
 209   const int32 start_time = 1;
 210   base::TimeTicks kBogusBirthTime = base::TimeTicks() +
 211       base::TimeDelta::FromMilliseconds(start_time);
 212   base::TrackingInfo pending_task(location, kBogusBirthTime);
 213   SetTestTime(1);
 214   TaskStopwatch stopwatch;
 215   stopwatch.Start();
 216   // Finally conclude the outer run.
 217   const int32 time_elapsed = 1000;
 218   SetTestTime(start_time + time_elapsed);
 219   stopwatch.Stop();
 220
 221   ThreadData::TallyRunOnNamedThreadIfTracking(pending_task, stopwatch);
 222
 223   birth_map.clear();
 224   deaths.clear();
 225   parent_child_set.clear();
 226   data->SnapshotMaps(0, &birth_map, &deaths, &parent_child_set);
 227   EXPECT_EQ(1u, birth_map.size());                         // 1 birth location.
 228   EXPECT_EQ(2, birth_map.begin()->second->birth_count());  // 2 births.
 229   EXPECT_EQ(1u, deaths.size());                            // 1 location.
 230   EXPECT_EQ(1, deaths.begin()->second.death_data.count);   // 1 death.
 231   if (ThreadData::TrackingParentChildStatus()) {
 232     EXPECT_EQ(1u, parent_child_set.size());                  // 1 child.
 233     EXPECT_EQ(parent_child_set.begin()->first,
 234               parent_child_set.begin()->second);
 235   } else {
 236     EXPECT_EQ(0u, parent_child_set.size());                  // no stats.
 237   }
 238
 239   // The births were at the same location as the one known death.
 240   EXPECT_EQ(birth_map.begin()->second, deaths.begin()->first);
 241
 242   ProcessDataSnapshot process_data;
 243   ThreadData::Snapshot(0, &process_data);
 244
 245   ASSERT_EQ(1u, process_data.phased_snapshots.size());
 246   auto it = process_data.phased_snapshots.find(0);
 247   ASSERT_TRUE(it != process_data.phased_snapshots.end());
 248   const ProcessDataPhaseSnapshot& process_data_phase = it->second;
 249   ASSERT_EQ(1u, process_data_phase.tasks.size());
 250   EXPECT_EQ(kFile, process_data_phase.tasks[0].birth.location.file_name);
 251   EXPECT_EQ(kFunction,
 252             process_data_phase.tasks[0].birth.location.function_name);
 253   EXPECT_EQ(kLineNumber,
 254             process_data_phase.tasks[0].birth.location.line_number);
 255   EXPECT_EQ(kWorkerThreadName, process_data_phase.tasks[0].birth.thread_name);
 256   EXPECT_EQ(1, process_data_phase.tasks[0].death_data.count);
 257   EXPECT_EQ(time_elapsed,
 258             process_data_phase.tasks[0].death_data.run_duration_sum);
 259   EXPECT_EQ(time_elapsed,
 260             process_data_phase.tasks[0].death_data.run_duration_max);
 261   EXPECT_EQ(time_elapsed,
 262             process_data_phase.tasks[0].death_data.run_duration_sample);
 263   EXPECT_EQ(0, process_data_phase.tasks[0].death_data.queue_duration_sum);
 264   EXPECT_EQ(0, process_data_phase.tasks[0].death_data.queue_duration_max);
 265   EXPECT_EQ(0, process_data_phase.tasks[0].death_data.queue_duration_sample);
 266   EXPECT_EQ(kWorkerThreadName, process_data_phase.tasks[0].death_thread_name);
 267
 268   if (ThreadData::TrackingParentChildStatus()) {
 269     ASSERT_EQ(1u, process_data_phase.descendants.size());
 270     EXPECT_EQ(kFile,
 271               process_data_phase.descendants[0].parent.location.file_name);
 272     EXPECT_EQ(kFunction,
 273               process_data_phase.descendants[0].parent.location.function_name);
 274     EXPECT_EQ(kLineNumber,
 275               process_data_phase.descendants[0].parent.location.line_number);
 276     EXPECT_EQ(kWorkerThreadName,
 277               process_data_phase.descendants[0].parent.thread_name);
 278     EXPECT_EQ(kFile,
 279               process_data_phase.descendants[0].child.location.file_name);
 280     EXPECT_EQ(kFunction,
 281               process_data_phase.descendants[0].child.location.function_name);
 282     EXPECT_EQ(kLineNumber,
 283               process_data_phase.descendants[0].child.location.line_number);
 284     EXPECT_EQ(kWorkerThreadName,
 285               process_data_phase.descendants[0].child.thread_name);
 286   } else {
 287     EXPECT_EQ(0u, process_data_phase.descendants.size());
 288   }
 289 }
 290
 291 TEST_F(TrackedObjectsTest, DeathDataTestRecordDeath) {
 292   if (!ThreadData::InitializeAndSetTrackingStatus(
 293           ThreadData::PROFILING_CHILDREN_ACTIVE)) {
 294     // Don't run the test if task tracking is not compiled in.
 295     return;
 296   }
 297
 298   scoped_ptr<DeathData> data(new DeathData());
 299   ASSERT_NE(data, reinterpret_cast<DeathData*>(NULL));
 300   EXPECT_EQ(data->run_duration_sum(), 0);
 301   EXPECT_EQ(data->run_duration_max(), 0);
 302   EXPECT_EQ(data->run_duration_sample(), 0);
 303   EXPECT_EQ(data->queue_duration_sum(), 0);
 304   EXPECT_EQ(data->queue_duration_max(), 0);
 305   EXPECT_EQ(data->queue_duration_sample(), 0);
 306   EXPECT_EQ(data->count(), 0);
 307   EXPECT_EQ(nullptr, data->last_phase_snapshot());
 308
 309   int32 run_ms = 42;
 310   int32 queue_ms = 8;
 311
 312   const int kUnrandomInt = 0;  // Fake random int that ensure we sample data.
 313   data->RecordDeath(queue_ms, run_ms, kUnrandomInt);
 314   EXPECT_EQ(data->run_duration_sum(), run_ms);
 315   EXPECT_EQ(data->run_duration_max(), run_ms);
 316   EXPECT_EQ(data->run_duration_sample(), run_ms);
 317   EXPECT_EQ(data->queue_duration_sum(), queue_ms);
 318   EXPECT_EQ(data->queue_duration_max(), queue_ms);
 319   EXPECT_EQ(data->queue_duration_sample(), queue_ms);
 320   EXPECT_EQ(data->count(), 1);
 321   EXPECT_EQ(nullptr, data->last_phase_snapshot());
 322
 323   data->RecordDeath(queue_ms, run_ms, kUnrandomInt);
 324   EXPECT_EQ(data->run_duration_sum(), run_ms + run_ms);
 325   EXPECT_EQ(data->run_duration_max(), run_ms);
 326   EXPECT_EQ(data->run_duration_sample(), run_ms);
 327   EXPECT_EQ(data->queue_duration_sum(), queue_ms + queue_ms);
 328   EXPECT_EQ(data->queue_duration_max(), queue_ms);
 329   EXPECT_EQ(data->queue_duration_sample(), queue_ms);
 330   EXPECT_EQ(data->count(), 2);
 331   EXPECT_EQ(nullptr, data->last_phase_snapshot());
 332 }
 333
 334 TEST_F(TrackedObjectsTest, DeathDataTest2Phases) {
 335   if (!ThreadData::InitializeAndSetTrackingStatus(
 336           ThreadData::PROFILING_CHILDREN_ACTIVE)) {
 337     // Don't run the test if task tracking is not compiled in.
 338     return;
 339   }
 340
 341   scoped_ptr<DeathData> data(new DeathData());
 342   ASSERT_NE(data, reinterpret_cast<DeathData*>(NULL));
 343
 344   int32 run_ms = 42;
 345   int32 queue_ms = 8;
 346
 347   const int kUnrandomInt = 0;  // Fake random int that ensure we sample data.
 348   data->RecordDeath(queue_ms, run_ms, kUnrandomInt);
 349   data->RecordDeath(queue_ms, run_ms, kUnrandomInt);
 350
 351   data->OnProfilingPhaseCompleted(123);
 352   EXPECT_EQ(data->run_duration_sum(), run_ms + run_ms);
 353   EXPECT_EQ(data->run_duration_max(), 0);
 354   EXPECT_EQ(data->run_duration_sample(), run_ms);
 355   EXPECT_EQ(data->queue_duration_sum(), queue_ms + queue_ms);
 356   EXPECT_EQ(data->queue_duration_max(), 0);
 357   EXPECT_EQ(data->queue_duration_sample(), queue_ms);
 358   EXPECT_EQ(data->count(), 2);
 359   ASSERT_NE(nullptr, data->last_phase_snapshot());
 360   EXPECT_EQ(123, data->last_phase_snapshot()->profiling_phase);
 361   EXPECT_EQ(2, data->last_phase_snapshot()->death_data.count);
 362   EXPECT_EQ(2 * run_ms,
 363             data->last_phase_snapshot()->death_data.run_duration_sum);
 364   EXPECT_EQ(run_ms, data->last_phase_snapshot()->death_data.run_duration_max);
 365   EXPECT_EQ(run_ms,
 366             data->last_phase_snapshot()->death_data.run_duration_sample);
 367   EXPECT_EQ(2 * queue_ms,
 368             data->last_phase_snapshot()->death_data.queue_duration_sum);
 369   EXPECT_EQ(queue_ms,
 370             data->last_phase_snapshot()->death_data.queue_duration_max);
 371   EXPECT_EQ(queue_ms,
 372             data->last_phase_snapshot()->death_data.queue_duration_sample);
 373   EXPECT_EQ(nullptr, data->last_phase_snapshot()->prev);
 374
 375   int32 run_ms1 = 21;
 376   int32 queue_ms1 = 4;
 377
 378   data->RecordDeath(queue_ms1, run_ms1, kUnrandomInt);
 379   EXPECT_EQ(data->run_duration_sum(), run_ms + run_ms + run_ms1);
 380   EXPECT_EQ(data->run_duration_max(), run_ms1);
 381   EXPECT_EQ(data->run_duration_sample(), run_ms1);
 382   EXPECT_EQ(data->queue_duration_sum(), queue_ms + queue_ms + queue_ms1);
 383   EXPECT_EQ(data->queue_duration_max(), queue_ms1);
 384   EXPECT_EQ(data->queue_duration_sample(), queue_ms1);
 385   EXPECT_EQ(data->count(), 3);
 386   ASSERT_NE(nullptr, data->last_phase_snapshot());
 387   EXPECT_EQ(123, data->last_phase_snapshot()->profiling_phase);
 388   EXPECT_EQ(2, data->last_phase_snapshot()->death_data.count);
 389   EXPECT_EQ(2 * run_ms,
 390             data->last_phase_snapshot()->death_data.run_duration_sum);
 391   EXPECT_EQ(run_ms, data->last_phase_snapshot()->death_data.run_duration_max);
 392   EXPECT_EQ(run_ms,
 393             data->last_phase_snapshot()->death_data.run_duration_sample);
 394   EXPECT_EQ(2 * queue_ms,
 395             data->last_phase_snapshot()->death_data.queue_duration_sum);
 396   EXPECT_EQ(queue_ms,
 397             data->last_phase_snapshot()->death_data.queue_duration_max);
 398   EXPECT_EQ(queue_ms,
 399             data->last_phase_snapshot()->death_data.queue_duration_sample);
 400   EXPECT_EQ(nullptr, data->last_phase_snapshot()->prev);
 401 }
 402
 403 TEST_F(TrackedObjectsTest, Delta) {
 404   if (!ThreadData::InitializeAndSetTrackingStatus(
 405           ThreadData::PROFILING_CHILDREN_ACTIVE)) {
 406     // Don't run the test if task tracking is not compiled in.
 407     return;
 408   }
 409
 410   DeathDataSnapshot snapshot;
 411   snapshot.count = 10;
 412   snapshot.run_duration_sum = 100;
 413   snapshot.run_duration_max = 50;
 414   snapshot.run_duration_sample = 25;
 415   snapshot.queue_duration_sum = 200;
 416   snapshot.queue_duration_max = 101;
 417   snapshot.queue_duration_sample = 26;
 418
 419   DeathDataSnapshot older_snapshot;
 420   older_snapshot.count = 2;
 421   older_snapshot.run_duration_sum = 95;
 422   older_snapshot.run_duration_max = 48;
 423   older_snapshot.run_duration_sample = 22;
 424   older_snapshot.queue_duration_sum = 190;
 425   older_snapshot.queue_duration_max = 99;
 426   older_snapshot.queue_duration_sample = 21;
 427
 428   const DeathDataSnapshot& delta = snapshot.Delta(older_snapshot);
 429   EXPECT_EQ(8, delta.count);
 430   EXPECT_EQ(5, delta.run_duration_sum);
 431   EXPECT_EQ(50, delta.run_duration_max);
 432   EXPECT_EQ(25, delta.run_duration_sample);
 433   EXPECT_EQ(10, delta.queue_duration_sum);
 434   EXPECT_EQ(101, delta.queue_duration_max);
 435   EXPECT_EQ(26, delta.queue_duration_sample);
 436 }
 437
 438 TEST_F(TrackedObjectsTest, DeactivatedBirthOnlyToSnapshotWorkerThread) {
 439   // Start in the deactivated state.
 440   if (!ThreadData::InitializeAndSetTrackingStatus(ThreadData::DEACTIVATED)) {
 441     // Don't run the test if task tracking is not compiled in.
 442     return;
 443   }
 444
 445   const char kFunction[] = "DeactivatedBirthOnlyToSnapshotWorkerThread";
 446   Location location(kFunction, kFile, kLineNumber, NULL);
 447   TallyABirth(location, std::string());
 448
 449   ProcessDataSnapshot process_data;
 450   ThreadData::Snapshot(0, &process_data);
 451
 452   ASSERT_EQ(1u, process_data.phased_snapshots.size());
 453
 454   auto it = process_data.phased_snapshots.find(0);
 455   ASSERT_TRUE(it != process_data.phased_snapshots.end());
 456   const ProcessDataPhaseSnapshot& process_data_phase = it->second;
 457
 458   ASSERT_EQ(0u, process_data_phase.tasks.size());
 459
 460   EXPECT_EQ(base::GetCurrentProcId(), process_data.process_id);
 461 }
 462
 463 TEST_F(TrackedObjectsTest, DeactivatedBirthOnlyToSnapshotMainThread) {
 464   // Start in the deactivated state.
 465   if (!ThreadData::InitializeAndSetTrackingStatus(ThreadData::DEACTIVATED)) {
 466     // Don't run the test if task tracking is not compiled in.
 467     return;
 468   }
 469
 470   const char kFunction[] = "DeactivatedBirthOnlyToSnapshotMainThread";
 471   Location location(kFunction, kFile, kLineNumber, NULL);
 472   TallyABirth(location, kMainThreadName);
 473
 474   ProcessDataSnapshot process_data;
 475   ThreadData::Snapshot(0, &process_data);
 476
 477   ASSERT_EQ(1u, process_data.phased_snapshots.size());
 478
 479   auto it = process_data.phased_snapshots.find(0);
 480   ASSERT_TRUE(it != process_data.phased_snapshots.end());
 481   const ProcessDataPhaseSnapshot& process_data_phase = it->second;
 482
 483   ASSERT_EQ(0u, process_data_phase.tasks.size());
 484
 485   EXPECT_EQ(base::GetCurrentProcId(), process_data.process_id);
 486 }
 487
 488 TEST_F(TrackedObjectsTest, BirthOnlyToSnapshotWorkerThread) {
 489   if (!ThreadData::InitializeAndSetTrackingStatus(
 490           ThreadData::PROFILING_CHILDREN_ACTIVE)) {
 491     // Don't run the test if task tracking is not compiled in.
 492     return;
 493   }
 494
 495   const char kFunction[] = "BirthOnlyToSnapshotWorkerThread";
 496   Location location(kFunction, kFile, kLineNumber, NULL);
 497   TallyABirth(location, std::string());
 498
 499   ProcessDataSnapshot process_data;
 500   ThreadData::Snapshot(0, &process_data);
 501   ExpectSimpleProcessData(process_data, kFunction, kWorkerThreadName,
 502                           kStillAlive, 1, 0, 0);
 503 }
 504
 505 TEST_F(TrackedObjectsTest, BirthOnlyToSnapshotMainThread) {
 506   if (!ThreadData::InitializeAndSetTrackingStatus(
 507           ThreadData::PROFILING_CHILDREN_ACTIVE)) {
 508     // Don't run the test if task tracking is not compiled in.
 509     return;
 510   }
 511
 512   const char kFunction[] = "BirthOnlyToSnapshotMainThread";
 513   Location location(kFunction, kFile, kLineNumber, NULL);
 514   TallyABirth(location, kMainThreadName);
 515
 516   ProcessDataSnapshot process_data;
 517   ThreadData::Snapshot(0, &process_data);
 518   ExpectSimpleProcessData(process_data, kFunction, kMainThreadName, kStillAlive,
 519                           1, 0, 0);
 520 }
 521
 522 TEST_F(TrackedObjectsTest, LifeCycleToSnapshotMainThread) {
 523   if (!ThreadData::InitializeAndSetTrackingStatus(
 524           ThreadData::PROFILING_CHILDREN_ACTIVE)) {
 525     // Don't run the test if task tracking is not compiled in.
 526     return;
 527   }
 528
 529   const char kFunction[] = "LifeCycleToSnapshotMainThread";
 530   Location location(kFunction, kFile, kLineNumber, NULL);
 531   TallyABirth(location, kMainThreadName);
 532
 533   const TrackedTime kTimePosted = TrackedTime::FromMilliseconds(1);
 534   const base::TimeTicks kDelayedStartTime = base::TimeTicks();
 535   // TrackingInfo will call TallyABirth() during construction.
 536   base::TrackingInfo pending_task(location, kDelayedStartTime);
 537   pending_task.time_posted = kTimePosted;  // Overwrite implied Now().
 538
 539   const unsigned int kStartOfRun = 5;
 540   const unsigned int kEndOfRun = 7;
 541   SetTestTime(kStartOfRun);
 542   TaskStopwatch stopwatch;
 543   stopwatch.Start();
 544   SetTestTime(kEndOfRun);
 545   stopwatch.Stop();
 546
 547   ThreadData::TallyRunOnNamedThreadIfTracking(pending_task, stopwatch);
 548
 549   ProcessDataSnapshot process_data;
 550   ThreadData::Snapshot(0, &process_data);
 551   ExpectSimpleProcessData(process_data, kFunction, kMainThreadName,
 552                           kMainThreadName, 1, 2, 4);
 553 }
 554
 555 TEST_F(TrackedObjectsTest, TwoPhases) {
 556   if (!ThreadData::InitializeAndSetTrackingStatus(
 557           ThreadData::PROFILING_CHILDREN_ACTIVE)) {
 558     // Don't run the test if task tracking is not compiled in.
 559     return;
 560   }
 561
 562   const char kFunction[] = "TwoPhases";
 563   Location location(kFunction, kFile, kLineNumber, NULL);
 564   TallyABirth(location, kMainThreadName);
 565
 566   const TrackedTime kTimePosted = TrackedTime::FromMilliseconds(1);
 567   const base::TimeTicks kDelayedStartTime = base::TimeTicks();
 568   // TrackingInfo will call TallyABirth() during construction.
 569   base::TrackingInfo pending_task(location, kDelayedStartTime);
 570   pending_task.time_posted = kTimePosted;  // Overwrite implied Now().
 571
 572   const unsigned int kStartOfRun = 5;
 573   const unsigned int kEndOfRun = 7;
 574   SetTestTime(kStartOfRun);
 575   TaskStopwatch stopwatch;
 576   stopwatch.Start();
 577   SetTestTime(kEndOfRun);
 578   stopwatch.Stop();
 579
 580   ThreadData::TallyRunOnNamedThreadIfTracking(pending_task, stopwatch);
 581
 582   ThreadData::OnProfilingPhaseCompleted(0);
 583
 584   TallyABirth(location, kMainThreadName);
 585
 586   const TrackedTime kTimePosted1 = TrackedTime::FromMilliseconds(9);
 587   const base::TimeTicks kDelayedStartTime1 = base::TimeTicks();
 588   // TrackingInfo will call TallyABirth() during construction.
 589   base::TrackingInfo pending_task1(location, kDelayedStartTime1);
 590   pending_task1.time_posted = kTimePosted1;  // Overwrite implied Now().
 591
 592   const unsigned int kStartOfRun1 = 11;
 593   const unsigned int kEndOfRun1 = 21;
 594   SetTestTime(kStartOfRun1);
 595   TaskStopwatch stopwatch1;
 596   stopwatch1.Start();
 597   SetTestTime(kEndOfRun1);
 598   stopwatch1.Stop();
 599
 600   ThreadData::TallyRunOnNamedThreadIfTracking(pending_task1, stopwatch1);
 601
 602   ProcessDataSnapshot process_data;
 603   ThreadData::Snapshot(1, &process_data);
 604
 605   ASSERT_EQ(2u, process_data.phased_snapshots.size());
 606
 607   auto it0 = process_data.phased_snapshots.find(0);
 608   ASSERT_TRUE(it0 != process_data.phased_snapshots.end());
 609   const ProcessDataPhaseSnapshot& process_data_phase0 = it0->second;
 610
 611   ASSERT_EQ(1u, process_data_phase0.tasks.size());
 612
 613   EXPECT_EQ(kFile, process_data_phase0.tasks[0].birth.location.file_name);
 614   EXPECT_EQ(kFunction,
 615             process_data_phase0.tasks[0].birth.location.function_name);
 616   EXPECT_EQ(kLineNumber,
 617             process_data_phase0.tasks[0].birth.location.line_number);
 618
 619   EXPECT_EQ(kMainThreadName, process_data_phase0.tasks[0].birth.thread_name);
 620
 621   EXPECT_EQ(1, process_data_phase0.tasks[0].death_data.count);
 622   EXPECT_EQ(2, process_data_phase0.tasks[0].death_data.run_duration_sum);
 623   EXPECT_EQ(2, process_data_phase0.tasks[0].death_data.run_duration_max);
 624   EXPECT_EQ(2, process_data_phase0.tasks[0].death_data.run_duration_sample);
 625   EXPECT_EQ(4, process_data_phase0.tasks[0].death_data.queue_duration_sum);
 626   EXPECT_EQ(4, process_data_phase0.tasks[0].death_data.queue_duration_max);
 627   EXPECT_EQ(4, process_data_phase0.tasks[0].death_data.queue_duration_sample);
 628
 629   EXPECT_EQ(kMainThreadName, process_data_phase0.tasks[0].death_thread_name);
 630
 631   EXPECT_EQ(0u, process_data_phase0.descendants.size());
 632
 633   auto it1 = process_data.phased_snapshots.find(1);
 634   ASSERT_TRUE(it1 != process_data.phased_snapshots.end());
 635   const ProcessDataPhaseSnapshot& process_data_phase1 = it1->second;
 636
 637   ASSERT_EQ(1u, process_data_phase1.tasks.size());
 638
 639   EXPECT_EQ(kFile, process_data_phase1.tasks[0].birth.location.file_name);
 640   EXPECT_EQ(kFunction,
 641             process_data_phase1.tasks[0].birth.location.function_name);
 642   EXPECT_EQ(kLineNumber,
 643             process_data_phase1.tasks[0].birth.location.line_number);
 644
 645   EXPECT_EQ(kMainThreadName, process_data_phase1.tasks[0].birth.thread_name);
 646
 647   EXPECT_EQ(1, process_data_phase1.tasks[0].death_data.count);
 648   EXPECT_EQ(10, process_data_phase1.tasks[0].death_data.run_duration_sum);
 649   EXPECT_EQ(10, process_data_phase1.tasks[0].death_data.run_duration_max);
 650   EXPECT_EQ(10, process_data_phase1.tasks[0].death_data.run_duration_sample);
 651   EXPECT_EQ(2, process_data_phase1.tasks[0].death_data.queue_duration_sum);
 652   EXPECT_EQ(2, process_data_phase1.tasks[0].death_data.queue_duration_max);
 653   EXPECT_EQ(2, process_data_phase1.tasks[0].death_data.queue_duration_sample);
 654
 655   EXPECT_EQ(kMainThreadName, process_data_phase1.tasks[0].death_thread_name);
 656
 657   EXPECT_EQ(0u, process_data_phase1.descendants.size());
 658
 659   EXPECT_EQ(base::GetCurrentProcId(), process_data.process_id);
 660 }
 661
 662 TEST_F(TrackedObjectsTest, ThreePhases) {
 663   if (!ThreadData::InitializeAndSetTrackingStatus(
 664           ThreadData::PROFILING_CHILDREN_ACTIVE)) {
 665     // Don't run the test if task tracking is not compiled in.
 666     return;
 667   }
 668
 669   const char kFunction[] = "ThreePhases";
 670   Location location(kFunction, kFile, kLineNumber, NULL);
 671
 672   // Phase 0
 673   {
 674     TallyABirth(location, kMainThreadName);
 675
 676     // TrackingInfo will call TallyABirth() during construction.
 677     SetTestTime(10);
 678     base::TrackingInfo pending_task(location, base::TimeTicks());
 679
 680     SetTestTime(17);
 681     TaskStopwatch stopwatch;
 682     stopwatch.Start();
 683     SetTestTime(23);
 684     stopwatch.Stop();
 685
 686     ThreadData::TallyRunOnNamedThreadIfTracking(pending_task, stopwatch);
 687   }
 688
 689   ThreadData::OnProfilingPhaseCompleted(0);
 690
 691   // Phase 1
 692   {
 693     TallyABirth(location, kMainThreadName);
 694
 695     SetTestTime(30);
 696     base::TrackingInfo pending_task(location, base::TimeTicks());
 697
 698     SetTestTime(35);
 699     TaskStopwatch stopwatch;
 700     stopwatch.Start();
 701     SetTestTime(39);
 702     stopwatch.Stop();
 703
 704     ThreadData::TallyRunOnNamedThreadIfTracking(pending_task, stopwatch);
 705   }
 706
 707   ThreadData::OnProfilingPhaseCompleted(1);
 708
 709   // Phase 2
 710   {
 711     TallyABirth(location, kMainThreadName);
 712
 713     // TrackingInfo will call TallyABirth() during construction.
 714     SetTestTime(40);
 715     base::TrackingInfo pending_task(location, base::TimeTicks());
 716
 717     SetTestTime(43);
 718     TaskStopwatch stopwatch;
 719     stopwatch.Start();
 720     SetTestTime(45);
 721     stopwatch.Stop();
 722
 723     ThreadData::TallyRunOnNamedThreadIfTracking(pending_task, stopwatch);
 724   }
 725
 726   // Snapshot and check results.
 727   ProcessDataSnapshot process_data;
 728   ThreadData::Snapshot(2, &process_data);
 729
 730   ASSERT_EQ(3u, process_data.phased_snapshots.size());
 731
 732   auto it0 = process_data.phased_snapshots.find(0);
 733   ASSERT_TRUE(it0 != process_data.phased_snapshots.end());
 734   const ProcessDataPhaseSnapshot& process_data_phase0 = it0->second;
 735
 736   ASSERT_EQ(1u, process_data_phase0.tasks.size());
 737
 738   EXPECT_EQ(kFile, process_data_phase0.tasks[0].birth.location.file_name);
 739   EXPECT_EQ(kFunction,
 740             process_data_phase0.tasks[0].birth.location.function_name);
 741   EXPECT_EQ(kLineNumber,
 742             process_data_phase0.tasks[0].birth.location.line_number);
 743
 744   EXPECT_EQ(kMainThreadName, process_data_phase0.tasks[0].birth.thread_name);
 745
 746   EXPECT_EQ(1, process_data_phase0.tasks[0].death_data.count);
 747   EXPECT_EQ(6, process_data_phase0.tasks[0].death_data.run_duration_sum);
 748   EXPECT_EQ(6, process_data_phase0.tasks[0].death_data.run_duration_max);
 749   EXPECT_EQ(6, process_data_phase0.tasks[0].death_data.run_duration_sample);
 750   EXPECT_EQ(7, process_data_phase0.tasks[0].death_data.queue_duration_sum);
 751   EXPECT_EQ(7, process_data_phase0.tasks[0].death_data.queue_duration_max);
 752   EXPECT_EQ(7, process_data_phase0.tasks[0].death_data.queue_duration_sample);
 753
 754   EXPECT_EQ(kMainThreadName, process_data_phase0.tasks[0].death_thread_name);
 755
 756   EXPECT_EQ(0u, process_data_phase0.descendants.size());
 757
 758   auto it1 = process_data.phased_snapshots.find(1);
 759   ASSERT_TRUE(it1 != process_data.phased_snapshots.end());
 760   const ProcessDataPhaseSnapshot& process_data_phase1 = it1->second;
 761
 762   ASSERT_EQ(1u, process_data_phase1.tasks.size());
 763
 764   EXPECT_EQ(kFile, process_data_phase1.tasks[0].birth.location.file_name);
 765   EXPECT_EQ(kFunction,
 766             process_data_phase1.tasks[0].birth.location.function_name);
 767   EXPECT_EQ(kLineNumber,
 768             process_data_phase1.tasks[0].birth.location.line_number);
 769
 770   EXPECT_EQ(kMainThreadName, process_data_phase1.tasks[0].birth.thread_name);
 771
 772   EXPECT_EQ(1, process_data_phase1.tasks[0].death_data.count);
 773   EXPECT_EQ(4, process_data_phase1.tasks[0].death_data.run_duration_sum);
 774   EXPECT_EQ(4, process_data_phase1.tasks[0].death_data.run_duration_max);
 775   EXPECT_EQ(4, process_data_phase1.tasks[0].death_data.run_duration_sample);
 776   EXPECT_EQ(5, process_data_phase1.tasks[0].death_data.queue_duration_sum);
 777   EXPECT_EQ(5, process_data_phase1.tasks[0].death_data.queue_duration_max);
 778   EXPECT_EQ(5, process_data_phase1.tasks[0].death_data.queue_duration_sample);
 779
 780   EXPECT_EQ(kMainThreadName, process_data_phase1.tasks[0].death_thread_name);
 781
 782   EXPECT_EQ(0u, process_data_phase1.descendants.size());
 783
 784   auto it2 = process_data.phased_snapshots.find(2);
 785   ASSERT_TRUE(it2 != process_data.phased_snapshots.end());
 786   const ProcessDataPhaseSnapshot& process_data_phase2 = it2->second;
 787
 788   ASSERT_EQ(1u, process_data_phase2.tasks.size());
 789
 790   EXPECT_EQ(kFile, process_data_phase2.tasks[0].birth.location.file_name);
 791   EXPECT_EQ(kFunction,
 792             process_data_phase2.tasks[0].birth.location.function_name);
 793   EXPECT_EQ(kLineNumber,
 794             process_data_phase2.tasks[0].birth.location.line_number);
 795
 796   EXPECT_EQ(kMainThreadName, process_data_phase2.tasks[0].birth.thread_name);
 797
 798   EXPECT_EQ(1, process_data_phase2.tasks[0].death_data.count);
 799   EXPECT_EQ(2, process_data_phase2.tasks[0].death_data.run_duration_sum);
 800   EXPECT_EQ(2, process_data_phase2.tasks[0].death_data.run_duration_max);
 801   EXPECT_EQ(2, process_data_phase2.tasks[0].death_data.run_duration_sample);
 802   EXPECT_EQ(3, process_data_phase2.tasks[0].death_data.queue_duration_sum);
 803   EXPECT_EQ(3, process_data_phase2.tasks[0].death_data.queue_duration_max);
 804   EXPECT_EQ(3, process_data_phase2.tasks[0].death_data.queue_duration_sample);
 805
 806   EXPECT_EQ(kMainThreadName, process_data_phase2.tasks[0].death_thread_name);
 807
 808   EXPECT_EQ(0u, process_data_phase2.descendants.size());
 809
 810   EXPECT_EQ(base::GetCurrentProcId(), process_data.process_id);
 811 }
 812
 813 TEST_F(TrackedObjectsTest, TwoPhasesSecondEmpty) {
 814   if (!ThreadData::InitializeAndSetTrackingStatus(
 815           ThreadData::PROFILING_CHILDREN_ACTIVE)) {
 816     // Don't run the test if task tracking is not compiled in.
 817     return;
 818   }
 819
 820   const char kFunction[] = "TwoPhasesSecondEmpty";
 821   Location location(kFunction, kFile, kLineNumber, NULL);
 822   ThreadData::InitializeThreadContext(kMainThreadName);
 823
 824   const TrackedTime kTimePosted = TrackedTime::FromMilliseconds(1);
 825   const base::TimeTicks kDelayedStartTime = base::TimeTicks();
 826   // TrackingInfo will call TallyABirth() during construction.
 827   base::TrackingInfo pending_task(location, kDelayedStartTime);
 828   pending_task.time_posted = kTimePosted;  // Overwrite implied Now().
 829
 830   const unsigned int kStartOfRun = 5;
 831   const unsigned int kEndOfRun = 7;
 832   SetTestTime(kStartOfRun);
 833   TaskStopwatch stopwatch;
 834   stopwatch.Start();
 835   SetTestTime(kEndOfRun);
 836   stopwatch.Stop();
 837
 838   ThreadData::TallyRunOnNamedThreadIfTracking(pending_task, stopwatch);
 839
 840   ThreadData::OnProfilingPhaseCompleted(0);
 841
 842   ProcessDataSnapshot process_data;
 843   ThreadData::Snapshot(1, &process_data);
 844
 845   ASSERT_EQ(2u, process_data.phased_snapshots.size());
 846
 847   auto it0 = process_data.phased_snapshots.find(0);
 848   ASSERT_TRUE(it0 != process_data.phased_snapshots.end());
 849   const ProcessDataPhaseSnapshot& process_data_phase0 = it0->second;
 850
 851   ASSERT_EQ(1u, process_data_phase0.tasks.size());
 852
 853   EXPECT_EQ(kFile, process_data_phase0.tasks[0].birth.location.file_name);
 854   EXPECT_EQ(kFunction,
 855             process_data_phase0.tasks[0].birth.location.function_name);
 856   EXPECT_EQ(kLineNumber,
 857             process_data_phase0.tasks[0].birth.location.line_number);
 858
 859   EXPECT_EQ(kMainThreadName, process_data_phase0.tasks[0].birth.thread_name);
 860
 861   EXPECT_EQ(1, process_data_phase0.tasks[0].death_data.count);
 862   EXPECT_EQ(2, process_data_phase0.tasks[0].death_data.run_duration_sum);
 863   EXPECT_EQ(2, process_data_phase0.tasks[0].death_data.run_duration_max);
 864   EXPECT_EQ(2, process_data_phase0.tasks[0].death_data.run_duration_sample);
 865   EXPECT_EQ(4, process_data_phase0.tasks[0].death_data.queue_duration_sum);
 866   EXPECT_EQ(4, process_data_phase0.tasks[0].death_data.queue_duration_max);
 867   EXPECT_EQ(4, process_data_phase0.tasks[0].death_data.queue_duration_sample);
 868
 869   EXPECT_EQ(kMainThreadName, process_data_phase0.tasks[0].death_thread_name);
 870
 871   auto it1 = process_data.phased_snapshots.find(1);
 872   ASSERT_TRUE(it1 != process_data.phased_snapshots.end());
 873   const ProcessDataPhaseSnapshot& process_data_phase1 = it1->second;
 874
 875   ASSERT_EQ(0u, process_data_phase1.tasks.size());
 876
 877   EXPECT_EQ(0u, process_data_phase0.descendants.size());
 878
 879   EXPECT_EQ(base::GetCurrentProcId(), process_data.process_id);
 880 }
 881
 882 TEST_F(TrackedObjectsTest, TwoPhasesFirstEmpty) {
 883   if (!ThreadData::InitializeAndSetTrackingStatus(
 884           ThreadData::PROFILING_CHILDREN_ACTIVE)) {
 885     // Don't run the test if task tracking is not compiled in.
 886     return;
 887   }
 888
 889   ThreadData::OnProfilingPhaseCompleted(0);
 890
 891   const char kFunction[] = "TwoPhasesSecondEmpty";
 892   Location location(kFunction, kFile, kLineNumber, NULL);
 893   ThreadData::InitializeThreadContext(kMainThreadName);
 894
 895   const TrackedTime kTimePosted = TrackedTime::FromMilliseconds(1);
 896   const base::TimeTicks kDelayedStartTime = base::TimeTicks();
 897   // TrackingInfo will call TallyABirth() during construction.
 898   base::TrackingInfo pending_task(location, kDelayedStartTime);
 899   pending_task.time_posted = kTimePosted;  // Overwrite implied Now().
 900
 901   const unsigned int kStartOfRun = 5;
 902   const unsigned int kEndOfRun = 7;
 903   SetTestTime(kStartOfRun);
 904   TaskStopwatch stopwatch;
 905   stopwatch.Start();
 906   SetTestTime(kEndOfRun);
 907   stopwatch.Stop();
 908
 909   ThreadData::TallyRunOnNamedThreadIfTracking(pending_task, stopwatch);
 910
 911   ProcessDataSnapshot process_data;
 912   ThreadData::Snapshot(1, &process_data);
 913
 914   ASSERT_EQ(1u, process_data.phased_snapshots.size());
 915
 916   auto it1 = process_data.phased_snapshots.find(1);
 917   ASSERT_TRUE(it1 != process_data.phased_snapshots.end());
 918   const ProcessDataPhaseSnapshot& process_data_phase1 = it1->second;
 919
 920   ASSERT_EQ(1u, process_data_phase1.tasks.size());
 921
 922   EXPECT_EQ(kFile, process_data_phase1.tasks[0].birth.location.file_name);
 923   EXPECT_EQ(kFunction,
 924             process_data_phase1.tasks[0].birth.location.function_name);
 925   EXPECT_EQ(kLineNumber,
 926             process_data_phase1.tasks[0].birth.location.line_number);
 927
 928   EXPECT_EQ(kMainThreadName, process_data_phase1.tasks[0].birth.thread_name);
 929
 930   EXPECT_EQ(1, process_data_phase1.tasks[0].death_data.count);
 931   EXPECT_EQ(2, process_data_phase1.tasks[0].death_data.run_duration_sum);
 932   EXPECT_EQ(2, process_data_phase1.tasks[0].death_data.run_duration_max);
 933   EXPECT_EQ(2, process_data_phase1.tasks[0].death_data.run_duration_sample);
 934   EXPECT_EQ(4, process_data_phase1.tasks[0].death_data.queue_duration_sum);
 935   EXPECT_EQ(4, process_data_phase1.tasks[0].death_data.queue_duration_max);
 936   EXPECT_EQ(4, process_data_phase1.tasks[0].death_data.queue_duration_sample);
 937
 938   EXPECT_EQ(kMainThreadName, process_data_phase1.tasks[0].death_thread_name);
 939
 940   EXPECT_EQ(base::GetCurrentProcId(), process_data.process_id);
 941 }
 942
 943 // We will deactivate tracking after the birth, and before the death, and
 944 // demonstrate that the lifecycle is completely tallied. This ensures that
 945 // our tallied births are matched by tallied deaths (except for when the
 946 // task is still running, or is queued).
 947 TEST_F(TrackedObjectsTest, LifeCycleMidDeactivatedToSnapshotMainThread) {
 948   if (!ThreadData::InitializeAndSetTrackingStatus(
 949           ThreadData::PROFILING_CHILDREN_ACTIVE)) {
 950     // Don't run the test if task tracking is not compiled in.
 951     return;
 952   }
 953
 954   const char kFunction[] = "LifeCycleMidDeactivatedToSnapshotMainThread";
 955   Location location(kFunction, kFile, kLineNumber, NULL);
 956   TallyABirth(location, kMainThreadName);
 957
 958   const TrackedTime kTimePosted = TrackedTime::FromMilliseconds(1);
 959   const base::TimeTicks kDelayedStartTime = base::TimeTicks();
 960   // TrackingInfo will call TallyABirth() during construction.
 961   base::TrackingInfo pending_task(location, kDelayedStartTime);
 962   pending_task.time_posted = kTimePosted;  // Overwrite implied Now().
 963
 964   // Turn off tracking now that we have births.
 965   EXPECT_TRUE(
 966       ThreadData::InitializeAndSetTrackingStatus(ThreadData::DEACTIVATED));
 967
 968   const unsigned int kStartOfRun = 5;
 969   const unsigned int kEndOfRun = 7;
 970   SetTestTime(kStartOfRun);
 971   TaskStopwatch stopwatch;
 972   stopwatch.Start();
 973   SetTestTime(kEndOfRun);
 974   stopwatch.Stop();
 975
 976   ThreadData::TallyRunOnNamedThreadIfTracking(pending_task, stopwatch);
 977
 978   ProcessDataSnapshot process_data;
 979   ThreadData::Snapshot(0, &process_data);
 980   ExpectSimpleProcessData(process_data, kFunction, kMainThreadName,
 981                           kMainThreadName, 1, 2, 4);
 982 }
 983
 984 // We will deactivate tracking before starting a life cycle, and neither
 985 // the birth nor the death will be recorded.
 986 TEST_F(TrackedObjectsTest, LifeCyclePreDeactivatedToSnapshotMainThread) {
 987   // Start in the deactivated state.
 988   if (!ThreadData::InitializeAndSetTrackingStatus(ThreadData::DEACTIVATED)) {
 989     // Don't run the test if task tracking is not compiled in.
 990     return;
 991   }
 992
 993   const char kFunction[] = "LifeCyclePreDeactivatedToSnapshotMainThread";
 994   Location location(kFunction, kFile, kLineNumber, NULL);
 995   TallyABirth(location, kMainThreadName);
 996
 997   const TrackedTime kTimePosted = TrackedTime::FromMilliseconds(1);
 998   const base::TimeTicks kDelayedStartTime = base::TimeTicks();
 999   // TrackingInfo will call TallyABirth() during construction.
1000   base::TrackingInfo pending_task(location, kDelayedStartTime);
1001   pending_task.time_posted = kTimePosted;  // Overwrite implied Now().
1002
1003   const unsigned int kStartOfRun = 5;
1004   const unsigned int kEndOfRun = 7;
1005   SetTestTime(kStartOfRun);
1006   TaskStopwatch stopwatch;
1007   stopwatch.Start();
1008   SetTestTime(kEndOfRun);
1009   stopwatch.Stop();
1010
1011   ThreadData::TallyRunOnNamedThreadIfTracking(pending_task, stopwatch);
1012
1013   ProcessDataSnapshot process_data;
1014   ThreadData::Snapshot(0, &process_data);
1015
1016   ASSERT_EQ(1u, process_data.phased_snapshots.size());
1017
1018   auto it = process_data.phased_snapshots.find(0);
1019   ASSERT_TRUE(it != process_data.phased_snapshots.end());
1020   const ProcessDataPhaseSnapshot& process_data_phase = it->second;
1021
1022   ASSERT_EQ(0u, process_data_phase.tasks.size());
1023
1024   EXPECT_EQ(base::GetCurrentProcId(), process_data.process_id);
1025 }
1026
1027 TEST_F(TrackedObjectsTest, TwoLives) {
1028   if (!ThreadData::InitializeAndSetTrackingStatus(
1029           ThreadData::PROFILING_CHILDREN_ACTIVE)) {
1030     // Don't run the test if task tracking is not compiled in.
1031     return;
1032   }
1033
1034   const char kFunction[] = "TwoLives";
1035   Location location(kFunction, kFile, kLineNumber, NULL);
1036   TallyABirth(location, kMainThreadName);
1037
1038   const TrackedTime kTimePosted = TrackedTime::FromMilliseconds(1);
1039   const base::TimeTicks kDelayedStartTime = base::TimeTicks();
1040   // TrackingInfo will call TallyABirth() during construction.
1041   base::TrackingInfo pending_task(location, kDelayedStartTime);
1042   pending_task.time_posted = kTimePosted;  // Overwrite implied Now().
1043
1044   const unsigned int kStartOfRun = 5;
1045   const unsigned int kEndOfRun = 7;
1046   SetTestTime(kStartOfRun);
1047   TaskStopwatch stopwatch;
1048   stopwatch.Start();
1049   SetTestTime(kEndOfRun);
1050   stopwatch.Stop();
1051
1052   ThreadData::TallyRunOnNamedThreadIfTracking(pending_task, stopwatch);
1053
1054   // TrackingInfo will call TallyABirth() during construction.
1055   base::TrackingInfo pending_task2(location, kDelayedStartTime);
1056   pending_task2.time_posted = kTimePosted;  // Overwrite implied Now().
1057   SetTestTime(kStartOfRun);
1058   TaskStopwatch stopwatch2;
1059   stopwatch2.Start();
1060   SetTestTime(kEndOfRun);
1061   stopwatch2.Stop();
1062
1063   ThreadData::TallyRunOnNamedThreadIfTracking(pending_task2, stopwatch2);
1064
1065   ProcessDataSnapshot process_data;
1066   ThreadData::Snapshot(0, &process_data);
1067   ExpectSimpleProcessData(process_data, kFunction, kMainThreadName,
1068                           kMainThreadName, 2, 2, 4);
1069 }
1070
1071 TEST_F(TrackedObjectsTest, DifferentLives) {
1072   if (!ThreadData::InitializeAndSetTrackingStatus(
1073           ThreadData::PROFILING_CHILDREN_ACTIVE)) {
1074     // Don't run the test if task tracking is not compiled in.
1075     return;
1076   }
1077
1078   // Use a well named thread.
1079   ThreadData::InitializeThreadContext(kMainThreadName);
1080   const char kFunction[] = "DifferentLives";
1081   Location location(kFunction, kFile, kLineNumber, NULL);
1082
1083   const TrackedTime kTimePosted = TrackedTime::FromMilliseconds(1);
1084   const base::TimeTicks kDelayedStartTime = base::TimeTicks();
1085   // TrackingInfo will call TallyABirth() during construction.
1086   base::TrackingInfo pending_task(location, kDelayedStartTime);
1087   pending_task.time_posted = kTimePosted;  // Overwrite implied Now().
1088
1089   const unsigned int kStartOfRun = 5;
1090   const unsigned int kEndOfRun = 7;
1091   SetTestTime(kStartOfRun);
1092   TaskStopwatch stopwatch;
1093   stopwatch.Start();
1094   SetTestTime(kEndOfRun);
1095   stopwatch.Stop();
1096
1097   ThreadData::TallyRunOnNamedThreadIfTracking(pending_task, stopwatch);
1098
1099   const int kSecondFakeLineNumber = 999;
1100   Location second_location(kFunction, kFile, kSecondFakeLineNumber, NULL);
1101
1102   // TrackingInfo will call TallyABirth() during construction.
1103   base::TrackingInfo pending_task2(second_location, kDelayedStartTime);
1104   pending_task2.time_posted = kTimePosted;  // Overwrite implied Now().
1105
1106   ProcessDataSnapshot process_data;
1107   ThreadData::Snapshot(0, &process_data);
1108
1109   ASSERT_EQ(1u, process_data.phased_snapshots.size());
1110   auto it = process_data.phased_snapshots.find(0);
1111   ASSERT_TRUE(it != process_data.phased_snapshots.end());
1112   const ProcessDataPhaseSnapshot& process_data_phase = it->second;
1113
1114   ASSERT_EQ(2u, process_data_phase.tasks.size());
1115
1116   EXPECT_EQ(kFile, process_data_phase.tasks[0].birth.location.file_name);
1117   EXPECT_EQ(kFunction,
1118             process_data_phase.tasks[0].birth.location.function_name);
1119   EXPECT_EQ(kLineNumber,
1120             process_data_phase.tasks[0].birth.location.line_number);
1121   EXPECT_EQ(kMainThreadName, process_data_phase.tasks[0].birth.thread_name);
1122   EXPECT_EQ(1, process_data_phase.tasks[0].death_data.count);
1123   EXPECT_EQ(2, process_data_phase.tasks[0].death_data.run_duration_sum);
1124   EXPECT_EQ(2, process_data_phase.tasks[0].death_data.run_duration_max);
1125   EXPECT_EQ(2, process_data_phase.tasks[0].death_data.run_duration_sample);
1126   EXPECT_EQ(4, process_data_phase.tasks[0].death_data.queue_duration_sum);
1127   EXPECT_EQ(4, process_data_phase.tasks[0].death_data.queue_duration_max);
1128   EXPECT_EQ(4, process_data_phase.tasks[0].death_data.queue_duration_sample);
1129   EXPECT_EQ(kMainThreadName, process_data_phase.tasks[0].death_thread_name);
1130   EXPECT_EQ(kFile, process_data_phase.tasks[1].birth.location.file_name);
1131   EXPECT_EQ(kFunction,
1132             process_data_phase.tasks[1].birth.location.function_name);
1133   EXPECT_EQ(kSecondFakeLineNumber,
1134             process_data_phase.tasks[1].birth.location.line_number);
1135   EXPECT_EQ(kMainThreadName, process_data_phase.tasks[1].birth.thread_name);
1136   EXPECT_EQ(1, process_data_phase.tasks[1].death_data.count);
1137   EXPECT_EQ(0, process_data_phase.tasks[1].death_data.run_duration_sum);
1138   EXPECT_EQ(0, process_data_phase.tasks[1].death_data.run_duration_max);
1139   EXPECT_EQ(0, process_data_phase.tasks[1].death_data.run_duration_sample);
1140   EXPECT_EQ(0, process_data_phase.tasks[1].death_data.queue_duration_sum);
1141   EXPECT_EQ(0, process_data_phase.tasks[1].death_data.queue_duration_max);
1142   EXPECT_EQ(0, process_data_phase.tasks[1].death_data.queue_duration_sample);
1143   EXPECT_EQ(kStillAlive, process_data_phase.tasks[1].death_thread_name);
1144   EXPECT_EQ(0u, process_data_phase.descendants.size());
1145   EXPECT_EQ(base::GetCurrentProcId(), process_data.process_id);
1146 }
1147
1148 TEST_F(TrackedObjectsTest, TaskWithNestedExclusion) {
1149   if (!ThreadData::InitializeAndSetTrackingStatus(
1150           ThreadData::PROFILING_CHILDREN_ACTIVE)) {
1151     // Don't run the test if task tracking is not compiled in.
1152     return;
1153   }
1154
1155   const char kFunction[] = "TaskWithNestedExclusion";
1156   Location location(kFunction, kFile, kLineNumber, NULL);
1157   TallyABirth(location, kMainThreadName);
1158
1159   const TrackedTime kTimePosted = TrackedTime::FromMilliseconds(1);
1160   const base::TimeTicks kDelayedStartTime = base::TimeTicks();
1161   // TrackingInfo will call TallyABirth() during construction.
1162   base::TrackingInfo pending_task(location, kDelayedStartTime);
1163   pending_task.time_posted = kTimePosted;  // Overwrite implied Now().
1164
1165   SetTestTime(5);
1166   TaskStopwatch task_stopwatch;
1167   task_stopwatch.Start();
1168   {
1169     SetTestTime(8);
1170     TaskStopwatch exclusion_stopwatch;
1171     exclusion_stopwatch.Start();
1172     SetTestTime(12);
1173     exclusion_stopwatch.Stop();
1174   }
1175   SetTestTime(15);
1176   task_stopwatch.Stop();
1177
1178   ThreadData::TallyRunOnNamedThreadIfTracking(pending_task, task_stopwatch);
1179
1180   ProcessDataSnapshot process_data;
1181   ThreadData::Snapshot(0, &process_data);
1182   ExpectSimpleProcessData(process_data, kFunction, kMainThreadName,
1183                           kMainThreadName, 1, 6, 4);
1184 }
1185
1186 TEST_F(TrackedObjectsTest, TaskWith2NestedExclusions) {
1187   if (!ThreadData::InitializeAndSetTrackingStatus(
1188           ThreadData::PROFILING_CHILDREN_ACTIVE)) {
1189     // Don't run the test if task tracking is not compiled in.
1190     return;
1191   }
1192
1193   const char kFunction[] = "TaskWith2NestedExclusions";
1194   Location location(kFunction, kFile, kLineNumber, NULL);
1195   TallyABirth(location, kMainThreadName);
1196
1197   const TrackedTime kTimePosted = TrackedTime::FromMilliseconds(1);
1198   const base::TimeTicks kDelayedStartTime = base::TimeTicks();
1199   // TrackingInfo will call TallyABirth() during construction.
1200   base::TrackingInfo pending_task(location, kDelayedStartTime);
1201   pending_task.time_posted = kTimePosted;  // Overwrite implied Now().
1202
1203   SetTestTime(5);
1204   TaskStopwatch task_stopwatch;
1205   task_stopwatch.Start();
1206   {
1207     SetTestTime(8);
1208     TaskStopwatch exclusion_stopwatch;
1209     exclusion_stopwatch.Start();
1210     SetTestTime(12);
1211     exclusion_stopwatch.Stop();
1212
1213     SetTestTime(15);
1214     TaskStopwatch exclusion_stopwatch2;
1215     exclusion_stopwatch2.Start();
1216     SetTestTime(18);
1217     exclusion_stopwatch2.Stop();
1218   }
1219   SetTestTime(25);
1220   task_stopwatch.Stop();
1221
1222   ThreadData::TallyRunOnNamedThreadIfTracking(pending_task, task_stopwatch);
1223
1224   ProcessDataSnapshot process_data;
1225   ThreadData::Snapshot(0, &process_data);
1226   ExpectSimpleProcessData(process_data, kFunction, kMainThreadName,
1227                           kMainThreadName, 1, 13, 4);
1228 }
1229
1230 TEST_F(TrackedObjectsTest, TaskWithNestedExclusionWithNestedTask) {
1231   if (!ThreadData::InitializeAndSetTrackingStatus(
1232           ThreadData::PROFILING_CHILDREN_ACTIVE)) {
1233     // Don't run the test if task tracking is not compiled in.
1234     return;
1235   }
1236
1237   const char kFunction[] = "TaskWithNestedExclusionWithNestedTask";
1238   Location location(kFunction, kFile, kLineNumber, NULL);
1239
1240   const int kSecondFakeLineNumber = 999;
1241
1242   TallyABirth(location, kMainThreadName);
1243
1244   const TrackedTime kTimePosted = TrackedTime::FromMilliseconds(1);
1245   const base::TimeTicks kDelayedStartTime = base::TimeTicks();
1246   // TrackingInfo will call TallyABirth() during construction.
1247   base::TrackingInfo pending_task(location, kDelayedStartTime);
1248   pending_task.time_posted = kTimePosted;  // Overwrite implied Now().
1249
1250   SetTestTime(5);
1251   TaskStopwatch task_stopwatch;
1252   task_stopwatch.Start();
1253   {
1254     SetTestTime(8);
1255     TaskStopwatch exclusion_stopwatch;
1256     exclusion_stopwatch.Start();
1257     {
1258       Location second_location(kFunction, kFile, kSecondFakeLineNumber, NULL);
1259       base::TrackingInfo nested_task(second_location, kDelayedStartTime);
1260        // Overwrite implied Now().
1261       nested_task.time_posted = TrackedTime::FromMilliseconds(8);
1262       SetTestTime(9);
1263       TaskStopwatch nested_task_stopwatch;
1264       nested_task_stopwatch.Start();
1265       SetTestTime(11);
1266       nested_task_stopwatch.Stop();
1267       ThreadData::TallyRunOnNamedThreadIfTracking(
1268           nested_task, nested_task_stopwatch);
1269     }
1270     SetTestTime(12);
1271     exclusion_stopwatch.Stop();
1272   }
1273   SetTestTime(15);
1274   task_stopwatch.Stop();
1275
1276   ThreadData::TallyRunOnNamedThreadIfTracking(pending_task, task_stopwatch);
1277
1278   ProcessDataSnapshot process_data;
1279   ThreadData::Snapshot(0, &process_data);
1280
1281   ASSERT_EQ(1u, process_data.phased_snapshots.size());
1282   auto it = process_data.phased_snapshots.find(0);
1283   ASSERT_TRUE(it != process_data.phased_snapshots.end());
1284   const ProcessDataPhaseSnapshot& process_data_phase = it->second;
1285
1286   // The order in which the two task follow is platform-dependent.
1287   int t0 =
1288       (process_data_phase.tasks[0].birth.location.line_number == kLineNumber)
1289           ? 0
1290           : 1;
1291   int t1 = 1 - t0;
1292
1293   ASSERT_EQ(2u, process_data_phase.tasks.size());
1294   EXPECT_EQ(kFile, process_data_phase.tasks[t0].birth.location.file_name);
1295   EXPECT_EQ(kFunction,
1296             process_data_phase.tasks[t0].birth.location.function_name);
1297   EXPECT_EQ(kLineNumber,
1298             process_data_phase.tasks[t0].birth.location.line_number);
1299   EXPECT_EQ(kMainThreadName, process_data_phase.tasks[t0].birth.thread_name);
1300   EXPECT_EQ(1, process_data_phase.tasks[t0].death_data.count);
1301   EXPECT_EQ(6, process_data_phase.tasks[t0].death_data.run_duration_sum);
1302   EXPECT_EQ(6, process_data_phase.tasks[t0].death_data.run_duration_max);
1303   EXPECT_EQ(6, process_data_phase.tasks[t0].death_data.run_duration_sample);
1304   EXPECT_EQ(4, process_data_phase.tasks[t0].death_data.queue_duration_sum);
1305   EXPECT_EQ(4, process_data_phase.tasks[t0].death_data.queue_duration_max);
1306   EXPECT_EQ(4, process_data_phase.tasks[t0].death_data.queue_duration_sample);
1307   EXPECT_EQ(kMainThreadName, process_data_phase.tasks[t0].death_thread_name);
1308   EXPECT_EQ(kFile, process_data_phase.tasks[t1].birth.location.file_name);
1309   EXPECT_EQ(kFunction,
1310             process_data_phase.tasks[t1].birth.location.function_name);
1311   EXPECT_EQ(kSecondFakeLineNumber,
1312             process_data_phase.tasks[t1].birth.location.line_number);
1313   EXPECT_EQ(kMainThreadName, process_data_phase.tasks[t1].birth.thread_name);
1314   EXPECT_EQ(1, process_data_phase.tasks[t1].death_data.count);
1315   EXPECT_EQ(2, process_data_phase.tasks[t1].death_data.run_duration_sum);
1316   EXPECT_EQ(2, process_data_phase.tasks[t1].death_data.run_duration_max);
1317   EXPECT_EQ(2, process_data_phase.tasks[t1].death_data.run_duration_sample);
1318   EXPECT_EQ(1, process_data_phase.tasks[t1].death_data.queue_duration_sum);
1319   EXPECT_EQ(1, process_data_phase.tasks[t1].death_data.queue_duration_max);
1320   EXPECT_EQ(1, process_data_phase.tasks[t1].death_data.queue_duration_sample);
1321   EXPECT_EQ(kMainThreadName, process_data_phase.tasks[t1].death_thread_name);
1322   EXPECT_EQ(0u, process_data_phase.descendants.size());
1323   EXPECT_EQ(base::GetCurrentProcId(), process_data.process_id);
1324 }
1325
1326 }  // namespace tracked_objects