Creating a framework for suppressing pollution of the profiler data

base/tracked_objects.cc

Index: base/tracked_objects.cc
diff --git a/base/tracked_objects.cc b/base/tracked_objects.cc
index 56b44c10b2c389fbb053bee442769c0eda51941a..3b2045a86b1a9c82688e5fd7641bea8cdc9fc071 100644
--- a/base/tracked_objects.cc
+++ b/base/tracked_objects.cc
@@ -269,7 +269,8 @@ ThreadData::ThreadData(const std::string& suggested_name)
     : next_(NULL),
       next_retired_worker_(NULL),
       worker_thread_number_(0),
-      incarnation_count_for_pool_(-1) {
+      incarnation_count_for_pool_(-1),
+      current_stopwatch_(NULL) {
   DCHECK_GE(suggested_name.size(), 0u);
   thread_name_ = suggested_name;
   PushToHeadOfList();  // Which sets real incarnation_count_for_pool_.
@@ -279,7 +280,8 @@ ThreadData::ThreadData(int thread_number)
     : next_(NULL),
       next_retired_worker_(NULL),
       worker_thread_number_(thread_number),
-      incarnation_count_for_pool_(-1)  {
+      incarnation_count_for_pool_(-1),
+      current_stopwatch_(NULL) {
   CHECK_GT(thread_number, 0);
   base::StringAppendF(&thread_name_, "WorkerThread-%d", thread_number);
   PushToHeadOfList();  // Which sets real incarnation_count_for_pool_.
@@ -434,7 +436,9 @@ Births* ThreadData::TallyABirth(const Location& location) {
 
 void ThreadData::TallyADeath(const Births& birth,
                              int32 queue_duration,
-                             int32 run_duration) {
+                             const TaskStopwatch& stopwatch) {
+  int32 run_duration = stopwatch.RunDurationMs();
+
   // Stir in some randomness, plus add constant in case durations are zero.
   const int32 kSomePrimeNumber = 2147483647;
   random_number_ += queue_duration + run_duration + kSomePrimeNumber;
@@ -481,8 +485,7 @@ Births* ThreadData::TallyABirthIfActive(const Location& location) {
 // static
 void ThreadData::TallyRunOnNamedThreadIfTracking(
     const base::TrackingInfo& completed_task,
-    const TrackedTime& start_of_run,
-    const TrackedTime& end_of_run) {
+    const TaskStopwatch& stopwatch) {
   if (!kTrackAllTaskObjects)
     return;  // Not compiled in.
 
@@ -492,7 +495,7 @@ void ThreadData::TallyRunOnNamedThreadIfTracking(
   const Births* birth = completed_task.birth_tally;
   if (!birth)
     return;
-  ThreadData* current_thread_data = Get();
+  ThreadData* current_thread_data = stopwatch.GetThreadData();
   if (!current_thread_data)
     return;
 
@@ -501,23 +504,20 @@ void ThreadData::TallyRunOnNamedThreadIfTracking(
   // get a time value since we "weren't tracking" and we were trying to be
   // efficient by not calling for a genuine time value. For simplicity, we'll
   // use a default zero duration when we can't calculate a true value.
+  TrackedTime start_of_run = stopwatch.StartTime();
   int32 queue_duration = 0;
-  int32 run_duration = 0;
   if (!start_of_run.is_null()) {
     queue_duration = (start_of_run - completed_task.EffectiveTimePosted())
         .InMilliseconds();
-    if (!end_of_run.is_null())
-      run_duration = (end_of_run - start_of_run).InMilliseconds();
   }
-  current_thread_data->TallyADeath(*birth, queue_duration, run_duration);
+  current_thread_data->TallyADeath(*birth, queue_duration, stopwatch);
 }
 
 // static
 void ThreadData::TallyRunOnWorkerThreadIfTracking(
     const Births* birth,
     const TrackedTime& time_posted,
-    const TrackedTime& start_of_run,
-    const TrackedTime& end_of_run) {
+    const TaskStopwatch& stopwatch) {
   if (!kTrackAllTaskObjects)
     return;  // Not compiled in.
 
@@ -536,25 +536,22 @@ void ThreadData::TallyRunOnWorkerThreadIfTracking(
   // other thread that might like to run).  Also, the worker threads tasks are
   // generally longer, and hence the cost of the lock may perchance be amortized
   // over the long task's lifetime.
-  ThreadData* current_thread_data = Get();
+  ThreadData* current_thread_data = stopwatch.GetThreadData();
   if (!current_thread_data)
     return;
 
+  TrackedTime start_of_run = stopwatch.StartTime();
   int32 queue_duration = 0;
-  int32 run_duration = 0;
   if (!start_of_run.is_null()) {
     queue_duration = (start_of_run - time_posted).InMilliseconds();
-    if (!end_of_run.is_null())
-      run_duration = (end_of_run - start_of_run).InMilliseconds();
   }
-  current_thread_data->TallyADeath(*birth, queue_duration, run_duration);
+  current_thread_data->TallyADeath(*birth, queue_duration, stopwatch);
 }
 
 // static
 void ThreadData::TallyRunInAScopedRegionIfTracking(
     const Births* birth,
-    const TrackedTime& start_of_run,
-    const TrackedTime& end_of_run) {
+    const TaskStopwatch& stopwatch) {
   if (!kTrackAllTaskObjects)
     return;  // Not compiled in.
 
@@ -564,15 +561,12 @@ void ThreadData::TallyRunInAScopedRegionIfTracking(
   if (!birth)
     return;
 
-  ThreadData* current_thread_data = Get();
+  ThreadData* current_thread_data = stopwatch.GetThreadData();
   if (!current_thread_data)
     return;
 
   int32 queue_duration = 0;
-  int32 run_duration = 0;
-  if (!start_of_run.is_null() && !end_of_run.is_null())
-    run_duration = (end_of_run - start_of_run).InMilliseconds();
-  current_thread_data->TallyADeath(*birth, queue_duration, run_duration);
+  current_thread_data->TallyADeath(*birth, queue_duration, stopwatch);
 }
 
 // static
@@ -858,6 +852,101 @@ void ThreadData::ShutdownSingleThreadedCleanup(bool leak) {
 }
 
 //------------------------------------------------------------------------------
+TaskStopwatch::TaskStopwatch()
+    : current_thread_data_(NULL),
+      excluded_duration_ms_(0),
+      parent_stopwatch_(NULL) {
+#ifndef NDEBUG
+  state_ = CREATED;
+  running_child_ = NULL;
+#endif
+}
+
+TaskStopwatch::~TaskStopwatch() {
+#ifndef NDEBUG
+  DCHECK(state_ != RUNNING);
+  DCHECK(running_child_ == NULL);
+#endif
+}
+
+void TaskStopwatch::Start(const TrackedTime& start_time) {
+#ifndef NDEBUG
+  DCHECK(state_ != RUNNING);
+  state_ = RUNNING;
+  DCHECK(running_child_ == NULL);
+#endif
+
+  excluded_duration_ms_ = 0;
+  start_time_ = start_time;
+  wallclock_duration_ms_ = 0;
+  current_thread_data_ = ThreadData::Get();
+  if (!current_thread_data_)
+    return;
+
+  parent_stopwatch_ = current_thread_data_->current_stopwatch_;
+#ifndef NDEBUG
+  if (parent_stopwatch_) {
+    DCHECK(parent_stopwatch_->state_ == RUNNING);
+    DCHECK(parent_stopwatch_->running_child_ == NULL);
+    parent_stopwatch_->running_child_ = this;
+  }
+#endif
+  current_thread_data_->current_stopwatch_ = this;
+}
+
+void TaskStopwatch::Stop(const TrackedTime& end_time) {
+#ifndef NDEBUG
+  DCHECK(state_ == RUNNING);
+  state_ = STOPPED;
+  DCHECK(running_child_ == NULL);
+#endif
+
+  if (!start_time_.is_null() && !end_time.is_null()) {
+    wallclock_duration_ms_ = (end_time - start_time_).InMilliseconds();
+  }
+
+  if (!current_thread_data_)
+    return;
+
+  DCHECK(current_thread_data_->current_stopwatch_ == this);
+  current_thread_data_->current_stopwatch_ = parent_stopwatch_;
+  if (!parent_stopwatch_)
+    return;
+
+#ifndef NDEBUG
+  DCHECK(parent_stopwatch_->state_ == RUNNING);
+  DCHECK(parent_stopwatch_->running_child_ == this);
+  parent_stopwatch_->running_child_ = NULL;
+#endif
+  parent_stopwatch_->excluded_duration_ms_ +=
+      wallclock_duration_ms_;
+  parent_stopwatch_ = NULL;
+}
+
+TrackedTime TaskStopwatch::StartTime() const {
+#ifndef NDEBUG
+  DCHECK(state_ != CREATED);
+#endif
+  return start_time_;
+}
+
+int32 TaskStopwatch::RunDurationMs() const {
+#ifndef NDEBUG
+  DCHECK(state_ == STOPPED);
+#endif
+
+  return wallclock_duration_ms_ - excluded_duration_ms_;
+}
+
+ThreadData* TaskStopwatch::GetThreadData() const {
+#ifndef NDEBUG
+  DCHECK(state_ != CREATED);
+#endif
+
+  return current_thread_data_;
+}
+
+//------------------------------------------------------------------------------
 TaskSnapshot::TaskSnapshot() {
 }