Creating a framework for suppressing pollution of the profiler data and applying for know cases of pollution.

See the bug.

The CL introduces TaskStopwatch that has to be used to measure run time for tasks. It takes care of double-counting
run time in the nested-tasks case by subtracting run time of nested tasks from their parents. TaskStopwatch can be
also used for subtracting other nested intervals, such as the time while a nested message pump runs. ThreadData::TallyADeath
now takes a stopwatch parameter instead of start_time and end_time. This helps avoid mistakes when the interval passed up to
the parent for exclusion is different from the interval for the current task duration.

BUG=401560

Review URL: https://codereview.chromium.org/445413003

Cr-Commit-Position: refs/heads/master@{#294865}

11 files changed, 499 insertions, 128 deletions

diff --git a/base/debug/task_annotator.cc b/base/debug/task_annotator.cc
index c6576c8..f2e4b73 100644
--- a/base/debug/task_annotator.cc
+++ b/base/debug/task_annotator.cc
@@ -28,10 +28,10 @@ void TaskAnnotator::DidQueueTask(const char* queue_function,
 void TaskAnnotator::RunTask(const char* queue_function,
                             const char* run_function,
                             const PendingTask& pending_task) {
-  tracked_objects::TrackedTime start_time =
-      tracked_objects::ThreadData::NowForStartOfRun(pending_task.birth_tally);
+  tracked_objects::ThreadData::PrepareForStartOfRun(pending_task.birth_tally);
+  tracked_objects::TaskStopwatch stopwatch;
   tracked_objects::Duration queue_duration =
-      start_time - pending_task.EffectiveTimePosted();
+      stopwatch.StartTime() - pending_task.EffectiveTimePosted();
 
   TRACE_EVENT_FLOW_END1(TRACE_DISABLED_BY_DEFAULT("toplevel.flow"),
                         queue_function,
@@ -61,8 +61,9 @@ void TaskAnnotator::RunTask(const char* queue_function,
 
   pending_task.task.Run();
 
+  stopwatch.Stop();
   tracked_objects::ThreadData::TallyRunOnNamedThreadIfTracking(
-      pending_task, start_time, tracked_objects::ThreadData::NowForEndOfRun());
+      pending_task, stopwatch);
 }
 
 uint64 TaskAnnotator::GetTaskTraceID(const PendingTask& task) const {
diff --git a/base/profiler/scoped_profile.cc b/base/profiler/scoped_profile.cc
index 93c86e92..e1edc97 100644
--- a/base/profiler/scoped_profile.cc
+++ b/base/profiler/scoped_profile.cc
@@ -12,8 +12,8 @@ namespace tracked_objects {
 
 
 ScopedProfile::ScopedProfile(const Location& location)
-    : birth_(ThreadData::TallyABirthIfActive(location)),
-      start_of_run_(ThreadData::NowForStartOfRun(birth_)) {
+    : birth_(ThreadData::TallyABirthIfActive(location)) {
+  ThreadData::PrepareForStartOfRun(birth_);
 }
 
 ScopedProfile::~ScopedProfile() {
@@ -21,10 +21,11 @@ ScopedProfile::~ScopedProfile() {
 }
 
 void ScopedProfile::StopClockAndTally() {
+  stopwatch_.Stop();
+
   if (!birth_)
     return;
-  ThreadData::TallyRunInAScopedRegionIfTracking(birth_, start_of_run_,
-                                                ThreadData::NowForEndOfRun());
+  ThreadData::TallyRunInAScopedRegionIfTracking(birth_, stopwatch_);
   birth_ = NULL;
 }
 
diff --git a/base/profiler/scoped_profile.h b/base/profiler/scoped_profile.h
index 8b77d6d..c435a1d 100644
--- a/base/profiler/scoped_profile.h
+++ b/base/profiler/scoped_profile.h
@@ -15,6 +15,7 @@
 #include "base/base_export.h"
 #include "base/location.h"
 #include "base/profiler/tracked_time.h"
+#include "base/tracked_objects.h"
 
 #if defined(GOOGLE_CHROME_BUILD)
 
@@ -57,7 +58,7 @@ class BASE_EXPORT ScopedProfile {
 
  private:
   Births* birth_;  // Place in code where tracking started.
-  const TrackedTime start_of_run_;
+  TaskStopwatch stopwatch_;
 
   DISALLOW_COPY_AND_ASSIGN(ScopedProfile);
 };
diff --git a/base/profiler/tracked_time_unittest.cc b/base/profiler/tracked_time_unittest.cc
index ef84f15..3fa9383 100644
--- a/base/profiler/tracked_time_unittest.cc
+++ b/base/profiler/tracked_time_unittest.cc
@@ -75,10 +75,6 @@ TEST(TrackedTimeTest, TrackedTimerDisabled) {
   // Since we disabled tracking, we should get a null response.
   TrackedTime track_now = ThreadData::Now();
   EXPECT_TRUE(track_now.is_null());
-  track_now = ThreadData::NowForStartOfRun(NULL);
-  EXPECT_TRUE(track_now.is_null());
-  track_now = ThreadData::NowForEndOfRun();
-  EXPECT_TRUE(track_now.is_null());
 }
 
 TEST(TrackedTimeTest, TrackedTimerEnabled) {
diff --git a/base/run_loop.cc b/base/run_loop.cc
index 8344aa4..e92e110 100644
--- a/base/run_loop.cc
+++ b/base/run_loop.cc
@@ -5,6 +5,7 @@
 #include "base/run_loop.h"
 
 #include "base/bind.h"
+#include "base/tracked_objects.h"
 
 #if defined(OS_WIN)
 #include "base/message_loop/message_pump_dispatcher.h"
@@ -46,7 +47,13 @@ RunLoop::~RunLoop() {
 void RunLoop::Run() {
   if (!BeforeRun())
     return;
+
+  // Use task stopwatch to exclude the loop run time from the current task, if
+  // any.
+  tracked_objects::TaskStopwatch stopwatch;
   loop_->RunHandler();
+  stopwatch.Stop();
+
   AfterRun();
 }
 
diff --git a/base/threading/sequenced_worker_pool.cc b/base/threading/sequenced_worker_pool.cc
index 532f26e..38b2998 100644
--- a/base/threading/sequenced_worker_pool.cc
+++ b/base/threading/sequenced_worker_pool.cc
@@ -755,13 +755,13 @@ void SequencedWorkerPool::Inner::ThreadLoop(Worker* this_worker) {
           this_worker->set_running_task_info(
               SequenceToken(task.sequence_token_id), task.shutdown_behavior);
 
-          tracked_objects::TrackedTime start_time =
-              tracked_objects::ThreadData::NowForStartOfRun(task.birth_tally);
-
+          tracked_objects::ThreadData::PrepareForStartOfRun(task.birth_tally);
+          tracked_objects::TaskStopwatch stopwatch;
           task.task.Run();
+          stopwatch.Stop();
 
-          tracked_objects::ThreadData::TallyRunOnNamedThreadIfTracking(task,
-              start_time, tracked_objects::ThreadData::NowForEndOfRun());
+          tracked_objects::ThreadData::TallyRunOnNamedThreadIfTracking(
+              task, stopwatch);
 
           // Make sure our task is erased outside the lock for the
           // same reason we do this with delete_these_oustide_lock.
diff --git a/base/threading/worker_pool_posix.cc b/base/threading/worker_pool_posix.cc
index f00d799..167d20f 100644
--- a/base/threading/worker_pool_posix.cc
+++ b/base/threading/worker_pool_posix.cc
@@ -95,14 +95,14 @@ void WorkerThread::ThreadMain() {
         "src_file", pending_task.posted_from.file_name(),
         "src_func", pending_task.posted_from.function_name());
 
-    TrackedTime start_time =
-        tracked_objects::ThreadData::NowForStartOfRun(pending_task.birth_tally);
-
+    tracked_objects::ThreadData::PrepareForStartOfRun(pending_task.birth_tally);
+    tracked_objects::TaskStopwatch stopwatch;
     pending_task.task.Run();
+    stopwatch.Stop();
 
     tracked_objects::ThreadData::TallyRunOnWorkerThreadIfTracking(
         pending_task.birth_tally, TrackedTime(pending_task.time_posted),
-        start_time, tracked_objects::ThreadData::NowForEndOfRun());
+        stopwatch);
   }
 
   // The WorkerThread is non-joinable, so it deletes itself.
diff --git a/base/threading/worker_pool_win.cc b/base/threading/worker_pool_win.cc
index fa11dc5..8fc7324 100644
--- a/base/threading/worker_pool_win.cc
+++ b/base/threading/worker_pool_win.cc
@@ -25,17 +25,20 @@ DWORD CALLBACK WorkItemCallback(void* param) {
                "src_file", pending_task->posted_from.file_name(),
                "src_func", pending_task->posted_from.function_name());
 
-  tracked_objects::TrackedTime start_time =
-      tracked_objects::ThreadData::NowForStartOfRun(pending_task->birth_tally);
+  tracked_objects::ThreadData::PrepareForStartOfRun(pending_task->birth_tally);
 
   g_worker_pool_running_on_this_thread.Get().Set(true);
+
+  tracked_objects::TaskStopwatch stopwatch;
   pending_task->task.Run();
+  stopwatch.Stop();
+
   g_worker_pool_running_on_this_thread.Get().Set(false);
 
   tracked_objects::ThreadData::TallyRunOnWorkerThreadIfTracking(
       pending_task->birth_tally,
-      tracked_objects::TrackedTime(pending_task->time_posted), start_time,
-      tracked_objects::ThreadData::NowForEndOfRun());
+      tracked_objects::TrackedTime(pending_task->time_posted),
+      stopwatch);
 
   delete pending_task;
   return 0;
diff --git a/base/tracked_objects.cc b/base/tracked_objects.cc
index 56b44c1..659d421 100644
--- a/base/tracked_objects.cc
+++ b/base/tracked_objects.cc
@@ -237,6 +237,9 @@ void Births::Clear() { birth_count_ = 0; }
 // static
 NowFunction* ThreadData::now_function_ = NULL;
 
+// static
+bool ThreadData::now_function_is_time_ = false;
+
 // A TLS slot which points to the ThreadData instance for the current thread. We
 // do a fake initialization here (zeroing out data), and then the real in-place
 // construction happens when we call tls_index_.Initialize().
@@ -269,7 +272,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 +283,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 +439,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;
@@ -443,9 +450,13 @@ void ThreadData::TallyADeath(const Births& birth,
 
   // We don't have queue durations without OS timer. OS timer is automatically
   // used for task-post-timing, so the use of an alternate timer implies all
-  // queue times are invalid.
-  if (kAllowAlternateTimeSourceHandling && now_function_)
+  // queue times are invalid, unless it was explicitly said that we can trust
+  // the alternate timer.
+  if (kAllowAlternateTimeSourceHandling &&
+      now_function_ &&
+      !now_function_is_time_) {
     queue_duration = 0;
+  }
 
   DeathMap::iterator it = death_map_.find(&birth);
   DeathData* death_data;
@@ -481,8 +492,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 +502,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 +511,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 +543,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 +568,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
@@ -758,18 +759,12 @@ bool ThreadData::TrackingParentChildStatus() {
 }
 
 // static
-TrackedTime ThreadData::NowForStartOfRun(const Births* parent) {
+void ThreadData::PrepareForStartOfRun(const Births* parent) {
   if (kTrackParentChildLinks && parent && status_ > PROFILING_ACTIVE) {
     ThreadData* current_thread_data = Get();
     if (current_thread_data)
       current_thread_data->parent_stack_.push(parent);
   }
-  return Now();
-}
-
-// static
-TrackedTime ThreadData::NowForEndOfRun() {
-  return Now();
 }
 
 // static
@@ -858,6 +853,85 @@ void ThreadData::ShutdownSingleThreadedCleanup(bool leak) {
 }
 
 //------------------------------------------------------------------------------
+TaskStopwatch::TaskStopwatch()
+    : start_time_(ThreadData::Now()),
+      current_thread_data_(ThreadData::Get()),
+      excluded_duration_ms_(0),
+      parent_(NULL) {
+#if DCHECK_IS_ON
+  state_ = RUNNING;
+  child_ = NULL;
+#endif
+
+  wallclock_duration_ms_ = 0;
+  if (!current_thread_data_)
+    return;
+
+  parent_ = current_thread_data_->current_stopwatch_;
+#if DCHECK_IS_ON
+  if (parent_) {
+    DCHECK(parent_->state_ == RUNNING);
+    DCHECK(parent_->child_ == NULL);
+    parent_->child_ = this;
+  }
+#endif
+  current_thread_data_->current_stopwatch_ = this;
+}
+
+TaskStopwatch::~TaskStopwatch() {
+#if DCHECK_IS_ON
+  DCHECK(state_ != RUNNING);
+  DCHECK(child_ == NULL);
+#endif
+}
+
+void TaskStopwatch::Stop() {
+  const TrackedTime end_time = ThreadData::Now();
+#if DCHECK_IS_ON
+  DCHECK(state_ == RUNNING);
+  state_ = STOPPED;
+  DCHECK(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_;
+  if (!parent_)
+    return;
+
+#if DCHECK_IS_ON
+  DCHECK(parent_->state_ == RUNNING);
+  DCHECK(parent_->child_ == this);
+  parent_->child_ = NULL;
+#endif
+  parent_->excluded_duration_ms_ +=
+      wallclock_duration_ms_;
+  parent_ = NULL;
+}
+
+TrackedTime TaskStopwatch::StartTime() const {
+  return start_time_;
+}
+
+int32 TaskStopwatch::RunDurationMs() const {
+#if DCHECK_IS_ON
+  DCHECK(state_ == STOPPED);
+#endif
+
+  return wallclock_duration_ms_ - excluded_duration_ms_;
+}
+
+ThreadData* TaskStopwatch::GetThreadData() const {
+  return current_thread_data_;
+}
+
+//------------------------------------------------------------------------------
 TaskSnapshot::TaskSnapshot() {
 }
 
diff --git a/base/tracked_objects.h b/base/tracked_objects.h
index 511a289..055cf19 100644
--- a/base/tracked_objects.h
+++ b/base/tracked_objects.h
@@ -352,6 +352,8 @@ struct BASE_EXPORT TaskSnapshot {
 // harvest data from all existing instances.
 
 struct ProcessDataSnapshot;
+class BASE_EXPORT TaskStopwatch;
+
 class BASE_EXPORT ThreadData {
  public:
   // Current allowable states of the tracking system.  The states can vary
@@ -403,8 +405,7 @@ class BASE_EXPORT ThreadData {
   // finished). It is provided as an argument to help with testing.
   static void TallyRunOnNamedThreadIfTracking(
       const base::TrackingInfo& completed_task,
-      const TrackedTime& start_of_run,
-      const TrackedTime& end_of_run);
+      const TaskStopwatch& stopwatch);
 
   // Record the end of a timed run of an object.  The |birth| is the record for
   // the instance, the |time_posted| records that instant, which is presumed to
@@ -416,15 +417,13 @@ class BASE_EXPORT ThreadData {
   static void TallyRunOnWorkerThreadIfTracking(
       const Births* birth,
       const TrackedTime& time_posted,
-      const TrackedTime& start_of_run,
-      const TrackedTime& end_of_run);
+      const TaskStopwatch& stopwatch);
 
   // Record the end of execution in region, generally corresponding to a scope
   // being exited.
   static void TallyRunInAScopedRegionIfTracking(
       const Births* birth,
-      const TrackedTime& start_of_run,
-      const TrackedTime& end_of_run);
+      const TaskStopwatch& stopwatch);
 
   const std::string& thread_name() const { return thread_name_; }
 
@@ -460,14 +459,12 @@ class BASE_EXPORT ThreadData {
   // on.  This is currently a compiled option, atop TrackingStatus().
   static bool TrackingParentChildStatus();
 
-  // Special versions of Now() for getting times at start and end of a tracked
-  // run.  They are super fast when tracking is disabled, and have some internal
-  // side effects when we are tracking, so that we can deduce the amount of time
-  // accumulated outside of execution of tracked runs.
+  // Marks a start of a tracked run. It's super fast when tracking is disabled,
+  // and has some internal side effects when we are tracking, so that we can
+  // deduce the amount of time accumulated outside of execution of tracked runs.
   // The task that will be tracked is passed in as |parent| so that parent-child
   // relationships can be (optionally) calculated.
-  static TrackedTime NowForStartOfRun(const Births* parent);
-  static TrackedTime NowForEndOfRun();
+  static void PrepareForStartOfRun(const Births* parent);
 
   // Provide a time function that does nothing (runs fast) when we don't have
   // the profiler enabled.  It will generally be optimized away when it is
@@ -487,6 +484,7 @@ class BASE_EXPORT ThreadData {
   static void EnsureCleanupWasCalled(int major_threads_shutdown_count);
 
  private:
+  friend class TaskStopwatch;
   // Allow only tests to call ShutdownSingleThreadedCleanup.  We NEVER call it
   // in production code.
   // TODO(jar): Make this a friend in DEBUG only, so that the optimizer has a
@@ -523,7 +521,9 @@ class BASE_EXPORT ThreadData {
   Births* TallyABirth(const Location& location);
 
   // Find a place to record a death on this thread.
-  void TallyADeath(const Births& birth, int32 queue_duration, int32 duration);
+  void TallyADeath(const Births& birth,
+                   int32 queue_duration,
+                   const TaskStopwatch& stopwatch);
 
   // Snapshot (under a lock) the profiled data for the tasks in each ThreadData
   // instance.  Also updates the |birth_counts| tally for each task to keep
@@ -582,6 +582,10 @@ class BASE_EXPORT ThreadData {
   // increasing time functcion.
   static NowFunction* now_function_;
 
+  // If true, now_function_ returns values that can be used to calculate queue
+  // time.
+  static bool now_function_is_time_;
+
   // We use thread local store to identify which ThreadData to interact with.
   static base::ThreadLocalStorage::StaticSlot tls_index_;
 
@@ -665,9 +669,9 @@ class BASE_EXPORT ThreadData {
   mutable base::Lock map_lock_;
 
   // The stack of parents that are currently being profiled. This includes only
-  // tasks that have started a timer recently via NowForStartOfRun(), but not
-  // yet concluded with a NowForEndOfRun().  Usually this stack is one deep, but
-  // if a scoped region is profiled, or <sigh> a task runs a nested-message
+  // tasks that have started a timer recently via PrepareForStartOfRun(), but
+  // not yet concluded with a NowForEndOfRun().  Usually this stack is one deep,
+  // but if a scoped region is profiled, or <sigh> a task runs a nested-message
   // loop, then the stack can grow larger.  Note that we don't try to deduct
   // time in nested porfiles, as our current timer is based on wall-clock time,
   // and not CPU time (and we're hopeful that nested timing won't be a
@@ -686,10 +690,74 @@ class BASE_EXPORT ThreadData {
   // incarnations).
   int incarnation_count_for_pool_;
 
+  // Most recently started (i.e. most nested) stopwatch on the current thread,
+  // if it exists; NULL otherwise.
+  TaskStopwatch* current_stopwatch_;
+
   DISALLOW_COPY_AND_ASSIGN(ThreadData);
 };
 
 //------------------------------------------------------------------------------
+// Stopwatch to measure task run time or simply create a time interval that will
+// be subtracted from the current most nested task's run time. Stopwatches
+// coordinate with the stopwatches in which they are nested to avoid
+// double-counting nested tasks run times.
+
+class BASE_EXPORT TaskStopwatch {
+ public:
+  // Starts the stopwatch.
+  TaskStopwatch();
+  ~TaskStopwatch();
+
+  // Stops stopwatch.
+  void Stop();
+
+  // Returns the start time.
+  TrackedTime StartTime() const;
+
+  // Task's duration is calculated as the wallclock duration between starting
+  // and stopping this stopwatch, minus the wallclock durations of any other
+  // instances that are immediately nested in this one, started and stopped on
+  // this thread during that period.
+  int32 RunDurationMs() const;
+
+  // Returns tracking info for the current thread.
+  ThreadData* GetThreadData() const;
+
+ private:
+  // Time when the stopwatch was started.
+  TrackedTime start_time_;
+
+  // Wallclock duration of the task.
+  int32 wallclock_duration_ms_;
+
+  // Tracking info for the current thread.
+  ThreadData* current_thread_data_;
+
+  // Sum of wallclock durations of all stopwatches that were directly nested in
+  // this one.
+  int32 excluded_duration_ms_;
+
+  // Stopwatch which was running on our thread when this stopwatch was started.
+  // That preexisting stopwatch must be adjusted to the exclude the wallclock
+  // duration of this stopwatch.
+  TaskStopwatch* parent_;
+
+#if DCHECK_IS_ON
+  // State of the stopwatch. Stopwatch is first constructed in a running state,
+  // then stopped, then destructed.
+  enum {
+    RUNNING,
+    STOPPED
+  } state_;
+
+  // Currently running stopwatch that is directly nested in this one, if such
+  // stopwatch exists. NULL otherwise.
+  TaskStopwatch* child_;
+#endif
+};
+
+//------------------------------------------------------------------------------
 // A snapshotted representation of a (parent, child) task pair, for tracking
 // hierarchical profiles.
 
diff --git a/base/tracked_objects_unittest.cc b/base/tracked_objects_unittest.cc
index 7cbce90..3ca7d74 100644
--- a/base/tracked_objects_unittest.cc
+++ b/base/tracked_objects_unittest.cc
@@ -28,6 +28,10 @@ class TrackedObjectsTest : public testing::Test {
     // On entry, leak any database structures in case they are still in use by
     // prior threads.
     ThreadData::ShutdownSingleThreadedCleanup(true);
+
+    test_time_ = 0;
+    ThreadData::SetAlternateTimeSource(&TrackedObjectsTest::GetTestTime);
+    ThreadData::now_function_is_time_ = true;
   }
 
   virtual ~TrackedObjectsTest() {
@@ -39,6 +43,7 @@ class TrackedObjectsTest : public testing::Test {
   // Reset the profiler state.
   void Reset() {
     ThreadData::ShutdownSingleThreadedCleanup(false);
+    test_time_ = 0;
   }
 
   // Simulate a birth on the thread named |thread_name|, at the given
@@ -91,13 +96,28 @@ class TrackedObjectsTest : public testing::Test {
 
     EXPECT_EQ(base::GetCurrentProcId(), process_data.process_id);
   }
+
+  // Sets time that will be returned by ThreadData::Now().
+  static void SetTestTime(unsigned int test_time) { test_time_ = test_time; }
+
+ private:
+  // Returns test time in milliseconds.
+  static unsigned int GetTestTime() { return test_time_; }
+
+  // Test time in milliseconds.
+  static unsigned int test_time_;
 };
 
+// static
+unsigned int TrackedObjectsTest::test_time_;
+
+
 TEST_F(TrackedObjectsTest, MinimalStartupShutdown) {
   // Minimal test doesn't even create any tasks.
   if (!ThreadData::InitializeAndSetTrackingStatus(
-          ThreadData::PROFILING_CHILDREN_ACTIVE))
+          ThreadData::PROFILING_CHILDREN_ACTIVE)) {
     return;
+  }
 
   EXPECT_FALSE(ThreadData::first());  // No activity even on this thread.
   ThreadData* data = ThreadData::Get();
@@ -136,8 +156,9 @@ TEST_F(TrackedObjectsTest, MinimalStartupShutdown) {
 
 TEST_F(TrackedObjectsTest, TinyStartupShutdown) {
   if (!ThreadData::InitializeAndSetTrackingStatus(
-          ThreadData::PROFILING_CHILDREN_ACTIVE))
+          ThreadData::PROFILING_CHILDREN_ACTIVE)) {
     return;
+  }
 
   // Instigate tracking on a single tracked object, on our thread.
   const char kFunction[] = "TinyStartupShutdown";
@@ -160,16 +181,21 @@ TEST_F(TrackedObjectsTest, TinyStartupShutdown) {
 
   // Now instigate another birth, while we are timing the run of the first
   // execution.
-  ThreadData::NowForStartOfRun(first_birth);
+  ThreadData::PrepareForStartOfRun(first_birth);
   // Create a child (using the same birth location).
   // TrackingInfo will call TallyABirth() during construction.
-  base::TimeTicks kBogusBirthTime;
+  const int32 start_time = 1;
+  base::TimeTicks kBogusBirthTime = base::TimeTicks() +
+      base::TimeDelta::FromMilliseconds(start_time);
   base::TrackingInfo pending_task(location, kBogusBirthTime);
-  TrackedTime start_time(pending_task.time_posted);
+  SetTestTime(1);
+  TaskStopwatch stopwatch;
   // Finally conclude the outer run.
-  TrackedTime end_time = ThreadData::NowForEndOfRun();
-  ThreadData::TallyRunOnNamedThreadIfTracking(pending_task, start_time,
-                                              end_time);
+  const int32 time_elapsed = 1000;
+  SetTestTime(start_time + time_elapsed);
+  stopwatch.Stop();
+
+  ThreadData::TallyRunOnNamedThreadIfTracking(pending_task, stopwatch);
 
   birth_map.clear();
   death_map.clear();
@@ -193,7 +219,6 @@ TEST_F(TrackedObjectsTest, TinyStartupShutdown) {
   ProcessDataSnapshot process_data;
   ThreadData::Snapshot(false, &process_data);
 
-  const int32 time_elapsed = (end_time - start_time).InMilliseconds();
   ASSERT_EQ(1u, process_data.tasks.size());
   EXPECT_EQ(kFile, process_data.tasks[0].birth.location.file_name);
   EXPECT_EQ(kFunction, process_data.tasks[0].birth.location.function_name);
@@ -230,8 +255,9 @@ TEST_F(TrackedObjectsTest, TinyStartupShutdown) {
 
 TEST_F(TrackedObjectsTest, DeathDataTest) {
   if (!ThreadData::InitializeAndSetTrackingStatus(
-          ThreadData::PROFILING_CHILDREN_ACTIVE))
+          ThreadData::PROFILING_CHILDREN_ACTIVE)) {
     return;
+  }
 
   scoped_ptr<DeathData> data(new DeathData());
   ASSERT_NE(data, reinterpret_cast<DeathData*>(NULL));
@@ -271,8 +297,9 @@ TEST_F(TrackedObjectsTest, DeathDataTest) {
 
 TEST_F(TrackedObjectsTest, DeactivatedBirthOnlyToSnapshotWorkerThread) {
   // Start in the deactivated state.
-  if (!ThreadData::InitializeAndSetTrackingStatus(ThreadData::DEACTIVATED))
+  if (!ThreadData::InitializeAndSetTrackingStatus(ThreadData::DEACTIVATED)) {
     return;
+  }
 
   const char kFunction[] = "DeactivatedBirthOnlyToSnapshotWorkerThread";
   Location location(kFunction, kFile, kLineNumber, NULL);
@@ -287,8 +314,9 @@ TEST_F(TrackedObjectsTest, DeactivatedBirthOnlyToSnapshotWorkerThread) {
 
 TEST_F(TrackedObjectsTest, DeactivatedBirthOnlyToSnapshotMainThread) {
   // Start in the deactivated state.
-  if (!ThreadData::InitializeAndSetTrackingStatus(ThreadData::DEACTIVATED))
+  if (!ThreadData::InitializeAndSetTrackingStatus(ThreadData::DEACTIVATED)) {
     return;
+  }
 
   const char kFunction[] = "DeactivatedBirthOnlyToSnapshotMainThread";
   Location location(kFunction, kFile, kLineNumber, NULL);
@@ -303,8 +331,9 @@ TEST_F(TrackedObjectsTest, DeactivatedBirthOnlyToSnapshotMainThread) {
 
 TEST_F(TrackedObjectsTest, BirthOnlyToSnapshotWorkerThread) {
   if (!ThreadData::InitializeAndSetTrackingStatus(
-          ThreadData::PROFILING_CHILDREN_ACTIVE))
+          ThreadData::PROFILING_CHILDREN_ACTIVE)) {
     return;
+  }
 
   const char kFunction[] = "BirthOnlyToSnapshotWorkerThread";
   Location location(kFunction, kFile, kLineNumber, NULL);
@@ -318,8 +347,9 @@ TEST_F(TrackedObjectsTest, BirthOnlyToSnapshotWorkerThread) {
 
 TEST_F(TrackedObjectsTest, BirthOnlyToSnapshotMainThread) {
   if (!ThreadData::InitializeAndSetTrackingStatus(
-          ThreadData::PROFILING_CHILDREN_ACTIVE))
+          ThreadData::PROFILING_CHILDREN_ACTIVE)) {
     return;
+  }
 
   const char kFunction[] = "BirthOnlyToSnapshotMainThread";
   Location location(kFunction, kFile, kLineNumber, NULL);
@@ -333,8 +363,9 @@ TEST_F(TrackedObjectsTest, BirthOnlyToSnapshotMainThread) {
 
 TEST_F(TrackedObjectsTest, LifeCycleToSnapshotMainThread) {
   if (!ThreadData::InitializeAndSetTrackingStatus(
-          ThreadData::PROFILING_CHILDREN_ACTIVE))
+          ThreadData::PROFILING_CHILDREN_ACTIVE)) {
     return;
+  }
 
   const char kFunction[] = "LifeCycleToSnapshotMainThread";
   Location location(kFunction, kFile, kLineNumber, NULL);
@@ -347,11 +378,14 @@ TEST_F(TrackedObjectsTest, LifeCycleToSnapshotMainThread) {
   base::TrackingInfo pending_task(location, kDelayedStartTime);
   pending_task.time_posted = kTimePosted;  // Overwrite implied Now().
 
-  const TrackedTime kStartOfRun = TrackedTime() +
-      Duration::FromMilliseconds(5);
-  const TrackedTime kEndOfRun = TrackedTime() + Duration::FromMilliseconds(7);
-  ThreadData::TallyRunOnNamedThreadIfTracking(pending_task,
-      kStartOfRun, kEndOfRun);
+  const unsigned int kStartOfRun = 5;
+  const unsigned int kEndOfRun = 7;
+  SetTestTime(kStartOfRun);
+  TaskStopwatch stopwatch;
+  SetTestTime(kEndOfRun);
+  stopwatch.Stop();
+
+  ThreadData::TallyRunOnNamedThreadIfTracking(pending_task, stopwatch);
 
   ProcessDataSnapshot process_data;
   ThreadData::Snapshot(false, &process_data);
@@ -365,8 +399,9 @@ TEST_F(TrackedObjectsTest, LifeCycleToSnapshotMainThread) {
 // task is still running, or is queued).
 TEST_F(TrackedObjectsTest, LifeCycleMidDeactivatedToSnapshotMainThread) {
   if (!ThreadData::InitializeAndSetTrackingStatus(
-          ThreadData::PROFILING_CHILDREN_ACTIVE))
+          ThreadData::PROFILING_CHILDREN_ACTIVE)) {
     return;
+  }
 
   const char kFunction[] = "LifeCycleMidDeactivatedToSnapshotMainThread";
   Location location(kFunction, kFile, kLineNumber, NULL);
@@ -383,11 +418,14 @@ TEST_F(TrackedObjectsTest, LifeCycleMidDeactivatedToSnapshotMainThread) {
   EXPECT_TRUE(ThreadData::InitializeAndSetTrackingStatus(
       ThreadData::DEACTIVATED));
 
-  const TrackedTime kStartOfRun = TrackedTime() +
-      Duration::FromMilliseconds(5);
-  const TrackedTime kEndOfRun = TrackedTime() + Duration::FromMilliseconds(7);
-  ThreadData::TallyRunOnNamedThreadIfTracking(pending_task,
-      kStartOfRun, kEndOfRun);
+  const unsigned int kStartOfRun = 5;
+  const unsigned int kEndOfRun = 7;
+  SetTestTime(kStartOfRun);
+  TaskStopwatch stopwatch;
+  SetTestTime(kEndOfRun);
+  stopwatch.Stop();
+
+  ThreadData::TallyRunOnNamedThreadIfTracking(pending_task, stopwatch);
 
   ProcessDataSnapshot process_data;
   ThreadData::Snapshot(false, &process_data);
@@ -399,8 +437,9 @@ TEST_F(TrackedObjectsTest, LifeCycleMidDeactivatedToSnapshotMainThread) {
 // the birth nor the death will be recorded.
 TEST_F(TrackedObjectsTest, LifeCyclePreDeactivatedToSnapshotMainThread) {
   // Start in the deactivated state.
-  if (!ThreadData::InitializeAndSetTrackingStatus(ThreadData::DEACTIVATED))
+  if (!ThreadData::InitializeAndSetTrackingStatus(ThreadData::DEACTIVATED)) {
     return;
+  }
 
   const char kFunction[] = "LifeCyclePreDeactivatedToSnapshotMainThread";
   Location location(kFunction, kFile, kLineNumber, NULL);
@@ -413,11 +452,14 @@ TEST_F(TrackedObjectsTest, LifeCyclePreDeactivatedToSnapshotMainThread) {
   base::TrackingInfo pending_task(location, kDelayedStartTime);
   pending_task.time_posted = kTimePosted;  // Overwrite implied Now().
 
-  const TrackedTime kStartOfRun = TrackedTime() +
-      Duration::FromMilliseconds(5);
-  const TrackedTime kEndOfRun = TrackedTime() + Duration::FromMilliseconds(7);
-  ThreadData::TallyRunOnNamedThreadIfTracking(pending_task,
-      kStartOfRun, kEndOfRun);
+  const unsigned int kStartOfRun = 5;
+  const unsigned int kEndOfRun = 7;
+  SetTestTime(kStartOfRun);
+  TaskStopwatch stopwatch;
+  SetTestTime(kEndOfRun);
+  stopwatch.Stop();
+
+  ThreadData::TallyRunOnNamedThreadIfTracking(pending_task, stopwatch);
 
   ProcessDataSnapshot process_data;
   ThreadData::Snapshot(false, &process_data);
@@ -428,8 +470,9 @@ TEST_F(TrackedObjectsTest, LifeCyclePreDeactivatedToSnapshotMainThread) {
 
 TEST_F(TrackedObjectsTest, LifeCycleToSnapshotWorkerThread) {
   if (!ThreadData::InitializeAndSetTrackingStatus(
-          ThreadData::PROFILING_CHILDREN_ACTIVE))
+          ThreadData::PROFILING_CHILDREN_ACTIVE)) {
     return;
+  }
 
   const char kFunction[] = "LifeCycleToSnapshotWorkerThread";
   Location location(kFunction, kFile, kLineNumber, NULL);
@@ -437,12 +480,16 @@ TEST_F(TrackedObjectsTest, LifeCycleToSnapshotWorkerThread) {
   Births* birth = ThreadData::TallyABirthIfActive(location);
   EXPECT_NE(reinterpret_cast<Births*>(NULL), birth);
 
-  const TrackedTime kTimePosted = TrackedTime() + Duration::FromMilliseconds(1);
-  const TrackedTime kStartOfRun = TrackedTime() +
-      Duration::FromMilliseconds(5);
-  const TrackedTime kEndOfRun = TrackedTime() + Duration::FromMilliseconds(7);
-  ThreadData::TallyRunOnWorkerThreadIfTracking(birth, kTimePosted,
-      kStartOfRun, kEndOfRun);
+  const unsigned int kTimePosted = 1;
+  const unsigned int kStartOfRun = 5;
+  const unsigned int kEndOfRun = 7;
+  SetTestTime(kStartOfRun);
+  TaskStopwatch stopwatch;
+  SetTestTime(kEndOfRun);
+  stopwatch.Stop();
+
+  ThreadData::TallyRunOnWorkerThreadIfTracking(
+  birth, TrackedTime() + Duration::FromMilliseconds(kTimePosted), stopwatch);
 
   // Call for the ToSnapshot, but tell it to not reset the maxes after scanning.
   ProcessDataSnapshot process_data;
@@ -486,8 +533,9 @@ TEST_F(TrackedObjectsTest, LifeCycleToSnapshotWorkerThread) {
 
 TEST_F(TrackedObjectsTest, TwoLives) {
   if (!ThreadData::InitializeAndSetTrackingStatus(
-          ThreadData::PROFILING_CHILDREN_ACTIVE))
+          ThreadData::PROFILING_CHILDREN_ACTIVE)) {
     return;
+  }
 
   const char kFunction[] = "TwoLives";
   Location location(kFunction, kFile, kLineNumber, NULL);
@@ -500,18 +548,24 @@ TEST_F(TrackedObjectsTest, TwoLives) {
   base::TrackingInfo pending_task(location, kDelayedStartTime);
   pending_task.time_posted = kTimePosted;  // Overwrite implied Now().
 
-  const TrackedTime kStartOfRun = TrackedTime() +
-      Duration::FromMilliseconds(5);
-  const TrackedTime kEndOfRun = TrackedTime() + Duration::FromMilliseconds(7);
-  ThreadData::TallyRunOnNamedThreadIfTracking(pending_task,
-      kStartOfRun, kEndOfRun);
+  const unsigned int kStartOfRun = 5;
+  const unsigned int kEndOfRun = 7;
+  SetTestTime(kStartOfRun);
+  TaskStopwatch stopwatch;
+  SetTestTime(kEndOfRun);
+  stopwatch.Stop();
+
+  ThreadData::TallyRunOnNamedThreadIfTracking(pending_task, stopwatch);
 
   // TrackingInfo will call TallyABirth() during construction.
   base::TrackingInfo pending_task2(location, kDelayedStartTime);
   pending_task2.time_posted = kTimePosted;  // Overwrite implied Now().
+  SetTestTime(kStartOfRun);
+  TaskStopwatch stopwatch2;
+  SetTestTime(kEndOfRun);
+  stopwatch2.Stop();
 
-  ThreadData::TallyRunOnNamedThreadIfTracking(pending_task2,
-      kStartOfRun, kEndOfRun);
+  ThreadData::TallyRunOnNamedThreadIfTracking(pending_task2, stopwatch2);
 
   ProcessDataSnapshot process_data;
   ThreadData::Snapshot(false, &process_data);
@@ -521,8 +575,9 @@ TEST_F(TrackedObjectsTest, TwoLives) {
 
 TEST_F(TrackedObjectsTest, DifferentLives) {
   if (!ThreadData::InitializeAndSetTrackingStatus(
-          ThreadData::PROFILING_CHILDREN_ACTIVE))
+          ThreadData::PROFILING_CHILDREN_ACTIVE)) {
     return;
+  }
 
   // Use a well named thread.
   ThreadData::InitializeThreadContext(kMainThreadName);
@@ -536,11 +591,14 @@ TEST_F(TrackedObjectsTest, DifferentLives) {
   base::TrackingInfo pending_task(location, kDelayedStartTime);
   pending_task.time_posted = kTimePosted;  // Overwrite implied Now().
 
-  const TrackedTime kStartOfRun = TrackedTime() +
-      Duration::FromMilliseconds(5);
-  const TrackedTime kEndOfRun = TrackedTime() + Duration::FromMilliseconds(7);
-  ThreadData::TallyRunOnNamedThreadIfTracking(pending_task,
-      kStartOfRun, kEndOfRun);
+  const unsigned int kStartOfRun = 5;
+  const unsigned int kEndOfRun = 7;
+  SetTestTime(kStartOfRun);
+  TaskStopwatch stopwatch;
+  SetTestTime(kEndOfRun);
+  stopwatch.Stop();
+
+  ThreadData::TallyRunOnNamedThreadIfTracking(pending_task, stopwatch);
 
   const int kSecondFakeLineNumber = 999;
   Location second_location(kFunction, kFile, kSecondFakeLineNumber, NULL);
@@ -552,6 +610,7 @@ TEST_F(TrackedObjectsTest, DifferentLives) {
   ProcessDataSnapshot process_data;
   ThreadData::Snapshot(false, &process_data);
   ASSERT_EQ(2u, process_data.tasks.size());
+
   EXPECT_EQ(kFile, process_data.tasks[0].birth.location.file_name);
   EXPECT_EQ(kFunction, process_data.tasks[0].birth.location.function_name);
   EXPECT_EQ(kLineNumber, process_data.tasks[0].birth.location.line_number);
@@ -581,4 +640,165 @@ TEST_F(TrackedObjectsTest, DifferentLives) {
   EXPECT_EQ(base::GetCurrentProcId(), process_data.process_id);
 }
 
+TEST_F(TrackedObjectsTest, TaskWithNestedExclusion) {
+  if (!ThreadData::InitializeAndSetTrackingStatus(
+          ThreadData::PROFILING_CHILDREN_ACTIVE)) {
+    return;
+  }
+
+  const char kFunction[] = "TaskWithNestedExclusion";
+  Location location(kFunction, kFile, kLineNumber, NULL);
+  TallyABirth(location, kMainThreadName);
+
+  const base::TimeTicks kTimePosted = base::TimeTicks() +
+      base::TimeDelta::FromMilliseconds(1);
+  const base::TimeTicks kDelayedStartTime = base::TimeTicks();
+  // TrackingInfo will call TallyABirth() during construction.
+  base::TrackingInfo pending_task(location, kDelayedStartTime);
+  pending_task.time_posted = kTimePosted;  // Overwrite implied Now().
+
+  SetTestTime(5);
+  TaskStopwatch task_stopwatch;
+  {
+    SetTestTime(8);
+    TaskStopwatch exclusion_stopwatch;
+    SetTestTime(12);
+    exclusion_stopwatch.Stop();
+  }
+  SetTestTime(15);
+  task_stopwatch.Stop();
+
+  ThreadData::TallyRunOnNamedThreadIfTracking(pending_task, task_stopwatch);
+
+  ProcessDataSnapshot process_data;
+  ThreadData::Snapshot(false, &process_data);
+  ExpectSimpleProcessData(process_data, kFunction, kMainThreadName,
+                          kMainThreadName, 1, 6, 4);
+}
+
+TEST_F(TrackedObjectsTest, TaskWith2NestedExclusions) {
+  if (!ThreadData::InitializeAndSetTrackingStatus(
+          ThreadData::PROFILING_CHILDREN_ACTIVE)) {
+    return;
+  }
+
+  const char kFunction[] = "TaskWith2NestedExclusions";
+  Location location(kFunction, kFile, kLineNumber, NULL);
+  TallyABirth(location, kMainThreadName);
+
+  const base::TimeTicks kTimePosted = base::TimeTicks() +
+      base::TimeDelta::FromMilliseconds(1);
+  const base::TimeTicks kDelayedStartTime = base::TimeTicks();
+  // TrackingInfo will call TallyABirth() during construction.
+  base::TrackingInfo pending_task(location, kDelayedStartTime);
+  pending_task.time_posted = kTimePosted;  // Overwrite implied Now().
+
+  SetTestTime(5);
+  TaskStopwatch task_stopwatch;
+  {
+    SetTestTime(8);
+    TaskStopwatch exclusion_stopwatch;
+    SetTestTime(12);
+    exclusion_stopwatch.Stop();
+
+    SetTestTime(15);
+    TaskStopwatch exclusion_stopwatch2;
+    SetTestTime(18);
+    exclusion_stopwatch2.Stop();
+  }
+  SetTestTime(25);
+  task_stopwatch.Stop();
+
+  ThreadData::TallyRunOnNamedThreadIfTracking(pending_task, task_stopwatch);
+
+  ProcessDataSnapshot process_data;
+  ThreadData::Snapshot(false, &process_data);
+  ExpectSimpleProcessData(process_data, kFunction, kMainThreadName,
+                          kMainThreadName, 1, 13, 4);
+}
+
+TEST_F(TrackedObjectsTest, TaskWithNestedExclusionWithNestedTask) {
+  if (!ThreadData::InitializeAndSetTrackingStatus(
+          ThreadData::PROFILING_CHILDREN_ACTIVE)) {
+    return;
+  }
+
+  const char kFunction[] = "TaskWithNestedExclusionWithNestedTask";
+  Location location(kFunction, kFile, kLineNumber, NULL);
+
+  const int kSecondFakeLineNumber = 999;
+
+  TallyABirth(location, kMainThreadName);
+
+  const base::TimeTicks kTimePosted = base::TimeTicks() +
+      base::TimeDelta::FromMilliseconds(1);
+  const base::TimeTicks kDelayedStartTime = base::TimeTicks();
+  // TrackingInfo will call TallyABirth() during construction.
+  base::TrackingInfo pending_task(location, kDelayedStartTime);
+  pending_task.time_posted = kTimePosted;  // Overwrite implied Now().
+
+  SetTestTime(5);
+  TaskStopwatch task_stopwatch;
+  {
+    SetTestTime(8);
+    TaskStopwatch exclusion_stopwatch;
+    {
+      Location second_location(kFunction, kFile, kSecondFakeLineNumber, NULL);
+      base::TrackingInfo nested_task(second_location, kDelayedStartTime);
+       // Overwrite implied Now().
+      nested_task.time_posted =
+          base::TimeTicks() + base::TimeDelta::FromMilliseconds(8);
+      SetTestTime(9);
+      TaskStopwatch nested_task_stopwatch;
+      SetTestTime(11);
+      nested_task_stopwatch.Stop();
+      ThreadData::TallyRunOnNamedThreadIfTracking(
+          nested_task, nested_task_stopwatch);
+    }
+    SetTestTime(12);
+    exclusion_stopwatch.Stop();
+  }
+  SetTestTime(15);
+  task_stopwatch.Stop();
+
+  ThreadData::TallyRunOnNamedThreadIfTracking(pending_task, task_stopwatch);
+
+  ProcessDataSnapshot process_data;
+  ThreadData::Snapshot(false, &process_data);
+
+  // The order in which the two task follow is platform-dependent.
+  int t0 = (process_data.tasks[0].birth.location.line_number == kLineNumber) ?
+      0 : 1;
+  int t1 = 1 - t0;
+
+  ASSERT_EQ(2u, process_data.tasks.size());
+  EXPECT_EQ(kFile, process_data.tasks[t0].birth.location.file_name);
+  EXPECT_EQ(kFunction, process_data.tasks[t0].birth.location.function_name);
+  EXPECT_EQ(kLineNumber, process_data.tasks[t0].birth.location.line_number);
+  EXPECT_EQ(kMainThreadName, process_data.tasks[t0].birth.thread_name);
+  EXPECT_EQ(1, process_data.tasks[t0].death_data.count);
+  EXPECT_EQ(6, process_data.tasks[t0].death_data.run_duration_sum);
+  EXPECT_EQ(6, process_data.tasks[t0].death_data.run_duration_max);
+  EXPECT_EQ(6, process_data.tasks[t0].death_data.run_duration_sample);
+  EXPECT_EQ(4, process_data.tasks[t0].death_data.queue_duration_sum);
+  EXPECT_EQ(4, process_data.tasks[t0].death_data.queue_duration_max);
+  EXPECT_EQ(4, process_data.tasks[t0].death_data.queue_duration_sample);
+  EXPECT_EQ(kMainThreadName, process_data.tasks[t0].death_thread_name);
+  EXPECT_EQ(kFile, process_data.tasks[t1].birth.location.file_name);
+  EXPECT_EQ(kFunction, process_data.tasks[t1].birth.location.function_name);
+  EXPECT_EQ(kSecondFakeLineNumber,
+            process_data.tasks[t1].birth.location.line_number);
+  EXPECT_EQ(kMainThreadName, process_data.tasks[t1].birth.thread_name);
+  EXPECT_EQ(1, process_data.tasks[t1].death_data.count);
+  EXPECT_EQ(2, process_data.tasks[t1].death_data.run_duration_sum);
+  EXPECT_EQ(2, process_data.tasks[t1].death_data.run_duration_max);
+  EXPECT_EQ(2, process_data.tasks[t1].death_data.run_duration_sample);
+  EXPECT_EQ(1, process_data.tasks[t1].death_data.queue_duration_sum);
+  EXPECT_EQ(1, process_data.tasks[t1].death_data.queue_duration_max);
+  EXPECT_EQ(1, process_data.tasks[t1].death_data.queue_duration_sample);
+  EXPECT_EQ(kMainThreadName, process_data.tasks[t1].death_thread_name);
+  EXPECT_EQ(0u, process_data.descendants.size());
+  EXPECT_EQ(base::GetCurrentProcId(), process_data.process_id);
+}
+
 }  // namespace tracked_objects