8227089: Add timing information for merging humongous remembered sets

Reviewed-by: sangheki, kbarrett
This commit is contained in:
Thomas Schatzl 2019-07-17 16:33:19 +02:00
parent ffe79a37c3
commit b4d014896a
6 changed files with 13 additions and 2 deletions

View File

@ -66,6 +66,8 @@ G1GCPhaseTimes::G1GCPhaseTimes(STWGCTimer* gc_timer, uint max_gc_threads) :
_gc_par_phases[WaitForStrongCLD] = new WorkerDataArray<double>(max_gc_threads, "Wait For Strong CLD (ms):");
_gc_par_phases[WeakCLDRoots] = new WorkerDataArray<double>(max_gc_threads, "Weak CLD Roots (ms):");
_gc_par_phases[MergeER] = new WorkerDataArray<double>(max_gc_threads, "Eager Reclaim (ms):");
_gc_par_phases[MergeRS] = new WorkerDataArray<double>(max_gc_threads, "Remembered Sets (ms):");
_merge_rs_merged_sparse = new WorkerDataArray<size_t>(max_gc_threads, "Merged Sparse:");
_gc_par_phases[MergeRS]->link_thread_work_items(_merge_rs_merged_sparse, MergeRSMergedSparse);
@ -250,9 +252,10 @@ void G1GCPhaseTimes::note_gc_end() {
// Make sure all slots are uninitialized since this thread did not seem to have been started
ASSERT_PHASE_UNINITIALIZED(GCWorkerEnd);
ASSERT_PHASE_UNINITIALIZED(ExtRootScan);
ASSERT_PHASE_UNINITIALIZED(MergeHCC);
ASSERT_PHASE_UNINITIALIZED(MergeER);
ASSERT_PHASE_UNINITIALIZED(MergeRS);
ASSERT_PHASE_UNINITIALIZED(OptMergeRS);
ASSERT_PHASE_UNINITIALIZED(MergeHCC);
ASSERT_PHASE_UNINITIALIZED(MergeLB);
ASSERT_PHASE_UNINITIALIZED(ScanHR);
ASSERT_PHASE_UNINITIALIZED(CodeRoots);
@ -432,6 +435,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[MergeER]);
debug_phase(_gc_par_phases[MergeRS]);
if (G1HotCardCache::default_use_cache()) {
debug_phase(_gc_par_phases[MergeHCC]);
@ -563,6 +567,7 @@ const char* G1GCPhaseTimes::phase_name(GCParPhases phase) {
"CMRefRoots",
"WaitForStrongCLD",
"WeakCLDRoots",
"MergeER",
"MergeRS",
"OptMergeRS",
"MergeLB",

View File

@ -60,6 +60,7 @@ class G1GCPhaseTimes : public CHeapObj<mtGC> {
CMRefRoots,
WaitForStrongCLD,
WeakCLDRoots,
MergeER,
MergeRS,
OptMergeRS,
MergeLB,

View File

@ -684,7 +684,8 @@ void G1Policy::record_collection_pause_end(double pause_time_ms, size_t heap_use
if (remset_cards_scanned > 10) {
double avg_time_remset_scan = ((average_time_ms(G1GCPhaseTimes::ScanHR) + average_time_ms(G1GCPhaseTimes::OptScanHR)) *
remset_cards_scanned / total_cards_scanned) +
average_time_ms(G1GCPhaseTimes::MergeRS);
average_time_ms(G1GCPhaseTimes::MergeER) +
average_time_ms(G1GCPhaseTimes::MergeRS);
cost_per_remset_card_ms = avg_time_remset_scan / remset_cards_scanned;
_analytics->report_cost_per_remset_card_ms(cost_per_remset_card_ms, this_pause_was_young_only);

View File

@ -1105,6 +1105,8 @@ public:
!_fast_reclaim_handled &&
!Atomic::cmpxchg(true, &_fast_reclaim_handled, false)) {
G1GCParPhaseTimesTracker x(p, G1GCPhaseTimes::MergeER, worker_id);
G1FlushHumongousCandidateRemSets cl(_scan_state);
g1h->heap_region_iterate(&cl);

View File

@ -98,6 +98,7 @@ public class TestGCLogMessages {
// Merge Heap Roots
new LogMessageWithLevel("Merge Heap Roots", Level.INFO),
new LogMessageWithLevel("Prepare Merge Heap Roots", Level.DEBUG),
new LogMessageWithLevel("Eager Reclaim", Level.DEBUG),
new LogMessageWithLevel("Remembered Sets", Level.DEBUG),
new LogMessageWithLevel("Merged Sparse", Level.DEBUG),
new LogMessageWithLevel("Merged Fine", Level.DEBUG),

View File

@ -100,6 +100,7 @@ public class TestG1ParallelPhases {
"CMRefRoots",
"WaitForStrongCLD",
"WeakCLDRoots",
"MergeER",
"MergeHCC",
"MergeRS",
"MergeLB",