Add heap allocator usage to task profiler.

base/tracked_objects.cc

 // Copyright (c) 2012 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.
 
 #include "base/tracked_objects.h"
 
 #include <limits.h>
 #include <stdlib.h>
 
 #include "base/atomicops.h"
 #include "base/base_switches.h"
 #include "base/command_line.h"
 #include "base/compiler_specific.h"
 #include "base/debug/leak_annotations.h"
 #include "base/logging.h"
+#include "base/numerics/safe_conversions.h"
 #include "base/process/process_handle.h"
 #include "base/strings/stringprintf.h"
 #include "base/third_party/valgrind/memcheck.h"
 #include "base/threading/worker_pool.h"
 #include "base/tracking_info.h"
 #include "build/build_config.h"
 
 using base::TimeDelta;
 
 namespace base {
@@ skipping 41 matching lines @@
              switches::kProfilerTiming) ==
          switches::kProfilerTimingDisabledValue)
             ? DISABLED_TIMING
             : ENABLED_TIMING;
     base::subtle::NoBarrier_Store(&g_profiler_timing_enabled,
                                   current_timing_enabled);
   }
   return current_timing_enabled == ENABLED_TIMING;
 }
 
+void SaturatingAdd(const uint32_t addend, base::subtle::Atomic32* sum) {
+  // Bail quick if no work or already saturated.
+  if (addend == 0U || *sum == INT_MAX)

[Primiano Tucci (use gerrit), 2016/11/16 16:39:09]

I think you are supposed to use NoBarrier_Load and not dereference atomics
directly, it might break once we move to std::atomics otherwise

[Sigurður Ásgeirsson, 2016/11/16 21:30:28]

This is modeled after all other Atomic32 (member) accesses in this file, which
may all need a revamp once we we go to std::atomics. The threading model here is
that only the owning thread will ever modify a ThreadData, and so it is safe for
it to read it any old how.
I have no idea whether direct access vs *_Load impacts performance, nor how that
breaks down on different CPU architectures. I'd just as soon not add that
variable to this CL?

[Primiano Tucci (use gerrit), 2016/11/28 18:38:31]

what I am saying is that all the rest of the code in this file seems to use
NoBarrier_Load, why this is special?
Also note how below you use NoBarrier_Store, so this access is inconsistent even
within this function.
In an ideal world NoBarrier_Load just evaluated to dereferencing a volatile
pointer. 
In practice on Linux this is a bit slower because of the sysroot... long story
(crbug.com/592903) but that's going away.

[Sigurður Ásgeirsson, 2016/11/30 14:41:13]

No, this consistent with all other ThreadData member field access in this file.
The way it works is that all in owner-thread READS are direct, all off
owner-thread READs use NoBarrier_Load.

All ThreadData member variable WRITEs us NoBarrier store, to support off
owner-thread reads without race.

The threading model here is that only the owner thread will ever modify these
variables, so these objects aren't generally multithreaded.

[Primiano Tucci (use gerrit), 2016/11/30 16:22:09]

Uh! This is quite inconsistent, but at this point not something you are changing
or making worse so not a point of discussion anymore for this CL.
AFAIK there is no semantic difference between NoBarrier_Load and *, so not sure
why the code here uses both. "*" just happen to work and is leveraring the
implementation detail of base::subtle::atomic

The only extra guarantee that NoBarrier_Load/Store give is atomicity, which:
1) you really want in all cases, as you don't want to see half integers
2) you get anyways, because on all platforms we support integers load/stores are
intrinsically atomic.
Right, but this is still not a reason for not using NoBarrier_Load/Store. "*" is
leveraging an implementation detail of atomics and could potentially hit
compiler optimizations (because you are dereferncing a non-volatile variable, so
you are not telling the compiler that another thread might read/write it.)

+    return;
+
+  // Check for overflow.
+  int32_t new_sum = *sum + addend;
+  if (new_sum < *sum)

[Primiano Tucci (use gerrit), 2016/11/16 16:39:09]

