Detect child tasks born during a profiled tasks

base/tracked_objects_unittest.cc

 // Copyright (c) 2011 The Chromium Authors. All rights reserved.
 // Use of this source code is governed by a BSD-style license that can be
 // found in the LICENSE file.
 
 // Test of classes in the tracked_objects.h classes.
 
 #include "base/tracked_objects.h"
 
 #include "base/json/json_writer.h"
 #include "base/memory/scoped_ptr.h"
@@ skipping 28 matching lines @@
     return;
 
   EXPECT_FALSE(ThreadData::first());  // No activity even on this thread.
   ThreadData* data = ThreadData::Get();
   EXPECT_TRUE(ThreadData::first());  // Now class was constructed.
   EXPECT_TRUE(data);
   EXPECT_TRUE(!data->next());
   EXPECT_EQ(data, ThreadData::Get());
   ThreadData::BirthMap birth_map;
   ThreadData::DeathMap death_map;
-  data->SnapshotMaps(false, &birth_map, &death_map);
+  ThreadData::ParentChildSet parent_child_set;
+  data->SnapshotMaps(false, &birth_map, &death_map, &parent_child_set);
   EXPECT_EQ(0u, birth_map.size());
   EXPECT_EQ(0u, death_map.size());
+  EXPECT_EQ(0u, parent_child_set.size());
   // Cleanup with no leaking.
   ShutdownSingleThreadedCleanup(false);
 
   // Do it again, just to be sure we reset state completely.
   ThreadData::InitializeAndSetTrackingStatus(true);
   EXPECT_FALSE(ThreadData::first());  // No activity even on this thread.
   data = ThreadData::Get();
   EXPECT_TRUE(ThreadData::first());  // Now class was constructed.
   EXPECT_TRUE(data);
   EXPECT_TRUE(!data->next());
   EXPECT_EQ(data, ThreadData::Get());
   birth_map.clear();
   death_map.clear();
-  data->SnapshotMaps(false, &birth_map, &death_map);
+  data->SnapshotMaps(false, &birth_map, &death_map, &parent_child_set);
   EXPECT_EQ(0u, birth_map.size());
   EXPECT_EQ(0u, death_map.size());
+  EXPECT_EQ(0u, parent_child_set.size());
 }
 
 TEST_F(TrackedObjectsTest, TinyStartupShutdown) {
   if (!ThreadData::InitializeAndSetTrackingStatus(true))
     return;
 
   // Instigate tracking on a single tracked object, on our thread.
   const Location& location = FROM_HERE;
-  ThreadData::TallyABirthIfActive(location);
+  Births* first_birth = ThreadData::TallyABirthIfActive(location);
 
   ThreadData* data = ThreadData::first();
   ASSERT_TRUE(data);
   EXPECT_TRUE(!data->next());
   EXPECT_EQ(data, ThreadData::Get());
   ThreadData::BirthMap birth_map;
   ThreadData::DeathMap death_map;
-  data->SnapshotMaps(false, &birth_map, &death_map);
+  ThreadData::ParentChildSet parent_child_set;
+  data->SnapshotMaps(false, &birth_map, &death_map, &parent_child_set);
   EXPECT_EQ(1u, birth_map.size());                         // 1 birth location.
   EXPECT_EQ(1, birth_map.begin()->second->birth_count());  // 1 birth.
   EXPECT_EQ(0u, death_map.size());                         // No deaths.
+  EXPECT_EQ(0u, parent_child_set.size());                  // No children.
 
 
-  // Now instigate another birth, and a first death at the same location.
+  // Now instigate another birth, while we are timing the run of the first
+  // execution.
+  TrackedTime start_time =
+      ThreadData::NowForStartOfRun(first_birth);
+  // Create a child (using the same birth location).
   // TrackingInfo will call TallyABirth() during construction.
-  base::TimeTicks kBogusStartTime;
-  base::TrackingInfo pending_task(location, kBogusStartTime);
-  TrackedTime kBogusStartRunTime;
-  TrackedTime kBogusEndRunTime;
-  ThreadData::TallyRunOnNamedThreadIfTracking(pending_task, kBogusStartRunTime,
-                                              kBogusEndRunTime);
+  base::TimeTicks kBogusBirthTime;
+  base::TrackingInfo pending_task(location, kBogusBirthTime);
+  // Finally conclude the outer run.
+  TrackedTime end_time = ThreadData::NowForEndOfRun();
+  ThreadData::TallyRunOnNamedThreadIfTracking(pending_task, start_time,
+                                              end_time);
 
   birth_map.clear();
   death_map.clear();
-  data->SnapshotMaps(false, &birth_map, &death_map);
+  parent_child_set.clear();
+  data->SnapshotMaps(false, &birth_map, &death_map, &parent_child_set);
   EXPECT_EQ(1u, birth_map.size());                         // 1 birth location.
   EXPECT_EQ(2, birth_map.begin()->second->birth_count());  // 2 births.
   EXPECT_EQ(1u, death_map.size());                         // 1 location.
   EXPECT_EQ(1, death_map.begin()->second.count());         // 1 death.
+  if (ThreadData::tracking_parent_child_status()) {
+    EXPECT_EQ(1u, parent_child_set.size());                  // 1 child.
+    EXPECT_EQ(parent_child_set.begin()->first,
+              parent_child_set.begin()->second);
+  } else {
+    EXPECT_EQ(0u, parent_child_set.size());                  // no stats.
+  }
 
   // The births were at the same location as the one known death.
   EXPECT_EQ(birth_map.begin()->second, death_map.begin()->first);
 }
 
