8227084: Add timing information for merge heap root preparation
Reviewed-by: sangheki, kbarrett
--- a/src/hotspot/share/gc/g1/g1CollectedHeap.cpp Wed Jul 17 16:33:19 2019 +0200
+++ b/src/hotspot/share/gc/g1/g1CollectedHeap.cpp Wed Jul 17 16:33:19 2019 +0200
@@ -3683,7 +3683,7 @@
{
Ticks start = Ticks::now();
- rem_set()->merge_heap_roots(false /* remset_only */, G1GCPhaseTimes::MergeRS);
+ rem_set()->merge_heap_roots(true /* initial_evacuation */);
p->record_merge_heap_roots_time((Ticks::now() - start).seconds() * 1000.0);
}
@@ -3759,7 +3759,7 @@
{
Ticks start = Ticks::now();
- rem_set()->merge_heap_roots(true /* remset_only */, G1GCPhaseTimes::OptMergeRS);
+ rem_set()->merge_heap_roots(false /* initial_evacuation */);
phase_times()->record_or_add_optional_merge_heap_roots_time((Ticks::now() - start).seconds() * 1000.0);
}
--- a/src/hotspot/share/gc/g1/g1GCPhaseTimes.cpp Wed Jul 17 16:33:19 2019 +0200
+++ b/src/hotspot/share/gc/g1/g1GCPhaseTimes.cpp Wed Jul 17 16:33:19 2019 +0200
@@ -166,6 +166,8 @@
_cur_strong_code_root_purge_time_ms = 0.0;
_cur_merge_heap_roots_time_ms = 0.0;
_cur_optional_merge_heap_roots_time_ms = 0.0;
+ _cur_prepare_merge_heap_roots_time_ms = 0.0;
+ _cur_optional_prepare_merge_heap_roots_time_ms = 0.0;
_cur_evac_fail_recalc_used = 0.0;
_cur_evac_fail_remove_self_forwards = 0.0;
_cur_string_deduplication_time_ms = 0.0;
@@ -413,6 +415,8 @@
const double sum_ms = _cur_optional_evac_ms + _cur_optional_merge_heap_roots_time_ms;
if (sum_ms > 0) {
info_time("Merge Optional Heap Roots", _cur_optional_merge_heap_roots_time_ms);
+
+ debug_time("Prepare Optional Merge Heap Roots", _cur_optional_prepare_merge_heap_roots_time_ms);
debug_phase(_gc_par_phases[OptMergeRS]);
info_time("Evacuate Optional Collection Set", _cur_optional_evac_ms);
@@ -427,6 +431,7 @@
double G1GCPhaseTimes::print_evacuate_initial_collection_set() const {
info_time("Merge Heap Roots", _cur_merge_heap_roots_time_ms);
+ debug_time("Prepare Merge Heap Roots", _cur_prepare_merge_heap_roots_time_ms);
debug_phase(_gc_par_phases[MergeRS]);
if (G1HotCardCache::default_use_cache()) {
debug_phase(_gc_par_phases[MergeHCC]);
--- a/src/hotspot/share/gc/g1/g1GCPhaseTimes.hpp Wed Jul 17 16:33:19 2019 +0200
+++ b/src/hotspot/share/gc/g1/g1GCPhaseTimes.hpp Wed Jul 17 16:33:19 2019 +0200
@@ -164,6 +164,9 @@
double _cur_merge_heap_roots_time_ms;
double _cur_optional_merge_heap_roots_time_ms;
+ double _cur_prepare_merge_heap_roots_time_ms;
+ double _cur_optional_prepare_merge_heap_roots_time_ms;
+
double _cur_prepare_tlab_time_ms;
double _cur_resize_tlab_time_ms;
@@ -308,6 +311,14 @@
_cur_optional_merge_heap_roots_time_ms += ms;
}
+ void record_prepare_merge_heap_roots_time(double ms) {
+ _cur_prepare_merge_heap_roots_time_ms += ms;
+ }
+
+ void record_or_add_optional_prepare_merge_heap_roots_time(double ms) {
+ _cur_optional_prepare_merge_heap_roots_time_ms += ms;
+ }
+
void record_evac_fail_recalc_used_time(double ms) {
_cur_evac_fail_recalc_used = ms;
}
--- a/src/hotspot/share/gc/g1/g1RemSet.cpp Wed Jul 17 16:33:19 2019 +0200
+++ b/src/hotspot/share/gc/g1/g1RemSet.cpp Wed Jul 17 16:33:19 2019 +0200
@@ -1078,28 +1078,29 @@
HeapRegionClaimer _hr_claimer;
G1RemSetScanState* _scan_state;
- bool _remembered_set_only;
-
- G1GCPhaseTimes::GCParPhases _merge_phase;
+ bool _initial_evacuation;
volatile bool _fast_reclaim_handled;
public:
- G1MergeHeapRootsTask(G1RemSetScanState* scan_state, uint num_workers, bool remembered_set_only, G1GCPhaseTimes::GCParPhases merge_phase) :
+ G1MergeHeapRootsTask(G1RemSetScanState* scan_state, uint num_workers, bool initial_evacuation) :
AbstractGangTask("G1 Merge Heap Roots"),
_hr_claimer(num_workers),
_scan_state(scan_state),
- _remembered_set_only(remembered_set_only),
- _merge_phase(merge_phase),
+ _initial_evacuation(initial_evacuation),
_fast_reclaim_handled(false) { }
virtual void work(uint worker_id) {
G1CollectedHeap* g1h = G1CollectedHeap::heap();
G1GCPhaseTimes* p = g1h->phase_times();
+ G1GCPhaseTimes::GCParPhases merge_remset_phase = _initial_evacuation ?
+ G1GCPhaseTimes::MergeRS :
+ G1GCPhaseTimes::OptMergeRS;
+
// We schedule flushing the remembered sets of humongous fast reclaim candidates
// onto the card table first to allow the remaining parallelized tasks hide it.
- if (!_remembered_set_only &&
+ if (_initial_evacuation &&
p->fast_reclaim_humongous_candidates() > 0 &&
!_fast_reclaim_handled &&
!Atomic::cmpxchg(true, &_fast_reclaim_handled, false)) {
@@ -1107,33 +1108,33 @@
G1FlushHumongousCandidateRemSets cl(_scan_state);
g1h->heap_region_iterate(&cl);
- p->record_or_add_thread_work_item(_merge_phase, worker_id, cl.merged_sparse(), G1GCPhaseTimes::MergeRSMergedSparse);
- p->record_or_add_thread_work_item(_merge_phase, worker_id, cl.merged_fine(), G1GCPhaseTimes::MergeRSMergedFine);
- p->record_or_add_thread_work_item(_merge_phase, worker_id, cl.merged_coarse(), G1GCPhaseTimes::MergeRSMergedCoarse);
+ p->record_or_add_thread_work_item(merge_remset_phase, worker_id, cl.merged_sparse(), G1GCPhaseTimes::MergeRSMergedSparse);
+ p->record_or_add_thread_work_item(merge_remset_phase, worker_id, cl.merged_fine(), G1GCPhaseTimes::MergeRSMergedFine);
+ p->record_or_add_thread_work_item(merge_remset_phase, worker_id, cl.merged_coarse(), G1GCPhaseTimes::MergeRSMergedCoarse);
}
// Merge remembered sets of current candidates.
{
- G1GCParPhaseTimesTracker x(p, _merge_phase, worker_id, !_remembered_set_only /* must_record */);
+ G1GCParPhaseTimesTracker x(p, merge_remset_phase, worker_id, _initial_evacuation /* must_record */);
G1MergeCardSetClosure cl(_scan_state);
g1h->collection_set_iterate_increment_from(&cl, &_hr_claimer, worker_id);
- p->record_or_add_thread_work_item(_merge_phase, worker_id, cl.merged_sparse(), G1GCPhaseTimes::MergeRSMergedSparse);
- p->record_or_add_thread_work_item(_merge_phase, worker_id, cl.merged_fine(), G1GCPhaseTimes::MergeRSMergedFine);
- p->record_or_add_thread_work_item(_merge_phase, worker_id, cl.merged_coarse(), G1GCPhaseTimes::MergeRSMergedCoarse);
+ p->record_or_add_thread_work_item(merge_remset_phase, worker_id, cl.merged_sparse(), G1GCPhaseTimes::MergeRSMergedSparse);
+ p->record_or_add_thread_work_item(merge_remset_phase, worker_id, cl.merged_fine(), G1GCPhaseTimes::MergeRSMergedFine);
+ p->record_or_add_thread_work_item(merge_remset_phase, worker_id, cl.merged_coarse(), G1GCPhaseTimes::MergeRSMergedCoarse);
}
// Apply closure to log entries in the HCC.
- if (!_remembered_set_only && G1HotCardCache::default_use_cache()) {
- assert(_merge_phase == G1GCPhaseTimes::MergeRS, "Wrong merge phase");
+ if (_initial_evacuation && G1HotCardCache::default_use_cache()) {
+ assert(merge_remset_phase == G1GCPhaseTimes::MergeRS, "Wrong merge phase");
G1GCParPhaseTimesTracker x(p, G1GCPhaseTimes::MergeHCC, worker_id);
G1MergeLogBufferCardsClosure cl(g1h, _scan_state);
g1h->iterate_hcc_closure(&cl, worker_id);
}
// Now apply the closure to all remaining log entries.
- if (!_remembered_set_only) {
- assert(_merge_phase == G1GCPhaseTimes::MergeRS, "Wrong merge phase");
+ if (_initial_evacuation) {
+ assert(merge_remset_phase == G1GCPhaseTimes::MergeRS, "Wrong merge phase");
G1GCParPhaseTimesTracker x(p, G1GCPhaseTimes::MergeLB, worker_id);
G1MergeLogBufferCardsClosure cl(g1h, _scan_state);
@@ -1162,19 +1163,30 @@
percent_of(num_visited_cards, total_old_region_cards));
}
-void G1RemSet::merge_heap_roots(bool remembered_set_only, G1GCPhaseTimes::GCParPhases merge_phase) {
+void G1RemSet::merge_heap_roots(bool initial_evacuation) {
+ G1CollectedHeap* g1h = G1CollectedHeap::heap();
+
{
+ Ticks start = Ticks::now();
+
_scan_state->prepare_for_merge_heap_roots();
+
+ Tickspan total = Ticks::now() - start;
+ if (initial_evacuation) {
+ g1h->phase_times()->record_prepare_merge_heap_roots_time(total.seconds() * 1000.0);
+ } else {
+ g1h->phase_times()->record_or_add_optional_prepare_merge_heap_roots_time(total.seconds() * 1000.0);
+ }
}
- WorkGang* workers = G1CollectedHeap::heap()->workers();
- size_t const increment_length = G1CollectedHeap::heap()->collection_set()->increment_length();
+ WorkGang* workers = g1h->workers();
+ size_t const increment_length = g1h->collection_set()->increment_length();
- uint const num_workers = !remembered_set_only ? workers->active_workers() :
- MIN2(workers->active_workers(), (uint)increment_length);
+ uint const num_workers = initial_evacuation ? workers->active_workers() :
+ MIN2(workers->active_workers(), (uint)increment_length);
{
- G1MergeHeapRootsTask cl(_scan_state, num_workers, remembered_set_only, merge_phase);
+ G1MergeHeapRootsTask cl(_scan_state, num_workers, initial_evacuation);
log_debug(gc, ergo)("Running %s using %u workers for " SIZE_FORMAT " regions",
cl.name(), num_workers, increment_length);
workers->run_task(&cl, num_workers);
--- a/src/hotspot/share/gc/g1/g1RemSet.hpp Wed Jul 17 16:33:19 2019 +0200
+++ b/src/hotspot/share/gc/g1/g1RemSet.hpp Wed Jul 17 16:33:19 2019 +0200
@@ -95,8 +95,8 @@
// Merge cards from various sources (remembered sets, hot card cache, log buffers)
// and calculate the cards that need to be scanned later (via scan_heap_roots()).
- // If remembered_set_only is set, only merge remembered set cards.
- void merge_heap_roots(bool remembered_set_only, G1GCPhaseTimes::GCParPhases merge_phase);
+ // If initial_evacuation is set, this is called during the initial evacuation.
+ void merge_heap_roots(bool initial_evacuation);
// Prepare for and cleanup after scanning the heap roots. Must be called
// once before and after in sequential code.
--- a/test/hotspot/jtreg/gc/g1/TestGCLogMessages.java Wed Jul 17 16:33:19 2019 +0200
+++ b/test/hotspot/jtreg/gc/g1/TestGCLogMessages.java Wed Jul 17 16:33:19 2019 +0200
@@ -97,6 +97,7 @@
// Merge Heap Roots
new LogMessageWithLevel("Merge Heap Roots", Level.INFO),
+ new LogMessageWithLevel("Prepare Merge Heap Roots", Level.DEBUG),
new LogMessageWithLevel("Remembered Sets", Level.DEBUG),
new LogMessageWithLevel("Merged Sparse", Level.DEBUG),
new LogMessageWithLevel("Merged Fine", Level.DEBUG),