I think that integer overflow is still considered undefined behavior.
There is some discussion in 
http://stackoverflow.com/questions/16188263/is-signed-integer-overflow-still-...

Maybe just safer if you do 
if ((added >= std::numeric_limits(...) - current_sum) 
...

[Sigurður Ásgeirsson, 2016/11/16 21:30:28]

Ah, thanks. Went to base::CheckedNumeric - it seems to fit the bill?

[Primiano Tucci (use gerrit), 2016/11/28 18:38:31]

ah perfect thanks.

+    new_sum = INT_MAX;
+
+  base::subtle::NoBarrier_Store(sum, new_sum);
+}
+
 }  // namespace
 
 //------------------------------------------------------------------------------
 // DeathData tallies durations when a death takes place.
 
 DeathData::DeathData()
     : count_(0),
       sample_probability_count_(0),
       run_duration_sum_(0),
       queue_duration_sum_(0),
       run_duration_max_(0),
       queue_duration_max_(0),
       run_duration_sample_(0),
       queue_duration_sample_(0),
-      last_phase_snapshot_(nullptr) {
-}
+      alloc_ops_(0),
+      free_ops_(0),
+      allocated_bytes_(0),
+      freed_bytes_(0),
+      alloc_overhead_bytes_(0),
+      max_allocated_bytes_(0),
+      last_phase_snapshot_(nullptr) {}
 
 DeathData::DeathData(const DeathData& other)
     : count_(other.count_),
       sample_probability_count_(other.sample_probability_count_),
       run_duration_sum_(other.run_duration_sum_),
       queue_duration_sum_(other.queue_duration_sum_),
       run_duration_max_(other.run_duration_max_),
       queue_duration_max_(other.queue_duration_max_),
       run_duration_sample_(other.run_duration_sample_),
       queue_duration_sample_(other.queue_duration_sample_),