+TEST_F(TrackedObjectsTest, ParentChildTest) {
+  if (!ThreadData::InitializeAndSetTrackingStatus(true))
+    return;
+  if (!ThreadData::tracking_parent_child_status())
+    return;   // Feature not compiled in.
+
+  // Instigate tracking on a single tracked object, on our thread.
+  const int kFakeLineNumber = 1776;
+  const char* kFile = "FixedUnitTestFileName";
+  const char* kFunction = "ParentChildTest";
+  Location location(kFunction, kFile, kFakeLineNumber, NULL);
+  Births* first_birth = ThreadData::TallyABirthIfActive(location);
+
+  // Now instigate another birth, while we are timing the run of the first
+  // execution.
+  TrackedTime start_time =
+      ThreadData::NowForStartOfRun(first_birth);
+  // Create a child (using the same birth location).
+  // TrackingInfo will call TallyABirth() during construction.
+  base::TimeTicks kBogusBirthTime;
+  base::TrackingInfo pending_task(location, kBogusBirthTime);
+
+  // Don't conclude the run, so that we don't use the actual timer that we
+  // started for the outer profile.  This way the JSON will not include some
+  // random time.
+
+

[ramant (doing other things), 2011/12/13 19:14:45]

nit: extra line.

[jar (doing other things), 2011/12/13 20:29:10]

Done.

+  ThreadData* data = ThreadData::first();
+  ASSERT_TRUE(data);
+  EXPECT_TRUE(!data->next());
+  EXPECT_EQ(data, ThreadData::Get());
+
+  ThreadData::BirthMap birth_map;
+  ThreadData::DeathMap death_map;
+  ThreadData::ParentChildSet parent_child_set;
+
+  data->SnapshotMaps(false, &birth_map, &death_map, &parent_child_set);
+  EXPECT_EQ(1u, birth_map.size());                         // 1 birth location.
+  EXPECT_EQ(2, birth_map.begin()->second->birth_count());  // 2 births.
+  EXPECT_EQ(0u, death_map.size());                         // No status yet.
+  // Just like TinyStartupShutdown test.
+  EXPECT_EQ(1u, parent_child_set.size());                  // 1 child.
+  EXPECT_EQ(parent_child_set.begin()->first,
+            parent_child_set.begin()->second);
+
+  scoped_ptr<base::Value> value(ThreadData::ToValue(false));
+  std::string json;
+  base::JSONWriter::Write(value.get(), false, &json);
+  std::string birth_only_result = "{"
+      "\"descendants\":["
+        "{"
+          "\"child_location\":{"
+            "\"file_name\":\"FixedUnitTestFileName\","
+            "\"function_name\":\"ParentChildTest\","
+            "\"line_number\":1776"
+          "},"
+          "\"child_thread\":\"WorkerThread-1\","
+          "\"parent_location\":{"
+            "\"file_name\":\"FixedUnitTestFileName\","
+            "\"function_name\":\"ParentChildTest\","
+            "\"line_number\":1776"
+          "},"
+          "\"parent_thread\":\"WorkerThread-1\""
+        "}"
+      "],"
+      "\"list\":["
+        "{"
+          "\"birth_thread\":\"WorkerThread-1\","
+          "\"death_data\":{"
+            "\"count\":2,"
+            "\"queue_ms\":0,"
+            "\"queue_ms_max\":0,"
+            "\"queue_ms_sample\":0,"
+            "\"run_ms\":0,"
+            "\"run_ms_max\":0,"
+            "\"run_ms_sample\":0"
+          "},"
+          "\"death_thread\":\"Still_Alive\","
+          "\"location\":{"
+            "\"file_name\":\"FixedUnitTestFileName\","
+            "\"function_name\":\"ParentChildTest\","
+            "\"line_number\":1776"
+          "}"
+        "}"
+      "]"
+    "}";
+  EXPECT_EQ(json, birth_only_result);
+}
+
 TEST_F(TrackedObjectsTest, DeathDataTest) {
   if (!ThreadData::InitializeAndSetTrackingStatus(true))
     return;
 
   scoped_ptr<DeathData> data(new DeathData());
   ASSERT_NE(data, reinterpret_cast<DeathData*>(NULL));
   EXPECT_EQ(data->run_duration_sum(), 0);
   EXPECT_EQ(data->run_duration_sample(), 0);
   EXPECT_EQ(data->queue_duration_sum(), 0);
   EXPECT_EQ(data->queue_duration_sample(), 0);
@@ skipping 56 matching lines @@
   const char* kFunction = "BirthOnlyToValueWorkerThread";
   Location location(kFunction, kFile, kFakeLineNumber, NULL);
   Births* birth = ThreadData::TallyABirthIfActive(location);
   // We should now see a NULL birth record.
   EXPECT_EQ(birth, reinterpret_cast<Births*>(NULL));
 
   scoped_ptr<base::Value> value(ThreadData::ToValue(false));
   std::string json;
   base::JSONWriter::Write(value.get(), false, &json);
   std::string birth_only_result = "{"
+      "\"descendants\":["
+      "],"
       "\"list\":["
       "]"
     "}";
   EXPECT_EQ(json, birth_only_result);
 }
 
 TEST_F(TrackedObjectsTest, DeactivatedBirthOnlyToValueMainThread) {
   // Start in the deactivated state.
   if (!ThreadData::InitializeAndSetTrackingStatus(false))
     return;
 
   // Use a well named thread.
   ThreadData::InitializeThreadContext("SomeMainThreadName");
   const int kFakeLineNumber = 173;
   const char* kFile = "FixedFileName";
   const char* kFunction = "BirthOnlyToValueMainThread";
   Location location(kFunction, kFile, kFakeLineNumber, NULL);
   // Do not delete birth.  We don't own it.
   Births* birth = ThreadData::TallyABirthIfActive(location);
   // We expect to not get a birth record.
   EXPECT_EQ(birth, reinterpret_cast<Births*>(NULL));
 
   scoped_ptr<base::Value> value(ThreadData::ToValue(false));
   std::string json;
   base::JSONWriter::Write(value.get(), false, &json);
   std::string birth_only_result = "{"
+      "\"descendants\":["
+      "],"
       "\"list\":["
       "]"
     "}";
   EXPECT_EQ(json, birth_only_result);
 }
 
 TEST_F(TrackedObjectsTest, BirthOnlyToValueWorkerThread) {
   if (!ThreadData::InitializeAndSetTrackingStatus(true))
     return;
   // We don't initialize system with a thread name, so we're viewed as a worker
   // thread.
   const int kFakeLineNumber = 173;
   const char* kFile = "FixedFileName";
   const char* kFunction = "BirthOnlyToValueWorkerThread";
   Location location(kFunction, kFile, kFakeLineNumber, NULL);
   Births* birth = ThreadData::TallyABirthIfActive(location);
   EXPECT_NE(birth, reinterpret_cast<Births*>(NULL));
 
   scoped_ptr<base::Value> value(ThreadData::ToValue(false));
   std::string json;
   base::JSONWriter::Write(value.get(), false, &json);
   std::string birth_only_result = "{"
+      "\"descendants\":["
+      "],"
       "\"list\":["
         "{"
           "\"birth_thread\":\"WorkerThread-1\","
           "\"death_data\":{"
             "\"count\":1,"
             "\"queue_ms\":0,"
             "\"queue_ms_max\":0,"
             "\"queue_ms_sample\":0,"
             "\"run_ms\":0,"
             "\"run_ms_max\":0,"
@@ skipping 22 matching lines @@
   const char* kFunction = "BirthOnlyToValueMainThread";
   Location location(kFunction, kFile, kFakeLineNumber, NULL);
   // Do not delete birth.  We don't own it.
   Births* birth = ThreadData::TallyABirthIfActive(location);
   EXPECT_NE(birth, reinterpret_cast<Births*>(NULL));
 
   scoped_ptr<base::Value> value(ThreadData::ToValue(false));
   std::string json;
   base::JSONWriter::Write(value.get(), false, &json);
   std::string birth_only_result = "{"
+      "\"descendants\":["
+      "],"
       "\"list\":["
         "{"
           "\"birth_thread\":\"SomeMainThreadName\","
           "\"death_data\":{"
             "\"count\":1,"
             "\"queue_ms\":0,"
             "\"queue_ms_max\":0,"
             "\"queue_ms_sample\":0,"
             "\"run_ms\":0,"
             "\"run_ms_max\":0,"
@@ skipping 35 matching lines @@
   const TrackedTime kStartOfRun = TrackedTime() +
       Duration::FromMilliseconds(5);
   const TrackedTime kEndOfRun = TrackedTime() + Duration::FromMilliseconds(7);
   ThreadData::TallyRunOnNamedThreadIfTracking(pending_task,
       kStartOfRun, kEndOfRun);
 
   scoped_ptr<base::Value> value(ThreadData::ToValue(false));
   std::string json;
   base::JSONWriter::Write(value.get(), false, &json);
   std::string one_line_result = "{"
+      "\"descendants\":["
+      "],"
       "\"list\":["
         "{"
           "\"birth_thread\":\"SomeMainThreadName\","
           "\"death_data\":{"
             "\"count\":1,"
             "\"queue_ms\":4,"
             "\"queue_ms_max\":4,"
             "\"queue_ms_sample\":4,"
             "\"run_ms\":2,"
             "\"run_ms_max\":2,"
@@ skipping 42 matching lines @@
   const TrackedTime kStartOfRun = TrackedTime() +
       Duration::FromMilliseconds(5);
   const TrackedTime kEndOfRun = TrackedTime() + Duration::FromMilliseconds(7);
   ThreadData::TallyRunOnNamedThreadIfTracking(pending_task,
       kStartOfRun, kEndOfRun);
 
   scoped_ptr<base::Value> value(ThreadData::ToValue(false));
   std::string json;
   base::JSONWriter::Write(value.get(), false, &json);
   std::string one_line_result = "{"
+      "\"descendants\":["
+      "],"
       "\"list\":["
         "{"
           "\"birth_thread\":\"SomeMainThreadName\","
           "\"death_data\":{"
             "\"count\":1,"
             "\"queue_ms\":4,"
             "\"queue_ms_max\":4,"
             "\"queue_ms_sample\":4,"
             "\"run_ms\":2,"
             "\"run_ms_max\":2,"
@@ skipping 37 matching lines @@
   const TrackedTime kStartOfRun = TrackedTime() +
       Duration::FromMilliseconds(5);
   const TrackedTime kEndOfRun = TrackedTime() + Duration::FromMilliseconds(7);
   ThreadData::TallyRunOnNamedThreadIfTracking(pending_task,
       kStartOfRun, kEndOfRun);
 
   scoped_ptr<base::Value> value(ThreadData::ToValue(false));
   std::string json;
   base::JSONWriter::Write(value.get(), false, &json);
   std::string one_line_result = "{"
+      "\"descendants\":["
+      "],"
       "\"list\":["
       "]"
     "}";
   EXPECT_EQ(one_line_result, json);
 }
 
 TEST_F(TrackedObjectsTest, LifeCycleToValueWorkerThread) {
   if (!ThreadData::InitializeAndSetTrackingStatus(true))
     return;
 
@@ skipping 13 matching lines @@
       Duration::FromMilliseconds(5);
   const TrackedTime kEndOfRun = TrackedTime() + Duration::FromMilliseconds(7);
   ThreadData::TallyRunOnWorkerThreadIfTracking(birth, kTimePosted,
       kStartOfRun, kEndOfRun);
 
   // Call for the ToValue, but tell it to not the maxes after scanning.
   scoped_ptr<base::Value> value(ThreadData::ToValue(false));
   std::string json;
   base::JSONWriter::Write(value.get(), false, &json);
   std::string one_line_result = "{"
+      "\"descendants\":["
+      "],"
       "\"list\":["
         "{"
           "\"birth_thread\":\"WorkerThread-1\","
           "\"death_data\":{"
             "\"count\":1,"
             "\"queue_ms\":4,"
             "\"queue_ms_max\":4,"
             "\"queue_ms_sample\":4,"
             "\"run_ms\":2,"
             "\"run_ms_max\":2,"
@@ skipping 16 matching lines @@
   value.reset(ThreadData::ToValue(true));
   base::JSONWriter::Write(value.get(), false, &json);
   // Result should be unchanged.
   EXPECT_EQ(one_line_result, json);
 
   // Call for the ToValue, and now we'll see the result of the last translation,
   // as the max will have been pushed back to zero.
   value.reset(ThreadData::ToValue(false));
   base::JSONWriter::Write(value.get(), false, &json);
   std::string one_line_result_with_zeros = "{"
+      "\"descendants\":["
+      "],"
       "\"list\":["
         "{"
           "\"birth_thread\":\"WorkerThread-1\","
           "\"death_data\":{"
             "\"count\":1,"
             "\"queue_ms\":4,"
             "\"queue_ms_max\":0,"  // Note zero here.
             "\"queue_ms_sample\":4,"
             "\"run_ms\":2,"
             "\"run_ms_max\":0,"   // Note zero here.
@@ skipping 43 matching lines @@
   base::TrackingInfo pending_task2(location, kDelayedStartTime);
   pending_task2.time_posted = kTimePosted;  // Overwrite implied Now().
 
   ThreadData::TallyRunOnNamedThreadIfTracking(pending_task2,
       kStartOfRun, kEndOfRun);
 
   scoped_ptr<base::Value> value(ThreadData::ToValue(false));
   std::string json;
   base::JSONWriter::Write(value.get(), false, &json);
   std::string one_line_result = "{"
+      "\"descendants\":["
+      "],"
       "\"list\":["
         "{"
           "\"birth_thread\":\"SomeFileThreadName\","
           "\"death_data\":{"
             "\"count\":2,"
             "\"queue_ms\":8,"
             "\"queue_ms_max\":4,"
             "\"queue_ms_sample\":4,"
             "\"run_ms\":4,"
             "\"run_ms_max\":2,"
@@ skipping 39 matching lines @@
   Location second_location(kFunction, kFile, kSecondFakeLineNumber, NULL);
 
   // TrackingInfo will call TallyABirth() during construction.
   base::TrackingInfo pending_task2(second_location, kDelayedStartTime);
   pending_task2.time_posted = kTimePosted;  // Overwrite implied Now().
 
   scoped_ptr<base::Value> value(ThreadData::ToValue(false));
   std::string json;
   base::JSONWriter::Write(value.get(), false, &json);
   std::string one_line_result = "{"
+      "\"descendants\":["
+      "],"
       "\"list\":["
         "{"
           "\"birth_thread\":\"SomeFileThreadName\","
           "\"death_data\":{"
             "\"count\":1,"
             "\"queue_ms\":4,"
             "\"queue_ms_max\":4,"
             "\"queue_ms_sample\":4,"
             "\"run_ms\":2,"
             "\"run_ms_max\":2,"
@@ skipping 24 matching lines @@
             "\"line_number\":999"
           "}"
         "}"
       "]"
     "}";
   EXPECT_EQ(one_line_result, json);
 }
 
 
 }  // namespace tracked_objects