8227089: Add timing information for merging humongous remembered sets
Reviewed-by: sangheki, kbarrett
--- 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
@@ -66,6 +66,8 @@
_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 @@
// 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 @@
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 @@
"CMRefRoots",
"WaitForStrongCLD",
"WeakCLDRoots",
+ "MergeER",
"MergeRS",
"OptMergeRS",
"MergeLB",
--- 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
@@ -60,6 +60,7 @@
CMRefRoots,
WaitForStrongCLD,
WeakCLDRoots,
+ MergeER,
MergeRS,
OptMergeRS,
MergeLB,
--- a/src/hotspot/share/gc/g1/g1Policy.cpp Wed Jul 17 16:33:19 2019 +0200
+++ b/src/hotspot/share/gc/g1/g1Policy.cpp Wed Jul 17 16:33:19 2019 +0200
@@ -684,7 +684,8 @@
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);
--- 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
@@ -1105,6 +1105,8 @@
!_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);
--- 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
@@ -98,6 +98,7 @@
// 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),
--- a/test/jdk/jdk/jfr/event/gc/collection/TestG1ParallelPhases.java Wed Jul 17 16:33:19 2019 +0200
+++ b/test/jdk/jdk/jfr/event/gc/collection/TestG1ParallelPhases.java Wed Jul 17 16:33:19 2019 +0200
@@ -100,6 +100,7 @@
"CMRefRoots",
"WaitForStrongCLD",
"WeakCLDRoots",
+ "MergeER",
"MergeHCC",
"MergeRS",
"MergeLB",