GC clean up.
Greater use of directories and namespaces.
Fix bugs that cause verify options to fail.
Address numerous other issues:
GC barrier wait occurring holding locks:
GC barrier waits occur when we wait for threads to run the check point function
on themselves. This is happening with the heap bitmap and mutator lock held
meaning that a thread that tries to take either lock exclusively will block
waiting on a thread that is waiting. If this thread is the thread we're waiting
to run the check point then the VM will deadlock.
This deadlock occurred unnoticed as the call to check for wait safety was
removed in: https://googleplex-android-review.googlesource.com/#/c/249423/1.
NewTimingLogger:
Existing timing log states when a split ends but not when it begins. This isn't
good for systrace, in the context of GC it means that races between mutators
and the GC are hard to discover what phase the GC is in, we know what phase it
just finished and derive but that's not ideal.
Support for only 1 discontinuous space:
Code special cases continuous and large object space, rather than assuming we
can have a collection of both.
Sorted atomic stacks:
Used to improve verification performance. Simplify their use and add extra
checks.
Simplify mod-union table abstractions.
Reduce use of std::strings and their associated overhead in hot code.
Make time units of fields explicit.
Reduce confusion that IsAllocSpace is really IsDlMallocSpace.
Make GetTotalMemory (exposed via System) equal to the footprint (as in Dalvik)
rather than the max memory footprint.
Change-Id: Ie87067140fa4499b15edab691fe6565d79599812
diff --git a/src/base/mutex.cc b/src/base/mutex.cc
index a2851e5..fbec826 100644
--- a/src/base/mutex.cc
+++ b/src/base/mutex.cc
@@ -777,6 +777,11 @@
}
void ConditionVariable::Wait(Thread* self) {
+ guard_.CheckSafeToWait(self);
+ WaitHoldingLocks(self);
+}
+
+void ConditionVariable::WaitHoldingLocks(Thread* self) {
DCHECK(self == NULL || self == Thread::Current());
guard_.AssertExclusiveHeld(self);
unsigned int old_recursion_count = guard_.recursion_count_;
@@ -811,6 +816,7 @@
void ConditionVariable::TimedWait(Thread* self, int64_t ms, int32_t ns) {
DCHECK(self == NULL || self == Thread::Current());
guard_.AssertExclusiveHeld(self);
+ guard_.CheckSafeToWait(self);
unsigned int old_recursion_count = guard_.recursion_count_;
#if ART_USE_FUTEXES
timespec rel_ts;
diff --git a/src/base/mutex.h b/src/base/mutex.h
index a393765..24df572 100644
--- a/src/base/mutex.h
+++ b/src/base/mutex.h
@@ -307,6 +307,10 @@
// pointer copy, thereby defeating annotalysis.
void Wait(Thread* self) NO_THREAD_SAFETY_ANALYSIS;
void TimedWait(Thread* self, int64_t ms, int32_t ns) NO_THREAD_SAFETY_ANALYSIS;
+ // Variant of Wait that should be used with caution. Doesn't validate that no mutexes are held
+ // when waiting.
+ // TODO: remove this.
+ void WaitHoldingLocks(Thread* self) NO_THREAD_SAFETY_ANALYSIS;
private:
const char* const name_;
diff --git a/src/base/timing_logger.cc b/src/base/timing_logger.cc
index 6d5586c..c7cbbe5 100644
--- a/src/base/timing_logger.cc
+++ b/src/base/timing_logger.cc
@@ -82,7 +82,7 @@
}
void CumulativeLogger::SetName(const std::string& name) {
- name_ = name;
+ name_.assign(name);
}
void CumulativeLogger::Start() {
@@ -123,13 +123,40 @@
}
}
+void CumulativeLogger::AddNewLogger(const base::NewTimingLogger &logger) {
+ MutexLock mu(Thread::Current(), lock_);
+ const std::vector<std::pair<uint64_t, const char*> >& splits = logger.GetSplits();
+ typedef std::vector<std::pair<uint64_t, const char*> >::const_iterator It;
+ if (kIsDebugBuild && splits.size() != histograms_.size()) {
+ LOG(ERROR) << "Mismatch in splits.";
+ typedef std::vector<Histogram<uint64_t> *>::const_iterator It2;
+ It it = splits.begin();
+ It2 it2 = histograms_.begin();
+ while ((it != splits.end()) && (it2 != histograms_.end())) {
+ if (it != splits.end()) {
+ LOG(ERROR) << "\tsplit: " << it->second;
+ ++it;
+ }
+ if (it2 != histograms_.end()) {
+ LOG(ERROR) << "\tpreviously record: " << (*it2)->Name();
+ ++it2;
+ }
+ }
+ }
+ for (It it = splits.begin(), end = splits.end(); it != end; ++it) {
+ std::pair<uint64_t, const char*> split = *it;
+ uint64_t split_time = split.first;
+ const char* split_name = split.second;
+ AddPair(split_name, split_time);
+ }
+}
+
void CumulativeLogger::Dump(std::ostream &os) {
MutexLock mu(Thread::Current(), lock_);
DumpHistogram(os);
}
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 (index_ >= histograms_.size()) {
@@ -154,4 +181,89 @@
os << "Done Dumping histograms \n";
}
+
+namespace base {
+
+NewTimingLogger::NewTimingLogger(const char* name, bool precise, bool verbose)
+ : name_(name), precise_(precise), verbose_(verbose),
+ current_split_(NULL), current_split_start_ns_(0) {
+}
+
+void NewTimingLogger::Reset() {
+ current_split_ = NULL;
+ current_split_start_ns_ = 0;
+ splits_.clear();
+}
+
+void NewTimingLogger::StartSplit(const char* new_split_label) {
+ DCHECK(current_split_ == NULL);
+ if (verbose_) {
+ LOG(INFO) << "Begin: " << new_split_label;
+ }
+ current_split_ = new_split_label;
+ current_split_start_ns_ = NanoTime();
+}
+
+// Ends the current split and starts the one given by the label.
+void NewTimingLogger::NewSplit(const char* new_split_label) {
+ DCHECK(current_split_ != NULL);
+ uint64_t current_time = NanoTime();
+ uint64_t split_time = current_time - current_split_start_ns_;
+ splits_.push_back(std::pair<uint64_t, const char*>(split_time, current_split_));
+ if (verbose_) {
+ LOG(INFO) << "End: " << current_split_ << " " << PrettyDuration(split_time) << "\n"
+ << "Begin: " << new_split_label;
+ }
+ current_split_ = new_split_label;
+ current_split_start_ns_ = current_time;
+}
+
+void NewTimingLogger::EndSplit() {
+ DCHECK(current_split_ != NULL);
+ uint64_t current_time = NanoTime();
+ uint64_t split_time = current_time - current_split_start_ns_;
+ if (verbose_) {
+ LOG(INFO) << "End: " << current_split_ << " " << PrettyDuration(split_time);
+ }
+ splits_.push_back(std::pair<uint64_t, const char*>(split_time, current_split_));
+}
+
+uint64_t NewTimingLogger::GetTotalNs() const {
+ uint64_t total_ns = 0;
+ typedef std::vector<std::pair<uint64_t, const char*> >::const_iterator It;
+ for (It it = splits_.begin(), end = splits_.end(); it != end; ++it) {
+ std::pair<uint64_t, const char*> split = *it;
+ total_ns += split.first;
+ }
+ return total_ns;
+}
+
+void NewTimingLogger::Dump(std::ostream &os) const {
+ uint64_t longest_split = 0;
+ uint64_t total_ns = 0;
+ typedef std::vector<std::pair<uint64_t, const char*> >::const_iterator It;
+ for (It it = splits_.begin(), end = splits_.end(); it != end; ++it) {
+ std::pair<uint64_t, const char*> split = *it;
+ uint64_t split_time = split.first;
+ longest_split = std::max(longest_split, split_time);
+ total_ns += split_time;
+ }
+ // Compute which type of unit we will use for printing the timings.
+ TimeUnit tu = GetAppropriateTimeUnit(longest_split);
+ uint64_t divisor = GetNsToTimeUnitDivisor(tu);
+ // Print formatted splits.
+ for (It it = splits_.begin(), end = splits_.end(); it != end; ++it) {
+ std::pair<uint64_t, const char*> split = *it;
+ uint64_t split_time = split.first;
+ if (!precise_ && divisor >= 1000) {
+ // Make the fractional part 0.
+ split_time -= split_time % (divisor / 1000);
+ }
+ os << name_ << ": " << std::setw(8) << FormatDuration(split_time, tu) << " "
+ << split.second << "\n";
+ }
+ os << name_ << ": end, " << NsToMs(total_ns) << " ms\n";
+}
+
+} // namespace base
} // namespace art
diff --git a/src/base/timing_logger.h b/src/base/timing_logger.h
index bbcc286..65732b1 100644
--- a/src/base/timing_logger.h
+++ b/src/base/timing_logger.h
@@ -45,6 +45,10 @@
friend class CumulativeLogger;
};
+namespace base {
+ class NewTimingLogger;
+} // namespace base
+
class CumulativeLogger {
public:
@@ -61,6 +65,7 @@
// parent class that is unable to determine the "name" of a sub-class.
void SetName(const std::string& name);
void AddLogger(const TimingLogger& logger) LOCKS_EXCLUDED(lock_);
+ void AddNewLogger(const base::NewTimingLogger& logger) LOCKS_EXCLUDED(lock_);
private:
@@ -79,6 +84,59 @@
DISALLOW_COPY_AND_ASSIGN(CumulativeLogger);
};
+namespace base {
+
+// A replacement to timing logger that know when a split starts for the purposes of logging.
+// TODO: replace uses of TimingLogger with base::NewTimingLogger.
+class NewTimingLogger {
+ public:
+ explicit NewTimingLogger(const char* name, bool precise, bool verbose);
+
+ // Clears current splits and labels.
+ void Reset();
+
+ // Starts a split, a split shouldn't be in progress.
+ void StartSplit(const char* new_split_label);
+
+ // Ends the current split and starts the one given by the label.
+ void NewSplit(const char* new_split_label);
+
+ // Ends the current split and records the end time.
+ void EndSplit();
+
+ uint64_t GetTotalNs() const;
+
+ void Dump(std::ostream& os) const;
+
+ const std::vector<std::pair<uint64_t, const char*> >& GetSplits() const {
+ return splits_;
+ }
+
+ protected:
+ // The name of the timing logger.
+ const std::string name_;
+
+ // Do we want to print the exactly recorded split (true) or round down to the time unit being
+ // used (false).
+ const bool precise_;
+
+ // Verbose logging.
+ const bool verbose_;
+
+ // The name of the current split.
+ const char* current_split_;
+
+ // The nanosecond time the current split started on.
+ uint64_t current_split_start_ns_;
+
+ // Splits are nanosecond times and split names.
+ std::vector<std::pair<uint64_t, const char*> > splits_;
+
+ private:
+ DISALLOW_COPY_AND_ASSIGN(NewTimingLogger);
+};
+
+} // namespace base
} // namespace art
#endif // ART_SRC_TIMING_LOGGER_H_