heap: Migrate full GC cycle UMA metrics

Report full GC statistics to the Recorder API. These will be used by
Blink to populate UMA histograms. Existing UMA reporting in V8 remains
as is for now and will be removed in a followup.

With this CL, most full GC statistics are reported as part of
V8.GC.Cycle.*.Full.*. Also V8.GCMarkCompactReason is migrated to
V8.GC.Cycle.Reason.Full.

This CL goes together with:
https://chromium-review.googlesource.com/c/chromium/src/+/3353448

Bug: chromium:1154636
Change-Id: I199be75e75144a59e5f56a6872268d0ecad3a885
Reviewed-on: https://chromium-review.googlesource.com/c/v8/v8/+/3356195
Reviewed-by: Michael Lippautz <mlippautz@chromium.org>
Reviewed-by: Omer Katz <omerkatz@chromium.org>
Commit-Queue: Nikolaos Papaspyrou <nikolaos@chromium.org>
Cr-Commit-Position: refs/heads/main@{#79408}
This commit is contained in:
Nikolaos Papaspyrou 2022-03-08 18:05:58 +01:00 committed by V8 LUCI CQ
parent 9d3d5f224c
commit 924cc89384
4 changed files with 105 additions and 24 deletions

View File

@ -35,6 +35,7 @@ struct GarbageCollectionSizes {
};
struct GarbageCollectionFullCycle {
int reason = -1;
GarbageCollectionPhases total;
GarbageCollectionPhases total_cpp;
GarbageCollectionPhases main_thread;

View File

@ -479,7 +479,7 @@ void GCTracer::UpdateStatistics(GarbageCollector collector) {
}
RecordMutatorUtilization(current_.end_time,
duration + current_.incremental_marking_duration);
RecordGCSumCounters(duration);
RecordGCSumCounters();
ResetIncrementalMarkingCounters();
combined_mark_compact_speed_cache_ = 0.0;
FetchBackgroundMarkCompactCounters();
@ -1363,20 +1363,23 @@ void GCTracer::RecordGCPhasesHistograms(RecordGCPhasesInfo::Mode mode) {
}
}
void GCTracer::RecordGCSumCounters(double atomic_pause_duration) {
void GCTracer::RecordGCSumCounters() {
base::MutexGuard guard(&background_counter_mutex_);
const double overall_duration =
const double atomic_pause_duration = current_.scopes[Scope::MARK_COMPACTOR];
const double incremental_marking =
current_.incremental_marking_scopes[Scope::MC_INCREMENTAL_LAYOUT_CHANGE]
.duration +
current_.incremental_marking_scopes[Scope::MC_INCREMENTAL_START]
.duration +
current_.incremental_marking_scopes[Scope::MC_INCREMENTAL_SWEEPING]
.duration +
incremental_marking_duration_ +
current_.incremental_marking_scopes[Scope::MC_INCREMENTAL_FINALIZE]
.duration +
atomic_pause_duration;
.duration;
const double incremental_sweeping =
current_.incremental_marking_scopes[Scope::MC_INCREMENTAL_SWEEPING]
.duration;
const double overall_duration =
atomic_pause_duration + incremental_marking + incremental_sweeping;
const double background_duration =
background_counter_[Scope::MC_BACKGROUND_EVACUATE_COPY]
.total_duration_ms +
@ -1384,16 +1387,9 @@ void GCTracer::RecordGCSumCounters(double atomic_pause_duration) {
.total_duration_ms +
background_counter_[Scope::MC_BACKGROUND_MARKING].total_duration_ms +
background_counter_[Scope::MC_BACKGROUND_SWEEPING].total_duration_ms;
const double marking_duration =
current_.incremental_marking_scopes[Scope::MC_INCREMENTAL_LAYOUT_CHANGE]
.duration +
current_.incremental_marking_scopes[Scope::MC_INCREMENTAL_START]
.duration +
incremental_marking_duration_ +
current_.incremental_marking_scopes[Scope::MC_INCREMENTAL_FINALIZE]
.duration +
current_.scopes[Scope::MC_MARK];
const double atomic_marking_duration =
current_.scopes[Scope::MC_PROLOGUE] + current_.scopes[Scope::MC_MARK];
const double marking_duration = atomic_marking_duration + incremental_marking;
const double marking_background_duration =
background_counter_[Scope::MC_BACKGROUND_MARKING].total_duration_ms;
@ -1494,7 +1490,11 @@ void GCTracer::ReportFullCycleToRecorder() {
FlushBatchedIncrementalEvents(incremental_mark_batched_events_,
heap_->isolate());
}
v8::metrics::GarbageCollectionFullCycle event;
event.reason = static_cast<int>(current_.gc_reason);
// Managed C++ heap statistics:
if (cpp_heap) {
cpp_heap->GetMetricRecorder()->FlushBatchedIncrementalEvents();
const base::Optional<cppgc::internal::MetricRecorder::FullCycle>
@ -1522,7 +1522,87 @@ void GCTracer::ReportFullCycleToRecorder() {
event.main_thread_efficiency_cpp_in_bytes_per_us =
cppgc_event.main_thread_efficiency_in_bytes_per_us;
}
// TODO(chromium:1154636): Populate v8 metrics.
// Unified heap statistics:
const double atomic_pause_duration = current_.scopes[Scope::MARK_COMPACTOR];
const double incremental_marking =
current_.incremental_marking_scopes[Scope::MC_INCREMENTAL_LAYOUT_CHANGE]
.duration +
current_.incremental_marking_scopes[Scope::MC_INCREMENTAL_START]
.duration +
current_.incremental_marking_duration +
current_.incremental_marking_scopes[Scope::MC_INCREMENTAL_FINALIZE]
.duration;
const double incremental_sweeping =
current_.incremental_marking_scopes[Scope::MC_INCREMENTAL_SWEEPING]
.duration;
const double overall_duration =
atomic_pause_duration + incremental_marking + incremental_sweeping;
const double marking_background_duration =
current_.scopes[Scope::MC_BACKGROUND_MARKING];
const double sweeping_background_duration =
current_.scopes[Scope::MC_BACKGROUND_SWEEPING];
const double compact_background_duration =
current_.scopes[Scope::MC_BACKGROUND_EVACUATE_COPY] +
current_.scopes[Scope::MC_BACKGROUND_EVACUATE_UPDATE_POINTERS];
const double background_duration = marking_background_duration +
sweeping_background_duration +
compact_background_duration;
const double atomic_marking_duration =
current_.scopes[Scope::MC_PROLOGUE] + current_.scopes[Scope::MC_MARK];
const double marking_duration = atomic_marking_duration + incremental_marking;
const double weak_duration = current_.scopes[Scope::MC_CLEAR];
const double compact_duration = current_.scopes[Scope::MC_EVACUATE] +
current_.scopes[Scope::MC_FINISH] +
current_.scopes[Scope::MC_EPILOGUE];
const double atomic_sweeping_duration = current_.scopes[Scope::MC_SWEEP];
const double sweeping_duration =
atomic_sweeping_duration + incremental_sweeping;
event.main_thread_atomic.total_wall_clock_duration_in_us =
static_cast<int64_t>(atomic_pause_duration *
base::Time::kMicrosecondsPerMillisecond);
event.main_thread.total_wall_clock_duration_in_us = static_cast<int64_t>(
overall_duration * base::Time::kMicrosecondsPerMillisecond);
event.total.total_wall_clock_duration_in_us =
static_cast<int64_t>((overall_duration + background_duration) *
base::Time::kMicrosecondsPerMillisecond);
event.main_thread_atomic.mark_wall_clock_duration_in_us =
static_cast<int64_t>(atomic_marking_duration *
base::Time::kMicrosecondsPerMillisecond);
event.main_thread.mark_wall_clock_duration_in_us = static_cast<int64_t>(
marking_duration * base::Time::kMicrosecondsPerMillisecond);
event.total.mark_wall_clock_duration_in_us =
static_cast<int64_t>((marking_duration + marking_background_duration) *
base::Time::kMicrosecondsPerMillisecond);
event.main_thread_atomic.weak_wall_clock_duration_in_us =
event.main_thread.weak_wall_clock_duration_in_us =
event.total.weak_wall_clock_duration_in_us = static_cast<int64_t>(
weak_duration * base::Time::kMicrosecondsPerMillisecond);
event.main_thread_atomic.compact_wall_clock_duration_in_us =
event.main_thread.compact_wall_clock_duration_in_us =
static_cast<int64_t>(compact_duration *
base::Time::kMicrosecondsPerMillisecond);
event.total.compact_wall_clock_duration_in_us =
static_cast<int64_t>((compact_duration + compact_background_duration) *
base::Time::kMicrosecondsPerMillisecond);
event.main_thread_atomic.sweep_wall_clock_duration_in_us =
static_cast<int64_t>(atomic_sweeping_duration *
base::Time::kMicrosecondsPerMillisecond);
event.main_thread.sweep_wall_clock_duration_in_us = static_cast<int64_t>(
sweeping_duration * base::Time::kMicrosecondsPerMillisecond);
event.total.sweep_wall_clock_duration_in_us =
static_cast<int64_t>((sweeping_duration + sweeping_background_duration) *
base::Time::kMicrosecondsPerMillisecond);
// TODO(chromium:1154636): Populate the following:
// - event.main_thread_incremental
// - event.objects
// - event.memory
// - event.collection_rate_in_percent
// - event.efficiency_in_bytes_per_us
// - event.main_thread_efficiency_in_bytes_per_us
recorder->AddMainThreadEvent(event, GetContextId(heap_->isolate()));
}

View File

@ -440,7 +440,6 @@ class V8_EXPORT_PRIVATE GCTracer {
FRIEND_TEST(GCTracerTest, IncrementalScope);
FRIEND_TEST(GCTracerTest, IncrementalMarkingSpeed);
FRIEND_TEST(GCTracerTest, MutatorUtilization);
FRIEND_TEST(GCTracerTest, RecordGCSumHistograms);
FRIEND_TEST(GCTracerTest, RecordMarkCompactHistograms);
FRIEND_TEST(GCTracerTest, RecordScavengerHistograms);
@ -461,10 +460,10 @@ class V8_EXPORT_PRIVATE GCTracer {
void RecordMutatorUtilization(double mark_compactor_end_time,
double mark_compactor_duration);
// Overall time spent in mark compact within a given GC cycle. Exact
// accounting of events within a GC is not necessary which is why the
// recording takes place at the end of the atomic pause.
void RecordGCSumCounters(double atomic_pause_duration);
// Update counters for an entire full GC cycle. Exact accounting of events
// within a GC is not necessary which is why the recording takes place at the
// end of the atomic pause.
void RecordGCSumCounters();
double MonotonicallyIncreasingTimeInMs();

View File

@ -136,7 +136,6 @@ class Sweeper::IncrementalSweeperTask final : public CancelableTask {
void RunInternal() final {
VMState<GC> state(isolate_);
TRACE_EVENT_CALL_STATS_SCOPED(isolate_, "v8", "V8.Task");
sweeper_->incremental_sweeper_pending_ = false;
if (sweeper_->sweeping_in_progress()) {
@ -441,6 +440,8 @@ bool Sweeper::ConcurrentSweepSpace(AllocationSpace identity,
}
bool Sweeper::IncrementalSweepSpace(AllocationSpace identity) {
TRACE_GC_EPOCH(heap_->tracer(), GCTracer::Scope::MC_INCREMENTAL_SWEEPING,
ThreadKind::kMain);
if (Page* page = GetSweepingPageSafe(identity)) {
ParallelSweepPage(page, identity);
}