Creating a framework for suppressing pollution of the profiler data

base/tracked_objects.h

Index: base/tracked_objects.h
diff --git a/base/tracked_objects.h b/base/tracked_objects.h
index 511a289066184074110405bb254d568473d8423a..443846c41ce4a6f302d7fd635268bf8c924656f5 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_; }
 
@@ -487,6 +486,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 +523,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);

[jar (doing other things), 2014/08/08 01:34:48]

Care was taken to use a 32 bit quantity.  As I recall, this was done for both
atomicity of access, and also to provide for faster implementations (on
platforms where 64 bit arithmetic is implemented by super expensive library
calls!).

[vadimt, 2014/08/08 20:39:34]

TaskStopwatch still uses int32, so this is taken care of.

+  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
@@ -686,10 +688,77 @@ 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. Nested
+// stopwatches coordinate with their parent stopwatches to avoid double-counting
+// nested tasks run times.
+
+class BASE_EXPORT TaskStopwatch {
+ public:
+  TaskStopwatch();
+  ~TaskStopwatch();
+
+  // Starts stopwatch with the specified |start_time|.
+  void Start(const TrackedTime& start_time);
+
+  // Starts stopwatch with the current time.
+  void Start() { Start(ThreadData::Now()); }
+
+  // Stops stopwatch with the specified |start_time|.
+  void Stop(const TrackedTime& end_time);
+
+  // Stops stopwatch with the current time.
+  void Stop() { Stop(ThreadData::Now()); }
+
+  // Returns the start time.
+  TrackedTime StartTime() const;
+
+  // Returns task's duration. This method should be used when measuring run
+  // time for tasks. Task's durataion is calculated as the wallclock time
+  // difference between stopping the stopwatch and starting it, minus time
+  // spent in immediately nested stopwatches.
+  int32 TaskDurationMs() 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_;
+
+  // Total duration of all completed that were immediate children of this one.
+  int32 nested_stopwatches_duration_ms_;
+
+  // Stopwatch of which this one is an immediate child.

[jar (doing other things), 2014/08/08 01:34:48]

The words "parent" and "child" seem confusing.  I suspect you wanted to say;

// Stopwatch which was running on our thread when this stopwatch was started. 
That preexisting stopwatch must be adjusted to the exclude the duration of
existance of this stopwatch.

Maybe you can define parent and child, but I suspect it will be even more
complicated.

[vadimt, 2014/08/08 20:39:34]

Done.

+  TaskStopwatch* parent_stopwatch_;
+
+#ifndef NDEBUG
+  // State of the stopwatch. Stopwatch is reusable, i.e. it can be started after
+  // it was stopped.
+  enum {
+    CREATED,
+    RUNNING,
+    STOPPED
+  } state_;
+
+  // Currently running stopwatch that an immediate child of this one, if such
+  // child exists. NULL otherwise.
+  TaskStopwatch* running_child_;
+#endif
+};
+
+//------------------------------------------------------------------------------
 // A snapshotted representation of a (parent, child) task pair, for tracking
 // hierarchical profiles.