Delivering the FIRST_NONEMPTY_PAINT phase changing event to base/

base/tracked_objects.cc

Index: base/tracked_objects.cc
diff --git a/base/tracked_objects.cc b/base/tracked_objects.cc
index 32ec75cd79543b4e1e563446f37e1a26cc52783c..4f08923e40550fe7ef86836aaf700aa3fecefe47 100644
--- a/base/tracked_objects.cc
+++ b/base/tracked_objects.cc
@@ -15,6 +15,7 @@
 #include "base/logging.h"
 #include "base/process/process_handle.h"
 #include "base/profiler/alternate_timer.h"
+#include "base/stl_util.h"
 #include "base/strings/stringprintf.h"
 #include "base/third_party/valgrind/memcheck.h"
 #include "base/tracking_info.h"
@@ -96,14 +97,29 @@ inline bool IsProfilerTimingEnabled() {
 // DeathData tallies durations when a death takes place.
 
 DeathData::DeathData() {
-  Clear();
+  count_ = 0;
+  sample_probability_count_ = 0;
+  run_duration_sum_ = 0;
+  run_duration_max_ = 0;
+  run_duration_sample_ = 0;
+  queue_duration_sum_ = 0;
+  queue_duration_max_ = 0;
+  queue_duration_sample_ = 0;
+  last_phase_snapshot_ = nullptr;
 }
 
-DeathData::DeathData(int count) {
-  Clear();
+DeathData::DeathData(int count) : DeathData() {
   count_ = count;
 }
 
+DeathData::~DeathData() {
+  while (last_phase_snapshot_) {
+    DeathDataPhaseSnapshot* snapshot = last_phase_snapshot_;
+    last_phase_snapshot_ = snapshot->prev;
+    delete snapshot;
+  }
+}
+
 // TODO(jar): I need to see if this macro to optimize branching is worth using.
 //
 // This macro has no branching, so it is surely fast, and is equivalent to:
@@ -120,6 +136,8 @@ void DeathData::RecordDeath(const int32 queue_duration,
   // We'll just clamp at INT_MAX, but we should note this in the UI as such.
   if (count_ < INT_MAX)
     ++count_;
+  if (sample_probability_count_ < INT_MAX)
+    ++sample_probability_count_;
   queue_duration_sum_ += queue_duration;
   run_duration_sum_ += run_duration;
 
@@ -128,14 +146,16 @@ void DeathData::RecordDeath(const int32 queue_duration,
   if (run_duration_max_ < run_duration)
     run_duration_max_ = run_duration;
 
-  // Take a uniformly distributed sample over all durations ever supplied.
-  // The probability that we (instead) use this new sample is 1/count_.  This
-  // results in a completely uniform selection of the sample (at least when we
-  // don't clamp count_... but that should be inconsequentially likely).
-  // We ignore the fact that we correlated our selection of a sample to the run
-  // and queue times (i.e., we used them to generate random_number).
-  CHECK_GT(count_, 0);
-  if (0 == (random_number % count_)) {
+  // Take a uniformly distributed sample over all durations ever supplied during
+  // currrent profiling phase.
+  // The probability that we (instead) use this new sample is
+  // 1/sample_probability_count_. This results in a completely uniform selection
+  // of the sample (at least when we don't clamp sample_probability_count_...
+  // but that should be inconsequentially likely). We ignore the fact that we
+  // correlated our selection of a sample to the run and queue times (i.e., we
+  // used them to generate random_number).
+  CHECK_GT(sample_probability_count_, 0);
+  if (0 == (random_number % sample_probability_count_)) {
     queue_duration_sample_ = queue_duration;
     run_duration_sample_ = run_duration;
   }
@@ -163,14 +183,21 @@ int32 DeathData::queue_duration_sample() const {
   return queue_duration_sample_;
 }
 
-void DeathData::Clear() {
-  count_ = 0;
-  run_duration_sum_ = 0;
+DeathDataPhaseSnapshot* DeathData::last_phase_snapshot() const {
+  return last_phase_snapshot_;
+}
+
+void DeathData::OnProfilingPhaseCompletion(int profiling_phase) {
+  // Snapshotting and storing current state.
+  last_phase_snapshot_ = new DeathDataPhaseSnapshot(profiling_phase, *this);
+
+  // Not touching fields for which a delta can be computed by comparing with a
+  // snapshot from previos phase. Resetting other fields. Sample values will be
+  // reset upon next death recording because sample_probability_count_ is set to
+  // 0.
+  sample_probability_count_ = 0;
   run_duration_max_ = 0;
-  run_duration_sample_ = 0;
-  queue_duration_sum_ = 0;
   queue_duration_max_ = 0;
-  queue_duration_sample_ = 0;
 }
 
 //------------------------------------------------------------------------------
@@ -198,6 +225,12 @@ DeathDataSnapshot::DeathDataSnapshot(
 DeathDataSnapshot::~DeathDataSnapshot() {
 }
 
+void DeathDataSnapshot::CalculateDelta(const DeathDataSnapshot& older) {
+  count -= older.count;
+  run_duration_sum -= older.run_duration_sum;
+  queue_duration_sum -= older.queue_duration_sum;
+}
+
 //------------------------------------------------------------------------------
 BirthOnThread::BirthOnThread(const Location& location,
                              const ThreadData& current)
@@ -390,9 +423,60 @@ void ThreadData::OnThreadTerminationCleanup() {
 }
 
 // static
-void ThreadData::Snapshot(ProcessDataSnapshot* process_data_snapshot) {
-  ThreadData::SnapshotCurrentPhase(
-      &process_data_snapshot->phased_process_data_snapshots[0]);
+void ThreadData::Snapshot(int current_profiling_phase,
+                          ProcessDataSnapshot* process_data_snapshot) {
+  if (!kTrackAllTaskObjects)
+    return;  // Not compiled in.
+
+  BirthCountMap birth_counts;
+
+  // Get an unchanging copy of a ThreadData list.
+  ThreadData* my_list = ThreadData::first();
+
+  // Gather data serially.
+  // This hackish approach *can* get some slighly corrupt tallies, as we are
+  // grabbing values without the protection of a lock, but it has the advantage
+  // of working even with threads that don't have message loops.  If a user
+  // sees any strangeness, they can always just run their stats gathering a
+  // second time.
+  for (ThreadData* thread_data = my_list; thread_data;
+       thread_data = thread_data->next()) {
+    thread_data->SnapshotExecutedTasks(
+        current_profiling_phase,
+        &process_data_snapshot->phased_process_data_snapshots, &birth_counts);
+  }
+
+  // Add births that are still active -- i.e. objects that have tallied a birth,
+  // but have not yet tallied a matching death, and hence must be either
+  // running, queued up, or being held in limbo for future posting.
+  for (const auto& birth_count : birth_counts) {
+    if (birth_count.second > 0) {
+      process_data_snapshot
+          ->phased_process_data_snapshots[current_profiling_phase]
+          .tasks.push_back(TaskSnapshot(
+              BirthOnThreadSnapshot(*birth_count.first),
+              DeathDataSnapshot(DeathData(birth_count.second)), "Still_Alive"));
+    }
+  }
+}
+
+// static
+void ThreadData::OnProfilingPhaseCompletion(int profiling_phase) {
+  if (!kTrackAllTaskObjects)
+    return;  // Not compiled in.
+
+  // Get an unchanging copy of a ThreadData list.
+  ThreadData* my_list = ThreadData::first();
+
+  // Add snapshots for all death datas in all threads serially.
+  // This hackish approach *can* get some slighly corrupt tallies, as we are
+  // grabbing values without the protection of a lock, but it has the advantage
+  // of working even with threads that don't have message loops. Any corruption
+  // shouldn't cause "cascading damage" to anything else (in later phases).
+  for (ThreadData* thread_data = my_list; thread_data;
+       thread_data = thread_data->next()) {
+    thread_data->OnProfilingPhaseCompletionOnThread(profiling_phase);
+  }
 }
 
 Births* ThreadData::TallyABirth(const Location& location) {
@@ -424,7 +508,7 @@ Births* ThreadData::TallyABirth(const Location& location) {
   return child;
 }
 
-void ThreadData::TallyADeath(const Births& birth,
+void ThreadData::TallyADeath(const Births& births,
                              int32 queue_duration,
                              const TaskStopwatch& stopwatch) {
   int32 run_duration = stopwatch.RunDurationMs();
@@ -433,7 +517,7 @@ void ThreadData::TallyADeath(const Births& birth,
   const uint32 kSomePrimeNumber = 2147483647;
   random_number_ += queue_duration + run_duration + kSomePrimeNumber;
   // An address is going to have some randomness to it as well ;-).
-  random_number_ ^= static_cast<uint32>(&birth - reinterpret_cast<Births*>(0));
+  random_number_ ^= static_cast<uint32>(&births - reinterpret_cast<Births*>(0));
 
   // 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
@@ -445,20 +529,20 @@ void ThreadData::TallyADeath(const Births& birth,
     queue_duration = 0;
   }
 
-  DeathMap::iterator it = death_map_.find(&birth);
+  DeathMap::iterator it = death_map_.find(&births);
   DeathData* death_data;
   if (it != death_map_.end()) {
     death_data = &it->second;
   } else {
     base::AutoLock lock(map_lock_);  // Lock as the map may get relocated now.
-    death_data = &death_map_[&birth];
+    death_data = &death_map_[&births];
   }  // Release lock ASAP.
   death_data->RecordDeath(queue_duration, run_duration, random_number_);
 
   if (!kTrackParentChildLinks)
     return;
   if (!parent_stack_.empty()) {  // We might get turned off.
-    DCHECK_EQ(parent_stack_.top(), &birth);
+    DCHECK_EQ(parent_stack_.top(), &births);
     parent_stack_.pop();
   }
 }
@@ -486,8 +570,8 @@ void ThreadData::TallyRunOnNamedThreadIfTracking(
   // Even if we have been DEACTIVATED, we will process any pending births so
   // that our data structures (which counted the outstanding births) remain
   // consistent.
-  const Births* birth = completed_task.birth_tally;
-  if (!birth)
+  const Births* births = completed_task.birth_tally;
+  if (!births)
     return;
   ThreadData* current_thread_data = stopwatch.GetThreadData();
   if (!current_thread_data)
@@ -504,12 +588,12 @@ void ThreadData::TallyRunOnNamedThreadIfTracking(
     queue_duration = (start_of_run - completed_task.EffectiveTimePosted())
         .InMilliseconds();
   }
-  current_thread_data->TallyADeath(*birth, queue_duration, stopwatch);
+  current_thread_data->TallyADeath(*births, queue_duration, stopwatch);
 }
 
 // static
 void ThreadData::TallyRunOnWorkerThreadIfTracking(
-    const Births* birth,
+    const Births* births,
     const TrackedTime& time_posted,
     const TaskStopwatch& stopwatch) {
   if (!kTrackAllTaskObjects)
@@ -518,7 +602,7 @@ void ThreadData::TallyRunOnWorkerThreadIfTracking(
   // Even if we have been DEACTIVATED, we will process any pending births so
   // that our data structures (which counted the outstanding births) remain
   // consistent.
-  if (!birth)
+  if (!births)
     return;
 
   // TODO(jar): Support the option to coalesce all worker-thread activity under
@@ -539,12 +623,12 @@ void ThreadData::TallyRunOnWorkerThreadIfTracking(
   if (!start_of_run.is_null()) {
     queue_duration = (start_of_run - time_posted).InMilliseconds();
   }
-  current_thread_data->TallyADeath(*birth, queue_duration, stopwatch);
+  current_thread_data->TallyADeath(*births, queue_duration, stopwatch);
 }
 
 // static
 void ThreadData::TallyRunInAScopedRegionIfTracking(
-    const Births* birth,
+    const Births* births,
     const TaskStopwatch& stopwatch) {
   if (!kTrackAllTaskObjects)
     return;  // Not compiled in.
@@ -552,7 +636,7 @@ void ThreadData::TallyRunInAScopedRegionIfTracking(
   // Even if we have been DEACTIVATED, we will process any pending births so
   // that our data structures (which counted the outstanding births) remain
   // consistent.
-  if (!birth)
+  if (!births)
     return;
 
   ThreadData* current_thread_data = stopwatch.GetThreadData();
@@ -560,90 +644,56 @@ void ThreadData::TallyRunInAScopedRegionIfTracking(
     return;
 
   int32 queue_duration = 0;
-  current_thread_data->TallyADeath(*birth, queue_duration, stopwatch);
-}
-
-// static
-void ThreadData::SnapshotAllExecutedTasks(
-    ProcessDataPhaseSnapshot* process_data_phase,
-    BirthCountMap* birth_counts) {
-  if (!kTrackAllTaskObjects)
-    return;  // Not compiled in.
-
-  // Get an unchanging copy of a ThreadData list.
-  ThreadData* my_list = ThreadData::first();
-
-  // Gather data serially.
-  // This hackish approach *can* get some slighly corrupt tallies, as we are
-  // grabbing values without the protection of a lock, but it has the advantage
-  // of working even with threads that don't have message loops.  If a user
-  // sees any strangeness, they can always just run their stats gathering a
-  // second time.
-  for (ThreadData* thread_data = my_list;
-       thread_data;
-       thread_data = thread_data->next()) {
-    thread_data->SnapshotExecutedTasks(process_data_phase, birth_counts);
-  }
-}
-
-// static
-void ThreadData::SnapshotCurrentPhase(
-    ProcessDataPhaseSnapshot* process_data_phase) {
-  // Add births that have run to completion to |collected_data|.
-  // |birth_counts| tracks the total number of births recorded at each location
-  // for which we have not seen a death count.
-  BirthCountMap birth_counts;
-  ThreadData::SnapshotAllExecutedTasks(process_data_phase, &birth_counts);
-
-  // Add births that are still active -- i.e. objects that have tallied a birth,
-  // but have not yet tallied a matching death, and hence must be either
-  // running, queued up, or being held in limbo for future posting.
-  for (const auto& birth_count : birth_counts) {
-    if (birth_count.second > 0) {
-      process_data_phase->tasks.push_back(TaskSnapshot(
-          *birth_count.first, DeathData(birth_count.second), "Still_Alive"));
-    }
-  }
+  current_thread_data->TallyADeath(*births, queue_duration, stopwatch);
 }
 
 void ThreadData::SnapshotExecutedTasks(
-    ProcessDataPhaseSnapshot* process_data_phase,
+    int current_profiling_phase,
+    PhasedProcessDataSnapshotMap* phased_process_data_snapshots,
     BirthCountMap* birth_counts) {
   // Get copy of data, so that the data will not change during the iterations
   // and processing.
-  ThreadData::BirthMap birth_map;
-  ThreadData::DeathMap death_map;
-  ThreadData::ParentChildSet parent_child_set;
-  SnapshotMaps(&birth_map, &death_map, &parent_child_set);
-
-  for (const auto& death : death_map) {
-    process_data_phase->tasks.push_back(
-        TaskSnapshot(*death.first, death.second, thread_name()));
-    (*birth_counts)[death.first] -= death.first->birth_count();
-  }
+  BirthMap birth_map;
+  DeathsSnapshot deaths;
+  ParentChildSet parent_child_set;
+  SnapshotMaps(current_profiling_phase, &birth_map, &deaths, &parent_child_set);
 
   for (const auto& birth : birth_map) {
     (*birth_counts)[birth.second] += birth.second->birth_count();
   }
 
-  if (!kTrackParentChildLinks)
-    return;
+  for (const auto& death : deaths) {
+    (*birth_counts)[death.first] -= death.first->birth_count();
+
+    for (const DeathDataPhaseSnapshot* phase = &death.second; phase;
+         phase = phase->prev) {
+      DeathDataSnapshot death_data = phase->death_data;
 
-  for (const auto& parent_child : parent_child_set) {
-    process_data_phase->descendants.push_back(
-        ParentChildPairSnapshot(parent_child));
+      if (phase->prev)
+        death_data.CalculateDelta(phase->prev->death_data);
+
+      if (death_data.count > 0)
+        (*phased_process_data_snapshots)[phase->profiling_phase]
+            .tasks.push_back(TaskSnapshot(BirthOnThreadSnapshot(*death.first),
+                                          death_data, thread_name()));
+    }
   }
 }
 
 // This may be called from another thread.
-void ThreadData::SnapshotMaps(BirthMap* birth_map,
-                              DeathMap* death_map,
+void ThreadData::SnapshotMaps(int profiling_phase,
+                              BirthMap* birth_map,
+                              DeathsSnapshot* deaths,
                               ParentChildSet* parent_child_set) {
   base::AutoLock lock(map_lock_);
+
   for (const auto& birth : birth_map_)
     (*birth_map)[birth.first] = birth.second;
-  for (const auto& death : death_map_)
-    (*death_map)[death.first] = death.second;
+
+  for (const auto& death : death_map_) {
+    deaths->push_back(DeathsSnapshot::value_type(
+        death.first, DeathDataPhaseSnapshot(profiling_phase, death.second)));
+  }
 
   if (!kTrackParentChildLinks)
     return;
@@ -652,6 +702,14 @@ void ThreadData::SnapshotMaps(BirthMap* birth_map,
     parent_child_set->insert(parent_child);
 }
 
+void ThreadData::OnProfilingPhaseCompletionOnThread(int profiling_phase) {
+  base::AutoLock lock(map_lock_);
+
+  for (auto& death : death_map_) {
+    death.second.OnProfilingPhaseCompletion(profiling_phase);
+  }
+}
+
 static void OptionallyInitializeAlternateTimer() {
   NowFunction* alternate_time_source = GetAlternateTimeSource();
   if (alternate_time_source)
@@ -931,11 +989,23 @@ ThreadData* TaskStopwatch::GetThreadData() const {
 }
 
 //------------------------------------------------------------------------------
+// DeathDataPhaseSnapshot
+
+DeathDataPhaseSnapshot::DeathDataPhaseSnapshot(int profiling_phase,
+                                               const DeathData& death_data)
+    : profiling_phase(profiling_phase),
+      death_data(death_data),
+      prev(death_data.last_phase_snapshot()) {
+}
+
+//------------------------------------------------------------------------------
+// TaskSnapshot
+
 TaskSnapshot::TaskSnapshot() {
 }
 
-TaskSnapshot::TaskSnapshot(const BirthOnThread& birth,
-                           const DeathData& death_data,
+TaskSnapshot::TaskSnapshot(const BirthOnThreadSnapshot& birth,
+                           const DeathDataSnapshot& death_data,
                            const std::string& death_thread_name)
     : birth(birth),
       death_data(death_data),