Guard pause histogram with lock.
There is a race condition since the GC was updating this without
holding any locks. But the signal catcher could be dumping the
timings with DumpGcPerformanceInfo at the same time. This could
potentially cause out of bound errors, etc..
Also did a bit of cleanup.
Bug: 15446488
Change-Id: Icaff19d872cc7f7d31c34e4ddaae97502454e09c
diff --git a/runtime/gc/collector/garbage_collector.cc b/runtime/gc/collector/garbage_collector.cc
index 46d79bf..646c032 100644
--- a/runtime/gc/collector/garbage_collector.cc
+++ b/runtime/gc/collector/garbage_collector.cc
@@ -55,7 +55,8 @@
: heap_(heap),
name_(name),
pause_histogram_((name_ + " paused").c_str(), kPauseBucketSize, kPauseBucketCount),
- cumulative_timings_(name) {
+ cumulative_timings_(name),
+ pause_histogram_lock_("pause histogram lock", kDefaultMutexLevel, true) {
ResetCumulativeStatistics();
}
@@ -65,10 +66,11 @@
void GarbageCollector::ResetCumulativeStatistics() {
cumulative_timings_.Reset();
- pause_histogram_.Reset();
total_time_ns_ = 0;
total_freed_objects_ = 0;
total_freed_bytes_ = 0;
+ MutexLock mu(Thread::Current(), pause_histogram_lock_);
+ pause_histogram_.Reset();
}
void GarbageCollector::Run(GcCause gc_cause, bool clear_soft_references) {
@@ -95,6 +97,7 @@
}
total_time_ns_ += current_iteration->GetDurationNs();
for (uint64_t pause_time : current_iteration->GetPauseTimes()) {
+ MutexLock mu(self, pause_histogram_lock_);
pause_histogram_.AddValue(pause_time / 1000);
}
ATRACE_END();
@@ -137,8 +140,11 @@
}
void GarbageCollector::ResetMeasurements() {
+ {
+ MutexLock mu(Thread::Current(), pause_histogram_lock_);
+ pause_histogram_.Reset();
+ }
cumulative_timings_.Reset();
- pause_histogram_.Reset();
total_time_ns_ = 0;
total_freed_objects_ = 0;
total_freed_bytes_ = 0;
@@ -171,6 +177,36 @@
heap_->RecordFree(freed.objects, freed.bytes);
}
+uint64_t GarbageCollector::GetTotalPausedTimeNs() {
+ MutexLock mu(Thread::Current(), pause_histogram_lock_);
+ return pause_histogram_.AdjustedSum();
+}
+
+void GarbageCollector::DumpPerformanceInfo(std::ostream& os) {
+ const CumulativeLogger& logger = GetCumulativeTimings();
+ const size_t iterations = logger.GetIterations();
+ if (iterations == 0) {
+ return;
+ }
+ os << ConstDumpable<CumulativeLogger>(logger);
+ const uint64_t total_ns = logger.GetTotalNs();
+ double seconds = NsToMs(logger.GetTotalNs()) / 1000.0;
+ const uint64_t freed_bytes = GetTotalFreedBytes();
+ const uint64_t freed_objects = GetTotalFreedObjects();
+ {
+ MutexLock mu(Thread::Current(), pause_histogram_lock_);
+ Histogram<uint64_t>::CumulativeData cumulative_data;
+ pause_histogram_.CreateHistogram(&cumulative_data);
+ pause_histogram_.PrintConfidenceIntervals(os, 0.99, cumulative_data);
+ }
+ os << GetName() << " total time: " << PrettyDuration(total_ns)
+ << " mean time: " << PrettyDuration(total_ns / iterations) << "\n"
+ << GetName() << " freed: " << freed_objects
+ << " objects with total size " << PrettySize(freed_bytes) << "\n"
+ << GetName() << " throughput: " << freed_objects / seconds << "/s / "
+ << PrettySize(freed_bytes / seconds) << "/s\n";
+}
+
} // namespace collector
} // namespace gc
} // namespace art
diff --git a/runtime/gc/collector/garbage_collector.h b/runtime/gc/collector/garbage_collector.h
index 885569e..b809469 100644
--- a/runtime/gc/collector/garbage_collector.h
+++ b/runtime/gc/collector/garbage_collector.h
@@ -119,18 +119,13 @@
GarbageCollector(Heap* heap, const std::string& name);
virtual ~GarbageCollector() { }
-
const char* GetName() const {
return name_.c_str();
}
-
virtual GcType GetGcType() const = 0;
-
virtual CollectorType GetCollectorType() const = 0;
-
// Run the garbage collector.
void Run(GcCause gc_cause, bool clear_soft_references);
-
Heap* GetHeap() const {
return heap_;
}
@@ -138,24 +133,17 @@
const CumulativeLogger& GetCumulativeTimings() const {
return cumulative_timings_;
}
-
void ResetCumulativeStatistics();
-
// Swap the live and mark bitmaps of spaces that are active for the collector. For partial GC,
// this is the allocation space, for full GC then we swap the zygote bitmaps too.
void SwapBitmaps() EXCLUSIVE_LOCKS_REQUIRED(Locks::heap_bitmap_lock_);
- uint64_t GetTotalPausedTimeNs() const {
- return pause_histogram_.AdjustedSum();
- }
+ uint64_t GetTotalPausedTimeNs() LOCKS_EXCLUDED(pause_histogram_lock_);
int64_t GetTotalFreedBytes() const {
return total_freed_bytes_;
}
uint64_t GetTotalFreedObjects() const {
return total_freed_objects_;
}
- const Histogram<uint64_t>& GetPauseHistogram() const {
- return pause_histogram_;
- }
// Reset the cumulative timings and pause histogram.
void ResetMeasurements();
// Returns the estimated throughput in bytes / second.
@@ -174,11 +162,11 @@
void RecordFree(const ObjectBytePair& freed);
// Record a free of large objects.
void RecordFreeLOS(const ObjectBytePair& freed);
+ void DumpPerformanceInfo(std::ostream& os) LOCKS_EXCLUDED(pause_histogram_lock_);
protected:
// Run all of the GC phases.
virtual void RunPhases() = 0;
-
// Revoke all the thread-local buffers.
virtual void RevokeAllThreadLocalBuffers() = 0;
@@ -188,11 +176,12 @@
Heap* const heap_;
std::string name_;
// Cumulative statistics.
- Histogram<uint64_t> pause_histogram_;
+ Histogram<uint64_t> pause_histogram_ GUARDED_BY(pause_histogram_lock_);
uint64_t total_time_ns_;
uint64_t total_freed_objects_;
int64_t total_freed_bytes_;
CumulativeLogger cumulative_timings_;
+ mutable Mutex pause_histogram_lock_ DEFAULT_MUTEX_ACQUIRED_AFTER;
};
} // namespace collector
diff --git a/runtime/gc/heap.cc b/runtime/gc/heap.cc
index bf8cca7..152a853 100644
--- a/runtime/gc/heap.cc
+++ b/runtime/gc/heap.cc
@@ -772,28 +772,9 @@
// Dump cumulative loggers for each GC type.
uint64_t total_paused_time = 0;
for (auto& collector : garbage_collectors_) {
- const CumulativeLogger& logger = collector->GetCumulativeTimings();
- const size_t iterations = logger.GetIterations();
- const Histogram<uint64_t>& pause_histogram = collector->GetPauseHistogram();
- if (iterations != 0 && pause_histogram.SampleSize() != 0) {
- os << ConstDumpable<CumulativeLogger>(logger);
- const uint64_t total_ns = logger.GetTotalNs();
- const uint64_t total_pause_ns = collector->GetTotalPausedTimeNs();
- double seconds = NsToMs(logger.GetTotalNs()) / 1000.0;
- const uint64_t freed_bytes = collector->GetTotalFreedBytes();
- const uint64_t freed_objects = collector->GetTotalFreedObjects();
- Histogram<uint64_t>::CumulativeData cumulative_data;
- pause_histogram.CreateHistogram(&cumulative_data);
- pause_histogram.PrintConfidenceIntervals(os, 0.99, cumulative_data);
- os << collector->GetName() << " total time: " << PrettyDuration(total_ns)
- << " mean time: " << PrettyDuration(total_ns / iterations) << "\n"
- << collector->GetName() << " freed: " << freed_objects
- << " objects with total size " << PrettySize(freed_bytes) << "\n"
- << collector->GetName() << " throughput: " << freed_objects / seconds << "/s / "
- << PrettySize(freed_bytes / seconds) << "/s\n";
- total_duration += total_ns;
- total_paused_time += total_pause_ns;
- }
+ total_duration += collector->GetCumulativeTimings().GetTotalNs();
+ total_paused_time += collector->GetTotalPausedTimeNs();
+ collector->DumpPerformanceInfo(os);
collector->ResetMeasurements();
}
uint64_t allocation_time =