+      alloc_ops_(other.alloc_ops_),
+      free_ops_(other.free_ops_),
+      allocated_bytes_(other.allocated_bytes_),
+      freed_bytes_(other.freed_bytes_),
+      alloc_overhead_bytes_(other.alloc_overhead_bytes_),
+      max_allocated_bytes_(other.max_allocated_bytes_),
       last_phase_snapshot_(nullptr) {
   // This constructor will be used by std::map when adding new DeathData values
   // to the map.  At that point, last_phase_snapshot_ is still NULL, so we don't
   // need to worry about ownership transfer.
   DCHECK(other.last_phase_snapshot_ == nullptr);
 }
 
 DeathData::~DeathData() {
   while (last_phase_snapshot_) {
     const 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:
 //             if (assign_it)
 //               target = source;
 // We use a macro rather than a template to force this to inline.
 // Related code for calculating max is discussed on the web.
 #define CONDITIONAL_ASSIGN(assign_it, target, source) \
   ((target) ^= ((target) ^ (source)) & -static_cast<int32_t>(assign_it))
 
-void DeathData::RecordDeath(const int32_t queue_duration,
-                            const int32_t run_duration,
-                            const uint32_t random_number) {
+void DeathData::RecordDurations(const int32_t queue_duration,
+                                const int32_t run_duration,
+                                const uint32_t random_number) {
   // We'll just clamp at INT_MAX, but we should note this in the UI as such.
   if (count_ < INT_MAX)
     base::subtle::NoBarrier_Store(&count_, count_ + 1);
 
   int sample_probability_count =
       base::subtle::NoBarrier_Load(&sample_probability_count_);
   if (sample_probability_count < INT_MAX)
     ++sample_probability_count;
   base::subtle::NoBarrier_Store(&sample_probability_count_,
                                 sample_probability_count);
@@ skipping 16 matching lines @@
   // 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)) {
     base::subtle::NoBarrier_Store(&queue_duration_sample_, queue_duration);
     base::subtle::NoBarrier_Store(&run_duration_sample_, run_duration);
   }
 }
 
+void DeathData::RecordAllocations(const uint32_t alloc_ops,
+                                  const uint32_t free_ops,
+                                  const uint32_t allocated_bytes,
+                                  const uint32_t freed_bytes,
+                                  const uint32_t alloc_overhead_bytes,
+                                  const uint32_t max_allocated_bytes) {
+  // Use saturating arithmetic.
+  SaturatingAdd(alloc_ops, &alloc_ops_);
+  SaturatingAdd(free_ops, &free_ops_);
+  SaturatingAdd(allocated_bytes, &allocated_bytes_);
+  SaturatingAdd(freed_bytes, &freed_bytes_);
+  SaturatingAdd(alloc_overhead_bytes, &alloc_overhead_bytes_);
+
+  int32_t max = base::saturated_cast<int32_t>(max_allocated_bytes);
+  if (max > max_allocated_bytes_)
+    base::subtle::NoBarrier_Store(&max_allocated_bytes_, max);
+}
+
 void DeathData::OnProfilingPhaseCompleted(int profiling_phase) {
   // Snapshotting and storing current state.
-  last_phase_snapshot_ = new DeathDataPhaseSnapshot(
-      profiling_phase, count(), run_duration_sum(), run_duration_max(),
-      run_duration_sample(), queue_duration_sum(), queue_duration_max(),
-      queue_duration_sample(), last_phase_snapshot_);
+  last_phase_snapshot_ =
+      new DeathDataPhaseSnapshot(profiling_phase, *this, last_phase_snapshot_);
 
   // Not touching fields for which a delta can be computed by comparing with a
   // snapshot from the previous phase. Resetting other fields.  Sample values
   // will be reset upon next death recording because sample_probability_count_
   // is set to 0.
   // We avoid resetting to 0 in favor of deltas whenever possible.  The reason
   // is that for incrementable fields, resetting to 0 from the snapshot thread
   // potentially in parallel with incrementing in the death thread may result in
   // significant data corruption that has a potential to grow with time.  Not
   // resetting incrementable fields and using deltas will cause any
@@ skipping 19 matching lines @@
 }
 
 //------------------------------------------------------------------------------
 DeathDataSnapshot::DeathDataSnapshot()
     : count(-1),
       run_duration_sum(-1),
       run_duration_max(-1),
       run_duration_sample(-1),
       queue_duration_sum(-1),
       queue_duration_max(-1),
-      queue_duration_sample(-1) {
-}
+      queue_duration_sample(-1),
+      alloc_ops(-1),
+      free_ops(-1),
+      allocated_bytes(-1),
+      freed_bytes(-1),
+      alloc_overhead_bytes(-1),
+      max_allocated_bytes(-1) {}
 
 DeathDataSnapshot::DeathDataSnapshot(int count,
                                      int32_t run_duration_sum,
                                      int32_t run_duration_max,
                                      int32_t run_duration_sample,
                                      int32_t queue_duration_sum,
                                      int32_t queue_duration_max,
-                                     int32_t queue_duration_sample)
+                                     int32_t queue_duration_sample,
+                                     int32_t alloc_ops,
+                                     int32_t free_ops,
+                                     int32_t allocated_bytes,
+                                     int32_t freed_bytes,
+                                     int32_t alloc_overhead_bytes,
+                                     int32_t max_allocated_bytes)
     : count(count),
       run_duration_sum(run_duration_sum),
       run_duration_max(run_duration_max),
       run_duration_sample(run_duration_sample),
       queue_duration_sum(queue_duration_sum),
       queue_duration_max(queue_duration_max),
-      queue_duration_sample(queue_duration_sample) {}
+      queue_duration_sample(queue_duration_sample),
+      alloc_ops(alloc_ops),
+      free_ops(free_ops),
+      allocated_bytes(allocated_bytes),
+      freed_bytes(freed_bytes),
+      alloc_overhead_bytes(alloc_overhead_bytes),
+      max_allocated_bytes(max_allocated_bytes) {}
+
+DeathDataSnapshot::DeathDataSnapshot(const DeathData& death_data)
+    : count(death_data.count()),
+      run_duration_sum(death_data.run_duration_sum()),
+      run_duration_max(death_data.run_duration_max()),
+      run_duration_sample(death_data.run_duration_sample()),
+      queue_duration_sum(death_data.queue_duration_sum()),
+      queue_duration_max(death_data.queue_duration_max()),
+      queue_duration_sample(death_data.queue_duration_sample()),
+      alloc_ops(death_data.alloc_ops()),
+      free_ops(death_data.free_ops()),
+      allocated_bytes(death_data.allocated_bytes()),
+      freed_bytes(death_data.freed_bytes()),
+      alloc_overhead_bytes(death_data.alloc_overhead_bytes()),
+      max_allocated_bytes(death_data.max_allocated_bytes()) {}
+
+DeathDataSnapshot::DeathDataSnapshot(const DeathDataSnapshot& death_data) =
+    default;
 
 DeathDataSnapshot::~DeathDataSnapshot() {
 }
 
 DeathDataSnapshot DeathDataSnapshot::Delta(
     const DeathDataSnapshot& older) const {
-  return DeathDataSnapshot(count - older.count,
-                           run_duration_sum - older.run_duration_sum,
-                           run_duration_max, run_duration_sample,
-                           queue_duration_sum - older.queue_duration_sum,
-                           queue_duration_max, queue_duration_sample);
+  return DeathDataSnapshot(
+      count - older.count, run_duration_sum - older.run_duration_sum,
+      run_duration_max, run_duration_sample,
+      queue_duration_sum - older.queue_duration_sum, queue_duration_max,
+      queue_duration_sample, alloc_ops - older.alloc_ops,
+      free_ops - older.free_ops, allocated_bytes - older.allocated_bytes,
+      freed_bytes - older.freed_bytes,
+      alloc_overhead_bytes - older.alloc_overhead_bytes, max_allocated_bytes);
 }
 
 //------------------------------------------------------------------------------
 BirthOnThread::BirthOnThread(const Location& location,
                              const ThreadData& current)
     : location_(location),
       birth_thread_(&current) {
 }
 
 //------------------------------------------------------------------------------
@@ skipping 198 matching lines @@
 
   // 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.
   auto* current_phase_tasks =
       &process_data_snapshot->phased_snapshots[current_profiling_phase].tasks;
   for (const auto& birth_count : birth_counts) {
     if (birth_count.second > 0) {
       current_phase_tasks->push_back(
           TaskSnapshot(BirthOnThreadSnapshot(*birth_count.first),
-                       DeathDataSnapshot(birth_count.second, 0, 0, 0, 0, 0, 0),
+                       DeathDataSnapshot(birth_count.second, 0, 0, 0, 0, 0, 0,
+                                         0, 0, 0, 0, 0, 0),
                        "Still_Alive"));
     }
   }
 }
 
 // static
 void ThreadData::OnProfilingPhaseCompleted(int profiling_phase) {
   // Get an unchanging copy of a ThreadData list.
   ThreadData* my_list = ThreadData::first();
 
@@ skipping 38 matching lines @@
       static_cast<uint32_t>(&births - reinterpret_cast<Births*>(0));
 
   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_[&births];
   }  // Release lock ASAP.
