Replace histogram in CumulativeLogger with average am: 0613605645temp_RQ2A.210305.007

Original change: https://android-review.googlesource.com/c/platform/art/+/1611338

MUST ONLY BE SUBMITTED BY AUTOMERGER

Change-Id: I32cb8eb92bc864e6e08fe14a4198f345dc0e71b9

3 files changed, 51 insertions, 46 deletions

diff --git a/runtime/base/timing_logger.cc b/runtime/base/timing_logger.cc
index c4034b0c02..abf4f58b2c 100644
--- a/runtime/base/timing_logger.cc
+++ b/runtime/base/timing_logger.cc
@@ -20,7 +20,6 @@
 
 #include <android-base/logging.h>
 
-#include "base/histogram-inl.h"
 #include "base/mutex.h"
 #include "base/stl_util.h"
 #include "base/systrace.h"
@@ -34,8 +33,6 @@
 
 namespace art {
 
-constexpr size_t CumulativeLogger::kLowMemoryBucketCount;
-constexpr size_t CumulativeLogger::kDefaultBucketCount;
 constexpr size_t TimingLogger::kIndexNotFound;
 
 CumulativeLogger::CumulativeLogger(const std::string& name)
@@ -46,7 +43,7 @@ CumulativeLogger::CumulativeLogger(const std::string& name)
 }
 
 CumulativeLogger::~CumulativeLogger() {
-  STLDeleteElements(&histograms_);
+  cumulative_timers_.clear();
 }
 
 void CumulativeLogger::SetName(const std::string& name) {
@@ -66,7 +63,7 @@ void CumulativeLogger::Reset() {
   MutexLock mu(Thread::Current(), *GetLock());
   iterations_ = 0;
   total_time_ = 0;
-  STLDeleteElements(&histograms_);
+  cumulative_timers_.clear();
 }
 
 void CumulativeLogger::AddLogger(const TimingLogger &logger) {
@@ -88,46 +85,46 @@ size_t CumulativeLogger::GetIterations() const {
 
 void CumulativeLogger::Dump(std::ostream &os) const {
   MutexLock mu(Thread::Current(), *GetLock());
-  DumpHistogram(os);
+  DumpAverages(os);
 }
 
-void CumulativeLogger::AddPair(const std::string& label, uint64_t delta_time) {
+void CumulativeLogger::AddPair(const char* label, uint64_t delta_time) {
   // Convert delta time to microseconds so that we don't overflow our counters.
   delta_time /= kAdjust;
   total_time_ += delta_time;
-  Histogram<uint64_t>* histogram;
-  Histogram<uint64_t> candidate(label.c_str());
-  auto it = histograms_.find(&candidate);
-  if (it == histograms_.end()) {
-    const size_t max_buckets = Runtime::Current()->GetHeap()->IsLowMemoryMode() ?
-        kLowMemoryBucketCount : kDefaultBucketCount;
-    histogram = new Histogram<uint64_t>(label.c_str(), kInitialBucketSize, max_buckets);
-    histograms_.insert(histogram);
+  CumulativeTime candidate(label, delta_time);
+  auto it = std::lower_bound(cumulative_timers_.begin(), cumulative_timers_.end(), candidate);
+  // Maintain the vector sorted so that lookup above, which is more frequent can
+  // happen in log(n).
+  if (it == cumulative_timers_.end() || it->Name() != label) {
+    cumulative_timers_.insert(it, candidate);
   } else {
-    histogram = *it;
+    it->Add(delta_time);
   }
-  histogram->AddValue(delta_time);
 }
 
-class CompareHistorgramByTimeSpentDeclining {
- public:
-  bool operator()(const Histogram<uint64_t>* a, const Histogram<uint64_t>* b) const {
-    return a->Sum() > b->Sum();
-  }
-};
-
-void CumulativeLogger::DumpHistogram(std::ostream &os) const {
-  os << "Start Dumping histograms for " << iterations_ << " iterations"
+void CumulativeLogger::DumpAverages(std::ostream &os) const {
+  os << "Start Dumping Averages for " << iterations_ << " iterations"
      << " for " << name_ << "\n";
-  std::set<Histogram<uint64_t>*, CompareHistorgramByTimeSpentDeclining>
-      sorted_histograms(histograms_.begin(), histograms_.end());
-  for (Histogram<uint64_t>* histogram : sorted_histograms) {
-    Histogram<uint64_t>::CumulativeData cumulative_data;
-    // We don't expect DumpHistogram to be called often, so it is not performance critical.
-    histogram->CreateHistogram(&cumulative_data);
-    histogram->PrintConfidenceIntervals(os, 0.99, cumulative_data);
+  const size_t timers_sz = cumulative_timers_.size();
+  // Create an array of pointers to cumulative timers on stack and sort it in
+  // decreasing order of accumulated timer so that the most time consuming
+  // timer is printed first.
+  const CumulativeTime* sorted_timers[timers_sz];
+  for (size_t i = 0; i < timers_sz; i++) {
+    sorted_timers[i] = cumulative_timers_.data() + i;
+  }
+  std::sort(sorted_timers,
+            sorted_timers + timers_sz,
+            [](const CumulativeTime* a, const CumulativeTime* b) { return a->Sum() > b->Sum(); });
+  for (size_t i = 0; i < timers_sz; i++) {
+    const CumulativeTime *timer = sorted_timers[i];
+    uint64_t total_time_ns = timer->Sum() * kAdjust;
+    os << timer->Name()
+       << ":\tSum: " << PrettyDuration(total_time_ns)
+       << " Avg: " << PrettyDuration(total_time_ns / iterations_) << "\n";
   }
-  os << "Done Dumping histograms\n";
+  os << "Done Dumping Averages\n";
 }
 
 TimingLogger::TimingLogger(const char* name,
diff --git a/runtime/base/timing_logger.h b/runtime/base/timing_logger.h
index 974a14dd14..4f72a80399 100644
--- a/runtime/base/timing_logger.h
+++ b/runtime/base/timing_logger.h
@@ -17,7 +17,6 @@
 #ifndef ART_RUNTIME_BASE_TIMING_LOGGER_H_
 #define ART_RUNTIME_BASE_TIMING_LOGGER_H_
 
-#include "base/histogram.h"
 #include "base/locks.h"
 #include "base/macros.h"
 #include "base/time_utils.h"
@@ -48,19 +47,24 @@ class CumulativeLogger {
   size_t GetIterations() const REQUIRES(!GetLock());
 
  private:
-  class HistogramComparator {
+  class CumulativeTime {
    public:
-    bool operator()(const Histogram<uint64_t>* a, const Histogram<uint64_t>* b) const {
-      return a->Name() < b->Name();
+    CumulativeTime(const char* name, uint64_t time) : name_(name), time_(time) {}
+    void Add(uint64_t time) { time_ += time; }
+    const char* Name() const { return name_; }
+    uint64_t Sum() const { return time_; }
+    // Compare addresses of names for sorting.
+    bool operator< (const CumulativeTime& ct) const {
+      return std::less<const char*>()(name_, ct.name_);
     }
-  };
 
-  static constexpr size_t kLowMemoryBucketCount = 16;
-  static constexpr size_t kDefaultBucketCount = 100;
-  static constexpr size_t kInitialBucketSize = 50;  // 50 microseconds.
+   private:
+    const char* name_;
+    uint64_t time_;
+  };
 
-  void AddPair(const std::string &label, uint64_t delta_time) REQUIRES(GetLock());
-  void DumpHistogram(std::ostream &os) const REQUIRES(GetLock());
+  void DumpAverages(std::ostream &os) const REQUIRES(GetLock());
+  void AddPair(const char* label, uint64_t delta_time) REQUIRES(GetLock());
   uint64_t GetTotalTime() const {
     return total_time_;
   }
@@ -69,8 +73,11 @@ class CumulativeLogger {
     return lock_.get();
   }
 
-  static const uint64_t kAdjust = 1000;
-  std::set<Histogram<uint64_t>*, HistogramComparator> histograms_ GUARDED_BY(GetLock());
+  static constexpr uint64_t kAdjust = 1000;
+  // Use a vector to keep dirty memory to minimal number of pages. Using a
+  // hashtable would be performant, but could lead to more dirty pages. Also, we
+  // don't expect this vector to be too big.
+  std::vector<CumulativeTime> cumulative_timers_ GUARDED_BY(GetLock());
   std::string name_;
   const std::string lock_name_;
   mutable std::unique_ptr<Mutex> lock_ DEFAULT_MUTEX_ACQUIRED_AFTER;
diff --git a/runtime/gc/heap.h b/runtime/gc/heap.h
index 7cc06a71db..d45f276272 100644
--- a/runtime/gc/heap.h
+++ b/runtime/gc/heap.h
@@ -26,6 +26,7 @@
 
 #include "allocator_type.h"
 #include "base/atomic.h"
+#include "base/histogram.h"
 #include "base/macros.h"
 #include "base/mutex.h"
 #include "base/runtime_debug.h"