summaryrefslogtreecommitdiffstats
path: root/runtime/base/timing_logger.cc
diff options
context:
space:
mode:
Diffstat (limited to 'runtime/base/timing_logger.cc')
-rw-r--r--runtime/base/timing_logger.cc109
1 files changed, 60 insertions, 49 deletions
diff --git a/runtime/base/timing_logger.cc b/runtime/base/timing_logger.cc
index 11dc542..c8dee6d 100644
--- a/runtime/base/timing_logger.cc
+++ b/runtime/base/timing_logger.cc
@@ -22,7 +22,7 @@
#include "timing_logger.h"
#include "base/logging.h"
-#include "thread.h"
+#include "thread-inl.h"
#include "base/stl_util.h"
#include "base/histogram-inl.h"
@@ -39,7 +39,7 @@ CumulativeLogger::CumulativeLogger(const std::string& name)
}
CumulativeLogger::~CumulativeLogger() {
- STLDeleteValues(&histograms_);
+ STLDeleteElements(&histograms_);
}
void CumulativeLogger::SetName(const std::string& name) {
@@ -57,7 +57,7 @@ void CumulativeLogger::End() {
void CumulativeLogger::Reset() {
MutexLock mu(Thread::Current(), lock_);
iterations_ = 0;
- STLDeleteValues(&histograms_);
+ STLDeleteElements(&histograms_);
}
uint64_t CumulativeLogger::GetTotalNs() const {
@@ -67,60 +67,72 @@ uint64_t CumulativeLogger::GetTotalNs() const {
uint64_t CumulativeLogger::GetTotalTime() const {
MutexLock mu(Thread::Current(), lock_);
uint64_t total = 0;
- for (CumulativeLogger::HistogramsIterator it = histograms_.begin(), end = histograms_.end();
- it != end; ++it) {
- total += it->second->Sum();
+ for (Histogram<uint64_t>* histogram : histograms_) {
+ total += histogram->Sum();
}
return total;
}
-void CumulativeLogger::AddLogger(const base::TimingLogger &logger) {
+void CumulativeLogger::AddLogger(const TimingLogger &logger) {
MutexLock mu(Thread::Current(), lock_);
- const base::TimingLogger::SplitTimings& splits = logger.GetSplits();
- for (base::TimingLogger::SplitTimingsIterator it = splits.begin(), end = splits.end();
- it != end; ++it) {
- base::TimingLogger::SplitTiming split = *it;
+ const TimingLogger::SplitTimings& splits = logger.GetSplits();
+ for (auto it = splits.begin(), end = splits.end(); it != end; ++it) {
+ TimingLogger::SplitTiming split = *it;
uint64_t split_time = split.first;
const char* split_name = split.second;
AddPair(split_name, split_time);
}
}
+size_t CumulativeLogger::GetIterations() const {
+ MutexLock mu(Thread::Current(), lock_);
+ return iterations_;
+}
+
void CumulativeLogger::Dump(std::ostream &os) {
MutexLock mu(Thread::Current(), lock_);
DumpHistogram(os);
}
-void CumulativeLogger::AddPair(const std::string &label, uint64_t delta_time) {
+void CumulativeLogger::AddPair(const std::string& label, uint64_t delta_time) {
// Convert delta time to microseconds so that we don't overflow our counters.
delta_time /= kAdjust;
- if (histograms_.find(label) == histograms_.end()) {
- // TODO: Shoud this be a defined constant so we we know out of which orifice 16 and 100 were picked?
- const size_t max_buckets = Runtime::Current()->GetHeap()->IsLowMemoryMode() ? 16 : 100;
- // TODO: Should this be a defined constant so we know 50 of WTF?
- histograms_[label] = new Histogram<uint64_t>(label.c_str(), 50, max_buckets);
+ Histogram<uint64_t>* histogram;
+ Histogram<uint64_t> dummy(label.c_str());
+ auto it = histograms_.find(&dummy);
+ 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);
+ } else {
+ histogram = *it;
}
- histograms_[label]->AddValue(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) {
os << "Start Dumping histograms for " << iterations_ << " iterations"
<< " for " << name_ << "\n";
- for (CumulativeLogger::HistogramsIterator it = histograms_.begin(), end = histograms_.end();
- it != end; ++it) {
+ 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;
- it->second->CreateHistogram(cumulative_data);
- it->second->PrintConfidenceIntervals(os, 0.99, cumulative_data);
- // Reset cumulative values to save memory. We don't expect DumpHistogram to be called often, so
- // it is not performance critical.
+ // 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);
}
os << "Done Dumping histograms \n";
}
-
-namespace base {
-
TimingLogger::TimingLogger(const char* name, bool precise, bool verbose)
: name_(name), precise_(precise), verbose_(verbose), current_split_(NULL) {
}
@@ -131,33 +143,35 @@ void TimingLogger::Reset() {
}
void TimingLogger::StartSplit(const char* new_split_label) {
- DCHECK(new_split_label != NULL) << "Starting split (" << new_split_label << ") with null label.";
- TimingLogger::ScopedSplit* explicit_scoped_split = new TimingLogger::ScopedSplit(new_split_label, this);
+ DCHECK(new_split_label != nullptr) << "Starting split with null label.";
+ TimingLogger::ScopedSplit* explicit_scoped_split =
+ new TimingLogger::ScopedSplit(new_split_label, this);
explicit_scoped_split->explicit_ = true;
}
void TimingLogger::EndSplit() {
- CHECK(current_split_ != NULL) << "Ending a non-existent split.";
- DCHECK(current_split_->label_ != NULL);
- DCHECK(current_split_->explicit_ == true) << "Explicitly ending scoped split: " << current_split_->label_;
-
+ CHECK(current_split_ != nullptr) << "Ending a non-existent split.";
+ DCHECK(current_split_->label_ != nullptr);
+ DCHECK(current_split_->explicit_ == true)
+ << "Explicitly ending scoped split: " << current_split_->label_;
delete current_split_;
+ // TODO: current_split_ = nullptr;
}
// Ends the current split and starts the one given by the label.
void TimingLogger::NewSplit(const char* new_split_label) {
- CHECK(current_split_ != NULL) << "Inserting a new split (" << new_split_label
- << ") into a non-existent split.";
- DCHECK(new_split_label != NULL) << "New split (" << new_split_label << ") with null label.";
-
- current_split_->TailInsertSplit(new_split_label);
+ if (current_split_ == nullptr) {
+ StartSplit(new_split_label);
+ } else {
+ DCHECK(new_split_label != nullptr) << "New split (" << new_split_label << ") with null label.";
+ current_split_->TailInsertSplit(new_split_label);
+ }
}
uint64_t TimingLogger::GetTotalNs() const {
uint64_t total_ns = 0;
- for (base::TimingLogger::SplitTimingsIterator it = splits_.begin(), end = splits_.end();
- it != end; ++it) {
- base::TimingLogger::SplitTiming split = *it;
+ for (auto it = splits_.begin(), end = splits_.end(); it != end; ++it) {
+ TimingLogger::SplitTiming split = *it;
total_ns += split.first;
}
return total_ns;
@@ -166,9 +180,8 @@ uint64_t TimingLogger::GetTotalNs() const {
void TimingLogger::Dump(std::ostream &os) const {
uint64_t longest_split = 0;
uint64_t total_ns = 0;
- for (base::TimingLogger::SplitTimingsIterator it = splits_.begin(), end = splits_.end();
- it != end; ++it) {
- base::TimingLogger::SplitTiming split = *it;
+ for (auto it = splits_.begin(), end = splits_.end(); it != end; ++it) {
+ TimingLogger::SplitTiming split = *it;
uint64_t split_time = split.first;
longest_split = std::max(longest_split, split_time);
total_ns += split_time;
@@ -177,9 +190,8 @@ void TimingLogger::Dump(std::ostream &os) const {
TimeUnit tu = GetAppropriateTimeUnit(longest_split);
uint64_t divisor = GetNsToTimeUnitDivisor(tu);
// Print formatted splits.
- for (base::TimingLogger::SplitTimingsIterator it = splits_.begin(), end = splits_.end();
- it != end; ++it) {
- base::TimingLogger::SplitTiming split = *it;
+ for (auto it = splits_.begin(), end = splits_.end(); it != end; ++it) {
+ const TimingLogger::SplitTiming& split = *it;
uint64_t split_time = split.first;
if (!precise_ && divisor >= 1000) {
// Make the fractional part 0.
@@ -226,7 +238,7 @@ TimingLogger::ScopedSplit::~ScopedSplit() {
LOG(INFO) << "End: " << label_ << " " << PrettyDuration(split_time);
}
- // If one or more enclosed explcitly started splits are not terminated we can
+ // If one or more enclosed explicitly started splits are not terminated we can
// either fail or "unwind" the stack of splits in the timing logger to 'this'
// (by deleting the intervening scoped splits). This implements the latter.
TimingLogger::ScopedSplit* current = timing_logger_->current_split_;
@@ -288,5 +300,4 @@ void TimingLogger::ScopedSplit::Resume() {
ATRACE_BEGIN(label_);
}
-} // namespace base
} // namespace art
generated by cgit v1.1 at 2024-09-18 17:17:30 +0000