Add GC-related metrics to the telemetry infrastructure
Following metrics are added in this CL:
1) Young GC count
2) Full heap GC count
3) Young GC throughput histogram
4) Full heap GC throughput histogram
5) Total bytes allocated
6) Total GC meta data
The last one in itself is not useful. But when divided by GC count gives
an average of memory overhead of running a GC algorithm.
Test: art/test/testrunner/testrunner.py
Bug: 170149255
Change-Id: I5a93d1ceb9dc0764b8c6cebae038b98218c0656a
diff --git a/libartbase/base/metrics/metrics.h b/libartbase/base/metrics/metrics.h
index 9345565..ab535ea 100644
--- a/libartbase/base/metrics/metrics.h
+++ b/libartbase/base/metrics/metrics.h
@@ -39,7 +39,11 @@
#define ART_COUNTERS(COUNTER) \
COUNTER(ClassLoadingTotalTime) \
COUNTER(ClassVerificationTotalTime) \
- COUNTER(MutatorPauseTimeDuringGC)
+ COUNTER(MutatorPauseTimeDuringGC) \
+ COUNTER(YoungGcCount) \
+ COUNTER(FullGcCount) \
+ COUNTER(TotalBytesAllocated) \
+ COUNTER(TotalGcMetaDataSize)
// HISTOGRAM(counter_name, num_buckets, minimum_value, maximum_value)
//
@@ -57,7 +61,9 @@
#define ART_HISTOGRAMS(HISTOGRAM) \
HISTOGRAM(JitMethodCompileTime, 15, 0, 1'000'000) \
HISTOGRAM(YoungGcCollectionTime, 15, 0, 60'000) \
- HISTOGRAM(FullGcCollectionTime, 15, 0, 60'000)
+ HISTOGRAM(FullGcCollectionTime, 15, 0, 60'000) \
+ HISTOGRAM(YoungGcThroughput, 15, 0, 1'000) \
+ HISTOGRAM(FullGcThroughput, 15, 0, 1'000)
// A lot of the metrics implementation code is generated by passing one-off macros into ART_COUNTERS
// and ART_HISTOGRAMS. This means metrics.h and metrics.cc are very #define-heavy, which can be
diff --git a/runtime/gc/collector/concurrent_copying.cc b/runtime/gc/collector/concurrent_copying.cc
index d8db3fc..f58224d 100644
--- a/runtime/gc/collector/concurrent_copying.cc
+++ b/runtime/gc/collector/concurrent_copying.cc
@@ -153,10 +153,15 @@
}
// Return type of these functions are different. And even though the base class
// is same, using ternary operator complains.
+ metrics::ArtMetrics* metrics = GetMetrics();
if (young_gen_) {
- gc_time_histogram_ = GetMetrics()->YoungGcCollectionTime();
+ gc_time_histogram_ = metrics->YoungGcCollectionTime();
+ metrics_gc_count_ = metrics->YoungGcCount();
+ gc_throughput_histogram_ = metrics->YoungGcThroughput();
} else {
- gc_time_histogram_ = GetMetrics()->FullGcCollectionTime();
+ gc_time_histogram_ = metrics->FullGcCollectionTime();
+ metrics_gc_count_ = metrics->FullGcCount();
+ gc_throughput_histogram_ = metrics->FullGcThroughput();
}
}
diff --git a/runtime/gc/collector/garbage_collector.cc b/runtime/gc/collector/garbage_collector.cc
index a08ba85..f6bd996 100644
--- a/runtime/gc/collector/garbage_collector.cc
+++ b/runtime/gc/collector/garbage_collector.cc
@@ -70,6 +70,8 @@
rss_histogram_((name_ + " peak-rss").c_str(), kMemBucketSize, kMemBucketCount),
freed_bytes_histogram_((name_ + " freed-bytes").c_str(), kMemBucketSize, kMemBucketCount),
gc_time_histogram_(nullptr),
+ metrics_gc_count_(nullptr),
+ gc_throughput_histogram_(nullptr),
cumulative_timings_(name),
pause_histogram_lock_("pause histogram lock", kDefaultMutexLevel, true),
is_transaction_active_(false) {
@@ -140,6 +142,10 @@
}
rss *= kPageSize;
rss_histogram_.AddValue(rss / KB);
+ // Add up all the GC meta-data in bytes. It doesn't make sense in itself as it
+ // cannot be accumulated over GCs. So must be divided by gc-count while
+ // reporting.
+ GetMetrics()->TotalGcMetaDataSize()->Add(rss);
#endif
return rss;
}
@@ -147,6 +153,7 @@
void GarbageCollector::Run(GcCause gc_cause, bool clear_soft_references) {
ScopedTrace trace(android::base::StringPrintf("%s %s GC", PrettyCause(gc_cause), GetName()));
Thread* self = Thread::Current();
+ Runtime* runtime = Runtime::Current();
uint64_t start_time = NanoTime();
uint64_t thread_cpu_start_time = ThreadCpuNanoTime();
GetHeap()->CalculatePreGcWeightedAllocatedBytes();
@@ -154,7 +161,7 @@
current_iteration->Reset(gc_cause, clear_soft_references);
// Note transaction mode is single-threaded and there's no asynchronous GC and this flag doesn't
// change in the middle of a GC.
- is_transaction_active_ = Runtime::Current()->IsActiveTransaction();
+ is_transaction_active_ = runtime->IsActiveTransaction();
RunPhases(); // Run all the GC phases.
GetHeap()->CalculatePostGcWeightedAllocatedBytes();
// Add the current timings to the cumulative timings.
@@ -188,8 +195,16 @@
pause_histogram_.AdjustAndAddValue(pause_time);
total_pause_time += pause_time;
}
+ metrics::ArtMetrics* metrics = runtime->GetMetrics();
// Report STW pause time in microseconds.
- GetMetrics()->MutatorPauseTimeDuringGC()->Add(total_pause_time / 1'000);
+ metrics->MutatorPauseTimeDuringGC()->Add(total_pause_time / 1'000);
+ if (metrics_gc_count_ != nullptr) {
+ metrics_gc_count_->Add(1);
+ }
+ if (gc_throughput_histogram_ != nullptr) {
+ // Report GC throughput in MB/s.
+ gc_throughput_histogram_->Add(current_iteration->GetEstimatedThroughput() / MB);
+ }
is_transaction_active_ = false;
}
diff --git a/runtime/gc/collector/garbage_collector.h b/runtime/gc/collector/garbage_collector.h
index 9158b4a..b42f189 100644
--- a/runtime/gc/collector/garbage_collector.h
+++ b/runtime/gc/collector/garbage_collector.h
@@ -158,6 +158,8 @@
Histogram<uint64_t> rss_histogram_;
Histogram<size_t> freed_bytes_histogram_;
metrics::MetricsBase<int64_t>* gc_time_histogram_;
+ metrics::MetricsBase<uint64_t>* metrics_gc_count_;
+ metrics::MetricsBase<int64_t>* gc_throughput_histogram_;
uint64_t total_thread_cpu_time_ns_;
uint64_t total_time_ns_;
uint64_t total_freed_objects_;
diff --git a/runtime/gc/heap-inl.h b/runtime/gc/heap-inl.h
index b557146..61378c9 100644
--- a/runtime/gc/heap-inl.h
+++ b/runtime/gc/heap-inl.h
@@ -214,6 +214,7 @@
} else {
DCHECK(!Runtime::Current()->HasStatsEnabled());
}
+ GetMetrics()->TotalBytesAllocated()->Add(bytes_allocated);
if (kInstrumented) {
if (IsAllocTrackingEnabled()) {
// allocation_records_ is not null since it never becomes null after allocation tracking is