-  death_data->RecordDeath(queue_duration, run_duration, random_number_);
+  death_data->RecordDurations(queue_duration, run_duration, random_number_);
+
+#if BUILDFLAG(ENABLE_MEMORY_TASK_PROFILER)
+  if (stopwatch.heap_tracking_enabled()) {
+    base::debug::ThreadHeapUsage heap_usage = stopwatch.heap_usage().usage();
+    // Saturate the 64 bit counts on conversion to 32 bit storage.
+    death_data->RecordAllocations(
+        base::saturated_cast<int32_t>(heap_usage.alloc_ops),
+        base::saturated_cast<int32_t>(heap_usage.free_ops),
+        base::saturated_cast<int32_t>(heap_usage.alloc_bytes),
+        base::saturated_cast<int32_t>(heap_usage.free_bytes),
+        base::saturated_cast<int32_t>(heap_usage.alloc_overhead_bytes),
+        base::saturated_cast<int32_t>(heap_usage.max_allocated_bytes));
+  }
+#endif
 }
 
 // static
 Births* ThreadData::TallyABirthIfActive(const Location& location) {
   if (!TrackingStatus())
     return NULL;
   ThreadData* current_thread_data = Get();
   if (!current_thread_data)
     return NULL;
   return current_thread_data->TallyABirth(location);
@@ skipping 118 matching lines @@
                               BirthMap* birth_map,
                               DeathsSnapshot* deaths) {
   base::AutoLock lock(map_lock_);
 
   for (const auto& birth : birth_map_)
     (*birth_map)[birth.first] = birth.second;
 
   for (const auto& death : death_map_) {
     deaths->push_back(std::make_pair(
         death.first,
-        DeathDataPhaseSnapshot(profiling_phase, death.second.count(),
-                               death.second.run_duration_sum(),
-                               death.second.run_duration_max(),
-                               death.second.run_duration_sample(),
-                               death.second.queue_duration_sum(),
-                               death.second.queue_duration_max(),
-                               death.second.queue_duration_sample(),
+        DeathDataPhaseSnapshot(profiling_phase, death.second,
                                death.second.last_phase_snapshot())));
   }
 }
 
 void ThreadData::OnProfilingPhaseCompletedOnThread(int profiling_phase) {
   base::AutoLock lock(map_lock_);
 
   for (auto& death : death_map_) {
     death.second.OnProfilingPhaseCompleted(profiling_phase);
   }
@@ skipping 25 matching lines @@
 
   // Incarnation counter is only significant to testing, as it otherwise will
   // never again change in this process.
   ++incarnation_counter_;
 
   // The lock is not critical for setting status_, but it doesn't hurt.  It also
   // ensures that if we have a racy initialization, that we'll bail as soon as
   // we get the lock earlier in this method.
   base::subtle::Release_Store(&status_, kInitialStartupState);
   DCHECK(base::subtle::NoBarrier_Load(&status_) != UNINITIALIZED);
+
+#if BUILDFLAG(ENABLE_MEMORY_TASK_PROFILER)
+  // Make sure heap tracking is enabled ASAP if the default state is active.
+  if (kInitialStartupState == PROFILING_ACTIVE &&
+      !base::debug::ThreadHeapUsageTracker::IsHeapTrackingEnabled()) {
+    base::debug::ThreadHeapUsageTracker::EnableHeapTracking();
+  }
+#endif  // BUILDFLAG(ENABLE_MEMORY_TASK_PROFILER)
 }
 
 // static
 void ThreadData::InitializeAndSetTrackingStatus(Status status) {
   DCHECK_GE(status, DEACTIVATED);
   DCHECK_LE(status, PROFILING_ACTIVE);
 
   EnsureTlsInitialization();  // No-op if already initialized.
 
-  if (status > DEACTIVATED)
+  if (status > DEACTIVATED) {
     status = PROFILING_ACTIVE;
+
+#if BUILDFLAG(ENABLE_MEMORY_TASK_PROFILER)
+    if (!base::debug::ThreadHeapUsageTracker::IsHeapTrackingEnabled())
+      base::debug::ThreadHeapUsageTracker::EnableHeapTracking();
+#endif  // BUILDFLAG(ENABLE_MEMORY_TASK_PROFILER)
+  }
   base::subtle::Release_Store(&status_, status);
 }
 
 // static
 ThreadData::Status ThreadData::status() {
   return static_cast<ThreadData::Status>(base::subtle::Acquire_Load(&status_));
 }
 
 // static
 bool ThreadData::TrackingStatus() {
@@ skipping 87 matching lines @@
 //------------------------------------------------------------------------------
 TaskStopwatch::TaskStopwatch()
     : wallclock_duration_ms_(0),
       current_thread_data_(NULL),
       excluded_duration_ms_(0),
       parent_(NULL) {
 #if DCHECK_IS_ON()
   state_ = CREATED;
   child_ = NULL;
 #endif
+#if BUILDFLAG(ENABLE_MEMORY_TASK_PROFILER)
+  heap_tracking_enabled_ =
+      base::debug::ThreadHeapUsageTracker::IsHeapTrackingEnabled();
+#endif
 }
 
 TaskStopwatch::~TaskStopwatch() {
 #if DCHECK_IS_ON()
   DCHECK(state_ != RUNNING);
   DCHECK(child_ == NULL);
 #endif
 }
 
 void TaskStopwatch::Start() {
 #if DCHECK_IS_ON()
   DCHECK(state_ == CREATED);
   state_ = RUNNING;
 #endif
 
   start_time_ = ThreadData::Now();
+#if BUILDFLAG(ENABLE_MEMORY_TASK_PROFILER)
+  if (heap_tracking_enabled_)
+    heap_usage_.Start();
+#endif
 
   current_thread_data_ = ThreadData::Get();
   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;
 }
 
 void TaskStopwatch::Stop() {
   const TrackedTime end_time = ThreadData::Now();
 #if DCHECK_IS_ON()
   DCHECK(state_ == RUNNING);
   state_ = STOPPED;
   DCHECK(child_ == NULL);
 #endif
+#if BUILDFLAG(USE_EXPERIMENTAL_ALLOCATOR_SHIM)
+  if (heap_tracking_enabled_)
+    heap_usage_.Stop(true);
+#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_;
@@ skipping 18 matching lines @@
 }
 
 int32_t TaskStopwatch::RunDurationMs() const {
 #if DCHECK_IS_ON()
   DCHECK(state_ == STOPPED);
 #endif
 
   return wallclock_duration_ms_ - excluded_duration_ms_;
 }
 
+#if BUILDFLAG(ENABLE_MEMORY_TASK_PROFILER)
+const base::debug::ThreadHeapUsageTracker& TaskStopwatch::heap_usage() const {
+  return heap_usage_;
+}
+#endif
+
 ThreadData* TaskStopwatch::GetThreadData() const {
 #if DCHECK_IS_ON()
   DCHECK(state_ != CREATED);
 #endif
 
   return current_thread_data_;
 }
 
 //------------------------------------------------------------------------------
 // DeathDataPhaseSnapshot
 
 DeathDataPhaseSnapshot::DeathDataPhaseSnapshot(
     int profiling_phase,
-    int count,
-    int32_t run_duration_sum,
-    int32_t run_duration_max,
-    int32_t run_duration_sample,
-    int32_t queue_duration_sum,
-    int32_t queue_duration_max,
-    int32_t queue_duration_sample,
+    const DeathData& death,
     const DeathDataPhaseSnapshot* prev)
-    : profiling_phase(profiling_phase),
-      death_data(count,
-                 run_duration_sum,
-                 run_duration_max,
-                 run_duration_sample,
-                 queue_duration_sum,
-                 queue_duration_max,
-                 queue_duration_sample),
-      prev(prev) {}
+    : profiling_phase(profiling_phase), death_data(death), prev(prev) {}
 
 //------------------------------------------------------------------------------
 // TaskSnapshot
 
 TaskSnapshot::TaskSnapshot() {
 }
 
 TaskSnapshot::TaskSnapshot(const BirthOnThreadSnapshot& birth,
                            const DeathDataSnapshot& death_data,
                            const std::string& death_thread_name)
@@ skipping 28 matching lines @@
 #endif
 }
 
 ProcessDataSnapshot::ProcessDataSnapshot(const ProcessDataSnapshot& other) =
     default;
 
 ProcessDataSnapshot::~ProcessDataSnapshot() {
 }
 
 }  // namespace tracked_objects